User-ID Redistribution Agent : Close Connection to Agent

[tanmay_lemoriya]

I am getting high severity alerts for user id connection agent Failure - Redistribution Agent <Agent Name> (Vsys1):Close Connection to Agent. Would appreciate if anyone can help me understand the log to check if the issue occurred due to firewall or by someone did it manually.  If occurred on its own, then what could be the reason.

When i checked the user agent status, They are connected & reachable through ping as well.

While checking the useridd.logs, i could observe below errors.

2023-10-27 10:02:53.327 +0700 Error:  pan_user_id_agent_send_and_recv_msgs(pan_user_id_agent.c:4126): pan_user_msgs_recv() failed
2023-10-27 10:02:53.327 +0700 Error:  pan_user_id_agent_uia_proc_v5(pan_user_id_uia_v5.c:1254): pan_user_id_agent_send_and_recv_msgs() failed for <Agent Name>
2023-10-27 10:02:53.327 +0700 Error:  pan_user_id_agent_send_and_recv_msgs(pan_user_id_agent.c:4126): pan_user_msgs_recv() failed
2023-10-27 10:02:53.327 +0700 Error:  pan_user_id_agent_uia_proc_v5(pan_user_id_uia_v5.c:1254): pan_user_id_agent_send_and_recv_msgs() failed for <Agent Name>
2023-10-27 10:02:53.327 +0700 [agent name] useridd notify dist to reconnect
2023-10-27 10:02:53.327 +0700 [agent name] useridd notify dist to reconnect

While checking the distributord.logs, i could observe below errors.

2023-10-27 10:02:53.327 +0700 [agent My_Agent]vsys1 useridd requests reconnection
2023-10-27 10:02:53.328 +0700 [agent My_Agent] reset version to 6 to reconnect
2023-10-27 10:02:53.328 +0700 [agent My_Agent]vsys2 useridd requests reconnection
2023-10-27 10:02:53.328 +0700 2023-10-27 10:02:53.328 +0700 [agent My_Agent] reset version to 6 to reconnect
Error:  pan_distributor_agents_proc(pan_distributor_agent.c:3246): hasn't heard from My_Agent(1) for 540798 seconds
2023-10-27 10:02:53.328 +0700 Error:  pan_distributor_agents_proc(pan_distributor_agent.c:3246): hasn't heard from My_Agent(2) for 540798 seconds
2023-10-27 10:02:58.058 +0700 2023-10-27 10:02:58.058 +0700 [agent My_Agent] DCOM_SSL_CLNT_CONFIG
[agent My_Agent] DCOM_SSL_CLNT_CONFIG
2023-10-27 10:02:58.062 +0700 2023-10-27 10:02:58.062 +0700 [agent My_Agent] no service route available. Use default.
[agent My_Agent] no service route available. Use default.
2023-10-27 10:02:58.062 +0700 2023-10-27 10:02:58.062 +0700 add new conn My_Agent to dcom, fd = 1027, addr = ssl@X.X.X.X#5007
add new conn My_Agent to dcom, fd = 1028, addr = ssl@X.X.X.X#5007
2023-10-27 10:02:58.062 +0700 conn My_Agent is not connected.
2023-10-27 10:02:58.062 +0700 2023-10-27 10:02:58.062 +0700 conn My_Agent is not connected.
add socket fd 1027(My_Agent) into epoll 2 [prev total fds: 0, jobid: 0].
2023-10-27 10:02:58.062 +0700 add socket fd 1028(My_Agent) into epoll 3 [prev total fds: 0, jobid: 0].
2023-10-27 10:02:58.062 +0700 agent My_Agent didn't establish secure communication yet
2023-10-27 10:02:58.062 +0700 agent My_Agent didn't establish secure communication yet
2023-10-27 10:02:58.062 +0700 2023-10-27 10:02:58.062 +0700 pan_dcom_epoll: start epoll thread 3 at 1698375778(epoch: 1698375778)
pan_dcom_epoll: start epoll thread 2 at 1698375778(epoch: 1698375778)
2023-10-27 10:02:58.083 +0700 [agent My_Agent] DCOM_SSL_CLNT_PRE_CONN
2023-10-27 10:02:58.085 +0700 [agent My_Agent] DCOM_SSL_CLNT_PRE_CONN
2023-10-27 10:02:59.660 +0700 Error:  pan_dcom_ssl_connect(pan_dcom_ssl.c:331): conn My_Agent: SSL_connect return -1
2023-10-27 10:02:59.660 +0700 Error:  pan_dcom_ssl_connect(pan_dcom_ssl.c:332): SSL :error:00000000:lib(0):func(0):reason(0)
2023-10-27 10:02:59.660 +0700 Error:  pan_dcom_app_notify_callback(pan_dcom_sock.c:450): conn My_Agent failed in ssl notify
2023-10-27 10:02:59.660 +0700 conn My_Agent is not connected yet, err = 0
2023-10-27 10:02:59.660 +0700 close socket fd 1027(My_Agent)
2023-10-27 10:02:59.660 +0700 close conn My_Agent, same thread 0, b_notifying 0
2023-10-27 10:02:59.660 +0700 conn My_Agent has been closed by application[event=6]

System Logs:

2023/10/27 10:04:16 high     userid         connect 0  Redistribution Agent My_Agent(vsys2):  details: close connection to agent
2023/10/27 10:04:16 high     userid         connect 0  Redistribution Agent My_Agent(vsys1):  details: close connection to agent
2023/10/27 10:04:11 info     userid         disconn 0  User-ID-Agent My_Agent disconnected: IP X.X.X.X, port 5007 vsys2
2023/10/27 10:04:11 info     userid         disconn 0  User-ID-Agent My_Agent disconnected: IP X.X.X.X, port 5007 vsys1

[JayGolf]

Hi @tanmay.lemoriya ,

Please follow the steps in this KB to troubleshoot.

[Rahul.Balan]

did t get resolved if so how ?

[Rahul.Balan]

did t get resolved if so how ?

[tanmay_lemoriya]

The issue is still there & not resolved.

[WillyHarivonjy]

Hi, did you get to resolve this issue? I have the same behavior on my side try some steps but still having the issue.

Seems to be related to the certificate but not sure.

[Claw4609]

@WillyHarivonjy Did yours just start happening in the last few days? Cause Im assuming you need to update your firewalls and/or user id agent(s)

Refer to customer advisory: LIVEcommunity - Additional PAN-OS Certificate Expirations and New, Comprehensive Certificate Managem...

[WillyHarivonjy]

@Claw4609 This is a new deployment, I have the same software version on all my managed firewalls. And I only have the issue on 4 clusters out of 45 clusters. I think I'm not impacted by this article.

[Claw4609]

What PAN-OS version are you using? And are you using the built-in user-id agent or are you using the Windows user-id agent? If the Windows user-id agent, what version are you using?

[WillyHarivonjy]

Ok, my

- Panorama is on PanOS 10.2.8,

- all managed devices are on PanOS version 10.1.11-h4 (this is affected by the certificate advisory) but they have the last dynamic updates that replace the certificate with the one that expires on November 2024 as per this article https://live.paloaltonetworks.com/t5/customer-advisories/additional-pan-os-certificate-expirations-a...
- all managed firewalls are rebooted as per the recommendation on the certificate advisory, we expect to upgrade all firewalls to the target version that fixes the certificate expiration permanently before Nov 2024

- All managed firewall redistribute their user-id mapping to the Panorama and then the Panorama acts as a redistribution collector and shares all collected user-id to other firewalls.

-  So basically, each firewall acts as a user-id agent for the Panorama, and the Panorama also acts as a user-id agent for some sites as it collects all user-ip mapping for several sites

- The issue is some sites can connect to the Panorama as redistribution agents but some of them are not, on the logs the issue is related to SSL communication :

2024-04-09 16:26:15.820 +0200 Error: pan_dcom_ssl_read(pan_dcom_ssl.c:399): conn firewall01: SSSL_read() read a closure alert, nread 0 err 6

2024-04-09 16:26:15.820 +0200 Error: pan_dcom_ssl_write(pan_dcom_ssl.c:450): conn firewall01: ssl return 6, disconnect it
2024-04-09 16:26:15.820 +0200 Error: pan_dcom_sock_xmit(pan_dcom_sock.c:1423): failed to send message on firewall01, len = 2, err -1
2024-04-09 16:26:15.820 +0200 Error: pan_dcom_ssl_write(pan_dcom_ssl.c:449): SSL :error:1409F07F:SSL routines:ssl3_write_pending:bad write retry
2024-04-09 16:26:15.820 +0200 Error: pan_dcom_ssl_write(pan_dcom_ssl.c:450): conn firewall01: ssl return 1, disconnect it