skupperproject / skupper

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

skupper-router restart leads to network interruption #940

Open chassing opened 1 year ago

chassing commented 1 year ago

A restart of the skupper-router leads to a network interruption of around 1 - 2 minutes, regardless of router replica count. In this example, I restarted the router at 10:33:30 and couldn't reach a skupper-exposed HTTP service until ~ 10:35:20.

site-config:

data:
  cluster-local: "false"
  console: "true"
  console-authentication: openshift
  console-ingress: route
  controller-cpu: 500m
  controller-memory: 1Gi
  controller-memory-limit: 1Gi
  controller-pod-antiaffinity: skupper.io/component=controller
  edge: "false"
  ingress: loadbalancer
  name: app-sre-stage-01-skupper-vault-net
  router-console: "true"
  router-cpu: 500m
  router-memory: 1Gi
  router-memory-limit: 1Gi
  router-pod-antiaffinity: skupper.io/component=router
  routers: "3"
  service-controller: "true"
  service-sync: "false"
...

skupper-router/config-sync log

2022/11/07 10:33:30 Config Sync
2022/11/07 10:33:30 Version: 1.1.1
2022/11/07 10:33:30 Creating kube client...
2022/11/07 10:33:30 Creating informer...
2022/11/07 10:33:30 Waiting for informer to sync...
2022/11/07 10:33:30 Starting sync loop...
2022/11/07 10:33:30 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:30 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:30.713605       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:31 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:31 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:31.713175       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:32 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:32 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:32.712565       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:33 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:33 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:33.713197       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:34 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:34 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:34.713005       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:35 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:33:35 Delayed requeue skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
E1107 10:33:35.713669       1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused
2022/11/07 10:35:05 TcpConnectors added=[], deleted=[]
2022/11/07 10:35:05 TcpListeners added=[], deleted=[]
2022/11/07 10:35:05 HttpConnectors added=[], deleted=[]
2022/11/07 10:35:05 HttpListeners added=[], deleted=[{vault:8080 0.0.0.0 1026 vault:8080 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842 HTTP1  false   <nil>}]
2022/11/07 10:35:05 SslProfiles added=[], deleted=[]
2022/11/07 10:35:05 Sync profiles: Added []  Deleted []
2022/11/07 10:35:05 DELETE io.skupper.router.httpListener vault:8080
2022/11/07 10:35:05 sync failed: Bridge config is not synchronised yet
2022/11/07 10:35:05 Requeuing skupper-vault-net/skupper-internal after error: Bridge config is not synchronised yet
E1107 10:35:05.990776       1 config_sync.go:166] Bridge config is not synchronised yet
2022/11/07 10:35:16 TcpConnectors added=[], deleted=[]
2022/11/07 10:35:16 TcpListeners added=[], deleted=[]
2022/11/07 10:35:16 HttpConnectors added=[], deleted=[]
2022/11/07 10:35:16 HttpListeners added=[{vault:8080  1027 vault:8080 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842   false   <nil>}], deleted=[]
2022/11/07 10:35:16 SslProfiles added=[], deleted=[]
2022/11/07 10:35:16 Sync profiles: Added []  Deleted []
2022/11/07 10:35:16 CREATE io.skupper.router.httpListener vault:8080 map[address:vault:8080 name:vault:8080 port:1027 siteId:2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842]
2022/11/07 10:35:16 sync failed: Bridge config is not synchronised yet
2022/11/07 10:35:16 Requeuing skupper-vault-net/skupper-internal after error: Bridge config is not synchronised yet
E1107 10:35:16.725835       1 config_sync.go:166] Bridge config is not synchronised yet

skupper-router/router log

Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
Waiting for IP address...
2022-11-07 10:33:39.591877 +0000 SERVER (info) Container Name: app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4
2022-11-07 10:33:39.591942 +0000 ROUTER (info) Router started in Interior mode, area=0 id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4
2022-11-07 10:33:39.591950 +0000 ROUTER (info) Version: 2.1.0
2022-11-07 10:33:39.592235 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links
2022-11-07 10:33:39.592249 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber
2022-11-07 10:33:39.592325 +0000 ROUTER_CORE (info) Core module enabled: mobile_sync
2022-11-07 10:33:39.592356 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds
2022-11-07 10:33:39.592363 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection
2022-11-07 10:33:39.592374 +0000 ROUTER_CORE (info) Core module enabled: heartbeat_server
2022-11-07 10:33:39.592379 +0000 ROUTER_CORE (info) Core module present but disabled: heartbeat_edge
2022-11-07 10:33:39.592383 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client
2022-11-07 10:33:39.592389 +0000 ROUTER_CORE (info) Core module enabled: edge_addr_tracking
2022-11-07 10:33:39.592393 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks
2022-11-07 10:33:39.592399 +0000 ROUTER_CORE (info) Core module present but disabled: edge_router
2022-11-07 10:33:39.592547 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp
2022-11-07 10:33:39.592566 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2
2022-11-07 10:33:39.592585 +0000 FLOW_LOG (info) Protocol logging started
2022-11-07 10:33:39.592647 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x
2022-11-07 10:33:39.592749 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp
2022-11-07 10:33:39.592800 +0000 ROUTER_CORE (info) Router Core thread running. 0/app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4
2022-11-07 10:33:39.592837 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter.ma
2022-11-07 10:33:39.592856 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter.ma
2022-11-07 10:33:39.592864 +0000 ROUTER_CORE (info) In-process subscription M/$management
2022-11-07 10:33:39.592960 +0000 ROUTER_CORE (info) In-process subscription L/$management
2022-11-07 10:33:39.593050 +0000 ROUTER_CORE (info) In-process subscription M/sfe.j27x4:0
2022-11-07 10:33:39.593067 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter
2022-11-07 10:33:39.593075 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter
2022-11-07 10:33:39.593082 +0000 ROUTER_CORE (info) In-process subscription L/qdhello
2022-11-07 10:33:39.593212 +0000 ROUTER (info) Router Engine Instantiated: id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 instance=1667817219 max_routers=128
2022-11-07 10:33:39.601999 +0000 AGENT (info) Activating management agent on $_management_internal
2022-11-07 10:33:39.602044 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal
2022-11-07 10:33:39.603668 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false'
2022-11-07 10:33:39.604507 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default'
2022-11-07 10:33:39.604804 +0000 CONN_MGR (info) Created SSL Profile with name skupper-service-client
2022-11-07 10:33:39.605399 +0000 CONN_MGR (info) Created SSL Profile with name skupper-internal
2022-11-07 10:33:39.605937 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps
2022-11-07 10:33:39.607146 +0000 HTTP_ADAPTOR (info) Configured HTTP_ADAPTOR listener on 0.0.0.0:1026
2022-11-07 10:33:39.607946 +0000 CONN_MGR (info) Configured Listener: :55671 proto=any, role=inter-router, sslProfile=skupper-internal
2022-11-07 10:33:39.609196 +0000 CONN_MGR (info) Configured Listener: :45671 proto=any, role=edge, sslProfile=skupper-internal
2022-11-07 10:33:39.610458 +0000 CONN_MGR (info) Configured Listener: :9090 proto=any, role=normal, http
2022-11-07 10:33:39.611619 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal
2022-11-07 10:33:39.612830 +0000 CONN_MGR (info) Configured Listener: :5671 proto=any, role=normal, sslProfile=skupper-amqps
2022-11-07 10:33:39.613064 +0000 SERVER (info) HTTP server thread running
2022-11-07 10:33:39.613311 +0000 SERVER (notice) Listening for HTTP on :9090
2022-11-07 10:33:39.614029 +0000 CONN_MGR (info) Configured Listener: localhost:8888 proto=any, role=normal, http
2022-11-07 10:33:39.614262 +0000 SERVER (notice) Listening for HTTP on localhost:8888
2022-11-07 10:33:39.614779 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1)
2022-11-07 10:33:39.614948 +0000 SERVER (notice) Process VmSize 327.38 MiB (1.00 GiB available memory)
2022-11-07 10:33:39.663782 +0000 SERVER (notice) Listening on :55671
2022-11-07 10:33:39.663840 +0000 SERVER (notice) Listening on :45671
2022-11-07 10:33:39.663881 +0000 SERVER (notice) Listening on :5671
2022-11-07 10:33:39.663905 +0000 SERVER (notice) Listening on localhost:5672
2022-11-07 10:33:39.902739 +0000 SERVER (info) [C2] Accepted connection to :55671 from 10.128.20.57:42514
2022-11-07 10:33:39.907627 +0000 SERVER (info) [C1] Accepted connection to :55671 from 10.128.20.57:42500
2022-11-07 10:33:39.907661 +0000 SERVER (info) [C3] Accepted connection to :55671 from 10.128.20.57:42516
2022-11-07 10:33:39.964560 +0000 SERVER (info) [C6] Accepted connection to :55671 from 10.130.2.64:40652
2022-11-07 10:33:39.966425 +0000 SERVER (info) [C5] Accepted connection to :55671 from 10.130.2.64:40656
2022-11-07 10:33:39.966458 +0000 SERVER (info) [C4] Accepted connection to :55671 from 10.130.2.64:40650
2022-11-07 10:33:39.973363 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=10.128.20.57:42516 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=6, :"qd.group-correlator"="6DR7S2eGvQKBF0w", :"qd.annotations-version"=2}
2022-11-07 10:33:39.973462 +0000 ROUTER_CORE (info) [C2] Connection Opened: dir=in host=10.128.20.57:42514 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=5, :"qd.inter-router-role"=4, :"qd.group-correlator"="6DR7S2eGvQKBF0w"}
2022-11-07 10:33:39.973505 +0000 ROUTER_CORE (info) [C1] Connection Opened: dir=in host=10.128.20.57:42500 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=4, :"qd.inter-router-role"=4, :"qd.group-correlator"="6DR7S2eGvQKBF0w"}
2022-11-07 10:33:39.975653 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:33:39.975705 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:33:39.975725 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975738 +0000 ROUTER_CORE (info) [C3][L5] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975749 +0000 ROUTER_CORE (info) [C3][L6] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975761 +0000 ROUTER_CORE (info) [C3][L7] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975802 +0000 ROUTER_CORE (info) [C3][L8] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975819 +0000 ROUTER_CORE (info) [C3][L9] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975826 +0000 ROUTER_CORE (info) [C3][L10] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975833 +0000 ROUTER_CORE (info) [C3][L11] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975843 +0000 ROUTER_CORE (info) [C3][L12] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975853 +0000 ROUTER_CORE (info) [C3][L13] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975864 +0000 ROUTER_CORE (info) [C3][L14] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975874 +0000 ROUTER_CORE (info) [C3][L15] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975884 +0000 ROUTER_CORE (info) [C3][L16] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975895 +0000 ROUTER_CORE (info) [C3][L17] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975905 +0000 ROUTER_CORE (info) [C3][L18] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975917 +0000 ROUTER_CORE (info) [C3][L19] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975928 +0000 ROUTER_CORE (info) [C3][L20] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975938 +0000 ROUTER_CORE (info) [C3][L21] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975950 +0000 ROUTER_CORE (info) [C3][L22] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:39.975960 +0000 ROUTER_CORE (info) [C3][L23] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.006484 +0000 ROUTER_CORE (info) [C5] Connection Opened: dir=in host=10.130.2.64:40656 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=3, :"qd.group-correlator"="WBLoAjkVAW1GlUy", :"qd.annotations-version"=2}
2022-11-07 10:33:40.007475 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=10.130.2.64:40652 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=2, :"qd.inter-router-role"=4, :"qd.group-correlator"="WBLoAjkVAW1GlUy"}
2022-11-07 10:33:40.008858 +0000 ROUTER_CORE (info) [C5][L24] Link attached: dir=out source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:33:40.008887 +0000 ROUTER_CORE (info) [C5][L25] Link attached: dir=in source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:33:40.008901 +0000 ROUTER_CORE (info) [C5][L26] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008912 +0000 ROUTER_CORE (info) [C5][L27] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008922 +0000 ROUTER_CORE (info) [C5][L28] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008934 +0000 ROUTER_CORE (info) [C5][L29] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008946 +0000 ROUTER_CORE (info) [C5][L30] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008973 +0000 ROUTER_CORE (info) [C5][L31] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008986 +0000 ROUTER_CORE (info) [C5][L32] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.008999 +0000 ROUTER_CORE (info) [C5][L33] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009011 +0000 ROUTER_CORE (info) [C5][L34] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009024 +0000 ROUTER_CORE (info) [C5][L35] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009037 +0000 ROUTER_CORE (info) [C5][L36] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009050 +0000 ROUTER_CORE (info) [C5][L37] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009071 +0000 ROUTER_CORE (info) [C5][L38] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009090 +0000 ROUTER_CORE (info) [C5][L39] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009142 +0000 ROUTER_CORE (info) [C5][L40] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009157 +0000 ROUTER_CORE (info) [C5][L41] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009168 +0000 ROUTER_CORE (info) [C5][L42] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009204 +0000 ROUTER_CORE (info) [C5][L43] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009224 +0000 ROUTER_CORE (info) [C5][L44] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.009233 +0000 ROUTER_CORE (info) [C5][L45] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:33:40.011133 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=10.130.2.64:40650 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=1, :"qd.inter-router-role"=4, :"qd.group-correlator"="WBLoAjkVAW1GlUy"}
2022-11-07 10:33:40.259285 +0000 SERVER (info) [C7] Accepted connection to :5671 from 10.129.24.15:58352
2022-11-07 10:33:40.259324 +0000 SERVER (info) [C8] Accepted connection to :5671 from 10.129.24.15:58340
2022-11-07 10:33:40.269461 +0000 ROUTER_CORE (info) [C7] Connection Opened: dir=in host=10.129.24.15:58352 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=YHmGVL4d9qv6sQal0hOdlKqprnxpE1FuH35bZDkED5HMjauGlsyauw props=
2022-11-07 10:33:40.269565 +0000 ROUTER_CORE (info) [C8] Connection Opened: dir=in host=10.129.24.15:58340 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=Q_amYedpJP0swMhB2PRrFoil0ni4KzLpAUyslYQr92QghSh25XzsmQ props=
2022-11-07 10:33:40.271224 +0000 ROUTER_CORE (info) [C8][L46] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:33:40.271264 +0000 ROUTER_CORE (info) [C7][L47] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={<none> expire:sess}
2022-11-07 10:33:40.272117 +0000 ROUTER_CORE (info) [C8][L48] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-11-07 10:33:40.272962 +0000 ROUTER_CORE (info) [C8][L49] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:33:40.275415 +0000 ROUTER_CORE (info) [C8][L50] Link attached: dir=out source={2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842/skupper-site-query expire:sess} target={<none> expire:sess}
2022-11-07 10:33:41.584558 +0000 SERVER (info) [C9] Accepted connection to :55671 from 10.128.4.1:9223
2022-11-07 10:33:41.584626 +0000 SERVER (info) [C9] Connection from 10.128.4.1:9223 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:33:41.592480 +0000 FLOW_LOG (info) ROUTER [j27x4:0] BEGIN parent=2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842 namespace=skupper-vault-net imageName=skupper-router imageVersion=latest hostname=skupper-router-59fb8cd5-j27x4 name=0/app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 buildVersion=2.1.0
2022-11-07 10:33:41.595127 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'}
2022-11-07 10:33:41.595172 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1}
2022-11-07 10:33:41.595210 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': [], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': []}
2022-11-07 10:33:41.595256 +0000 ROUTER_LS (info) Computed radius: 1
2022-11-07 10:33:42.596294 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'}
2022-11-07 10:33:42.596378 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1}
2022-11-07 10:33:42.596409 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx']}
2022-11-07 10:33:42.596436 +0000 ROUTER_LS (info) Computed radius: 1
2022-11-07 10:33:47.598025 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'}
2022-11-07 10:33:47.598092 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1}
2022-11-07 10:33:47.598122 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': [], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': []}
2022-11-07 10:33:47.598155 +0000 ROUTER_LS (info) Computed radius: 1
2022-11-07 10:34:01.519854 +0000 SERVER (info) [C10] Accepted connection to :55671 from 10.128.4.1:6850
2022-11-07 10:34:01.577175 +0000 SERVER (info) [C10] Connection from 10.128.4.1:6850 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:34:21.520506 +0000 SERVER (info) [C11] Accepted connection to :55671 from 10.128.4.1:37950
2022-11-07 10:34:21.576799 +0000 SERVER (info) [C11] Connection from 10.128.4.1:37950 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:34:30.530882 +0000 SERVER (info) [C12] Accepted connection to localhost:5672 from ::1:33864
2022-11-07 10:34:30.531070 +0000 ROUTER_CORE (info) [C12] Connection Opened: dir=in host=::1:33864 encrypted=no auth=no user=anonymous container_id=stLMzSKUwIp1urrkMqbeshytHRZA2O6j0VdBQgWGefdP0C7Th40A8w props=
2022-11-07 10:34:30.531537 +0000 ROUTER_CORE (info) [C12][L51] Link attached: dir=out source={(dyn)<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:34:30.531757 +0000 ROUTER_CORE (info) [C12][L52] Link attached: dir=in source={<none> expire:sess} target={$management expire:sess}
2022-11-07 10:34:30.531976 +0000 ROUTER_CORE (info) [C12][L53] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:34:41.520919 +0000 SERVER (info) [C13] Accepted connection to :55671 from 10.128.4.1:9490
2022-11-07 10:34:41.578183 +0000 SERVER (info) [C13] Connection from 10.128.4.1:9490 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:35:01.521059 +0000 SERVER (info) [C14] Accepted connection to :55671 from 10.128.4.1:62637
2022-11-07 10:35:01.577150 +0000 SERVER (info) [C14] Connection from 10.128.4.1:62637 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:35:05.990242 +0000 HTTP_ADAPTOR (info) Deleting HttpListener for vault:8080, 0.0.0.0:1026
2022-11-07 10:35:05.990291 +0000 HTTP_ADAPTOR (info) Deleted HTTP adaptor configuration 'vault:8080' for address vault:8080, 0.0.0.0:1026, siteId 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842.
2022-11-07 10:35:06.021776 +0000 FLOW_LOG (info) LISTENER [j27x4:1] BEGIN END parent=j27x4:0 destHost=0.0.0.0 protocol=http1 destPort=1026 vanAddress=vault:8080 name=vault:8080
2022-11-07 10:35:11.583922 +0000 SERVER (info) [C15] Accepted connection to :55671 from 10.128.4.1:9701
2022-11-07 10:35:11.584000 +0000 SERVER (info) [C15] Connection from 10.128.4.1:9701 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:35:12.620949 +0000 SERVER (info) [C16] Accepted connection to :45671 from 10.128.4.1:56961
2022-11-07 10:35:12.622648 +0000 SERVER (info) [C17] Accepted connection to :55671 from 10.128.4.1:65057
2022-11-07 10:35:12.629187 +0000 SERVER (info) [C18] Accepted connection to :55671 from 10.128.4.1:12849
2022-11-07 10:35:12.630713 +0000 ROUTER_CORE (info) [C16] Connection Opened: dir=in host=10.128.4.1:56961 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=26, :"qd.annotations-version"=2}
2022-11-07 10:35:12.632995 +0000 ROUTER_CORE (info) [C17] Connection Opened: dir=in host=10.128.4.1:65057 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=121527, :"qd.inter-router-role"=4, :"qd.group-correlator"="gYQ40+7+lj0r2zG"}
2022-11-07 10:35:12.633034 +0000 ROUTER_CORE (info) [C16] Client attached to heartbeat server (container=appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb, endpoint=0x7f5fb40e2588)
2022-11-07 10:35:12.633057 +0000 ROUTER_CORE (info) [C16][L54] Link attached: dir=in source={<none> expire:sess} target={_$qd.edge_heartbeat expire:link}
2022-11-07 10:35:12.633102 +0000 ROUTER_CORE (info) [C16][L55] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:35:12.633131 +0000 ROUTER_CORE (info) [C16][L56] Link attached: dir=out source={appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb expire:link caps::"qd.router-edge-downlink"} target={<none> expire:sess caps::"qd.router-edge-downlink"}
2022-11-07 10:35:12.633169 +0000 ROUTER_CORE (info) [C16][L57] Link attached: dir=out source={_$qd.edge_addr_tracking expire:link} target={<none> expire:sess}
2022-11-07 10:35:12.633197 +0000 ROUTER_CORE (info) [C16][L58] Link attached: dir=in source={<none> expire:sess} target={mc/sfe.all expire:link}
2022-11-07 10:35:12.633212 +0000 ROUTER_CORE (info) [C16][L59] Link attached: dir=in source={<none> expire:sess} target={mc/sfe.k7jmb:0 expire:link}
2022-11-07 10:35:12.633226 +0000 ROUTER_CORE (info) [C16][L60] Link attached: dir=out source={sfe.k7jmb:0 expire:link} target={<none> expire:sess}
2022-11-07 10:35:12.633241 +0000 ROUTER_CORE (info) [C16][L61] Link attached: dir=out source={vault:8080 expire:link} target={<none> expire:sess}
2022-11-07 10:35:12.633253 +0000 ROUTER_CORE (info) [C16][L62] Link attached: dir=in source={<none> expire:sess} target={vault:8080 expire:link}
2022-11-07 10:35:12.633273 +0000 ROUTER_CORE (info) [C16][L63] Link attached: dir=in source={<none> expire:sess} target={mc/$skupper-service-sync expire:link}
2022-11-07 10:35:12.636774 +0000 ROUTER_CORE (info) [C18] Connection Opened: dir=in host=10.128.4.1:12849 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=121528, :"qd.group-correlator"="gYQ40+7+lj0r2zG", :"qd.annotations-version"=2}
2022-11-07 10:35:12.638795 +0000 ROUTER_CORE (info) [C18][L64] Link attached: dir=out source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:35:12.638833 +0000 ROUTER_CORE (info) [C18][L65] Link attached: dir=in source={<none> expire:sess caps::"qd.router"} target={<none> expire:sess caps::"qd.router"}
2022-11-07 10:35:12.638882 +0000 ROUTER_CORE (info) [C18][L66] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.638900 +0000 ROUTER_CORE (info) [C18][L67] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.638912 +0000 ROUTER_CORE (info) [C18][L68] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.638924 +0000 ROUTER_CORE (info) [C18][L69] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.638936 +0000 ROUTER_CORE (info) [C18][L70] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.638988 +0000 ROUTER_CORE (info) [C18][L71] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639007 +0000 ROUTER_CORE (info) [C18][L72] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639020 +0000 ROUTER_CORE (info) [C18][L73] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639031 +0000 ROUTER_CORE (info) [C18][L74] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639042 +0000 ROUTER_CORE (info) [C18][L75] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639054 +0000 ROUTER_CORE (info) [C18][L76] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639065 +0000 ROUTER_CORE (info) [C18][L77] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639075 +0000 ROUTER_CORE (info) [C18][L78] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639088 +0000 ROUTER_CORE (info) [C18][L79] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639099 +0000 ROUTER_CORE (info) [C18][L80] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639111 +0000 ROUTER_CORE (info) [C18][L81] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639126 +0000 ROUTER_CORE (info) [C18][L82] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639137 +0000 ROUTER_CORE (info) [C18][L83] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639147 +0000 ROUTER_CORE (info) [C18][L84] Link attached: dir=out source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:12.639159 +0000 ROUTER_CORE (info) [C18][L85] Link attached: dir=in source={<none> expire:sess caps::"qd.router-data"} target={<none> expire:sess caps::"qd.router-data"}
2022-11-07 10:35:14.627760 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'}
2022-11-07 10:35:14.627830 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 2, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 2}
2022-11-07 10:35:14.627944 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm']}
2022-11-07 10:35:14.628005 +0000 ROUTER_LS (info) Computed radius: 2
2022-11-07 10:35:16.630330 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'}
2022-11-07 10:35:16.630412 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 2, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 2}
2022-11-07 10:35:16.630459 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm']}
2022-11-07 10:35:16.630486 +0000 ROUTER_LS (info) Computed radius: 2
2022-11-07 10:35:16.724837 +0000 HTTP_ADAPTOR (info) Configured HTTP_ADAPTOR listener on 0.0.0.0:1027
2022-11-07 10:35:16.725756 +0000 HTTP_ADAPTOR (info) Listener vault:8080: listening for client connections on 0.0.0.0:1027 with backlog 128
2022-11-07 10:35:21.584199 +0000 SERVER (info) [C19] Accepted connection to :55671 from 10.128.4.1:46705
2022-11-07 10:35:21.584241 +0000 SERVER (info) [C19] Connection from 10.128.4.1:46705 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted)
2022-11-07 10:35:22.006259 +0000 HTTP_ADAPTOR (info) Listener vault:8080: new incoming client connection to 0.0.0.0:1027
2022-11-07 10:35:22.006505 +0000 ROUTER_CORE (info) [C20] Connection Opened: dir=in host=10.128.34.20:42706 encrypted=no auth=no user= container_id=HTTP/1.x Adaptor props=
2022-11-07 10:35:22.006560 +0000 HTTP_ADAPTOR (info) [C20] HTTP/1.x client connection established from 10.128.34.20:42706
2022-11-07 10:35:22.006584 +0000 ROUTER_CORE (info) [C20][L86] Link attached: dir=out source={(dyn)<none> expire:link} target={<none> expire:link}
2022-11-07 10:35:22.006683 +0000 ROUTER_CORE (info) [C20][L87] Link attached: dir=in source={<none> expire:link} target={vault:8080 expire:link}
2022-11-07 10:35:22.010516 +0000 ROUTER_CORE (info) [C16][L88] Link attached: dir=in source={<none> expire:sess} target={<none> expire:sess}
2022-11-07 10:35:22.013127 +0000 HTTP_ADAPTOR (info) [C20] HTTP/1.x client disconnected
2022-11-07 10:35:22.013166 +0000 ROUTER_CORE (info) [C20][L86] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-11-07 10:35:22.013200 +0000 ROUTER_CORE (info) [C20][L87] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
2022-11-07 10:35:22.013210 +0000 ROUTER_CORE (info) [C20] Connection Closed

Skupper Version:

oc get deploy skupper-site-controller -oyaml | grep image
...
image: quay.io/skupper/site-controller:1.1.1
...

I've tested it several times by restarting the router pods via oc rollout restart deployment.apps/skupper-router

ted-ross commented 1 year ago

Thanks for raising this. If there is more than one replica, there should be no outage of connectivity during the rollout-restart.

-Ted

On Mon, Nov 7, 2022 at 6:22 AM Christian Assing @.***> wrote:

A restart of the skupper-router leads to a network interruption of around 1 - 2 minutes, regardless of router replica count. In this example, I restarted the router at 10:33:30 and couldn't reach a skupper-exposed HTTP service until ~ 10:35:20.

site-config:

data: cluster-local: "false" console: "true" console-authentication: openshift console-ingress: route controller-cpu: 500m controller-memory: 1Gi controller-memory-limit: 1Gi controller-pod-antiaffinity: skupper.io/component=controller edge: "false" ingress: loadbalancer name: app-sre-stage-01-skupper-vault-net router-console: "true" router-cpu: 500m router-memory: 1Gi router-memory-limit: 1Gi router-pod-antiaffinity: skupper.io/component=router routers: "3" service-controller: "true" service-sync: "false" ...

skupper-router/config-sync log

2022/11/07 10:33:30 Config Sync 2022/11/07 10:33:30 Version: 1.1.1 2022/11/07 10:33:30 Creating kube client... 2022/11/07 10:33:30 Creating informer... 2022/11/07 10:33:30 Waiting for informer to sync... 2022/11/07 10:33:30 Starting sync loop... 2022/11/07 10:33:30 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:30 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:30.713605 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:31 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:31 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:31.713175 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:32 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:32 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:32.712565 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:33 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:33 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:33.713197 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:34 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:34 Requeuing skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:34.713005 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:35 sync failed: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:33:35 Delayed requeue skupper-vault-net/skupper-internal after error: Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused E1107 10:33:35.713669 1 config_sync.go:166] Could not get management agent : Failed to create connection: dial tcp [::1]:5672: connect: connection refused 2022/11/07 10:35:05 TcpConnectors added=[], deleted=[] 2022/11/07 10:35:05 TcpListeners added=[], deleted=[] 2022/11/07 10:35:05 HttpConnectors added=[], deleted=[] 2022/11/07 10:35:05 HttpListeners added=[], deleted=[{vault:8080 0.0.0.0 1026 vault:8080 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842 HTTP1 false }] 2022/11/07 10:35:05 SslProfiles added=[], deleted=[] 2022/11/07 10:35:05 Sync profiles: Added [] Deleted [] 2022/11/07 10:35:05 DELETE io.skupper.router.httpListener vault:8080 2022/11/07 10:35:05 sync failed: Bridge config is not synchronised yet 2022/11/07 10:35:05 Requeuing skupper-vault-net/skupper-internal after error: Bridge config is not synchronised yet E1107 10:35:05.990776 1 config_sync.go:166] Bridge config is not synchronised yet 2022/11/07 10:35:16 TcpConnectors added=[], deleted=[] 2022/11/07 10:35:16 TcpListeners added=[], deleted=[] 2022/11/07 10:35:16 HttpConnectors added=[], deleted=[] 2022/11/07 10:35:16 HttpListeners added=[{vault:8080 1027 vault:8080 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842 false }], deleted=[] 2022/11/07 10:35:16 SslProfiles added=[], deleted=[] 2022/11/07 10:35:16 Sync profiles: Added [] Deleted [] 2022/11/07 10:35:16 CREATE io.skupper.router.httpListener vault:8080 map[address:vault:8080 name:vault:8080 port:1027 siteId:2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842] 2022/11/07 10:35:16 sync failed: Bridge config is not synchronised yet 2022/11/07 10:35:16 Requeuing skupper-vault-net/skupper-internal after error: Bridge config is not synchronised yet E1107 10:35:16.725835 1 config_sync.go:166] Bridge config is not synchronised yet

skupper-router/router log

Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... Waiting for IP address... 2022-11-07 10:33:39.591877 +0000 SERVER (info) Container Name: app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 2022-11-07 10:33:39.591942 +0000 ROUTER (info) Router started in Interior mode, area=0 id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 2022-11-07 10:33:39.591950 +0000 ROUTER (info) Version: 2.1.0 2022-11-07 10:33:39.592235 +0000 ROUTER_CORE (info) Streaming link scrubber: Scan interval: 30 seconds, max free pool: 128 links 2022-11-07 10:33:39.592249 +0000 ROUTER_CORE (info) Core module enabled: streaming_link_scrubber 2022-11-07 10:33:39.592325 +0000 ROUTER_CORE (info) Core module enabled: mobile_sync 2022-11-07 10:33:39.592356 +0000 ROUTER_CORE (info) Stuck delivery detection: Scan interval: 30 seconds, Delivery age threshold: 10 seconds 2022-11-07 10:33:39.592363 +0000 ROUTER_CORE (info) Core module enabled: stuck_delivery_detection 2022-11-07 10:33:39.592374 +0000 ROUTER_CORE (info) Core module enabled: heartbeat_server 2022-11-07 10:33:39.592379 +0000 ROUTER_CORE (info) Core module present but disabled: heartbeat_edge 2022-11-07 10:33:39.592383 +0000 ROUTER_CORE (info) Core module enabled: address_lookup_client 2022-11-07 10:33:39.592389 +0000 ROUTER_CORE (info) Core module enabled: edge_addr_tracking 2022-11-07 10:33:39.592393 +0000 ROUTER_CORE (info) Core module present but disabled: core_test_hooks 2022-11-07 10:33:39.592399 +0000 ROUTER_CORE (info) Core module present but disabled: edge_router 2022-11-07 10:33:39.592547 +0000 ROUTER_CORE (info) Protocol adaptor registered: tcp 2022-11-07 10:33:39.592566 +0000 ROUTER_CORE (info) Protocol adaptor registered: http2 2022-11-07 10:33:39.592585 +0000 FLOW_LOG (info) Protocol logging started 2022-11-07 10:33:39.592647 +0000 ROUTER_CORE (info) Protocol adaptor registered: http/1.x 2022-11-07 10:33:39.592749 +0000 ROUTER_CORE (info) Protocol adaptor registered: amqp 2022-11-07 10:33:39.592800 +0000 ROUTER_CORE (info) Router Core thread running. 0/app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 2022-11-07 10:33:39.592837 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter.ma 2022-11-07 10:33:39.592856 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter.ma 2022-11-07 10:33:39.592864 +0000 ROUTER_CORE (info) In-process subscription M/$management 2022-11-07 10:33:39.592960 +0000 ROUTER_CORE (info) In-process subscription L/$management 2022-11-07 10:33:39.593050 +0000 ROUTER_CORE (info) In-process subscription M/sfe.j27x4:0 2022-11-07 10:33:39.593067 +0000 ROUTER_CORE (info) In-process subscription L/qdrouter 2022-11-07 10:33:39.593075 +0000 ROUTER_CORE (info) In-process subscription T/qdrouter 2022-11-07 10:33:39.593082 +0000 ROUTER_CORE (info) In-process subscription L/qdhello 2022-11-07 10:33:39.593212 +0000 ROUTER (info) Router Engine Instantiated: id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 instance=1667817219 max_routers=128 2022-11-07 10:33:39.601999 +0000 AGENT (info) Activating management agent on $_management_internal 2022-11-07 10:33:39.602044 +0000 ROUTER_CORE (info) In-process subscription L/$_management_internal 2022-11-07 10:33:39.603668 +0000 POLICY (info) Policy configured maxConnections: 65535, policyDir: '',access rules enabled: 'false', use hostname patterns: 'false' 2022-11-07 10:33:39.604507 +0000 POLICY (info) Policy fallback defaultVhost is defined: '$default' 2022-11-07 10:33:39.604804 +0000 CONN_MGR (info) Created SSL Profile with name skupper-service-client 2022-11-07 10:33:39.605399 +0000 CONN_MGR (info) Created SSL Profile with name skupper-internal 2022-11-07 10:33:39.605937 +0000 CONN_MGR (info) Created SSL Profile with name skupper-amqps 2022-11-07 10:33:39.607146 +0000 HTTP_ADAPTOR (info) Configured HTTP_ADAPTOR listener on 0.0.0.0:1026 2022-11-07 10:33:39.607946 +0000 CONN_MGR (info) Configured Listener: :55671 proto=any, role=inter-router, sslProfile=skupper-internal 2022-11-07 10:33:39.609196 +0000 CONN_MGR (info) Configured Listener: :45671 proto=any, role=edge, sslProfile=skupper-internal 2022-11-07 10:33:39.610458 +0000 CONN_MGR (info) Configured Listener: :9090 proto=any, role=normal, http 2022-11-07 10:33:39.611619 +0000 CONN_MGR (info) Configured Listener: localhost:5672 proto=any, role=normal 2022-11-07 10:33:39.612830 +0000 CONN_MGR (info) Configured Listener: :5671 proto=any, role=normal, sslProfile=skupper-amqps 2022-11-07 10:33:39.613064 +0000 SERVER (info) HTTP server thread running 2022-11-07 10:33:39.613311 +0000 SERVER (notice) Listening for HTTP on :9090 2022-11-07 10:33:39.614029 +0000 CONN_MGR (info) Configured Listener: localhost:8888 proto=any, role=normal, http 2022-11-07 10:33:39.614262 +0000 SERVER (notice) Listening for HTTP on localhost:8888 2022-11-07 10:33:39.614779 +0000 SERVER (notice) Operational, 4 Threads Running (process ID 1) 2022-11-07 10:33:39.614948 +0000 SERVER (notice) Process VmSize 327.38 MiB (1.00 GiB available memory) 2022-11-07 10:33:39.663782 +0000 SERVER (notice) Listening on :55671 2022-11-07 10:33:39.663840 +0000 SERVER (notice) Listening on :45671 2022-11-07 10:33:39.663881 +0000 SERVER (notice) Listening on :5671 2022-11-07 10:33:39.663905 +0000 SERVER (notice) Listening on localhost:5672 2022-11-07 10:33:39.902739 +0000 SERVER (info) [C2] Accepted connection to :55671 from 10.128.20.57:42514 2022-11-07 10:33:39.907627 +0000 SERVER (info) [C1] Accepted connection to :55671 from 10.128.20.57:42500 2022-11-07 10:33:39.907661 +0000 SERVER (info) [C3] Accepted connection to :55671 from 10.128.20.57:42516 2022-11-07 10:33:39.964560 +0000 SERVER (info) [C6] Accepted connection to :55671 from 10.130.2.64:40652 2022-11-07 10:33:39.966425 +0000 SERVER (info) [C5] Accepted connection to :55671 from 10.130.2.64:40656 2022-11-07 10:33:39.966458 +0000 SERVER (info) [C4] Accepted connection to :55671 from 10.130.2.64:40650 2022-11-07 10:33:39.973363 +0000 ROUTER_CORE (info) [C3] Connection Opened: dir=in host=10.128.20.57:42516 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=6, :"qd.group-correlator"="6DR7S2eGvQKBF0w", :"qd.annotations-version"=2} 2022-11-07 10:33:39.973462 +0000 ROUTER_CORE (info) [C2] Connection Opened: dir=in host=10.128.20.57:42514 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=5, :"qd.inter-router-role"=4, :"qd.group-correlator"="6DR7S2eGvQKBF0w"} 2022-11-07 10:33:39.973505 +0000 ROUTER_CORE (info) [C1] Connection Opened: dir=in host=10.128.20.57:42500 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=4, :"qd.inter-router-role"=4, :"qd.group-correlator"="6DR7S2eGvQKBF0w"} 2022-11-07 10:33:39.975653 +0000 ROUTER_CORE (info) [C3][L2] Link attached: dir=out source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:33:39.975705 +0000 ROUTER_CORE (info) [C3][L3] Link attached: dir=in source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:33:39.975725 +0000 ROUTER_CORE (info) [C3][L4] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975738 +0000 ROUTER_CORE (info) [C3][L5] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975749 +0000 ROUTER_CORE (info) [C3][L6] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975761 +0000 ROUTER_CORE (info) [C3][L7] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975802 +0000 ROUTER_CORE (info) [C3][L8] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975819 +0000 ROUTER_CORE (info) [C3][L9] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975826 +0000 ROUTER_CORE (info) [C3][L10] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975833 +0000 ROUTER_CORE (info) [C3][L11] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975843 +0000 ROUTER_CORE (info) [C3][L12] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975853 +0000 ROUTER_CORE (info) [C3][L13] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975864 +0000 ROUTER_CORE (info) [C3][L14] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975874 +0000 ROUTER_CORE (info) [C3][L15] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975884 +0000 ROUTER_CORE (info) [C3][L16] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975895 +0000 ROUTER_CORE (info) [C3][L17] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975905 +0000 ROUTER_CORE (info) [C3][L18] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975917 +0000 ROUTER_CORE (info) [C3][L19] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975928 +0000 ROUTER_CORE (info) [C3][L20] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975938 +0000 ROUTER_CORE (info) [C3][L21] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975950 +0000 ROUTER_CORE (info) [C3][L22] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:39.975960 +0000 ROUTER_CORE (info) [C3][L23] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.006484 +0000 ROUTER_CORE (info) [C5] Connection Opened: dir=in host=10.130.2.64:40656 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=3, :"qd.group-correlator"="WBLoAjkVAW1GlUy", :"qd.annotations-version"=2} 2022-11-07 10:33:40.007475 +0000 ROUTER_CORE (info) [C6] Connection Opened: dir=in host=10.130.2.64:40652 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=2, :"qd.inter-router-role"=4, :"qd.group-correlator"="WBLoAjkVAW1GlUy"} 2022-11-07 10:33:40.008858 +0000 ROUTER_CORE (info) [C5][L24] Link attached: dir=out source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:33:40.008887 +0000 ROUTER_CORE (info) [C5][L25] Link attached: dir=in source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:33:40.008901 +0000 ROUTER_CORE (info) [C5][L26] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008912 +0000 ROUTER_CORE (info) [C5][L27] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008922 +0000 ROUTER_CORE (info) [C5][L28] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008934 +0000 ROUTER_CORE (info) [C5][L29] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008946 +0000 ROUTER_CORE (info) [C5][L30] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008973 +0000 ROUTER_CORE (info) [C5][L31] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008986 +0000 ROUTER_CORE (info) [C5][L32] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.008999 +0000 ROUTER_CORE (info) [C5][L33] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009011 +0000 ROUTER_CORE (info) [C5][L34] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009024 +0000 ROUTER_CORE (info) [C5][L35] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009037 +0000 ROUTER_CORE (info) [C5][L36] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009050 +0000 ROUTER_CORE (info) [C5][L37] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009071 +0000 ROUTER_CORE (info) [C5][L38] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009090 +0000 ROUTER_CORE (info) [C5][L39] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009142 +0000 ROUTER_CORE (info) [C5][L40] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009157 +0000 ROUTER_CORE (info) [C5][L41] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009168 +0000 ROUTER_CORE (info) [C5][L42] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009204 +0000 ROUTER_CORE (info) [C5][L43] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009224 +0000 ROUTER_CORE (info) [C5][L44] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.009233 +0000 ROUTER_CORE (info) [C5][L45] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:33:40.011133 +0000 ROUTER_CORE (info) [C4] Connection Opened: dir=in host=10.130.2.64:40650 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router container_id=app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=1, :"qd.inter-router-role"=4, :"qd.group-correlator"="WBLoAjkVAW1GlUy"} 2022-11-07 10:33:40.259285 +0000 SERVER (info) [C7] Accepted connection to :5671 from 10.129.24.15:58352 2022-11-07 10:33:40.259324 +0000 SERVER (info) [C8] Accepted connection to :5671 from 10.129.24.15:58340 2022-11-07 10:33:40.269461 +0000 ROUTER_CORE (info) [C7] Connection Opened: dir=in host=10.129.24.15:58352 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=YHmGVL4d9qv6sQal0hOdlKqprnxpE1FuH35bZDkED5HMjauGlsyauw props= 2022-11-07 10:33:40.269565 +0000 ROUTER_CORE (info) [C8] Connection Opened: dir=in host=10.129.24.15:58340 encrypted=TLSv1.3 auth=EXTERNAL user=CN=skupper-router-local container_id=Q_amYedpJP0swMhB2PRrFoil0ni4KzLpAUyslYQr92QghSh25XzsmQ props= 2022-11-07 10:33:40.271224 +0000 ROUTER_CORE (info) [C8][L46] Link attached: dir=out source={(dyn) expire:sess} target={ expire:sess} 2022-11-07 10:33:40.271264 +0000 ROUTER_CORE (info) [C7][L47] Link attached: dir=out source={mc/$skupper-service-sync expire:sess} target={ expire:sess} 2022-11-07 10:33:40.272117 +0000 ROUTER_CORE (info) [C8][L48] Link attached: dir=in source={ expire:sess} target={$management expire:sess} 2022-11-07 10:33:40.272962 +0000 ROUTER_CORE (info) [C8][L49] Link attached: dir=in source={ expire:sess} target={ expire:sess} 2022-11-07 10:33:40.275415 +0000 ROUTER_CORE (info) [C8][L50] Link attached: dir=out source={2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842/skupper-site-query expire:sess} target={ expire:sess} 2022-11-07 10:33:41.584558 +0000 SERVER (info) [C9] Accepted connection to :55671 from 10.128.4.1:9223 2022-11-07 10:33:41.584626 +0000 SERVER (info) [C9] Connection from 10.128.4.1:9223 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:33:41.592480 +0000 FLOW_LOG (info) ROUTER [j27x4:0] BEGIN parent=2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842 namespace=skupper-vault-net imageName=skupper-router imageVersion=latest hostname=skupper-router-59fb8cd5-j27x4 name=0/app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-j27x4 buildVersion=2.1.0 2022-11-07 10:33:41.595127 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'} 2022-11-07 10:33:41.595172 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1} 2022-11-07 10:33:41.595210 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': [], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': []} 2022-11-07 10:33:41.595256 +0000 ROUTER_LS (info) Computed radius: 1 2022-11-07 10:33:42.596294 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'} 2022-11-07 10:33:42.596378 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1} 2022-11-07 10:33:42.596409 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx']} 2022-11-07 10:33:42.596436 +0000 ROUTER_LS (info) Computed radius: 1 2022-11-07 10:33:47.598025 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'} 2022-11-07 10:33:47.598092 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1} 2022-11-07 10:33:47.598122 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': [], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': []} 2022-11-07 10:33:47.598155 +0000 ROUTER_LS (info) Computed radius: 1 2022-11-07 10:34:01.519854 +0000 SERVER (info) [C10] Accepted connection to :55671 from 10.128.4.1:6850 2022-11-07 10:34:01.577175 +0000 SERVER (info) [C10] Connection from 10.128.4.1:6850 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:34:21.520506 +0000 SERVER (info) [C11] Accepted connection to :55671 from 10.128.4.1:37950 2022-11-07 10:34:21.576799 +0000 SERVER (info) [C11] Connection from 10.128.4.1:37950 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:34:30.530882 +0000 SERVER (info) [C12] Accepted connection to localhost:5672 from ::1:33864 2022-11-07 10:34:30.531070 +0000 ROUTER_CORE (info) [C12] Connection Opened: dir=in host=::1:33864 encrypted=no auth=no user=anonymous container_id=stLMzSKUwIp1urrkMqbeshytHRZA2O6j0VdBQgWGefdP0C7Th40A8w props= 2022-11-07 10:34:30.531537 +0000 ROUTER_CORE (info) [C12][L51] Link attached: dir=out source={(dyn) expire:sess} target={ expire:sess} 2022-11-07 10:34:30.531757 +0000 ROUTER_CORE (info) [C12][L52] Link attached: dir=in source={ expire:sess} target={$management expire:sess} 2022-11-07 10:34:30.531976 +0000 ROUTER_CORE (info) [C12][L53] Link attached: dir=in source={ expire:sess} target={ expire:sess} 2022-11-07 10:34:41.520919 +0000 SERVER (info) [C13] Accepted connection to :55671 from 10.128.4.1:9490 2022-11-07 10:34:41.578183 +0000 SERVER (info) [C13] Connection from 10.128.4.1:9490 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:35:01.521059 +0000 SERVER (info) [C14] Accepted connection to :55671 from 10.128.4.1:62637 2022-11-07 10:35:01.577150 +0000 SERVER (info) [C14] Connection from 10.128.4.1:62637 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:35:05.990242 +0000 HTTP_ADAPTOR (info) Deleting HttpListener for vault:8080, 0.0.0.0:1026 2022-11-07 10:35:05.990291 +0000 HTTP_ADAPTOR (info) Deleted HTTP adaptor configuration 'vault:8080' for address vault:8080, 0.0.0.0:1026, siteId 2cfe2ef1-21d0-4e01-b6f5-95a5ad0a4842. 2022-11-07 10:35:06.021776 +0000 FLOW_LOG (info) LISTENER [j27x4:1] BEGIN END parent=j27x4:0 destHost=0.0.0.0 protocol=http1 destPort=1026 vanAddress=vault:8080 name=vault:8080 2022-11-07 10:35:11.583922 +0000 SERVER (info) [C15] Accepted connection to :55671 from 10.128.4.1:9701 2022-11-07 10:35:11.584000 +0000 SERVER (info) [C15] Connection from 10.128.4.1:9701 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:35:12.620949 +0000 SERVER (info) [C16] Accepted connection to :45671 from 10.128.4.1:56961 2022-11-07 10:35:12.622648 +0000 SERVER (info) [C17] Accepted connection to :55671 from 10.128.4.1:65057 2022-11-07 10:35:12.629187 +0000 SERVER (info) [C18] Accepted connection to :55671 from 10.128.4.1:12849 2022-11-07 10:35:12.630713 +0000 ROUTER_CORE (info) [C16] Connection Opened: dir=in host=10.128.4.1:56961 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=26, :"qd.annotations-version"=2} 2022-11-07 10:35:12.632995 +0000 ROUTER_CORE (info) [C17] Connection Opened: dir=in host=10.128.4.1:65057 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=121527, :"qd.inter-router-role"=4, :"qd.group-correlator"="gYQ40+7+lj0r2zG"} 2022-11-07 10:35:12.633034 +0000 ROUTER_CORE (info) [C16] Client attached to heartbeat server (container=appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb, endpoint=0x7f5fb40e2588) 2022-11-07 10:35:12.633057 +0000 ROUTERCORE (info) [C16][L54] Link attached: dir=in source={ expire:sess} target={$qd.edge_heartbeat expire:link} 2022-11-07 10:35:12.633102 +0000 ROUTER_CORE (info) [C16][L55] Link attached: dir=in source={ expire:sess} target={ expire:sess} 2022-11-07 10:35:12.633131 +0000 ROUTER_CORE (info) [C16][L56] Link attached: dir=out source={appsres03ue1-skupper-vault-skupper-router-6bbb5c6c8f-k7jmb expire:link caps::"qd.router-edge-downlink"} target={ expire:sess caps::"qd.router-edge-downlink"} 2022-11-07 10:35:12.633169 +0000 ROUTERCORE (info) [C16][L57] Link attached: dir=out source={$qd.edge_addr_tracking expire:link} target={ expire:sess} 2022-11-07 10:35:12.633197 +0000 ROUTER_CORE (info) [C16][L58] Link attached: dir=in source={ expire:sess} target={mc/sfe.all expire:link} 2022-11-07 10:35:12.633212 +0000 ROUTER_CORE (info) [C16][L59] Link attached: dir=in source={ expire:sess} target={mc/sfe.k7jmb:0 expire:link} 2022-11-07 10:35:12.633226 +0000 ROUTER_CORE (info) [C16][L60] Link attached: dir=out source={sfe.k7jmb:0 expire:link} target={ expire:sess} 2022-11-07 10:35:12.633241 +0000 ROUTER_CORE (info) [C16][L61] Link attached: dir=out source={vault:8080 expire:link} target={ expire:sess} 2022-11-07 10:35:12.633253 +0000 ROUTER_CORE (info) [C16][L62] Link attached: dir=in source={ expire:sess} target={vault:8080 expire:link} 2022-11-07 10:35:12.633273 +0000 ROUTER_CORE (info) [C16][L63] Link attached: dir=in source={ expire:sess} target={mc/$skupper-service-sync expire:link} 2022-11-07 10:35:12.636774 +0000 ROUTER_CORE (info) [C18] Connection Opened: dir=in host=10.128.4.1:12849 encrypted=TLSv1.3 auth=EXTERNAL user=CN=site-token container_id=app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=121528, :"qd.group-correlator"="gYQ40+7+lj0r2zG", :"qd.annotations-version"=2} 2022-11-07 10:35:12.638795 +0000 ROUTER_CORE (info) [C18][L64] Link attached: dir=out source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:35:12.638833 +0000 ROUTER_CORE (info) [C18][L65] Link attached: dir=in source={ expire:sess caps::"qd.router"} target={ expire:sess caps::"qd.router"} 2022-11-07 10:35:12.638882 +0000 ROUTER_CORE (info) [C18][L66] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.638900 +0000 ROUTER_CORE (info) [C18][L67] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.638912 +0000 ROUTER_CORE (info) [C18][L68] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.638924 +0000 ROUTER_CORE (info) [C18][L69] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.638936 +0000 ROUTER_CORE (info) [C18][L70] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.638988 +0000 ROUTER_CORE (info) [C18][L71] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639007 +0000 ROUTER_CORE (info) [C18][L72] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639020 +0000 ROUTER_CORE (info) [C18][L73] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639031 +0000 ROUTER_CORE (info) [C18][L74] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639042 +0000 ROUTER_CORE (info) [C18][L75] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639054 +0000 ROUTER_CORE (info) [C18][L76] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639065 +0000 ROUTER_CORE (info) [C18][L77] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639075 +0000 ROUTER_CORE (info) [C18][L78] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639088 +0000 ROUTER_CORE (info) [C18][L79] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639099 +0000 ROUTER_CORE (info) [C18][L80] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639111 +0000 ROUTER_CORE (info) [C18][L81] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639126 +0000 ROUTER_CORE (info) [C18][L82] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639137 +0000 ROUTER_CORE (info) [C18][L83] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639147 +0000 ROUTER_CORE (info) [C18][L84] Link attached: dir=out source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:12.639159 +0000 ROUTER_CORE (info) [C18][L85] Link attached: dir=in source={ expire:sess caps::"qd.router-data"} target={ expire:sess caps::"qd.router-data"} 2022-11-07 10:35:14.627760 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'} 2022-11-07 10:35:14.627830 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 2, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 2} 2022-11-07 10:35:14.627944 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm']} 2022-11-07 10:35:14.628005 +0000 ROUTER_LS (info) Computed radius: 2 2022-11-07 10:35:16.630330 +0000 ROUTER_LS (info) Computed next hops: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp'} 2022-11-07 10:35:16.630412 +0000 ROUTER_LS (info) Computed costs: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': 1, 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': 1, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': 2, 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': 2} 2022-11-07 10:35:16.630459 +0000 ROUTER_LS (info) Computed valid origins: {'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn'], 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm': ['app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2', 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-2m6qp': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-m7zf2': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm'], 'app-sre-stage-02-skupper-vault-net-skupper-router-86c5b4b9cc-vsbdn': ['app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-qg2vx', 'app-sre-stage-01-skupper-vault-net-skupper-router-59fb8cd5-n7fpm']} 2022-11-07 10:35:16.630486 +0000 ROUTER_LS (info) Computed radius: 2 2022-11-07 10:35:16.724837 +0000 HTTP_ADAPTOR (info) Configured HTTP_ADAPTOR listener on 0.0.0.0:1027 2022-11-07 10:35:16.725756 +0000 HTTP_ADAPTOR (info) Listener vault:8080: listening for client connections on 0.0.0.0:1027 with backlog 128 2022-11-07 10:35:21.584199 +0000 SERVER (info) [C19] Accepted connection to :55671 from 10.128.4.1:46705 2022-11-07 10:35:21.584241 +0000 SERVER (info) [C19] Connection from 10.128.4.1:46705 (to :55671) failed: amqp:connection:framing-error No protocol header found (connection aborted) 2022-11-07 10:35:22.006259 +0000 HTTP_ADAPTOR (info) Listener vault:8080: new incoming client connection to 0.0.0.0:1027 2022-11-07 10:35:22.006505 +0000 ROUTER_CORE (info) [C20] Connection Opened: dir=in host=10.128.34.20:42706 encrypted=no auth=no user= container_id=HTTP/1.x Adaptor props= 2022-11-07 10:35:22.006560 +0000 HTTP_ADAPTOR (info) [C20] HTTP/1.x client connection established from 10.128.34.20:42706 2022-11-07 10:35:22.006584 +0000 ROUTER_CORE (info) [C20][L86] Link attached: dir=out source={(dyn) expire:link} target={ expire:link} 2022-11-07 10:35:22.006683 +0000 ROUTER_CORE (info) [C20][L87] Link attached: dir=in source={ expire:link} target={vault:8080 expire:link} 2022-11-07 10:35:22.010516 +0000 ROUTER_CORE (info) [C16][L88] Link attached: dir=in source={ expire:sess} target={ expire:sess} 2022-11-07 10:35:22.013127 +0000 HTTP_ADAPTOR (info) [C20] HTTP/1.x client disconnected 2022-11-07 10:35:22.013166 +0000 ROUTER_CORE (info) [C20][L86] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 2022-11-07 10:35:22.013200 +0000 ROUTER_CORE (info) [C20][L87] Link lost: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no 2022-11-07 10:35:22.013210 +0000 ROUTER_CORE (info) [C20] Connection Closed

Skupper Version:

oc get deploy skupper-site-controller -oyaml | grep image ... image: quay.io/skupper/site-controller:1.1.1 ...

I've tested it several times by restarting the router pods via oc rollout restart deployment.apps/skupper-router

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

chassing commented 1 year ago

I've three replicas of the router running, as shown in the site-config above. That's the reason why I've opened this issue.

grs commented 1 year ago

Are you restarting the routers on the site that initiates the link, or the site to which the link was created? I can only reproduce for the former and have a fix for that (pr #942). If it is the latter it would be useful to get all the router logs and the service controller logs to give more clues on what might be going on, in order to be able to reproduce.

chassing commented 1 year ago
flowchart LR
    app-sre-stage-02 --> app-sre-stage-01
    appsres03ue1 --> app-sre-stage-01

This is the skupper link setup, and the logs are from app-sre-stage-01, which receives the links.

I restarted the router on app-sre-stage-01 again, please find all logs attached.

app-sre-stage-01-skupper.zip

grs commented 1 year ago

Thanks! Do you happen to have the router logs from routers in app-sre-stage-02?

The three routers in app-sre-stage-01 start up around 08:45:44 and are fully meshed by 08:45:51, with app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-fg8n6 connecting to app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-6pgt5 and app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-mp85w both at 08:45:45 and app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-6pgt5 connecting to app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-mp85w at 08:45:51).

However the routers in app-sre-stage-02 don't connect in until 08:47:12, and all of them connect in to the same router, app-sre-stage-01-skupper-vault-net-skupper-router-5945495956-mp85w.

Since the other two local routers connected without issue, the inter router listener (port 55671) was clearly working before this. So what causes the delay?

There are errors logged with the message 'No protocol header found' in the logs of all three of these routers. I suspect these are probes from the loadbalancer (the liveness probe for the skupper-router deployment is configured to be a GET against port 9090). In each router log all of these come from the same ip, but the ips differe between the three router logs. 10.129.12.1 for skupper-router-5945495956-mp85w, 10.131.16.1 for skupper-router-5945495956-fg8n6 and 10.128.18.1 for skupper-router-5945495956-6pgt5 (this may just be a result of the pods all running on different nodes, e.g. if they come from the kubelet).

The first probe logged for skupper-router-5945495956-6pgt5 is at 08:46:30, the first for skupper-router-5945495956-fg8n6 is at 08:46:08 and the first for skupper-router-5945495956-mp85w is at 08:46:48. They come at roughly 20 second intervals (sometimes 10, sometimes 30). Though it is odd that all three external routers came through the the local router that was last to receive its first probe (assuming I am correct in identifying them as such), they are in all cases quite a bit later than the formation of the local mesh (which is the point we can be sure that the listeners are active).

grs commented 1 year ago

Is there a reason to use ingress=loadbalancer instead of ingress=route (which is the default on openshift)?

chassing commented 1 year ago

Please find the app-sre-stage-02 logs attached.

app-sre-stage-02-skupper-router-logs.zip

And here is the site-config of app-sre-stage-02

data:
  controller-memory-limit: 1Gi
  controller-pod-antiaffinity: skupper.io/component=controller
  router-cpu: 500m
  router-memory: 1Gi
  routers: '3'
  name: app-sre-stage-02-skupper-vault-net
  console-authentication: openshift
  controller-memory: 1Gi
  service-sync: 'true'
  router-console: 'true'
  router-memory-limit: 1Gi
  service-controller: 'true'
  ingress: route
  router-pod-antiaffinity: skupper.io/component=router
  console: 'true'
  controller-cpu: 500m
  cluster-local: 'false'
  edge: 'false'
  console-ingress: route

During my POC with skupper I've tested loadbalancer and route as ingress. So there isn't any reason behind it. I can change it if you want.

grs commented 1 year ago

Thanks for the extra logs. It looks like the connections to the loadbalancer host hang for a minute starting at 08:45:44.

Do you get the same delay with route as ingress?

chassing commented 1 year ago

I've changed to ingress=route and restarted appsres03ue1 (exposes a service via skupper; it's an edge site, see skupper-config below), app-stage-02, and app-stage-01 in this order. Yes, I see the same delay as with ingress=loadbalancer.

appsres03ue1 skupper-site

data:
  controller-memory-limit: 1Gi
  controller-pod-antiaffinity: skupper.io/component=controller
  router-cpu: 500m
  router-memory: 1Gi
  routers: '3'
  name: appsres03ue1-skupper-vault
  console-authentication: openshift
  controller-memory: 1Gi
  service-sync: 'true'
  router-console: 'false'
  router-memory-limit: 1Gi
  service-controller: 'true'
  ingress: none
  router-pod-antiaffinity: skupper.io/component=router
  console: 'true'
  controller-cpu: 500m
  cluster-local: 'false'
  edge: 'true'
  console-ingress: route

Here are all logs again:

app-sre-stage-01-logs.zip app-sre-stage-02-logs.zip appsres03ue1-logs.zip

grs commented 1 year ago

Unfortunately at present changing the ingress value in the skupper-site cm will not result in a change. You need to delete and re-init skupper.

Thanks for the logs though, they show the loadbalancer still in use. this time the delay looked more like 45 seconds, but the pattern is the same.

chassing commented 1 year ago

Ah good to know. I re-init all 3 skupper deployments and then restarted appsre03ue1, app-sre-stage-02, and app-sre-stage-01 in this order.

restart appsre03ue1: no interruption; the service was reachble on app-sre-stage-02 and app-sre-stage-01 restart app-sre-stage-02: interruption as expected (pr #942) restart app-sre-stage-01: app-sre-stage-01 and 02 short interruption but still an interruption

here are the logs app-sre-stage-01-logs.zip app-sre-stage-02-logs.zip appsres03ue1-logs.zip

grs commented 1 year ago

Many thanks for trying that and your continued patience!

How long was the short interruption?

In stage-02/skupper-router-844c875f6d-59lkn-router.log there is an unexpected delay between two attempts to connect to the other site:

2022-11-11 12:34:02.915426 +0000 SERVER (info) [C24] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error
2022-11-11 12:34:02.916142 +0000 SERVER (info) [C25] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error
2022-11-11 12:34:02.917101 +0000 SERVER (info) [C23] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error

<<<< 22 seconds between these calls (or is the second set just taking a long time to timeout?)

2022-11-11 12:34:24.929588 +0000 SERVER (info) [C28] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error
2022-11-11 12:34:24.932400 +0000 SERVER (info) [C27] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error
2022-11-11 12:34:24.934477 +0000 SERVER (info) [C29] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error

However in stage-02/skupper-router-844c875f6d-jlfzv-router.log we see another router in the site establishing a connection during that gap at 12:34:04:

2022-11-11 12:33:59.317550 +0000 SERVER (info) [C1] Connection to skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 failed: amqp:connection:framing-error SSL Failure: Unknown error
2022-11-11 12:34:04.347373 +0000 ROUTER_CORE (info) [C23] Connection Opened: dir=out host=skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 encrypted=TLSv1.3 auth=EXTERNAL user=(null) container_id=app-sre-stage-01-skupper-vault-net-skupper-router-55dc74df7b-9h4dk props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=5, :"qd.annotations-version"=2}

Likewise in stage-02/skupper-router-844c875f6d-v4fzn-router.log, the router establishes a connection at 12:34:04:

2022-11-11 12:34:04.977868 +0000 ROUTER_CORE (info) [C33] Connection Opened: dir=out host=skupper-inter-router-skupper-vault-net.apps.app-sre-stage-0.k3s7.p1.openshiftapps.com:443 encrypted=TLSv1.3 auth=EXTERNAL user=(null) container_id=app-sre-stage-01-skupper-vault-net-skupper-router-55dc74df7b-jxnbb props={:product="skupper-router", :version="2.1.0", :"qd.conn-id"=9, :"qd.annotations-version"=2}
chassing commented 1 year ago

No worries, I'm glad I can help.

My test is basically running curl (on clusters app-sre-stage-01 and 02) in an endless loop with a connection timeout of one second. The interruption (http connection issues) was less than 10 seconds with an error rate of ~ 70%.

chassing commented 1 year ago

I retested today with skupper version 1.2.0.