search

skupperproject / skupper

Skupper is an implementation of a Virtual Application Network, enabling rich hybrid cloud communication.
http://skupper.io
Apache License 2.0
589 stars 73 forks source link

Frequent "Link Lost" in skupper-router logs #988

Open sahil87 opened 1 year ago

sahil87 commented 1 year ago

Hi, after the update to Skupper Controller 1.2.0, we are seeing a high frequency of "List Lost" and "PN_RAW_CONNECTION_DISCONNECTED" messages in the skupper-router logs.

Is this a cause for concern?

The logs keep flowing very fast. (frequent PN_RAW_CONNECTION_DISCONNECTED followed by "Link attached" messages.)

image

The number of network-related errors has also increased in our app, but it is difficult to pinpoint if it's happening because of this.

ted-ross commented 1 year ago

The "link lost" logs are normal when a connection is dropped. The increased frequency of these in your application is probably not normal. Is there any error indication in the "FLOW_LOG (info) FLOW ..." line in the logs? The latter part is truncated in your attached image.

-Ted

On Wed, Jan 11, 2023 at 2:50 AM Sahil Ahuja @.***> wrote:

Hi, after the update to Skupper 1.2.0, we are seeing a high frequency of "List Lost" and "PN_RAW_CONNECTION_DISCONNECTED" messages in Skupper Router.

Is this a cause for concern?

The logs keep flowing very fast. (frequent PN_RAW_CONNECTION_DISCONNECTED followed by "Link attached" messages.

[image: image] https://user-images.githubusercontent.com/9037064/211745904-0dd1a87f-c4ba-4f19-b95b-6e5bb9ac1a00.png

The number of network-related errors has also increased in our app, but it is difficult to pinpoint if it's happening because of this.

— Reply to this email directly, view it on GitHub https://github.com/skupperproject/skupper/issues/988, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAFEKJWDYMRX5HGGZZKCOHDWRZP3ZANCNFSM6AAAAAATXWUDEE . You are receiving this because you are subscribed to this thread.Message ID: @.***>

sahil87 commented 1 year ago

Adding a full page of logs, including parts that say FLOW_LOG:

2023-01-15 13:51:54.105594 +0000 SERVER (info) [C72612] Accepted connection to :55671 from 10.244.0.1:34483
2023-01-15 13:51:54.340196 +0000 SERVER (info) [C72611] Connection from 10.244.0.1:13346 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:00.114205 +0000 SERVER (info) [C72612] Connection from 10.244.0.1:34483 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:00.119602 +0000 SERVER (info) [C72613] Accepted connection to :55671 from 10.244.0.1:56842
2023-01-15 13:52:01.871780 +0000 TCP_ADAPTOR (info) [C72614] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646
2023-01-15 13:52:01.871991 +0000 TCP_ADAPTOR (info) [C72614] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646
2023-01-15 13:52:01.872009 +0000 TCP_ADAPTOR (info) [C72614] Opening server-side core connection 10.244.0.143:3646
2023-01-15 13:52:01.872028 +0000 ROUTER_CORE (info) [C72614] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
2023-01-15 13:52:01.872069 +0000 ROUTER_CORE (info) [C72614][L24958] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={<none> expire:link}
2023-01-15 13:52:01.872136 +0000 ROUTER_CORE (info) [C72614][L24959] Link attached: dir=in source={<none> expire:link} target={amqp:/_edge/us-site-skupper-router-5d7ff99966-mj64s/temp.5SC4tywktuFXt1g expire:link}
2023-01-15 13:52:02.074741 +0000 TCP_ADAPTOR (info) [C72614] EOS
2023-01-15 13:52:02.074794 +0000 TCP_ADAPTOR (info) [C72614] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0
2023-01-15 13:52:02.074817 +0000 ROUTER_CORE (info) [C72614][L24959] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:52:02.074835 +0000 ROUTER_CORE (info) [C72614][L24958] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:52:02.074842 +0000 ROUTER_CORE (info) [C72614] Connection Closed
2023-01-15 13:52:02.225855 +0000 FLOW_LOG (info) FLOW [lq6db:12176] BEGIN END parent=lq6db:962 counterflow=mj64s:9355 sourceHost=10.244.0.140 sourcePort=49630 octets=999 latency=373 trace=Local octetsUnacked=999 windowSize=1459620
2023-01-15 13:52:03.588358 +0000 TCP_ADAPTOR (info) [C72615] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646
2023-01-15 13:52:03.588580 +0000 TCP_ADAPTOR (info) [C72615] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646
2023-01-15 13:52:03.588597 +0000 TCP_ADAPTOR (info) [C72615] Opening server-side core connection 10.244.0.143:3646
2023-01-15 13:52:03.588615 +0000 ROUTER_CORE (info) [C72615] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
2023-01-15 13:52:03.588664 +0000 ROUTER_CORE (info) [C72615][L24960] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={<none> expire:link}
2023-01-15 13:52:03.588745 +0000 ROUTER_CORE (info) [C72615][L24961] Link attached: dir=in source={<none> expire:link} target={amqp:/_edge/us-site-skupper-router-5d7ff99966-mj64s/temp.0WZUB0yLfbPl7_j expire:link}
2023-01-15 13:52:03.790443 +0000 TCP_ADAPTOR (info) [C72615] EOS
2023-01-15 13:52:03.790481 +0000 TCP_ADAPTOR (info) [C72615] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0
2023-01-15 13:52:03.790498 +0000 ROUTER_CORE (info) [C72615][L24961] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:52:03.790524 +0000 ROUTER_CORE (info) [C72615][L24960] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:52:03.790535 +0000 ROUTER_CORE (info) [C72615] Connection Closed
2023-01-15 13:52:03.826430 +0000 FLOW_LOG (info) FLOW [lq6db:12177] BEGIN END parent=lq6db:962 counterflow=mj64s:9356 sourceHost=10.244.0.140 sourcePort=49632 octets=999 latency=409 trace=Local octetsUnacked=999 windowSize=1459620
2023-01-15 13:52:06.127684 +0000 SERVER (info) [C72613] Connection from 10.244.0.1:56842 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:24.172083 +0000 SERVER (info) [C72616] Accepted connection to :55671 from 10.244.0.1:61091
2023-01-15 13:52:30.182614 +0000 SERVER (info) [C72616] Connection from 10.244.0.1:61091 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:30.187922 +0000 SERVER (info) [C72617] Accepted connection to :55671 from 10.244.0.1:4667
2023-01-15 13:52:30.429655 +0000 SERVER (info) [C72618] Accepted connection to :45671 from 10.244.0.1:63485
2023-01-15 13:52:36.183412 +0000 SERVER (info) [C72617] Connection from 10.244.0.1:4667 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:36.439388 +0000 SERVER (info) [C72618] Connection from 10.244.0.1:63485 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:52:54.215277 +0000 SERVER (info) [C72619] Accepted connection to :55671 from 10.244.0.1:25273
2023-01-15 13:53:00.223127 +0000 SERVER (info) [C72619] Connection from 10.244.0.1:25273 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:53:02.772167 +0000 TCP_ADAPTOR (info) [C72620] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646
2023-01-15 13:53:02.772374 +0000 TCP_ADAPTOR (info) [C72620] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646
2023-01-15 13:53:02.772398 +0000 TCP_ADAPTOR (info) [C72620] Opening server-side core connection 10.244.0.143:3646
2023-01-15 13:53:02.772425 +0000 ROUTER_CORE (info) [C72620] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
2023-01-15 13:53:02.772467 +0000 ROUTER_CORE (info) [C72620][L24962] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={<none> expire:link}
2023-01-15 13:53:02.772536 +0000 ROUTER_CORE (info) [C72620][L24963] Link attached: dir=in source={<none> expire:link} target={amqp:/_edge/us-site-skupper-router-5d7ff99966-mj64s/temp.Af7F9Ff1zppt+sW expire:link}
2023-01-15 13:53:02.974117 +0000 TCP_ADAPTOR (info) [C72620] EOS
2023-01-15 13:53:02.974157 +0000 TCP_ADAPTOR (info) [C72620] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0
2023-01-15 13:53:02.974175 +0000 ROUTER_CORE (info) [C72620][L24963] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:53:02.974193 +0000 ROUTER_CORE (info) [C72620][L24962] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:53:02.974198 +0000 ROUTER_CORE (info) [C72620] Connection Closed
2023-01-15 13:53:03.042502 +0000 FLOW_LOG (info) FLOW [lq6db:12178] BEGIN END parent=lq6db:962 counterflow=mj64s:9357 sourceHost=10.244.0.140 sourcePort=60388 octets=999 latency=403 trace=Local octetsUnacked=999 windowSize=1459620
2023-01-15 13:53:04.456847 +0000 TCP_ADAPTOR (info) [C72621] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646
2023-01-15 13:53:04.457055 +0000 TCP_ADAPTOR (info) [C72621] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646
2023-01-15 13:53:04.457071 +0000 TCP_ADAPTOR (info) [C72621] Opening server-side core connection 10.244.0.143:3646
2023-01-15 13:53:04.457091 +0000 ROUTER_CORE (info) [C72621] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
2023-01-15 13:53:04.457128 +0000 ROUTER_CORE (info) [C72621][L24964] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={<none> expire:link}
2023-01-15 13:53:04.457201 +0000 ROUTER_CORE (info) [C72621][L24965] Link attached: dir=in source={<none> expire:link} target={amqp:/_edge/us-site-skupper-router-5d7ff99966-mj64s/temp.9FPrXZPugCLYDlG expire:link}
2023-01-15 13:53:04.658970 +0000 TCP_ADAPTOR (info) [C72621] EOS
2023-01-15 13:53:04.659015 +0000 TCP_ADAPTOR (info) [C72621] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0
2023-01-15 13:53:04.659036 +0000 ROUTER_CORE (info) [C72621][L24965] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:53:04.659062 +0000 ROUTER_CORE (info) [C72621][L24964] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2023-01-15 13:53:04.659072 +0000 ROUTER_CORE (info) [C72621] Connection Closed
2023-01-15 13:53:04.843185 +0000 FLOW_LOG (info) FLOW [lq6db:12179] BEGIN END parent=lq6db:962 counterflow=mj64s:9358 sourceHost=10.244.0.140 sourcePort=60396 octets=999 latency=362 trace=Local octetRate=99 octetsUnacked=999 windowSize=1459620
2023-01-15 13:53:06.243418 +0000 SERVER (info) [C72622] Accepted connection to :55671 from 10.244.0.1:24698
2023-01-15 13:53:12.253410 +0000 SERVER (info) [C72622] Connection from 10.244.0.1:24698 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-15 13:53:18.274584 +0000 SERVER (info) [C72623] Accepted connection to :55671 from 10.244.0.1:57777
ted-ross commented 1 year ago

What I see there is repeated TCP connections in which the server returns 925 octets to the client before the connection is closed. Is this what you expect from your application?

I don't see any error indications.

On Mon, Jan 16, 2023 at 12:54 AM Sahil Ahuja @.***> wrote:

Adding a full page of logs, including parts that say FLOW_LOG:

2023-01-16 05:41:09.102793 +0000 ROUTER_CORE (info) [C84540] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"} 41 2023-01-16 05:41:09.102839 +0000 ROUTER_CORE (info) [C84540][L30048] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={ expire:link} 40 2023-01-16 05:41:09.102941 +0000 ROUTER_CORE (info) [C84540][L30049] Link attached: dir=in source={ expire:link} target={amqp:/_edge/in-site-skupper-router-7bcf465c88-wv2cj/temp.cl0hqXYMiOI04Lp expire:link} 39 2023-01-16 05:41:09.114630 +0000 TCP_ADAPTOR (info) [C84540] EOS 38 2023-01-16 05:41:09.114658 +0000 TCP_ADAPTOR (info) [C84540] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0 37 2023-01-16 05:41:09.114682 +0000 ROUTER_CORE (info) [C84540][L30049] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 36 2023-01-16 05:41:09.114697 +0000 ROUTER_CORE (info) [C84540][L30048] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 35 2023-01-16 05:41:09.114706 +0000 ROUTER_CORE (info) [C84540] Connection Closed 34 2023-01-16 05:41:09.134358 +0000 TCP_ADAPTOR (info) [C84541] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646 33 2023-01-16 05:41:09.134561 +0000 TCP_ADAPTOR (info) [C84541] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646 32 2023-01-16 05:41:09.134583 +0000 TCP_ADAPTOR (info) [C84541] Opening server-side core connection 10.244.0.143:3646 31 2023-01-16 05:41:09.134605 +0000 ROUTER_CORE (info) [C84541] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"} 30 2023-01-16 05:41:09.134649 +0000 ROUTER_CORE (info) [C84541][L30050] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={ expire:link} 29 2023-01-16 05:41:09.134735 +0000 ROUTER_CORE (info) [C84541][L30051] Link attached: dir=in source={ expire:link} target={amqp:/_edge/in-site-skupper-router-7bcf465c88-wv2cj/temp.nsvqoEHF6exiD+B expire:link} 28 2023-01-16 05:41:09.149452 +0000 TCP_ADAPTOR (info) [C84541] EOS 27 2023-01-16 05:41:09.149475 +0000 TCP_ADAPTOR (info) [C84541] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0 26 2023-01-16 05:41:09.149492 +0000 ROUTER_CORE (info) [C84541][L30051] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 25 2023-01-16 05:41:09.149506 +0000 ROUTER_CORE (info) [C84541][L30050] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 24 2023-01-16 05:41:09.149514 +0000 ROUTER_CORE (info) [C84541] Connection Closed 23 2023-01-16 05:41:09.271284 +0000 FLOW_LOG (info) FLOW [lq6db:14720] BEGIN END parent=lq6db:962 counterflow=wv2cj:2680 sourceHost=10.244.0.140 sourcePort=35658 octets=925 latency=379 trace=Local octetsUnacked=925 windowSize=1459620 22 2023-01-16 05:41:09.271309 +0000 FLOW_LOG (info) FLOW [lq6db:14721] BEGIN END parent=lq6db:962 counterflow=wv2cj:2681 sourceHost=10.244.0.140 sourcePort=35670 octets=925 latency=369 trace=Local octetsUnacked=925 windowSize=1459620 21 2023-01-16 05:41:09.271318 +0000 FLOW_LOG (info) FLOW [lq6db:14722] BEGIN END parent=lq6db:962 counterflow=wv2cj:2682 sourceHost=10.244.0.140 sourcePort=35684 octets=925 latency=391 trace=Local octetsUnacked=925 windowSize=1459620 20 2023-01-16 05:41:09.596155 +0000 SERVER (info) [C84535] Connection from 10.244.0.1:60627 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 19 2023-01-16 05:41:09.601807 +0000 SERVER (info) [C70817] Accepted connection to :55671 from 10.244.0.1:63405 18 2023-01-16 05:41:09.642091 +0000 TCP_ADAPTOR (info) [C84542] qdr_tcp_connection_egress call pn_proactor_raw_connect(). Egress connecting to: 10.244.0.143:3646 17 2023-01-16 05:41:09.642283 +0000 TCP_ADAPTOR (info) [C84542] PN_RAW_CONNECTION_CONNECTED Connector egress connected to 10.244.0.143:3646 16 2023-01-16 05:41:09.642300 +0000 TCP_ADAPTOR (info) [C84542] Opening server-side core connection 10.244.0.143:3646 15 2023-01-16 05:41:09.642319 +0000 ROUTER_CORE (info) [C84542] Connection Opened: dir=out host=10.244.0.143:3646 encrypted=no auth=no user= container_id=TcpAdaptor props={:"qd.adaptor"="tcp"} 14 2023-01-16 05:41:09.642353 +0000 ROUTER_CORE (info) [C84542][L30052] Link attached: dir=out source={deployment-z5api-viewer:3646 expire:link} target={ expire:link} 13 2023-01-16 05:41:09.642426 +0000 ROUTER_CORE (info) [C84542][L30053] Link attached: dir=in source={ expire:link} target={amqp:/_edge/in-site-skupper-router-7bcf465c88-wv2cj/temp.sB4EFEwRZcNEURP expire:link} 12 2023-01-16 05:41:09.657621 +0000 TCP_ADAPTOR (info) [C84542] EOS 11 2023-01-16 05:41:09.657645 +0000 TCP_ADAPTOR (info) [C84542] PN_RAW_CONNECTION_DISCONNECTED connector, drained_buffers=0 10 2023-01-16 05:41:09.657693 +0000 ROUTER_CORE (info) [C84542][L30053] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 9 2023-01-16 05:41:09.657713 +0000 ROUTER_CORE (info) [C84542][L30052] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 8 2023-01-16 05:41:09.657719 +0000 ROUTER_CORE (info) [C84542] Connection Closed 7 2023-01-16 05:41:09.671378 +0000 FLOW_LOG (info) FLOW [lq6db:14723] BEGIN END parent=lq6db:962 counterflow=wv2cj:2683 sourceHost=10.244.0.140 sourcePort=35694 octets=925 latency=344 trace=Local octetsUnacked=925 windowSize=1459620 6 2023-01-16 05:41:09.852943 +0000 SERVER (info) [C84536] Connection from 10.244.0.1:62072 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 5 2023-01-16 05:41:09.858219 +0000 SERVER (info) [C70818] Accepted connection to :45671 from 10.244.0.1:65494 4 2023-01-16 05:41:15.597719 +0000 SERVER (info) [C70817] Connection from 10.244.0.1:63405 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 3 2023-01-16 05:41:15.603267 +0000 SERVER (info) [C84543] Accepted connection to :55671 from 10.244.0.1:23706 2 2023-01-16 05:41:15.854635 +0000 SERVER (info) [C70818] Connection from 10.244.0.1:65494 (to :45671) failed: amqp:connection:framing-error No protocol header

— Reply to this email directly, view it on GitHub https://github.com/skupperproject/skupper/issues/988#issuecomment-1383520275, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAFEKJR4EFSC75YZP74MRQTWSTNUHANCNFSM6AAAAAATXWUDEE . You are receiving this because you commented.Message ID: @.***>

sahil87 commented 1 year ago

Ok. Thank you! As to your question of whether the app is supposed to do that - I don't know (not sure how Redis service behaves at the network layer)

Here is our configuration:

I really need to get better at detecting what an error state is by looking at skupper logs. Are any of the following logs indicative of errors? Again, thank you in advance for helping out!

"TLS handshake error" in skupper-service-controller:

2023/01/17 18:22:35 http: TLS handshake error from 10.244.0.1:19160: EOF
2023/01/17 18:22:36 http: TLS handshake error from 10.244.0.1:26724: EOF
2023/01/17 18:22:41 http: TLS handshake error from 10.244.0.1:37993: EOF
2023/01/17 18:22:42 http: TLS handshake error from 10.244.0.1:24415: EOF
2023/01/17 18:22:47 http: TLS handshake error from 10.244.0.1:53336: EOF
2023/01/17 18:22:48 http: TLS handshake error from 10.244.0.1:42075: EOF
2023/01/17 18:22:53 http: TLS handshake error from 10.244.0.1:48246: EOF
2023/01/17 18:22:54 http: TLS handshake error from 10.244.0.1:35476: EOF
Interior nodes are [map[address:amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf cost:<nil> id:bknd-site-skupper-router-668ccd9fc-brwsf identity:router.node/bknd-site-skupper-router-668ccd9fc-brwsf index:0 instance:1673871744 lastTopoChange:0 linkState:[] name:router.node/bknd-site-skupper-router-668ccd9fc-brwsf nextHop:(self) protocolVersion:1 routerLink:<nil> type:io.skupper.router.router.node validOrigins:[]]]
BatchQuery([{io.skupper.router.connection [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management}])
Waiting for response 1 of 1
BatchQuery([{io.skupper.router.router [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management} {io.skupper.router.router [] amqp:/_edge/in-site-skupper-router-6558d9c789-gqdxg/$management} {io.skupper.router.router [] amqp:/_edge/us-site-skupper-router-6674f68874-2xzd6/$management}])
2023/01/17 18:22:59 http: TLS handshake error from 10.244.0.1:41341: EOF
Waiting for response 1 of 3
Waiting for response 2 of 3
Waiting for response 3 of 3
BatchQuery([{io.skupper.router.connection [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management} {io.skupper.router.connection [] amqp:/_edge/in-site-skupper-router-6558d9c789-gqdxg/$management} {io.skupper.router.connection [] amqp:/_edge/us-site-skupper-router-6674f68874-2xzd6/$management}])
2023/01/17 18:23:00 http: TLS handshake error from 10.244.0.1:54631: EOF
Waiting for response 1 of 3
Waiting for response 2 of 3
Waiting for response 3 of 3
Interior nodes are [map[address:amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf cost:<nil> id:bknd-site-skupper-router-668ccd9fc-brwsf identity:router.node/bknd-site-skupper-router-668ccd9fc-brwsf index:0 instance:1673871744 lastTopoChange:0 linkState:[] name:router.node/bknd-site-skupper-router-668ccd9fc-brwsf nextHop:(self) protocolVersion:1 routerLink:<nil> type:io.skupper.router.router.node validOrigins:[]]]
BatchQuery([{io.skupper.router.connection [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management}])
Waiting for response 1 of 1
BatchQuery([{io.skupper.router.router [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management} {io.skupper.router.router [] amqp:/_edge/in-site-skupper-router-6558d9c789-gqdxg/$management} {io.skupper.router.router [] amqp:/_edge/us-site-skupper-router-6674f68874-2xzd6/$management}])
Waiting for response 1 of 3
Waiting for response 2 of 3
Waiting for response 3 of 3
BatchQuery([{io.skupper.router.connection [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management} {io.skupper.router.connection [] amqp:/_edge/in-site-skupper-router-6558d9c789-gqdxg/$management} {io.skupper.router.connection [] amqp:/_edge/us-site-skupper-router-6674f68874-2xzd6/$management}])
Waiting for response 1 of 3
Waiting for response 2 of 3
Waiting for response 3 of 3
BatchQuery([{io.skupper.router.httpRequestInfo [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management}])
Waiting for response 1 of 1
BatchQuery([{io.skupper.router.tcpConnection [] amqp:/_topo/0/bknd-site-skupper-router-668ccd9fc-brwsf/$management}])
Waiting for response 1 of 1
BatchQuery([])
2023/01/17 18:23:06 http: TLS handshake error from 10.244.0.1:54184: EOF
2023/01/17 18:23:06 http: TLS handshake error from 10.244.0.1:55753: EOF
2023/01/17 18:23:12 http: TLS handshake error from 10.244.0.1:51360: EOF
2023/01/17 18:23:12 http: TLS handshake error from 10.244.0.1:63513: EOF
2023/01/17 18:23:18 http: TLS handshake error from 10.244.0.1:48503: EOF
2023/01/17 18:23:18 http: TLS handshake error from 10.244.0.1:46088: EOF

"amqp:connection:framing-error" in skupper-router:

2023-01-17 19:03:02.836336 +0000 SERVER (info) [C37169] Accepted connection to :45671 from 10.244.0.1:31659
2023-01-17 19:03:08.559012 +0000 SERVER (info) [C37168] Connection from 10.244.0.1:46399 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:08.565395 +0000 SERVER (info) [C37170] Accepted connection to :55671 from 10.244.0.1:29376
2023-01-17 19:03:08.831828 +0000 SERVER (info) [C37169] Connection from 10.244.0.1:31659 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:08.837154 +0000 SERVER (info) [C37171] Accepted connection to :45671 from 10.244.0.1:3552
2023-01-17 19:03:14.559076 +0000 SERVER (info) [C37170] Connection from 10.244.0.1:29376 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:14.565056 +0000 SERVER (info) [C37172] Accepted connection to :55671 from 10.244.0.1:6935
2023-01-17 19:03:14.832046 +0000 SERVER (info) [C37171] Connection from 10.244.0.1:3552 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:14.837658 +0000 SERVER (info) [C37173] Accepted connection to :45671 from 10.244.0.1:54522
2023-01-17 19:03:20.559220 +0000 SERVER (info) [C37172] Connection from 10.244.0.1:6935 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:20.564791 +0000 SERVER (info) [C37174] Accepted connection to :55671 from 10.244.0.1:13466
2023-01-17 19:03:20.832094 +0000 SERVER (info) [C37173] Connection from 10.244.0.1:54522 (to :45671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2023-01-17 19:03:20.837657 +0000 SERVER (info) [C37175] Accepted connection to :45671 from 10.244.0.1:3330
lordgordon commented 1 year ago

I have a similar issue with skupper linking a Kafka cluster between two sites. It started when I increased the number of services using Kafka.