Reason for Solace CLIENT_CLIENT_DISCONNECT

dreamoka
dreamoka Member Posts: 56 ✭✭✭
edited May 2022 in PubSub+ Event Broker #1

Recently some of the microservice AMQP applications are disconnected based on the solace event logs. However, the microservice AMQP applications did not detect any "CONNECTION_CLOSE" event. And, the applications did not trigger DISCONNECT action.

Is there any documentation of the reasons and the explanation for the causes of them? How to troubleshoot to find more information? Why the application did not appear in the Client -> AMQP List?

  • K8s : Using Microk8s (3 Nodes)
  • Microservices Application : Using NodeJS (AMQP-PROMISE)
  • Solace : Using Docker-Compose (Version 9.12.1.17) - Outside the K8s Cluster


2022-05-21T01:00:10.139+00:00 <local3.notice> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_UNBIND: default #amqp/client/cc91953864d36d09/food-input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb Client (59) #amqp/client/cc91953864d36d09/food-in
put-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb username testAccount Unbind to Flow Id (78), ForwardingMode(StoreAndForward), final statistics - flow(255, 0, 0, 0, 0, 0, 0, 0, 2997, 0), isActive(No), Reason(Client disconnected)
2022-05-21T01:00:10.141+00:00 <local3.info> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_DISCONNECT: default #amqp/client/cc91953864d36d09/food-input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb Client (59) #amqp/client/cc91953864d36d09/food-
input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb username testAccount WebSessionId (N/A) reason(Peer TCP Reset) final statistics - dp(104, 2955, 2951, 2997, 3055, 5952, 6915, 118733, 3991887, 1496290, 3998802, 1615023, 0, 0, 0, 0, 0, 0, 0,
 0, 0, 0) conn(0, 0, 192.168.105.161:60776, CLOSD, 0, 0, 0) zip(0, 0, 0, 0, 0.00, 0.00, 0, 0, 0, 0, 0, 0, 0, 0) web(0, 0, 0, 0, 0, 0, 0), SslVersion(), SslCipher()
2022-05-21T01:00:10.613+00:00 <local3.info> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_DISCONNECT: default #amqp/client/26253499ce1fbce5/a2c7ad9b-540d-4116-85cf-e8dfe8d43d71 Client (4) #amqp/client/26253499ce1fbce5/a2c7ad9b-540d-4116-85cf
-e8dfe8d43d71 username testAccount WebSessionId (N/A) reason(Peer TCP Reset) final statistics - dp(2, 2, 0, 0, 2, 2, 223, 401, 0, 0, 223, 401, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.105.161:38101, CLOSD, 0, 0, 0) zip(0, 0, 0, 0, 0.
00, 0.00, 0, 0, 0, 0, 0, 0, 0, 0) web(0, 0, 0, 0, 0, 0, 0), SslVersion(), SslCipher()
2022-05-21T01:00:13.141+00:00 <local3.info> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_CLOSE_FLOW: default #amqp/client/cc91953864d36d09/food-input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb Client (59) #amqp/client/cc91953864d36d09/food-
input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb username testAccount Pub flow session flow name 8b608e84651042bbaa485cdea5fd00ef (7), transacted session id -1, publisher id 6, last message id 4573, window size 247, final statistics - flow
(0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 2951)
2022-05-21T01:01:10.158+00:00 <local3.notice> 031cdc6fee4f event: VPN: VPN_AD_QENDPT_DELETE: default - Message VPN (0) Topic Endpoint food-input-adaptor/d874f7c9-9620-2243-b12f-3fe039a4f1eb/food-input-adaptor deleted, final statistics - sp
ool(145051, 145023, 145051, 0, 0, 0, 1202584, 2997) bind(1, 1, 0, 0, 0)
2022-05-21T01:31:46.979+00:00 <local3.notice> 031cdc6fee4f event: SYSTEM: SYSTEM_AUTHENTICATION_SESSION_OPENED: - - SEMP session 192.168.7.1-48 internal authentication opened for user localAccount (admin)
2022-05-21T01:35:13.360+00:00 <local3.notice> 031cdc6fee4f event: SYSTEM: SYSTEM_AUTHENTICATION_SESSION_OPENED: - - CLI session pts/0 [10572] internal authentication opened for user appuser (appuser)


After a while

2022-05-21T01:51:36.127+00:00 <local3.notice> 031cdc6fee4f event: VPN: VPN_AD_QENDPT_CREATE: default - Message VPN (0) Topic Endpoint food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4/food-input-adaptor created
2022-05-21T01:51:36.130+00:00 <local3.notice> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_BIND_SUCCESS: default #amqp/client/4b2080ad03c99e16/food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 Client (87) #amqp/client/4b2080ad03c99e16/
food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 username testAccount Bind to Non-Durable Topic Endpoint food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4/food-input-adaptor Topic(caas/food/input), AccessType(Exclusive), Quota(5000M
B), MaxMessageSize(10000000B), AllOthersPermission(No-Access), RespectTTL(No), RejectMsgToSenderOnDiscard(No), ReplayFrom(N/A), GrantedPermission(Read|Consume|Modify-Topic|Delete), FlowType(Consumer-Redelivery), FlowId(85), ForwardingMod
e(StoreAndForward), MaxRedelivery(0), TransactedSessionId(-1) completed
2022-05-21T01:51:39.692+00:00 <local3.notice> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_UNBIND: default #amqp/client/4b2080ad03c99e16/food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 Client (87) #amqp/client/4b2080ad03c99e16/food-in
put-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 username testAccount Unbind to Flow Id (85), ForwardingMode(StoreAndForward), final statistics - flow(1, 0, 0, 0, 0, 0, 0, 0, 0, 0), isActive(No), Reason(Client disconnected)
2022-05-21T01:51:39.693+00:00 <local3.info> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_DISCONNECT: default #amqp/client/4b2080ad03c99e16/food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 Client (87) #amqp/client/4b2080ad03c99e16/food-
input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 username testAccount WebSessionId (N/A) reason(Peer TCP Reset) final statistics - dp(5, 4, 0, 0, 5, 4, 417, 693, 0, 0, 417, 693, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.7.1:63510, C
LOSD, 0, 0, 0) zip(0, 0, 0, 0, 0.00, 0.00, 0, 0, 0, 0, 0, 0, 0, 0) web(0, 0, 0, 0, 0, 0, 0), SslVersion(), SslCipher()
2022-05-21T01:51:42.693+00:00 <local3.info> 031cdc6fee4f event: CLIENT: CLIENT_CLIENT_CLOSE_FLOW: default #amqp/client/4b2080ad03c99e16/food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 Client (87) #amqp/client/4b2080ad03c99e16/food-
input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4 username testAccount Pub flow session flow name 9ad69d02d736443489115e34529e6e68 (22), transacted session id -1, publisher id 21, last message id 1544, window size 247, final statistics - fl
ow(0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0)
2022-05-21T01:51:42.818+00:00 <local3.notice> 031cdc6fee4f event: SYSTEM: SYSTEM_AUTHENTICATION_SESSION_CLOSED: - - CLI session pts/0 [10572] closed for user appuser (appuser)
2022-05-21T01:52:39.712+00:00 <local3.notice> 031cdc6fee4f event: VPN: VPN_AD_QENDPT_DELETE: default - Message VPN (0) Topic Endpoint food-input-adaptor/703ee98b-f552-a94f-bb00-7b59cf576ae4/food-input-adaptor deleted, final statistics - sp
ool(0, 0, 0, 0, 0, 0, 0, 0) bind(1, 1, 0, 0, 0)
....


Tagged:

Comments

  • uherbst
    uherbst Member, Employee Posts: 129 Solace Employee
    #2

    Hi @dreamoka ,


    The event.log says "Peer TCP Reset"... that means, the broker received a TCP RST packet from the client ip.

    MAYBE this is caused by some network equipment / firewall.

    The (hard) way to debug this is to run tcpdump on both sides (application and broker) and check both pcap traces.

    If you run your broker in k8s (as you said), you have to run tcpdump on the node, where the broker pod is running.


    Uli

  • dreamoka
    dreamoka Member Posts: 56 ✭✭✭
    edited May 2022 #3

    Hi @uherbst

    Sorry. The Broker is running outside my K8s Cluster. It was run in the virtual machine using Docker Compose in Solace PubSub+

    K8s Cluster

    • Node 1 : Two Pods - Pod 1 : Application A - food-input-adaptor (Issue) , Pod 2 : Application B (Issue). Application A -> Health Check Application API -> found out the conn-> is_open -> return true.
    • Node 2 : Three Pod - Pod 1 : Application C (No issue), Pod 2 : Application D (No Issue), Pod 3 - Application E (No issue)
    • Node 3: One Pod - Pod 1: Application F (No Issue),

    Only Node 1 has issue (Event Portal did not show Application A and B Client - In Client -> AMQP Tab). Application C, D , E and F found in the Client-> AMQP Tab in the Event Portal.

    Initially the application A and B can connect to message broker , accept message and send message without any issue. After 8 hours ++ of inactivity of application A and B, I checked the Event Portal and found out the application A and B missing from the Client List.

    Just curious, normally, what cause client to send TCP RST packet? What should i look in the tcpdump?

  • dreamoka
    dreamoka Member Posts: 56 ✭✭✭
    #4

    Another curious question, does solace message broker implement TCP-Keep Alive for AMQP connection?

Categories

This Month's Leaders

This Week's Leaders