search

skupperproject / skupper

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

Connection from edge to interior fails: "Failed to redeem claim: connection refused" #725

Closed CreatorSky closed 11 months ago

CreatorSky commented 2 years ago

I have an interior site in GCP GKE (public) and an edge site on-prem minikube (private).

I am creating token on Public site (skupper token create public.yaml) and trying to create a link from Private site using the same token (skupper link create public.yaml).

When I check the link status on private site using: skupper link status, I get: Link link1 not active (Failed to redeem claim: Post https://GCP_LOADBALANCER_IP:8081/aae1c600-bbee-11ec-ae2c-acde48001122?site-version=0.8.7: dial tcp GCP_LOADBALANCER_IP:8081: connect: connection refused)

I have verified that GCP firewall is accepting the incoming connections with GCP_LOADBALANCER_IP on both port 8080 and 8081. I can even access the skupper dashboard at https://GCP_LOADBALANCER_IP:8080.

What could have gone wrong here?

grs commented 2 years ago

Is that host accessible from within your private cluster? (I.e. if you kubectl exec into the pod and try and curl against that (or similar) does it seem to connect?)

CreatorSky commented 2 years ago

Yes, it can establish a connection to the host on port 8080. But fails to do so on port 8081. (using telnet here)

grs commented 2 years ago

What is the error on port 8081?

CreatorSky commented 2 years ago

Connection refused

grs commented 2 years ago

What does kubectl svc show on the GKE namespace?

CreatorSky commented 2 years ago 
NAME                   TYPE           CLUSTER-IP   EXTERNAL-IP     PORT(S)                           AGE
kubernetes             ClusterIP      10.8.0.1     <none>          443/TCP                           8d
skupper                LoadBalancer   10.8.2.77    IP_1_HERE       8080:30263/TCP,8081:30580/TCP     65m
skupper-router         LoadBalancer   10.8.7.210   IP_2_HERE       55671:30172/TCP,45671:31639/TCP   66m
skupper-router-local   ClusterIP      10.8.14.57   <none>          5671/TCP                          66m
grs commented 2 years ago

That all looks fine, not sure why it can't connect to the 8081 port. Try creating a token with --token-type cert and see if that allows them to be linked?

CreatorSky commented 2 years ago

tried that as well. Doesn't work, though it doesn't say "Connection refused" when checking link status. Instead it says Link not active.

grs commented 2 years ago

can you look at the skupper-router log in the edge namespace?

CreatorSky commented 2 years ago 
2022-04-14 12:28:38.928091 +0000 SERVER (info) Container Name: private-skupper-router-7fc988c97d-6kdtw
2022-04-14 12:28:38.928233 +0000 ROUTER (info) Router started in Edge mode
2022-04-14 12:28:38.928250 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 12:28:38.928660 +0000 ROUTER_CORE (info) Core module enabled: edge_router
2022-04-14 12:28:38.928675 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 12:28:38.928682 +0000 ROUTER_CORE (info) Core module present but disabled: edge_addr_tracking
2022-04-14 12:28:38.928688 +0000 ROUTER_CORE (info) Core module present but disabled: address_lookup_server
2022-04-14 12:28:38.928695 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 12:28:38.928716 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 12:28:38.928724 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 12:28:38.928731 +0000 ROUTER_CORE (info) Core module present but disabled: mobile_sync
2022-04-14 12:28:38.928738 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 12:28:38.928745 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 12:28:38.928754 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 12:28:38.928761 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 12:28:38.928769 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 12:28:38.929078 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-7fc988c97d-6kdtw
2022-04-14 12:28:38.929146 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 12:28:38.929168 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 12:28:38.929312 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 12:28:38.939485 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 12:28:38.939537 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 12:28:38.942042 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 12:28:38.942840 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 12:28:38.943160 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 12:28:38.944754 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 12:28:38.944950 +0000 SERVER (info) HTTP server thread running
2022-04-14 12:28:38.945026 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 12:28:38.945162 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 12:28:38.945802 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 12:28:38.946994 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 12:28:38.947597 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 12:28:38.947742 +0000 SERVER (notice) Process VmSize 185.75 MiB (125.79 GiB available memory)
2022-04-14 12:28:38.948065 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 12:28:38.948138 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 12:28:39.762029 +0000 SERVER (info) [C1] Accepted connection to localhost:5672 from 127.0.0.1:43058
2022-04-14 12:28:39.762603 +0000 ROUTER_CORE (info) [C1] Connection Opened: dir=in host=127.0.0.1:43058 vhost= encrypted=no auth=no user=anonymous container_id=SDa5c6shQhfEqfTMtoBjKEbx8abKtAcZQMH0aVp4FLoxPK2OVImSNg props=
2022-04-14 12:28:39.763855 +0000 ROUTER_CORE (info) [C1][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:28:39.764424 +0000 ROUTER_CORE (info) [C1][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 12:28:39.764941 +0000 ROUTER_CORE (info) [C1][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:28:40.059326 +0000 SERVER (info) [C2] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:20924
2022-04-14 12:28:40.074252 +0000 ROUTER_CORE (info) [C2] Connection Opened: dir=in host=172.17.0.1:20924 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=crW9xxQxQ2juINEMOPEbUj1W7Vqyx1qe5RYmwUHOzponEMz9U2C-LA props=
2022-04-14 12:28:40.075046 +0000 ROUTER_CORE (info) [C2][L5] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:28:40.075629 +0000 ROUTER_CORE (info) [C2][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 12:28:40.076030 +0000 ROUTER_CORE (info) [C2][L7] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:28:40.077601 +0000 ROUTER_CORE (info) [C2][L8] Link attached: dir=out source={428cb772-f194-416a-aa97-6c18122e478b/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 12:28:41.048318 +0000 SERVER (info) [C3] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:35516
2022-04-14 12:28:41.060478 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=172.17.0.1:35516 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=ZXus2KqPjJKx5oP10oB7uLGcEukttW86ACyh2fgzFVxY1WTpIYoIQQ props=
2022-04-14 12:28:41.061457 +0000 ROUTER_CORE (info) [C3][L9] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 12:28:41.062038 +0000 ROUTER_CORE (info) [C3][L10] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 12:32:06.032093 +0000 SERVER (info) [C4] Accepted connection to localhost:5672 from 127.0.0.1:44752
2022-04-14 12:32:06.032558 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=127.0.0.1:44752 vhost= encrypted=no auth=no user=anonymous container_id=e9946c3f-23dc-43aa-a970-b654779bc3e3 props=
2022-04-14 12:32:06.034056 +0000 ROUTER_CORE (info) [C4][L11] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 12:32:06.035497 +0000 ROUTER_CORE (info) [C4][L12] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:32:06.049692 +0000 SERVER (info) [C4] Connection from 127.0.0.1:44752 (to localhost:5672) failed: amqp:connection:framing-error connection aborted
2022-04-14 12:32:06.049822 +0000 ROUTER_CORE (info) [C4][L11] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 12:32:06.049951 +0000 ROUTER_CORE (info) [C4][L12] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 12:32:06.049992 +0000 ROUTER_CORE (info) [C4] Connection Closed
2022-04-14 12:37:15.055135 +0000 SERVER (info) [C5] Accepted connection to localhost:5672 from 127.0.0.1:48496
2022-04-14 12:37:15.055704 +0000 ROUTER_CORE (info) [C5] Connection Opened: dir=in host=127.0.0.1:48496 vhost= encrypted=no auth=no user=anonymous container_id=b1132608-fe5e-4038-8fba-1ed44e086bfb props=
2022-04-14 12:37:15.057154 +0000 ROUTER_CORE (info) [C5][L13] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 12:37:15.058362 +0000 ROUTER_CORE (info) [C5][L14] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 12:37:15.069565 +0000 SERVER (info) [C5] Connection from 127.0.0.1:48496 (to localhost:5672) failed: amqp:connection:framing-error connection aborted
2022-04-14 12:37:15.069636 +0000 ROUTER_CORE (info) [C5][L13] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 12:37:15.069680 +0000 ROUTER_CORE (info) [C5][L14] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 12:37:15.069700 +0000 ROUTER_CORE (info) [C5] Connection Closed
2022-04-14 15:09:01.761601 +0000 SERVER (info) [C6] Accepted connection to localhost:5672 from 127.0.0.1:42326
2022-04-14 15:09:01.761943 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=127.0.0.1:42326 vhost= encrypted=no auth=no user=anonymous container_id=12db3c2a-b0d2-40df-8f43-70047a136230 props=
2022-04-14 15:09:01.763766 +0000 ROUTER_CORE (info) [C6][L15] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:09:01.765108 +0000 ROUTER_CORE (info) [C6][L16] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:09:01.777565 +0000 SERVER (info) [C6] Connection from 127.0.0.1:42326 (to localhost:5672) failed: amqp:connection:framing-error connection aborted
2022-04-14 15:09:01.777692 +0000 ROUTER_CORE (info) [C6][L15] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 15:09:01.777741 +0000 ROUTER_CORE (info) [C6][L16] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 15:09:01.777762 +0000 ROUTER_CORE (info) [C6] Connection Closed
grs commented 2 years ago

That doesn't look to have tried linking with the second token. Did you run skupper link create again with the cert token? What does skupper link status on the private site say?

CreatorSky commented 2 years ago

oh sorry, here is the one with cert token.

2022-04-14 15:17:07.561069 +0000 SERVER (info) Container Name: private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.561199 +0000 ROUTER (info) Router started in Edge mode
2022-04-14 15:17:07.561212 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 15:17:07.561620 +0000 ROUTER_CORE (info) Core module enabled: edge_router
2022-04-14 15:17:07.561636 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 15:17:07.561643 +0000 ROUTER_CORE (info) Core module present but disabled: edge_addr_tracking
2022-04-14 15:17:07.561649 +0000 ROUTER_CORE (info) Core module present but disabled: address_lookup_server
2022-04-14 15:17:07.561656 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 15:17:07.561686 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 15:17:07.561695 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 15:17:07.561701 +0000 ROUTER_CORE (info) Core module present but disabled: mobile_sync
2022-04-14 15:17:07.561708 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 15:17:07.561715 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 15:17:07.561723 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 15:17:07.561730 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 15:17:07.561737 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 15:17:07.562036 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.562098 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 15:17:07.562118 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 15:17:07.562250 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 15:17:07.572123 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 15:17:07.572207 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 15:17:07.574431 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 15:17:07.575209 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 15:17:07.575529 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 15:17:07.576154 +0000 CONN_MGR (info) Created SSL Profile with name link1-profile
2022-04-14 15:17:07.577728 +0000 CONN_MGR (info) Configured Connector: IP_2_HERE:45671 proto=any, role=edge, sslProfile=link1-profile
2022-04-14 15:17:07.578772 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 15:17:07.578989 +0000 SERVER (info) HTTP server thread running
2022-04-14 15:17:07.579065 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 15:17:07.579162 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 15:17:07.579874 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 15:17:07.581051 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 15:17:07.581661 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 15:17:07.581806 +0000 SERVER (notice) Process VmSize 185.77 MiB (125.79 GiB available memory)
2022-04-14 15:17:07.582218 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 15:17:07.582265 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 15:17:07.604870 +0000 SERVER (info) [C1] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:12.627526 +0000 SERVER (info) [C2] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:15.826435 +0000 SERVER (info) [C3] Accepted connection to localhost:5672 from 127.0.0.1:47698
2022-04-14 15:17:15.827182 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=127.0.0.1:47698 vhost= encrypted=no auth=no user=anonymous container_id=3j9EaeKWuUAlyvjaPeqegp8AFp1eqP-FP54Ti1ps_lTa0f8HWgg9fA props=
2022-04-14 15:17:15.828365 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:15.829092 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:15.829639 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.875896 +0000 SERVER (info) [C4] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:45254
2022-04-14 15:17:16.890212 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=172.17.0.1:45254 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=HOhNPnk-KZ4uWqaGp1AhKC_FhDJIX6YJ6W39xTZjmEbe-jMbPjU3Qw props=
2022-04-14 15:17:16.891074 +0000 ROUTER_CORE (info) [C4][L5] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.891662 +0000 ROUTER_CORE (info) [C4][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:16.892172 +0000 ROUTER_CORE (info) [C4][L7] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.894078 +0000 ROUTER_CORE (info) [C4][L8] Link attached: dir=out source={428cb772-f194-416a-aa97-6c18122e478b/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.650552 +0000 SERVER (info) [C5] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:17.866975 +0000 SERVER (info) [C6] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:24591
2022-04-14 15:17:17.878498 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=172.17.0.1:24591 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=2foiSxBFzaBIZIP02var1BtHDLAwGQSWpmo9dXdSrg9aWp-oL677OA props=
2022-04-14 15:17:17.879562 +0000 ROUTER_CORE (info) [C6][L9] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.880261 +0000 ROUTER_CORE (info) [C6][L10] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 15:17:22.672719 +0000 SERVER (info) [C7] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:27.695651 +0000 SERVER (info) [C8] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:32.722901 +0000 SERVER (info) [C9] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
ubuntu@cto-lab-02:~$ k logs skupper-router-67dc44548f-v9b7z -c router
2022-04-14 15:17:07.561069 +0000 SERVER (info) Container Name: private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.561199 +0000 ROUTER (info) Router started in Edge mode
2022-04-14 15:17:07.561212 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 15:17:07.561620 +0000 ROUTER_CORE (info) Core module enabled: edge_router
2022-04-14 15:17:07.561636 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 15:17:07.561643 +0000 ROUTER_CORE (info) Core module present but disabled: edge_addr_tracking
2022-04-14 15:17:07.561649 +0000 ROUTER_CORE (info) Core module present but disabled: address_lookup_server
2022-04-14 15:17:07.561656 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 15:17:07.561686 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 15:17:07.561695 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 15:17:07.561701 +0000 ROUTER_CORE (info) Core module present but disabled: mobile_sync
2022-04-14 15:17:07.561708 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 15:17:07.561715 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 15:17:07.561723 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 15:17:07.561730 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 15:17:07.561737 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 15:17:07.562036 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.562098 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 15:17:07.562118 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 15:17:07.562250 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 15:17:07.572123 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 15:17:07.572207 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 15:17:07.574431 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 15:17:07.575209 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 15:17:07.575529 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 15:17:07.576154 +0000 CONN_MGR (info) Created SSL Profile with name link1-profile
2022-04-14 15:17:07.577728 +0000 CONN_MGR (info) Configured Connector: IP_2_HERE:45671 proto=any, role=edge, sslProfile=link1-profile
2022-04-14 15:17:07.578772 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 15:17:07.578989 +0000 SERVER (info) HTTP server thread running
2022-04-14 15:17:07.579065 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 15:17:07.579162 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 15:17:07.579874 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 15:17:07.581051 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 15:17:07.581661 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 15:17:07.581806 +0000 SERVER (notice) Process VmSize 185.77 MiB (125.79 GiB available memory)
2022-04-14 15:17:07.582218 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 15:17:07.582265 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 15:17:07.604870 +0000 SERVER (info) [C1] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:12.627526 +0000 SERVER (info) [C2] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:15.826435 +0000 SERVER (info) [C3] Accepted connection to localhost:5672 from 127.0.0.1:47698
2022-04-14 15:17:15.827182 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=127.0.0.1:47698 vhost= encrypted=no auth=no user=anonymous container_id=3j9EaeKWuUAlyvjaPeqegp8AFp1eqP-FP54Ti1ps_lTa0f8HWgg9fA props=
2022-04-14 15:17:15.828365 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:15.829092 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:15.829639 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.875896 +0000 SERVER (info) [C4] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:45254
2022-04-14 15:17:16.890212 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=172.17.0.1:45254 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=HOhNPnk-KZ4uWqaGp1AhKC_FhDJIX6YJ6W39xTZjmEbe-jMbPjU3Qw props=
2022-04-14 15:17:16.891074 +0000 ROUTER_CORE (info) [C4][L5] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.891662 +0000 ROUTER_CORE (info) [C4][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:16.892172 +0000 ROUTER_CORE (info) [C4][L7] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.894078 +0000 ROUTER_CORE (info) [C4][L8] Link attached: dir=out source={428cb772-f194-416a-aa97-6c18122e478b/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.650552 +0000 SERVER (info) [C5] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:17.866975 +0000 SERVER (info) [C6] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:24591
2022-04-14 15:17:17.878498 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=172.17.0.1:24591 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=2foiSxBFzaBIZIP02var1BtHDLAwGQSWpmo9dXdSrg9aWp-oL677OA props=
2022-04-14 15:17:17.879562 +0000 ROUTER_CORE (info) [C6][L9] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.880261 +0000 ROUTER_CORE (info) [C6][L10] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 15:17:22.672719 +0000 SERVER (info) [C7] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:27.695651 +0000 SERVER (info) [C8] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:32.722901 +0000 SERVER (info) [C9] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:37.743730 +0000 SERVER (info) [C10] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
ubuntu@cto-lab-02:~$ k logs skupper-router-67dc44548f-v9b7z -c router
2022-04-14 15:17:07.561069 +0000 SERVER (info) Container Name: private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.561199 +0000 ROUTER (info) Router started in Edge mode
2022-04-14 15:17:07.561212 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 15:17:07.561620 +0000 ROUTER_CORE (info) Core module enabled: edge_router
2022-04-14 15:17:07.561636 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 15:17:07.561643 +0000 ROUTER_CORE (info) Core module present but disabled: edge_addr_tracking
2022-04-14 15:17:07.561649 +0000 ROUTER_CORE (info) Core module present but disabled: address_lookup_server
2022-04-14 15:17:07.561656 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 15:17:07.561686 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 15:17:07.561695 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 15:17:07.561701 +0000 ROUTER_CORE (info) Core module present but disabled: mobile_sync
2022-04-14 15:17:07.561708 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 15:17:07.561715 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 15:17:07.561723 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 15:17:07.561730 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 15:17:07.561737 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 15:17:07.562036 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.562098 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 15:17:07.562118 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 15:17:07.562250 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 15:17:07.572123 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 15:17:07.572207 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 15:17:07.574431 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 15:17:07.575209 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 15:17:07.575529 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 15:17:07.576154 +0000 CONN_MGR (info) Created SSL Profile with name link1-profile
2022-04-14 15:17:07.577728 +0000 CONN_MGR (info) Configured Connector: IP_2_HERE:45671 proto=any, role=edge, sslProfile=link1-profile
2022-04-14 15:17:07.578772 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 15:17:07.578989 +0000 SERVER (info) HTTP server thread running
2022-04-14 15:17:07.579065 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 15:17:07.579162 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 15:17:07.579874 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 15:17:07.581051 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 15:17:07.581661 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 15:17:07.581806 +0000 SERVER (notice) Process VmSize 185.77 MiB (125.79 GiB available memory)
2022-04-14 15:17:07.582218 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 15:17:07.582265 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 15:17:07.604870 +0000 SERVER (info) [C1] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:12.627526 +0000 SERVER (info) [C2] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:15.826435 +0000 SERVER (info) [C3] Accepted connection to localhost:5672 from 127.0.0.1:47698
2022-04-14 15:17:15.827182 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=127.0.0.1:47698 vhost= encrypted=no auth=no user=anonymous container_id=3j9EaeKWuUAlyvjaPeqegp8AFp1eqP-FP54Ti1ps_lTa0f8HWgg9fA props=
2022-04-14 15:17:15.828365 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:15.829092 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:15.829639 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.875896 +0000 SERVER (info) [C4] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:45254
2022-04-14 15:17:16.890212 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=172.17.0.1:45254 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=HOhNPnk-KZ4uWqaGp1AhKC_FhDJIX6YJ6W39xTZjmEbe-jMbPjU3Qw props=
2022-04-14 15:17:16.891074 +0000 ROUTER_CORE (info) [C4][L5] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.891662 +0000 ROUTER_CORE (info) [C4][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:16.892172 +0000 ROUTER_CORE (info) [C4][L7] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.894078 +0000 ROUTER_CORE (info) [C4][L8] Link attached: dir=out source={428cb772-f194-416a-aa97-6c18122e478b/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.650552 +0000 SERVER (info) [C5] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:17.866975 +0000 SERVER (info) [C6] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:24591
2022-04-14 15:17:17.878498 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=172.17.0.1:24591 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=2foiSxBFzaBIZIP02var1BtHDLAwGQSWpmo9dXdSrg9aWp-oL677OA props=
2022-04-14 15:17:17.879562 +0000 ROUTER_CORE (info) [C6][L9] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.880261 +0000 ROUTER_CORE (info) [C6][L10] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 15:17:22.672719 +0000 SERVER (info) [C7] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:27.695651 +0000 SERVER (info) [C8] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:32.722901 +0000 SERVER (info) [C9] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:37.743730 +0000 SERVER (info) [C10] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:42.771392 +0000 SERVER (info) [C11] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
ubuntu@cto-lab-02:~$ k logs skupper-router-67dc44548f-v9b7z -c router
2022-04-14 15:17:07.561069 +0000 SERVER (info) Container Name: private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.561199 +0000 ROUTER (info) Router started in Edge mode
2022-04-14 15:17:07.561212 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 15:17:07.561620 +0000 ROUTER_CORE (info) Core module enabled: edge_router
2022-04-14 15:17:07.561636 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 15:17:07.561643 +0000 ROUTER_CORE (info) Core module present but disabled: edge_addr_tracking
2022-04-14 15:17:07.561649 +0000 ROUTER_CORE (info) Core module present but disabled: address_lookup_server
2022-04-14 15:17:07.561656 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 15:17:07.561686 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 15:17:07.561695 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 15:17:07.561701 +0000 ROUTER_CORE (info) Core module present but disabled: mobile_sync
2022-04-14 15:17:07.561708 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 15:17:07.561715 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 15:17:07.561723 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 15:17:07.561730 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 15:17:07.561737 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 15:17:07.562036 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-67dc44548f-v9b7z
2022-04-14 15:17:07.562098 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 15:17:07.562118 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 15:17:07.562250 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 15:17:07.572123 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 15:17:07.572207 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 15:17:07.574431 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 15:17:07.575209 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 15:17:07.575529 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 15:17:07.576154 +0000 CONN_MGR (info) Created SSL Profile with name link1-profile
2022-04-14 15:17:07.577728 +0000 CONN_MGR (info) Configured Connector: IP_2_HERE:45671 proto=any, role=edge, sslProfile=link1-profile
2022-04-14 15:17:07.578772 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 15:17:07.578989 +0000 SERVER (info) HTTP server thread running
2022-04-14 15:17:07.579065 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 15:17:07.579162 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 15:17:07.579874 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 15:17:07.581051 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 15:17:07.581661 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 15:17:07.581806 +0000 SERVER (notice) Process VmSize 185.77 MiB (125.79 GiB available memory)
2022-04-14 15:17:07.582218 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 15:17:07.582265 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 15:17:07.604870 +0000 SERVER (info) [C1] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:12.627526 +0000 SERVER (info) [C2] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:15.826435 +0000 SERVER (info) [C3] Accepted connection to localhost:5672 from 127.0.0.1:47698
2022-04-14 15:17:15.827182 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=127.0.0.1:47698 vhost= encrypted=no auth=no user=anonymous container_id=3j9EaeKWuUAlyvjaPeqegp8AFp1eqP-FP54Ti1ps_lTa0f8HWgg9fA props=
2022-04-14 15:17:15.828365 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:15.829092 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:15.829639 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.875896 +0000 SERVER (info) [C4] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:45254
2022-04-14 15:17:16.890212 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=172.17.0.1:45254 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=HOhNPnk-KZ4uWqaGp1AhKC_FhDJIX6YJ6W39xTZjmEbe-jMbPjU3Qw props=
2022-04-14 15:17:16.891074 +0000 ROUTER_CORE (info) [C4][L5] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.891662 +0000 ROUTER_CORE (info) [C4][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:17:16.892172 +0000 ROUTER_CORE (info) [C4][L7] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:17:16.894078 +0000 ROUTER_CORE (info) [C4][L8] Link attached: dir=out source={428cb772-f194-416a-aa97-6c18122e478b/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.650552 +0000 SERVER (info) [C5] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:17.866975 +0000 SERVER (info) [C6] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:24591
2022-04-14 15:17:17.878498 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=172.17.0.1:24591 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=2foiSxBFzaBIZIP02var1BtHDLAwGQSWpmo9dXdSrg9aWp-oL677OA props=
2022-04-14 15:17:17.879562 +0000 ROUTER_CORE (info) [C6][L9] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 15:17:17.880261 +0000 ROUTER_CORE (info) [C6][L10] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 15:17:22.672719 +0000 SERVER (info) [C7] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:27.695651 +0000 SERVER (info) [C8] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:32.722901 +0000 SERVER (info) [C9] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:37.743730 +0000 SERVER (info) [C10] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:42.771392 +0000 SERVER (info) [C11] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671
2022-04-14 15:17:47.793943 +0000 SERVER (info) [C12] Connection to IP_2_HERE:45671 failed: proton:io Connection refused - disconnected IP_2_HERE:45671

After applying cert token on private site: 

$ skupper link status
Link link1 not active
grs commented 2 years ago

If you try the private side not using the router-mode=edge, do you get the same result (uses different port)?

CreatorSky commented 2 years ago

So, I deleted everything (skupper delete), tried skupper init without edge mode on private site, same error with both type of token. (Apparently still uses 8081)

grs commented 2 years ago

The claim token (default) will indeed use 8081, however the cert token should use 55671. Do you have the router log for the cert token case?

CreatorSky commented 2 years ago

yes my bad, it uses 55671 in cert token. Here's the log, private site running interior mode:

2022-04-14 15:31:13.526518 +0000 SERVER (info) Container Name: private-skupper-router-5785c66959-pzxvg
2022-04-14 15:31:13.526658 +0000 ROUTER (info) Router started in Interior mode, area=0 id=private-skupper-router-5785c66959-pzxvg
2022-04-14 15:31:13.526670 +0000 ROUTER (info) Version: 1.17.1
2022-04-14 15:31:13.527060 +0000 ROUTER_CORE (info) Core module present but disabled: edge_router
2022-04-14 15:31:13.527074 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-04-14 15:31:13.527088 +0000 ROUTER_CORE (info) Core module enabled: edge_addr_tracking
2022-04-14 15:31:13.527096 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_server
2022-04-14 15:31:13.527102 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-04-14 15:31:13.527121 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-04-14 15:31:13.527130 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-04-14 15:31:13.527199 +0000 ROUTER_CORE (info) Core module enabled: mobile_sync
2022-04-14 15:31:13.527208 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-04-14 15:31:13.527214 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-04-14 15:31:13.527221 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-04-14 15:31:13.527227 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-04-14 15:31:13.527233 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-04-14 15:31:13.527446 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-04-14 15:31:13.527514 +0000 ROUTER_CORE (info) Router Core thread running. 0/private-skupper-router-5785c66959-pzxvg
2022-04-14 15:31:13.527578 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter.ma
2022-04-14 15:31:13.527621 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter.ma
2022-04-14 15:31:13.527645 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-04-14 15:31:13.527794 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-04-14 15:31:13.527821 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter
2022-04-14 15:31:13.527845 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter
2022-04-14 15:31:13.527858 +0000 ROUTER_CORE (info) In-process subscription L/qdhello
2022-04-14 15:31:13.527871 +0000 ROUTER (info) Router Engine Instantiated: id=private-skupper-router-5785c66959-pzxvg instance=1649950273 max_routers=128
2022-04-14 15:31:13.537329 +0000 AGENT (info) Activating management agent on $_management_internal
2022-04-14 15:31:13.537379 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-04-14 15:31:13.539404 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-04-14 15:31:13.540103 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-04-14 15:31:13.540387 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-04-14 15:31:13.540961 +0000 CONN_MGR (info) Created SSL Profile with name link1-profile
2022-04-14 15:31:13.541521 +0000 CONN_MGR (info) Created SSL Profile with name skupper-internal
2022-04-14 15:31:13.542993 +0000 CONN_MGR (info) Configured Connector: IP_2_HERE:55671 proto=any, role=inter-router, sslProfile=link1-profile
2022-04-14 15:31:13.543892 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-04-14 15:31:13.544939 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-04-14 15:31:13.545883 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:55671 proto=any, role=inter-router, sslProfile=skupper-internal
2022-04-14 15:31:13.546834 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:45671 proto=any, role=edge, sslProfile=skupper-internal
2022-04-14 15:31:13.547789 +0000 CONN_MGR (info) Configured Listener: 0.0.0.0:9090 proto=any, role=normal, http
2022-04-14 15:31:13.548022 +0000 SERVER (info) HTTP server thread running
2022-04-14 15:31:13.548092 +0000 SERVER (notice) Disabling ipv6 on 0.0.0.0:9090
2022-04-14 15:31:13.548205 +0000 SERVER (notice) Listening for HTTP on 0.0.0.0:9090
2022-04-14 15:31:13.548355 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-04-14 15:31:13.548494 +0000 SERVER (notice) Process VmSize 185.78 MiB (125.79 GiB available memory)
2022-04-14 15:31:13.548842 +0000 SERVER (notice) Listening on 0.0.0.0:5671
2022-04-14 15:31:13.548896 +0000 SERVER (notice) Listening on localhost:5672
2022-04-14 15:31:13.548959 +0000 SERVER (notice) Listening on 0.0.0.0:55671
2022-04-14 15:31:13.549004 +0000 SERVER (notice) Listening on 0.0.0.0:45671
2022-04-14 15:31:13.561381 +0000 SERVER (info) [C2] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:45179
2022-04-14 15:31:13.571077 +0000 SERVER (info) [C1] Connection to IP_2_HERE:55671 failed: proton:io Connection refused - disconnected IP_2_HERE:55671
2022-04-14 15:31:13.572902 +0000 ROUTER_CORE (info) [C2] Connection Opened: dir=in host=172.17.0.1:45179 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=mh4uCnl7drHqEER6ymxApnH_6gy7tGpbCGi7I_d5wwbnIbzZi6m4Vw props=
2022-04-14 15:31:13.573777 +0000 ROUTER_CORE (info) [C2][L2] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:31:13.574208 +0000 ROUTER_CORE (info) [C2][L3] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:31:13.574473 +0000 ROUTER_CORE (info) [C2][L4] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:31:13.576951 +0000 ROUTER_CORE (info) [C2][L5] Link attached: dir=out source={52bfef05-6bca-44e4-a201-be0dd704aa1e/skupper-site-query expire:sess} target={<none> expire:sess}
2022-04-14 15:31:13.768620 +0000 SERVER (info) [C3] Accepted connection to localhost:5672 from 127.0.0.1:57262
2022-04-14 15:31:13.769107 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=127.0.0.1:57262 vhost= encrypted=no auth=no user=anonymous container_id=40068a6d-c1b5-4af2-b192-f38ffa762979 props=
2022-04-14 15:31:13.771811 +0000 ROUTER_CORE (info) [C3][L6] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-04-14 15:31:13.774127 +0000 ROUTER_CORE (info) [C3][L7] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-04-14 15:31:13.791874 +0000 SERVER (info) [C3] Connection from 127.0.0.1:57262 (to localhost:5672) failed: amqp:connection:framing-error connection aborted
2022-04-14 15:31:13.792014 +0000 ROUTER_CORE (info) [C3][L6] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 15:31:13.792122 +0000 ROUTER_CORE (info) [C3][L7] Link lost: del=1 presett=1 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-04-14 15:31:13.792144 +0000 ROUTER_CORE (info) [C3] Connection Closed
2022-04-14 15:31:14.461829 +0000 SERVER (info) [C4] Accepted connection to 0.0.0.0:5671 from 172.17.0.1:1498
2022-04-14 15:31:14.473896 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=172.17.0.1:1498 vhost= encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=8WknCctAq47BPU9qNXZe_QIXg-lT0BclAGxLFwDTpy68gIcN9LIqAA props=
2022-04-14 15:31:14.474927 +0000 ROUTER_CORE (info) [C4][L8] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-04-14 15:31:14.475661 +0000 ROUTER_CORE (info) [C4][L9] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:sess}
2022-04-14 15:31:18.595517 +0000 SERVER (info) [C5] Connection to IP_2_HERE:55671 failed: proton:io Connection refused - disconnected IP_2_HERE:55671
2022-04-14 15:31:23.618365 +0000 SERVER (info) [C6] Connection to IP_2_HERE:55671 failed: proton:io Connection refused - disconnected IP_2_HERE:55671
2022-04-14 15:31:28.639222 +0000 SERVER (info) [C7] Connection to IP_2_HERE:55671 failed: proton:io Connection refused - disconnected IP_2_HERE:55671
grs commented 2 years ago

And if you exec into that pod and try to telnet to IP_2_HERE:55671, do you get the same thing?

CreatorSky commented 2 years ago

Yes, connection refused. Even though both ports 55671 & 45671 are allowed through firewall.

grs commented 2 years ago

If you can't connect to that IP and port then I suspect that there is something in between preventing the connection. As you said the console (which is plain http) worked, I suspect maybe there is an HTTP proxy through which all traffic is directed or something?

CreatorSky commented 2 years ago

So, something strange happened. When I checked link status after long weekend on Monday. It was active. From logs, it seems it kept trying to connect to the Public site but failed for 2-3 days and suddenly connected successfully.

I didn't change anything, the pods also haven't been restarted.

Today, I tried to connect another on-prem site - Private2 to Public site but same error: Connection failed: connection refused. Though another GKE site: Public2 can connect without any problem.

Attaching router logs here: router.log.

grs commented 2 years ago

Ok, that looks like something just resolved itself in the network. I would maybe ask your IT or GKE support if they have any further insight.