Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Network connectivity blocked for when connecting with an upstream that uses a server-first protocol #13364

Open
fullykubed opened this issue Nov 21, 2024 · 8 comments
Open

Network connectivity blocked for when connecting with an upstream that uses a server-first protocol #13364

fullykubed opened this issue Nov 21, 2024 · 8 comments
Labels
bug

Comments

@fullykubed
Copy link

fullykubed commented Nov 21, 2024 •
edited
Loading

What is the issue?

UPDATE: This appears to affect any service trying to communicate with NATS over a linkerd mesh. As long
as the pod initiating the request to NATS is in linkerd mesh and config.linkerd.io/skip-outbound-ports is NOT set to 4222, no network connection can be established with an upstream NATS server. Ideally, we would like to mark 4222 opaque rather than skipping it; however, opaque ports do not fix this issue.

I have deployed Hashicorp Vault with an external plugin integration.

The external plugin runs as a forked process inside the main vault container:

PID   USER     TIME  COMMAND
    1 vault     0:00 /bin/sh -ec cp /vault/config/extraconfig-from-values.hcl /tmp/storageconfig.hcl; [
   11 vault     0:00 {docker-entrypoi} /usr/bin/dumb-init /bin/sh /usr/local/bin/docker-entrypoint.sh va
   12 vault     0:01 vault server -config=/tmp/storageconfig.hcl
  102 vault     0:00 sh
  131 vault     0:00 watch -n 1 ps aux
  225 vault     0:00 /plugins/vault-plugin-secrets-nats
  245 vault     0:00 ps aux

When the Vault pod has a linkerd proxy injected, the external plugin (/plugins/vault-plugin-secrets-nats) starts having connection timeout errors. The plugin works fine without linkerd.

How can it be reproduced?

  1. Deploy linkerd edge-24.11.2 with native sidecars enabled and using the linkerd CNI
  2. Deploy vault 1.14.7 with a plugin integration that makes network requests
  3. Inject the linkerd proxy sidecar into the Vault pods
  4. Notice that the Vault plugin cannot make network requests

Logs, error output, etc

Vault - Connectivity Failure Logs

vault-1 vault {"@level":"debug","@message":"{\"level\":\"warn\",\"operator\":\"nats-e33f\",\"account\":\"default\",\"error\":\"read tcp 10.0.114.159:60930-\u003e172.20.39.221:4222: i/o timeout\",\"time\":1732228415,\"message\":\"cannot create conection to account server\"}","@module":"secrets.nats-secrets.nats-secrets_b3b73875.nats-secrets.vault-plugin-secrets-nats","@timestamp":"2024-11-21T22:33:35.910136Z"}

Vault - linkerd-proxy sidecar logs

{"timestamp":"2024-11-21T22:33:35.704774Z","level":"DEBUG","fields":{"message":"Resolving a SRV record","name":"linkerd-policy.linkerd.svc.cluster.local."},"target":"linkerd_dns","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.704829Z","level":"DEBUG","fields":{"message":"querying: linkerd-policy.linkerd.svc.cluster.local. SRV"},"target":"hickory_proto::xfer::dns_handle","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.704886Z","level":"DEBUG","fields":{"message":"sending request: [Query { name: Name(\"linkerd-policy.linkerd.svc.cluster.local.\"), query_type: SRV, query_class: IN }]"},"target":"hickory_resolver::name_server::name_server_pool","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.704906Z","level":"DEBUG","fields":{"message":"existing connection: NameServerConfig { socket_addr: 172.20.0.10:53, protocol: Udp, tls_dns_name: None, trust_negative_responses: false, bind_addr: None }"},"target":"hickory_resolver::name_server::name_server","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.704916Z","level":"DEBUG","fields":{"message":"enqueueing message:QUERY:[Query { name: Name(\"linkerd-policy.linkerd.svc.cluster.local.\"), query_type: SRV, query_class: IN }]"},"target":"hickory_proto::xfer","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.704939Z","level":"DEBUG","fields":{"message":"final message: ; header 3073:QUERY:RD:NoError:QUERY:0/0/0\n; query\n;; linkerd-policy.linkerd.svc.cluster.local. IN SRV\n"},"target":"hickory_proto::udp::udp_client_stream","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.705023Z","level":"DEBUG","fields":{"message":"created socket successfully"},"target":"hickory_proto::udp::udp_stream","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706129Z","level":"DEBUG","fields":{"message":"received message id: 3073"},"target":"hickory_proto::udp::udp_client_stream","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706174Z","level":"DEBUG","fields":{"message":"Response:; header 3073:RESPONSE:RD,AA:NoError:QUERY:2/0/2\n; query\n;; linkerd-policy.linkerd.svc.cluster.local. IN SRV\n; answers 2\nlinkerd-policy.linkerd.svc.cluster.local. 5 IN SRV 0 50 8090 10-0-178-133.linkerd-policy.linkerd.svc.cluster.local.\nlinkerd-policy.linkerd.svc.cluster.local. 5 IN SRV 0 50 8090 10-0-99-124.linkerd-policy.linkerd.svc.cluster.local.\n; nameservers 0\n; additionals 2\n10-0-99-124.linkerd-policy.linkerd.svc.cluster.local. 5 IN A 10.0.99.124\n10-0-178-133.linkerd-policy.linkerd.svc.cluster.local. 5 IN A 10.0.178.133\n"},"target":"hickory_resolver::error","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706209Z","level":"DEBUG","fields":{"message":"Response:; header 3073:RESPONSE:RD,AA:NoError:QUERY:2/0/2\n; query\n;; linkerd-policy.linkerd.svc.cluster.local. IN SRV\n; answers 2\nlinkerd-policy.linkerd.svc.cluster.local. 5 IN SRV 0 50 8090 10-0-178-133.linkerd-policy.linkerd.svc.cluster.local.\nlinkerd-policy.linkerd.svc.cluster.local. 5 IN SRV 0 50 8090 10-0-99-124.linkerd-policy.linkerd.svc.cluster.local.\n; nameservers 0\n; additionals 2\n10-0-99-124.linkerd-policy.linkerd.svc.cluster.local. 5 IN A 10.0.99.124\n10-0-178-133.linkerd-policy.linkerd.svc.cluster.local. 5 IN A 10.0.178.133\n"},"target":"hickory_resolver::error","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706250Z","level":"DEBUG","fields":{"ttl":"4.999988087s","addrs":"[10.0.178.133:8090, 10.0.99.124:8090]"},"target":"linkerd_dns","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706259Z","level":"DEBUG","fields":{"addrs":"[10.0.178.133:8090, 10.0.99.124:8090]","name":"linkerd-policy.linkerd.svc.cluster.local:8090"},"target":"linkerd_proxy_dns_resolve","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706273Z","level":"DEBUG","fields":{"message":"Discovered","update":"Reset([(10.0.178.133:8090, ()), (10.0.99.124:8090, ())])"},"target":"linkerd_proxy_balance_queue::worker","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706280Z","level":"DEBUG","fields":{"message":"Endpoint unchanged","addr":"10.0.178.133:8090"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.706286Z","level":"DEBUG","fields":{"message":"Endpoint unchanged","addr":"10.0.99.124:8090"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902255Z","level":"DEBUG","fields":{"message":"Could not detect protocol","read":0},"target":"linkerd_proxy_http::detect","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902293Z","level":"DEBUG","fields":{"message":"Detected protocol","protocol":"None","elapsed":"4.995037625s"},"target":"linkerd_detect","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902305Z","level":"DEBUG","fields":{"message":"Using ClientPolicy routes","addr":"nats-e33f.default.svc.cluster.local:4222"},"target":"linkerd_app_outbound::opaq","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902319Z","level":"DEBUG","fields":{"message":"Caching new value","key":"Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: \"opaq\" }, filters: ], distribution: FirstAvailable([RouteBackend { filters: ], backend: Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 1 }, version: Version(0) } })"},"target":"linkerd_idle_cache","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902601Z","level":"DEBUG","fields":{"message":"Adding","backend":"Concrete { target: Balance(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: \"opaq\" }, filters: ], distribution: FirstAvailable([RouteBackend { filters: ], backend: Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 9 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }) }"},"target":"linkerd_distribute::cache","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902658Z","level":"DEBUG","fields":{"message":"Resolving"},"target":"linkerd_proxy_balance","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902683Z","level":"DEBUG","fields":{"message":"Spawning p2c pool queue","capacity":10000,"failfast":"3s"},"target":"linkerd_proxy_balance","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902721Z","level":"DEBUG","fields":{"message":"Selected route","meta":"RouteRef(Default { name: \"opaq\" })"},"target":"linkerd_app_outbound::opaq::logical::router","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902730Z","level":"DEBUG","fields":{"message":"New distribution","backends":"FirstAvailable(ServiceKeys { ids: [KeyId { idx: 0 }], keys: {KeyId { idx: 0 }: Backend { route_ref: RouteRef(Default { name: \"opaq\" }), concrete: Concrete { target: Balance(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: \"opaq\" }, filters: ], distribution: FirstAvailable([RouteBackend { filters: ], backend: Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: \"nats-e33f.default.svc.cluster.local:4222\" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 28 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name(\"nats-e33f.default.svc.cluster.local\"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: \"core\", kind: \"Service\", name: \"nats-e33f\", namespace: \"default\", section: None, port: Some(4222) }) } }} })"},"target":"linkerd_distribute::stack","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902845Z","level":"DEBUG","fields":{"message":"Resolving","dst":"nats-e33f.default.svc.cluster.local:4222","context":"{\"ns\":\"vault\", \"nodeName\":\"ip-10-0-101-156.us-east-2.compute.internal\", \"pod\":\"vault-1\"}\n"},"target":"linkerd_proxy_api_resolve::resolve","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902880Z","level":"DEBUG","fields":{"message":"No ready endpoints"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902951Z","level":"DEBUG","fields":{"message":"No ready endpoints"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902978Z","level":"DEBUG","fields":{"message":"send","frame":"Headers { stream_id: StreamId(37), flags: (0x4: END_HEADERS) }"},"target":"h2::codec::framed_write","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.902997Z","level":"DEBUG","fields":{"message":"send","frame":"Data { stream_id: StreamId(37) }"},"target":"h2::codec::framed_write","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.903004Z","level":"DEBUG","fields":{"message":"send","frame":"Data { stream_id: StreamId(37), flags: (0x1: END_STREAM) }"},"target":"h2::codec::framed_write","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904322Z","level":"DEBUG","fields":{"message":"received","frame":"Headers { stream_id: StreamId(37), flags: (0x4: END_HEADERS) }"},"target":"h2::codec::framed_read","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904377Z","level":"DEBUG","fields":{"message":"received","frame":"Data { stream_id: StreamId(37) }"},"target":"h2::codec::framed_read","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904524Z","level":"DEBUG","fields":{"message":"Add","endpoints":"3"},"target":"linkerd_proxy_api_resolve::resolve","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904537Z","level":"DEBUG","fields":{"message":"Discovered","update":"Reset([(10.0.101.57:4222, Metadata { labels: {\"control_plane_ns\": \"linkerd\", \"namespace\": \"default\", \"pod\": \"nats-e33f-0\", \"service\": \"nats-e33f\", \"serviceaccount\": \"nats-e33f\", \"statefulset\": \"nats-e33f\", \"zone\": \"us-east-2a\", \"zone_locality\": \"local\"}, weight: 10000, protocol_hint: Http2, tagged_transport_port: None, identity: Some(ClientTls { server_name: ServerName(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\")), server_id: ServerId(Dns(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\"))), alpn: None }), authority_override: None, http2: ClientParams { flow_control: None, keep_alive: Some(ClientKeepAlive { interval: 10s, timeout: 3s, while_idle: true }), max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(true) }), (10.0.181.53:4222, Metadata { labels: {\"control_plane_ns\": \"linkerd\", \"namespace\": \"default\", \"pod\": \"nats-e33f-2\", \"service\": \"nats-e33f\", \"serviceaccount\": \"nats-e33f\", \"statefulset\": \"nats-e33f\", \"zone\": \"us-east-2b\", \"zone_locality\": \"remote\"}, weight: 10000, protocol_hint: Http2, tagged_transport_port: None, identity: Some(ClientTls { server_name: ServerName(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\")), server_id: ServerId(Dns(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\"))), alpn: None }), authority_override: None, http2: ClientParams { flow_control: None, keep_alive: Some(ClientKeepAlive { interval: 10s, timeout: 3s, while_idle: true }), max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) }), (10.0.243.151:4222, Metadata { labels: {\"control_plane_ns\": \"linkerd\", \"namespace\": \"default\", \"pod\": \"nats-e33f-1\", \"service\": \"nats-e33f\", \"serviceaccount\": \"nats-e33f\", \"statefulset\": \"nats-e33f\", \"zone\": \"us-east-2c\", \"zone_locality\": \"remote\"}, weight: 10000, protocol_hint: Http2, tagged_transport_port: None, identity: Some(ClientTls { server_name: ServerName(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\")), server_id: ServerId(Dns(Name(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\"))), alpn: None }), authority_override: None, http2: ClientParams { flow_control: None, keep_alive: Some(ClientKeepAlive { interval: 10s, timeout: 3s, while_idle: true }), max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) })])"},"target":"linkerd_proxy_balance_queue::worker","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904629Z","level":"INFO","fields":{"message":"Adding endpoint","addr":"10.0.101.57:4222"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904645Z","level":"INFO","fields":{"message":"Adding endpoint","addr":"10.0.181.53:4222"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904680Z","level":"INFO","fields":{"message":"Adding endpoint","addr":"10.0.243.151:4222"},"target":"linkerd_pool_p2c","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.904716Z","level":"DEBUG","fields":{"message":"Connecting","server.addr":"10.0.101.57:4222"},"target":"linkerd_proxy_transport::connect","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.905441Z","level":"DEBUG","fields":{"message":"Connected","local.addr":"10.0.114.159:50474","keepalive":"Some(10s)"},"target":"linkerd_proxy_transport::connect","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.905492Z","level":"DEBUG","fields":{"message":"No cached session for DnsName(\"nats-e33f.default.serviceaccount.identity.linkerd.cluster.local\")","log.target":"rustls::client::hs","log.module_path":"rustls::client::hs","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/hs.rs","log.line":73},"target":"rustls::client::hs","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.905635Z","level":"DEBUG","fields":{"message":"Not resuming any session","log.target":"rustls::client::hs","log.module_path":"rustls::client::hs","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/hs.rs","log.line":132},"target":"rustls::client::hs","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.906393Z","level":"DEBUG","fields":{"message":"Using ciphersuite TLS13_CHACHA20_POLY1305_SHA256","log.target":"rustls::client::hs","log.module_path":"rustls::client::hs","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/hs.rs","log.line":615},"target":"rustls::client::hs","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.906421Z","level":"DEBUG","fields":{"message":"Not resuming","log.target":"rustls::client::tls13","log.module_path":"rustls::client::tls13","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/tls13.rs","log.line":142},"target":"rustls::client::tls13","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.907166Z","level":"DEBUG","fields":{"message":"TLS1.3 encrypted extensions: [ServerNameAck]","log.target":"rustls::client::tls13","log.module_path":"rustls::client::tls13","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/tls13.rs","log.line":381},"target":"rustls::client::tls13","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.907211Z","level":"DEBUG","fields":{"message":"ALPN protocol is None","log.target":"rustls::client::hs","log.module_path":"rustls::client::hs","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/hs.rs","log.line":472},"target":"rustls::client::hs","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.907239Z","level":"DEBUG","fields":{"message":"Got CertificateRequest CertificateRequestPayloadTLS13 { context: , extensions: [SignatureAlgorithms([ECDSA_NISTP384_SHA384, ECDSA_NISTP256_SHA256, ED25519, RSA_PSS_SHA512, RSA_PSS_SHA384, RSA_PSS_SHA256, RSA_PKCS1_SHA512, RSA_PKCS1_SHA384, RSA_PKCS1_SHA256]), AuthorityNames([DistinguishedName(306531123010060355040a130970616e66616374756d31143012060355040b130b656e67696e656572696e673139303706035504031330687474703a2f2f7661756c742d6163746976652e7661756c742e7376632e636c75737465722e6c6f63616c3a38323030)])] }","log.target":"rustls::client::tls13","log.module_path":"rustls::client::tls13","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/tls13.rs","log.line":538},"target":"rustls::client::tls13","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.907420Z","level":"DEBUG","fields":{"message":"Attempting client auth","log.target":"rustls::client::common","log.module_path":"rustls::client::common","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/client/common.rs","log.line":100},"target":"rustls::client::common","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.908499Z","level":"DEBUG","fields":{},"target":"linkerd_tls::client","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.908517Z","level":"DEBUG","fields":{"message":"client connection open"},"target":"linkerd_transport_metrics::client","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.908575Z","level":"DEBUG","fields":{"message":"Sending warning alert CloseNotify","log.target":"rustls::common_state","log.module_path":"rustls::common_state","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/common_state.rs","log.line":498},"target":"rustls::common_state","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.910485Z","level":"DEBUG","fields":{"message":"Connection closed","reason":"logical service nats-e33f.default.svc.cluster.local:4222: route default.opaq: server: Transport endpoint is not connected (os error 107)","client.addr":"10.0.114.159:60930","server.addr":"172.20.39.221:4222"},"target":"linkerd_app_core::serve","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.910600Z","level":"DEBUG","fields":{"message":"Awaiting idleness"},"target":"linkerd_idle_cache","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:35.944719Z","level":"DEBUG","fields":{"service.ready":true,"message":"processing request"},"target":"tower::buffer::worker","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:37.616785Z","level":"DEBUG","fields":{"message":"Peeked bytes from TCP stream","sz":0},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616850Z","level":"DEBUG","fields":{"message":"Attempting to buffer TLS ClientHello after incomplete peek"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616856Z","level":"DEBUG","fields":{"message":"Reading bytes from TCP stream","buf.capacity":"8192"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616863Z","level":"DEBUG","fields":{"message":"Read bytes from TCP stream","buf.len":"110"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616884Z","level":"DEBUG","fields":{"message":"Detected protocol","protocol":"Some(HTTP/1)","elapsed":"5.284µs"},"target":"linkerd_detect","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616893Z","level":"DEBUG","fields":{"message":"Creating HTTP service","version":"HTTP/1"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616913Z","level":"DEBUG","fields":{"message":"Handling as HTTP","version":"HTTP/1"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616933Z","level":"DEBUG","fields":{"message":"parsed 4 headers"},"target":"hyper::proto::h1::io","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616939Z","level":"DEBUG","fields":{"message":"incoming body is empty"},"target":"hyper::proto::h1::conn","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.616957Z","level":"DEBUG","fields":{"message":"Request authorized","server.group":"","server.kind":"default","server.name":"all-unauthenticated","route.group":"","route.kind":"default","route.name":"probe","authz.group":"","authz.kind":"default","authz.name":"probe","client.tls":"None(NoClientHello)","client.ip":"10.0.101.156"},"target":"linkerd_app_inbound::policy::http","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617066Z","level":"DEBUG","fields":{"message":"flushed 107 bytes"},"target":"hyper::proto::h1::io","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617092Z","level":"DEBUG","fields":{"message":"The client is shutting down the connection","res":"Ok(())"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617123Z","level":"DEBUG","fields":{"message":"Connection closed"},"target":"linkerd_app_core::serve","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617138Z","level":"DEBUG","fields":{"message":"Peeked bytes from TCP stream","sz":0},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617143Z","level":"DEBUG","fields":{"message":"Attempting to buffer TLS ClientHello after incomplete peek"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617147Z","level":"DEBUG","fields":{"message":"Reading bytes from TCP stream","buf.capacity":"8192"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617153Z","level":"DEBUG","fields":{"message":"Read bytes from TCP stream","buf.len":"109"},"target":"linkerd_tls::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617162Z","level":"DEBUG","fields":{"message":"Detected protocol","protocol":"Some(HTTP/1)","elapsed":"2.215µs"},"target":"linkerd_detect","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617168Z","level":"DEBUG","fields":{"message":"Creating HTTP service","version":"HTTP/1"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617179Z","level":"DEBUG","fields":{"message":"Handling as HTTP","version":"HTTP/1"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617189Z","level":"DEBUG","fields":{"message":"parsed 4 headers"},"target":"hyper::proto::h1::io","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617193Z","level":"DEBUG","fields":{"message":"incoming body is empty"},"target":"hyper::proto::h1::conn","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617204Z","level":"DEBUG","fields":{"message":"Request authorized","server.group":"","server.kind":"default","server.name":"all-unauthenticated","route.group":"","route.kind":"default","route.name":"probe","authz.group":"","authz.kind":"default","authz.name":"probe","client.tls":"None(NoClientHello)","client.ip":"10.0.101.156"},"target":"linkerd_app_inbound::policy::http","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617259Z","level":"DEBUG","fields":{"message":"flushed 106 bytes"},"target":"hyper::proto::h1::io","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617278Z","level":"DEBUG","fields":{"message":"The client is shutting down the connection","res":"Ok(())"},"target":"linkerd_proxy_http::server","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.617315Z","level":"DEBUG","fields":{"message":"Connection closed"},"target":"linkerd_app_core::serve","threadId":"ThreadId(2)"}
{"timestamp":"2024-11-21T22:33:37.880163Z","level":"DEBUG","fields":{"message":"send","frame":"Ping { ack: false, payload: [59, 124, 219, 122, 11, 135, 22, 180] }"},"target":"h2::codec::framed_write","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:37.882167Z","level":"DEBUG","fields":{"message":"received","frame":"Ping { ack: true, payload: [59, 124, 219, 122, 11, 135, 22, 180] }"},"target":"h2::codec::framed_read","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:37.885333Z","level":"DEBUG","fields":{"message":"received","frame":"Ping { ack: false, payload: [59, 124, 219, 122, 11, 135, 22, 180] }"},"target":"h2::codec::framed_read","threadId":"ThreadId(1)"}
{"timestamp":"2024-11-21T22:33:37.886186Z","level":"DEBUG","fields":{"message":"send","frame":"Ping { ack: true, payload: [59, 124, 219, 122, 11, 135, 22, 180] }"},"target":"h2::codec::framed_write","threadId":"ThreadId(1)"}

Upstream Target - Linkerd proxy logs

nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.950964Z","level":"DEBUG","fields":{"message":"Accepted TLS connection","client.id":"Some(ClientId(Dns(Name(\"vault.vault.serviceaccount.identity.linkerd.cluster.local\"))))","alpn":"None"},"target":"linkerd_meshtls_rustls::server","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951024Z","level":"DEBUG","fields":{"message":"Could not detect protocol","read":0},"target":"linkerd_proxy_http::detect","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951033Z","level":"DEBUG","fields":{"message":"Detected protocol","protocol":"None","elapsed":"25.05µs"},"target":"linkerd_detect","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951044Z","level":"DEBUG","fields":{"message":"Connection authorized","permit":"ServerPermit { dst: OrigDstAddr(10.0.178.135:4222), protocol: Detect { http: [Route { hosts: [], rules: [Rule { matches: [MatchRequest { path: Some(Prefix(\"/\")), headers: [], query_params: [], method: None }], policy: RoutePolicy { meta: Default { name: \"default\" }, authorizations: [Authorization { networks: [Network { net: 0.0.0.0/0, except: [] }, Network { net: ::/0, except: [] }], authentication: Unauthenticated, meta: Default { name: \"all-unauthenticated\" } }, Authorization { networks: [Network { net: 127.0.0.1/32, except: [] }, Network { net: ::1/128, except: [] }], authentication: Unauthenticated, meta: Default { name: \"localhost\" } }], filters: [] } }] }], timeout: 10s, tcp_authorizations: [Authorization { networks: [Network { net: 0.0.0.0/0, except: [] }, Network { net: ::/0, except: [] }], authentication: Unauthenticated, meta: Default { name: \"all-unauthenticated\" } }, Authorization { networks: [Network { net: 127.0.0.1/32, except: [] }, Network { net: ::1/128, except: [] }], authentication: Unauthenticated, meta: Default { name: \"localhost\" } }] }, labels: ServerAuthzLabels { server: ServerLabel(Default { name: \"all-unauthenticated\" }), authz: Default { name: \"all-unauthenticated\" } } }","tls":"Some(Established { client_id: Some(ClientId(Dns(Name(\"vault.vault.serviceaccount.identity.linkerd.cluster.local\")))), negotiated_protocol: None })","client":"10.0.114.159:57206"},"target":"linkerd_app_inbound::policy::tcp","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951149Z","level":"DEBUG","fields":{"message":"Connecting","server.addr":"10.0.178.135:4222"},"target":"linkerd_proxy_transport::connect","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951315Z","level":"DEBUG","fields":{"message":"Connected","local.addr":"10.0.178.135:60814","keepalive":"None"},"target":"linkerd_proxy_transport::connect","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.951535Z","level":"DEBUG","fields":{"message":"client connection open"},"target":"linkerd_transport_metrics::client","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.952279Z","level":"DEBUG","fields":{"message":"Sending warning alert CloseNotify","log.target":"rustls::common_state","log.module_path":"rustls::common_state","log.file":"/usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/rustls-0.21.12/src/common_state.rs","log.line":498},"target":"rustls::common_state","threadId":"ThreadId(1)"}
nats-e33f-2 linkerd-proxy {"timestamp":"2024-11-21T22:53:40.952476Z","level":"DEBUG","fields":{"message":"Connection closed"},"target":"linkerd_app_core::serve","threadId":"ThreadId(1)"}

output of linkerd check -o short

linkerd-cni-plugin
------------------
× cni plugin ConfigMap exists
    configmaps "linkerd-cni-config" not found
    see https://linkerd.io/2/checks/#cni-plugin-cm-exists for hints

linkerd-viz
-----------
‼ linkerd-viz pods are injected
    could not find proxy container for linkerd-cni-6kvsj pod
    see https://linkerd.io/2/checks/#l5d-viz-pods-injection for hints
‼ viz extension proxies are up-to-date
    some proxies are not running the current version:
	* linkerd-destination-6844785b58-87vfv (edge-24.11.2)
	* linkerd-destination-6844785b58-9csrc (edge-24.11.2)
	* linkerd-identity-8b6d99bcc-r7vtx (edge-24.11.2)
	* linkerd-identity-8b6d99bcc-s5pr2 (edge-24.11.2)
	* linkerd-proxy-injector-5d996485c4-qbffn (edge-24.11.2)
	* linkerd-proxy-injector-5d996485c4-vhwmr (edge-24.11.2)
	* metrics-api-85bd4f64d6-48jnl (edge-24.11.2)
	* tap-c495f5677-b5qjg (edge-24.11.2)
	* tap-c495f5677-ptwgh (edge-24.11.2)
	* tap-injector-598bd59c9-4fwx4 (edge-24.11.2)
	* tap-injector-598bd59c9-jf9d6 (edge-24.11.2)
	* web-768896dd8f-6b7sg (edge-24.11.2)
	* web-768896dd8f-vlm5p (edge-24.11.2)
    see https://linkerd.io/2/checks/#l5d-viz-proxy-cp-version for hints
‼ viz extension proxies and cli versions match
    linkerd-destination-6844785b58-87vfv running edge-24.11.2 but cli running edge-24.5.1
    see https://linkerd.io/2/checks/#l5d-viz-proxy-cli-version for hints
‼ prometheus is installed and configured correctly
    missing ClusterRoles: linkerd-linkerd-prometheus
    see https://linkerd.io/2/checks/#l5d-viz-prometheus for hints

Status check results are ×

Environment

  • EKS: 1.29
  • Linkerd: edge-24.11.2

Possible solution

No response

Additional context

No response

Would you like to work on fixing this bug?

None
@fullykubed fullykubed added the bug label Nov 21, 2024
@fullykubed
Copy link
Author

fullykubed commented Nov 21, 2024 •
edited
Loading

Some additional testing that did NOT fix the problem:

  • removing the upstream target from the linkerd service mesh
  • changing opaque ports to skipped ports on the upstream target

The only thing that appears to fix the problem is removing Vault from the service mesh by disabling linkerd proxy injection.

@fullykubed
Copy link
Author

Note that there are no NetworkPolicy resources or Linkerd CRs installed in the cluster at all that should be impacting this network connection.

@fullykubed
Copy link
Author

fullykubed commented Nov 21, 2024 •
edited
Loading

Adding config.linkerd.io/skip-outbound-ports to the Vault pods for the relevant ports (4222) also resolves the issue.

Oddly, adding config.linkerd.io/skip-inbound-ports to the upstream pods and/or services does NOT resolve the issue... this seems very odd b/c shouldn't this be the equivalent of adding config.linkerd.io/skip-outbound-ports to Vault?

@fullykubed fullykubed changed the title Network Connectivity Blocked for Forked Processes NATS Network Connectivity Blocked Nov 22, 2024
@fullykubed
Copy link
Author

Update: Appears to impact any pod trying to communicate with NATS as long as the pod is in the service mesh and config.linkerd.io/skip-outbound-ports does not have 4222 (the NATS server port) in it.

@fullykubed
Copy link
Author

Given the above, I have created a simplified scenario that demonstrates the problem:

  1. Removed the linkerd-proxy from the NATS nodes
  2. I have created a pod that runs nats account info. This works when the pod does not have a linkerd-proxy sidecar but fails with a connection timeout if the linkerd-proxy sidecar is present (regardless of whether it is a native sidecar or not).
  3. Enabled trace logs on the linkerd-proxy sidecar.

Here are the logs from the sidecar when running nats account info from the main container:

bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698127s] DEBUG ThreadId(01) linkerd_service_profiles::client: Resolved profile profile=Profile { addr: Some(LogicalAddr(nats-e33f.default.svc.cluster.local:4222)), http_routes: [], targets: [], opaque_protocol: false, endpoint: None }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698144s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698149s] TRACE ThreadId(01) h2::proto::streams::recv: release_capacity; size=482
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698150s] TRACE ThreadId(01) h2::proto::streams::recv: release_connection_capacity; size=482, connection in_flight_data=482
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698152s] TRACE ThreadId(01) tower::load::peak_ewma: update peak rtt=8.325225ms prior=0.10201515613079733ms
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698203s] DEBUG ThreadId(01) linkerd_app_outbound::policy::api: policy=ClientPolicy { parent: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, protocol: Detect { timeout: 10s, http1: Http1 { routes: [Route { hosts: [], rules: [Rule { matches: [MatchRequest { path: Some(Prefix("/")), headers: [], query_params: [], method: None }], policy: RoutePolicy { meta: Default { name: "http" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: RouteParams { timeouts: Timeouts { response: None, idle: None, request: None }, retry: None, allow_l5d_request_headers: false } } }] }], failure_accrual: None }, http2: Http2 { routes: [Route { hosts: [], rules: [Rule { matches: [MatchRequest { path: Some(Prefix("/")), headers: [], query_params: [], method: None }], policy: RoutePolicy { meta: Default { name: "http" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: RouteParams { timeouts: Timeouts { response: None, idle: None, request: None }, retry: None, allow_l5d_request_headers: false } } }] }], failure_accrual: None }, opaque: Opaque { routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }) } }, backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698243s] DEBUG ThreadId(01) linkerd_app_outbound::discover: Discovered
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698247s] DEBUG ThreadId(01) tower::buffer::worker: service.ready=true processing request
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698250s] TRACE ThreadId(01) tower::buffer::worker: returning response future
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698252s] TRACE ThreadId(01) tower::buffer::worker: worker polling for next message
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698276s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698284s] TRACE ThreadId(01) linkerd_detect: Starting protocol detection capacity=1024 timeout=10s
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698289s] TRACE ThreadId(01) linkerd_proxy_http::detect: Reading capacity=1024
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.698422s] TRACE ThreadId(01) linkerd_idle_cache: Reset
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.704319s] TRACE ThreadId(01) linkerd_duplex: poll
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.705066s] TRACE ThreadId(01) linkerd_duplex: already shutdown direction=client->server
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.705165s] TRACE ThreadId(01) linkerd_duplex: reading direction=server->client
bastion-7dd45cdc99-rj9mf linkerd-proxy [   217.705638s] TRACE ThreadId(01) linkerd_duplex: read 40B direction=server->client
--
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684374s] DEBUG ThreadId(01) linkerd_app_outbound::opaq: Using ClientPolicy routes addr=nats-e33f.default.svc.cluster.local:4222
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684386s] DEBUG ThreadId(01) linkerd_idle_cache: Caching new value key=Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 1 }, version: Version(0) } })
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684432s] DEBUG ThreadId(01) linkerd_distribute::cache: Adding backend=Concrete { target: Balance(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 9 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }) }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684463s] TRACE ThreadId(01) linkerd_stack_tracing: new
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684468s] DEBUG ThreadId(01) linkerd_proxy_balance: Resolving
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684473s] TRACE ThreadId(01) linkerd_proxy_balance: Budilding metrics labels=ConcreteLabels { parent: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), backend: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), logical: "nats-e33f.default.svc.cluster.local:4222", concrete: "nats-e33f.default.svc.cluster.local:4222" }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684499s] DEBUG ThreadId(01) linkerd_proxy_balance: Spawning p2c pool queue capacity=10000 failfast=3s
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684511s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684518s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684532s] TRACE ThreadId(01) linkerd_app_outbound::opaq::logical::router: Selecting Opaq route
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684535s] DEBUG ThreadId(01) linkerd_app_outbound::opaq::logical::router: Selected route meta=RouteRef(Default { name: "opaq" })
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684540s] DEBUG ThreadId(01) linkerd_distribute::stack: New distribution backends=FirstAvailable(ServiceKeys { ids: [KeyId { idx: 0 }], keys: {KeyId { idx: 0 }: Backend { route_ref: RouteRef(Default { name: "opaq" }), concrete: Concrete { target: Balance(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 28 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }) } }} })
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684567s] TRACE ThreadId(01) linkerd_proxy_balance_queue::service: poll=Ready(Ok(()))
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684570s] TRACE ThreadId(01) linkerd_stack::gate: Acquired permit
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684573s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684577s] TRACE ThreadId(01) linkerd_proxy_balance_queue::service: Sending request to worker
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684582s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684592s] TRACE ThreadId(01) linkerd_proxy_balance_queue::worker: Discovering while awaiting requests
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684597s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684600s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684602s] DEBUG ThreadId(01) linkerd_proxy_api_resolve::resolve: Resolving dst=nats-e33f.default.svc.cluster.local:4222 context={"ns":"bastion", "nodeName":"ip-10-0-237-36.us-east-2.compute.internal", "pod":"bastion-7dd45cdc99-rj9mf"}
bastion-7dd45cdc99-rj9mf linkerd-proxy
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684606s] TRACE ThreadId(01) linkerd_stack_tracing: drop
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684611s] TRACE ThreadId(01) linkerd_proxy_balance_queue::service: poll=Ready(Ok(()))
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684614s] TRACE ThreadId(01) linkerd_stack::gate: Acquired permit
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684615s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684626s] TRACE ThreadId(01) linkerd_proxy_balance_queue::service: Sending request to worker
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684633s] TRACE ThreadId(01) linkerd_proxy_balance_queue::worker: Driving pool
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684635s] TRACE ThreadId(01) linkerd_pool_p2c: Polling pending
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684638s] TRACE ThreadId(01) linkerd_proxy_balance_queue::worker: Pool driven
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684640s] TRACE ThreadId(01) linkerd_proxy_balance_queue::worker: Waiting for inner service readiness
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684643s] TRACE ThreadId(01) linkerd_pool_p2c: Polling pending pending=0
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.684645s] TRACE ThreadId(01) linkerd_pool_p2c: All endpoints are ready
--
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703314s] TRACE ThreadId(01) linkerd_proxy_resolve::recover: update=Reset([(10.0.212.213:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-1", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2c", "zone_locality": "local"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(true) }), (10.0.107.131:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-0", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2a", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) }), (10.0.181.87:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-2", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2b", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) })])
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703337s] DEBUG ThreadId(01) linkerd_proxy_balance_queue::worker: Discovered update=Reset([(10.0.212.213:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-1", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2c", "zone_locality": "local"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(true) }), (10.0.107.131:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-0", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2a", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) }), (10.0.181.87:4222, Metadata { labels: {"namespace": "default", "pod": "nats-e33f-2", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2b", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) })])
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703352s]  INFO ThreadId(01) linkerd_pool_p2c: Adding endpoint addr=10.0.212.213:4222
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703356s] TRACE ThreadId(01) linkerd_app_outbound::opaq::concrete: Resolved endpoint addr=10.0.212.213:4222 metadata=Metadata { labels: {"namespace": "default", "pod": "nats-e33f-1", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2c", "zone_locality": "local"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(true) } target=Balance { addr: NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, ewma: EwmaConfig { default_rtt: 30ms, decay: 10s }, queue: QueueConfig { capacity: 10000, failfast_timeout: 3s }, parent: Concrete { target: Balance(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 32 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }) } }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703398s] TRACE ThreadId(01) linkerd_stack_tracing: new
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703406s]  INFO ThreadId(01) linkerd_pool_p2c: Adding endpoint addr=10.0.107.131:4222
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703408s] TRACE ThreadId(01) linkerd_app_outbound::opaq::concrete: Resolved endpoint addr=10.0.107.131:4222 metadata=Metadata { labels: {"namespace": "default", "pod": "nats-e33f-0", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2a", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) } target=Balance { addr: NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, ewma: EwmaConfig { default_rtt: 30ms, decay: 10s }, queue: QueueConfig { capacity: 10000, failfast_timeout: 3s }, parent: Concrete { target: Balance(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 34 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }) } }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703429s] TRACE ThreadId(01) linkerd_stack_tracing: new
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703432s]  INFO ThreadId(01) linkerd_pool_p2c: Adding endpoint addr=10.0.181.87:4222
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703434s] TRACE ThreadId(01) linkerd_app_outbound::opaq::concrete: Resolved endpoint addr=10.0.181.87:4222 metadata=Metadata { labels: {"namespace": "default", "pod": "nats-e33f-2", "service": "nats-e33f", "serviceaccount": "nats-e33f", "statefulset": "nats-e33f", "zone": "us-east-2b", "zone_locality": "remote"}, weight: 10000, protocol_hint: Unknown, tagged_transport_port: None, identity: None, authority_override: None, http2: ClientParams { flow_control: None, keep_alive: None, max_concurrent_reset_streams: None, max_frame_size: None, max_send_buf_size: None }, is_zone_local: Some(false) } target=Balance { addr: NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, ewma: EwmaConfig { default_rtt: 30ms, decay: 10s }, queue: QueueConfig { capacity: 10000, failfast_timeout: 3s }, parent: Concrete { target: Balance(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }, EwmaConfig { default_rtt: 30ms, decay: 10s }), parent: Opaq(OpaqSidecar { orig_dst: OrigDstAddr(172.20.39.221:4222), routes: Receiver { shared: Shared { value: RwLock(PhantomData<std::sync::rwlock::RwLock<linkerd_app_outbound::opaq::logical::Routes>>, RwLock { data: Routes { logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, routes: Some(Route { policy: RoutePolicy { meta: Default { name: "opaq" }, filters: [], distribution: FirstAvailable([RouteBackend { filters: [], backend: Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) } }]), params: () } }), backends: [Backend { meta: Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }, queue: Queue { capacity: 100, failfast_timeout: 3s }, dispatcher: BalanceP2c(PeakEwma(PeakEwma { decay: 10s, default_rtt: 30ms }), DestinationGet { path: "nats-e33f.default.svc.cluster.local:4222" }) }] } }), version: Version(0), is_closed: false, ref_count_rx: 36 }, version: Version(0) } }), logical: Logical { meta: ParentRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }), addr: Name(NameAddr { name: Name("nats-e33f.default.svc.cluster.local"), port: 4222 }) }, backend_ref: BackendRef(Resource { group: "core", kind: "Service", name: "nats-e33f", namespace: "default", section: None, port: Some(4222) }) } }
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703546s] TRACE ThreadId(01) linkerd_stack_tracing: new
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703553s] TRACE ThreadId(01) linkerd_proxy_resolve::recover: polling
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703557s] TRACE ThreadId(01) linkerd_pool_p2c: Polling pending pending=3
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703560s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703563s] TRACE ThreadId(01) tower::ready_cache::cache: endpoint ready
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703567s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703569s] TRACE ThreadId(01) tower::ready_cache::cache: endpoint ready
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703571s] TRACE ThreadId(01) linkerd_stack_tracing: service ready=true ok=true
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703573s] TRACE ThreadId(01) tower::ready_cache::cache: endpoint ready
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703575s] TRACE ThreadId(01) linkerd_pool_p2c: All endpoints are ready
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703578s] TRACE ThreadId(01) tower::load::peak_ewma: update rtt=000ms decay=000079ns; next=030ms
bastion-7dd45cdc99-rj9mf linkerd-proxy [   219.703580s] TRACE ThreadId(01) tower::load::peak_ewma: load estimate=30ms pending=0 cost=Cost(29999920.7401047)

Hope that helps narrow the scope of what might potentially be going wrong.

@fullykubed
Copy link
Author

I do believe that the request is reaching the NATS server, but weirdly the only logs that get generated even in the highest possible log level are:

nats-e33f-2 nats [1] 2024/11/22 02:13:44.520469 [DBG] 10.0.191.109:44152 - cid:39 - Client connection created
nats-e33f-2 nats [1] 2024/11/22 02:13:44.520736 [DBG] 10.0.191.109:44152 - cid:39 - Client connection closed: Client Closed

@fullykubed
Copy link
Author

All of this said, I still think this is a bug in linkerd (vs in NATS) b/c I do not believe that adding the linkerd-proxy sidecar to a pod should prevent network connectivity via server-first protocols such as NATS (regardless of whether the upstream is in the mesh or not).

@fullykubed
Copy link
Author

fullykubed commented Nov 22, 2024 •
edited
Loading

Here are the linkerd-debug logs from the client pod that get generated when running nats account info:

Running as user "root" and group "root". This could be dangerous.
Capturing on 'any'
tshark: cap_set_proc() fail return: Operation not permitted

tshark: cap_set_proc() fail return: Operation not permitted

 ** (tshark:1323) 03:12:48.191679 [Main MESSAGE] -- Capture started.
 ** (tshark:1323) 03:12:48.191791 [Main MESSAGE] -- File: "/tmp/wireshark_anyG8AIX2.pcapng"
Frame 222: 76 bytes on wire (608 bits), 76 bytes captured (608 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:52.461666413 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245172.461666413 seconds
    [Time delta from previous captured frame: 0.000015790 seconds]
    [Time delta from previous displayed frame: 0.000000000 seconds]
    [Time since reference or first frame: 3.836341687 seconds]
    Frame Number: 222
    Frame Length: 76 bytes (608 bits)
    Capture Length: 76 bytes (608 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Loopback (772)
    Link-layer address length: 6
    Source: 00:00:00_00:00:00 (00:00:00:00:00:00)
    Unused: 6800
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 172.20.39.221, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 60
    Identification: 0x0000 (0)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0x7617 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 172.20.39.221
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 49548, Seq: 0, Ack: 1, Len: 0
    Source Port: 4222
    Destination Port: 49548
    [Stream index: 30]
    [Conversation completeness: Incomplete (0)]
    [TCP Segment Len: 0]
    Sequence Number: 0    (relative sequence number)
    Sequence Number (raw): 2822495753
    [Next Sequence Number: 1    (relative sequence number)]
    Acknowledgment Number: 1    (relative ack number)
    Acknowledgment number (raw): 823263247
    1010 .... = Header Length: 40 bytes (10)
    Flags: 0x012 (SYN, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..1. = Syn: Set
            [Expert Info (Chat/Sequence): Connection establish acknowledge (SYN+ACK): server port 4222]
                [Connection establish acknowledge (SYN+ACK): server port 4222]
                [Severity level: Chat]
                [Group: Sequence]
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????A??S?]
    Window: 65483
    [Calculated window size: 65483]
    Checksum: 0x85d3 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (20 bytes), Maximum segment size, SACK permitted, Timestamps, No-Operation (NOP), Window scale
        TCP Option - Maximum segment size: 65495 bytes
            Kind: Maximum Segment Size (2)
            Length: 4
            MSS Value: 65495
        TCP Option - SACK permitted
            Kind: SACK Permitted (4)
            Length: 2
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 2879053702: TSval 2879053702, TSecr 791640261
            Timestamp echo reply: 791640261
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Window scale: 7 (multiply by 128)
            Kind: Window Scale (3)
            Length: 3
            Shift count: 7
            [Multiplier: 128]
    [Timestamps]
        [Time since first frame in this TCP stream: 0.000000000 seconds]
        [Time since previous frame in this TCP stream: 0.000000000 seconds]

Frame 329: 76 bytes on wire (608 bits), 76 bytes captured (608 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.450903346 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.450903346 seconds
    [Time delta from previous captured frame: 0.000303966 seconds]
    [Time delta from previous displayed frame: 1.989236933 seconds]
    [Time since reference or first frame: 5.825578620 seconds]
    Frame Number: 329
    Frame Length: 76 bytes (608 bits)
    Capture Length: 76 bytes (608 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Sent by us (4)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 5e:20:13:1c:14:20 (5e:20:13:1c:14:20)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.167.179, Dst: 10.0.191.102
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 60
    Identification: 0xb33f (45887)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0xcd62 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.167.179
    Destination Address: 10.0.191.102
Transmission Control Protocol, Src Port: 50326, Dst Port: 4222, Seq: 0, Len: 0
    Source Port: 50326
    Destination Port: 4222
    [Stream index: 42]
    [Conversation completeness: Incomplete (0)]
    [TCP Segment Len: 0]
    Sequence Number: 0    (relative sequence number)
    Sequence Number (raw): 2735317032
    [Next Sequence Number: 1    (relative sequence number)]
    Acknowledgment Number: 0
    Acknowledgment number (raw): 0
    1010 .... = Header Length: 40 bytes (10)
    Flags: 0x002 (SYN)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...0 .... = Acknowledgment: Not set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..1. = Syn: Set
            [Expert Info (Chat/Sequence): Connection establish request (SYN): server port 4222]
                [Connection establish request (SYN): server port 4222]
                [Severity level: Chat]
                [Group: Sequence]
        .... .... ...0 = Fin: Not set
        [TCP Flags: ??????????S?]
    Window: 62727
    [Calculated window size: 62727]
    Checksum: 0x7b48 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (20 bytes), Maximum segment size, SACK permitted, Timestamps, No-Operation (NOP), Window scale
        TCP Option - Maximum segment size: 8961 bytes
            Kind: Maximum Segment Size (2)
            Length: 4
            MSS Value: 8961
        TCP Option - SACK permitted
            Kind: SACK Permitted (4)
            Length: 2
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 1167893533: TSval 1167893533, TSecr 0
            Timestamp echo reply: 0
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Window scale: 7 (multiply by 128)
            Kind: Window Scale (3)
            Length: 3
            Shift count: 7
            [Multiplier: 128]
    [Timestamps]
        [Time since first frame in this TCP stream: 0.000000000 seconds]
        [Time since previous frame in this TCP stream: 0.000000000 seconds]

Frame 330: 76 bytes on wire (608 bits), 76 bytes captured (608 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.451110608 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.451110608 seconds
    [Time delta from previous captured frame: 0.000207262 seconds]
    [Time delta from previous displayed frame: 0.000207262 seconds]
    [Time since reference or first frame: 5.825785882 seconds]
    Frame Number: 330
    Frame Length: 76 bytes (608 bits)
    Capture Length: 76 bytes (608 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 1a:84:f8:f4:ee:01 (1a:84:f8:f4:ee:01)
    Unused: 0304
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.191.102, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 60
    Identification: 0x0000 (0)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 125
    Protocol: TCP (6)
    Header Checksum: 0x82a2 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.191.102
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 50326, Seq: 0, Ack: 1, Len: 0
    Source Port: 4222
    Destination Port: 50326
    [Stream index: 42]
    [Conversation completeness: Incomplete, SYN_SENT (1)]
    [TCP Segment Len: 0]
    Sequence Number: 0    (relative sequence number)
    Sequence Number (raw): 2334478608
    [Next Sequence Number: 1    (relative sequence number)]
    Acknowledgment Number: 1    (relative ack number)
    Acknowledgment number (raw): 2735317033
    1010 .... = Header Length: 40 bytes (10)
    Flags: 0x012 (SYN, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..1. = Syn: Set
            [Expert Info (Chat/Sequence): Connection establish acknowledge (SYN+ACK): server port 4222]
                [Connection establish acknowledge (SYN+ACK): server port 4222]
                [Severity level: Chat]
                [Group: Sequence]
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????A??S?]
    Window: 62643
    [Calculated window size: 62643]
    Checksum: 0xc113 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (20 bytes), Maximum segment size, SACK permitted, Timestamps, No-Operation (NOP), Window scale
        TCP Option - Maximum segment size: 8961 bytes
            Kind: Maximum Segment Size (2)
            Length: 4
            MSS Value: 8961
        TCP Option - SACK permitted
            Kind: SACK Permitted (4)
            Length: 2
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 3448524285: TSval 3448524285, TSecr 1167893533
            Timestamp echo reply: 1167893533
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Window scale: 7 (multiply by 128)
            Kind: Window Scale (3)
            Length: 3
            Shift count: 7
            [Multiplier: 128]
    [Timestamps]
        [Time since first frame in this TCP stream: 0.000207262 seconds]
        [Time since previous frame in this TCP stream: 0.000207262 seconds]
    [SEQ/ACK analysis]
        [This is an ACK to the segment in frame: 329]
        [The RTT to ACK the segment was: 0.000207262 seconds]

Frame 331: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.451131399 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.451131399 seconds
    [Time delta from previous captured frame: 0.000020791 seconds]
    [Time delta from previous displayed frame: 0.000020791 seconds]
    [Time since reference or first frame: 5.825806673 seconds]
    Frame Number: 331
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Sent by us (4)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 5e:20:13:1c:14:20 (5e:20:13:1c:14:20)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.167.179, Dst: 10.0.191.102
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0xb340 (45888)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0xcd69 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.167.179
    Destination Address: 10.0.191.102
Transmission Control Protocol, Src Port: 50326, Dst Port: 4222, Seq: 1, Ack: 1, Len: 0
    Source Port: 50326
    Destination Port: 4222
    [Stream index: 42]
    [Conversation completeness: Incomplete, CLIENT_ESTABLISHED (3)]
    [TCP Segment Len: 0]
    Sequence Number: 1    (relative sequence number)
    Sequence Number (raw): 2735317033
    [Next Sequence Number: 1    (relative sequence number)]
    Acknowledgment Number: 1    (relative ack number)
    Acknowledgment number (raw): 2334478609
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x010 (ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????A????]
    Window: 491
    [Calculated window size: 62848]
    [Window size scaling factor: 128]
    Checksum: 0x7b40 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 1167893534: TSval 1167893534, TSecr 3448524285
            Timestamp echo reply: 3448524285
    [Timestamps]
        [Time since first frame in this TCP stream: 0.000228053 seconds]
        [Time since previous frame in this TCP stream: 0.000020791 seconds]
    [SEQ/ACK analysis]
        [This is an ACK to the segment in frame: 330]
        [The RTT to ACK the segment was: 0.000020791 seconds]
        [iRTT: 0.000228053 seconds]

Frame 332: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.451172679 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.451172679 seconds
    [Time delta from previous captured frame: 0.000041280 seconds]
    [Time delta from previous displayed frame: 0.000041280 seconds]
    [Time since reference or first frame: 5.825847953 seconds]
    Frame Number: 332
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Sent by us (4)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 5e:20:13:1c:14:20 (5e:20:13:1c:14:20)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.167.179, Dst: 10.0.191.102
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0xb341 (45889)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0xcd68 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.167.179
    Destination Address: 10.0.191.102
Transmission Control Protocol, Src Port: 50326, Dst Port: 4222, Seq: 1, Ack: 1, Len: 0
    Source Port: 50326
    Destination Port: 4222
    [Stream index: 42]
    [Conversation completeness: Incomplete, ESTABLISHED (7)]
    [TCP Segment Len: 0]
    Sequence Number: 1    (relative sequence number)
    Sequence Number (raw): 2735317033
    [Next Sequence Number: 2    (relative sequence number)]
    Acknowledgment Number: 1    (relative ack number)
    Acknowledgment number (raw): 2334478609
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x011 (FIN, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...1 = Fin: Set
            [Expert Info (Chat/Sequence): Connection finish (FIN)]
                [Connection finish (FIN)]
                [Severity level: Chat]
                [Group: Sequence]
        [TCP Flags: ???????A???F]
            [Expert Info (Note/Sequence): This frame initiates the connection closing]
                [This frame initiates the connection closing]
                [Severity level: Note]
                [Group: Sequence]
    Window: 491
    [Calculated window size: 62848]
    [Window size scaling factor: 128]
    Checksum: 0x7b40 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 1167893534: TSval 1167893534, TSecr 3448524285
            Timestamp echo reply: 3448524285
    [Timestamps]
        [Time since first frame in this TCP stream: 0.000269333 seconds]
        [Time since previous frame in this TCP stream: 0.000041280 seconds]

Frame 333: 582 bytes on wire (4656 bits), 582 bytes captured (4656 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453351182 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453351182 seconds
    [Time delta from previous captured frame: 0.002178503 seconds]
    [Time delta from previous displayed frame: 0.002178503 seconds]
    [Time since reference or first frame: 5.828026456 seconds]
    Frame Number: 333
    Frame Length: 582 bytes (4656 bits)
    Capture Length: 582 bytes (4656 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp:data]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 1a:84:f8:f4:ee:01 (1a:84:f8:f4:ee:01)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.191.102, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 566
    Identification: 0xa65f (42591)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 125
    Protocol: TCP (6)
    Header Checksum: 0xda48 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.191.102
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 50326, Seq: 1, Ack: 2, Len: 514
    Source Port: 4222
    Destination Port: 50326
    [Stream index: 42]
    [Conversation completeness: Complete, NO_DATA (23)]
    [TCP Segment Len: 514]
    Sequence Number: 1    (relative sequence number)
    Sequence Number (raw): 2334478609
    [Next Sequence Number: 515    (relative sequence number)]
    Acknowledgment Number: 2    (relative ack number)
    Acknowledgment number (raw): 2735317034
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x018 (PSH, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 1... = Push: Set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????AP???]
    Window: 490
    [Calculated window size: 62720]
    [Window size scaling factor: 128]
    Checksum: 0x1a1a [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 3448524287: TSval 3448524287, TSecr 1167893534
            Timestamp echo reply: 1167893534
    [Timestamps]
        [Time since first frame in this TCP stream: 0.002447836 seconds]
        [Time since previous frame in this TCP stream: 0.002178503 seconds]
    [SEQ/ACK analysis]
        [This is an ACK to the segment in frame: 332]
        [The RTT to ACK the segment was: 0.002178503 seconds]
        [iRTT: 0.000228053 seconds]
        [Bytes in flight: 514]
        [Bytes sent since last PSH flag: 514]
    TCP payload (514 bytes)
Data (514 bytes)

0000  49 4e 46 4f 20 7b 22 73 65 72 76 65 72 5f 69 64   INFO {"server_id
0010  22 3a 22 4e 42 50 54 36 5a 4f 46 49 54 46 4c 44   ":"NBPT6ZOFITFLD
0020  45 59 41 35 4d 43 58 35 4a 4b 59 44 37 48 57 43   EYA5MCX5JKYD7HWC
0030  42 35 45 58 4a 41 52 32 35 50 33 56 4f 37 55 55   B5EXJAR25P3VO7UU
0040  58 59 32 52 44 48 47 50 32 54 50 22 2c 22 73 65   XY2RDHGP2TP","se
0050  72 76 65 72 5f 6e 61 6d 65 22 3a 22 6e 61 74 73   rver_name":"nats
0060  2d 65 33 33 66 2d 32 22 2c 22 76 65 72 73 69 6f   -e33f-2","versio
0070  6e 22 3a 22 32 2e 31 30 2e 32 32 22 2c 22 70 72   n":"2.10.22","pr
0080  6f 74 6f 22 3a 31 2c 22 67 69 74 5f 63 6f 6d 6d   oto":1,"git_comm
0090  69 74 22 3a 22 32 34 30 65 39 61 34 22 2c 22 67   it":"240e9a4","g
00a0  6f 22 3a 22 67 6f 31 2e 32 32 2e 38 22 2c 22 68   o":"go1.22.8","h
00b0  6f 73 74 22 3a 22 30 2e 30 2e 30 2e 30 22 2c 22   ost":"0.0.0.0","
00c0  70 6f 72 74 22 3a 34 32 32 32 2c 22 68 65 61 64   port":4222,"head
00d0  65 72 73 22 3a 74 72 75 65 2c 22 61 75 74 68 5f   ers":true,"auth_
00e0  72 65 71 75 69 72 65 64 22 3a 74 72 75 65 2c 22   required":true,"
00f0  6d 61 78 5f 70 61 79 6c 6f 61 64 22 3a 38 33 38   max_payload":838
0100  38 36 30 38 2c 22 6a 65 74 73 74 72 65 61 6d 22   8608,"jetstream"
0110  3a 74 72 75 65 2c 22 63 6c 69 65 6e 74 5f 69 64   :true,"client_id
0120  22 3a 36 36 2c 22 63 6c 69 65 6e 74 5f 69 70 22   ":66,"client_ip"
0130  3a 22 31 30 2e 30 2e 31 36 37 2e 31 37 39 22 2c   :"10.0.167.179",
0140  22 6e 6f 6e 63 65 22 3a 22 30 59 47 30 42 55 44   "nonce":"0YG0BUD
0150  4c 67 43 36 61 34 47 77 22 2c 22 63 6c 75 73 74   LgC6a4Gw","clust
0160  65 72 22 3a 22 6e 61 74 73 2d 65 33 33 66 22 2c   er":"nats-e33f",
0170  22 63 6f 6e 6e 65 63 74 5f 75 72 6c 73 22 3a 5b   "connect_urls":[
0180  22 31 30 2e 30 2e 31 39 31 2e 31 30 32 3a 34 32   "10.0.191.102:42
0190  32 32 22 2c 22 31 30 2e 30 2e 31 30 37 2e 31 33   22","10.0.107.13
01a0  36 3a 34 32 32 32 22 2c 22 31 30 2e 30 2e 32 32   6:4222","10.0.22
01b0  33 2e 31 31 37 3a 34 32 32 32 22 5d 2c 22 78 6b   3.117:4222"],"xk
01c0  65 79 22 3a 22 58 41 53 57 49 37 32 32 35 5a 45   ey":"XASWI7225ZE
01d0  4b 48 34 44 36 36 53 34 41 44 58 58 4f 37 5a 48   KH4D66S4ADXXO7ZH
01e0  55 54 55 41 33 37 36 55 50 46 36 5a 59 49 48 35   UTUA376UPF6ZYIH5
01f0  54 4f 4e 32 56 5a 57 42 43 58 4e 4b 5a 22 7d 20   TON2VZWBCXNKZ"}
0200  0d 0a                                             ..
    Data: 494e464f207b227365727665725f6964223a224e425054365a4f464954464c4445594135?
    [Length: 514]

Frame 334: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453384048 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453384048 seconds
    [Time delta from previous captured frame: 0.000032866 seconds]
    [Time delta from previous displayed frame: 0.000032866 seconds]
    [Time since reference or first frame: 5.828059322 seconds]
    Frame Number: 334
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Sent by us (4)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 5e:20:13:1c:14:20 (5e:20:13:1c:14:20)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.167.179, Dst: 10.0.191.102
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0xb342 (45890)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0xcd67 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.167.179
    Destination Address: 10.0.191.102
Transmission Control Protocol, Src Port: 50326, Dst Port: 4222, Seq: 2, Ack: 515, Len: 0
    Source Port: 50326
    Destination Port: 4222
    [Stream index: 42]
    [Conversation completeness: Complete, WITH_DATA (31)]
    [TCP Segment Len: 0]
    Sequence Number: 2    (relative sequence number)
    Sequence Number (raw): 2735317034
    [Next Sequence Number: 2    (relative sequence number)]
    Acknowledgment Number: 515    (relative ack number)
    Acknowledgment number (raw): 2334479123
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x010 (ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????A????]
    Window: 487
    [Calculated window size: 62336]
    [Window size scaling factor: 128]
    Checksum: 0x7b40 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 1167893536: TSval 1167893536, TSecr 3448524287
            Timestamp echo reply: 3448524287
    [Timestamps]
        [Time since first frame in this TCP stream: 0.002480702 seconds]
        [Time since previous frame in this TCP stream: 0.000032866 seconds]
    [SEQ/ACK analysis]
        [This is an ACK to the segment in frame: 333]
        [The RTT to ACK the segment was: 0.000032866 seconds]
        [iRTT: 0.000228053 seconds]

Frame 335: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453401780 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453401780 seconds
    [Time delta from previous captured frame: 0.000017732 seconds]
    [Time delta from previous displayed frame: 0.000017732 seconds]
    [Time since reference or first frame: 5.828077054 seconds]
    Frame Number: 335
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 1a:84:f8:f4:ee:01 (1a:84:f8:f4:ee:01)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.191.102, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0xa660 (42592)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 125
    Protocol: TCP (6)
    Header Checksum: 0xdc49 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.191.102
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 50326, Seq: 515, Ack: 2, Len: 0
    Source Port: 4222
    Destination Port: 50326
    [Stream index: 42]
    [Conversation completeness: Complete, WITH_DATA (31)]
    [TCP Segment Len: 0]
    Sequence Number: 515    (relative sequence number)
    Sequence Number (raw): 2334479123
    [Next Sequence Number: 516    (relative sequence number)]
    Acknowledgment Number: 2    (relative ack number)
    Acknowledgment number (raw): 2735317034
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x011 (FIN, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...1 = Fin: Set
            [Expert Info (Chat/Sequence): Connection finish (FIN)]
                [Connection finish (FIN)]
                [Severity level: Chat]
                [Group: Sequence]
        [TCP Flags: ???????A???F]
            [Expert Info (Note/Sequence): This frame undergoes the connection closing]
                [This frame undergoes the connection closing]
                [Severity level: Note]
                [Group: Sequence]
    Window: 490
    [Calculated window size: 62720]
    [Window size scaling factor: 128]
    Checksum: 0xfdef [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 3448524287: TSval 3448524287, TSecr 1167893534
            Timestamp echo reply: 1167893534
    [Timestamps]
        [Time since first frame in this TCP stream: 0.002498434 seconds]
        [Time since previous frame in this TCP stream: 0.000017732 seconds]

Frame 336: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453409575 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453409575 seconds
    [Time delta from previous captured frame: 0.000007795 seconds]
    [Time delta from previous displayed frame: 0.000007795 seconds]
    [Time since reference or first frame: 5.828084849 seconds]
    Frame Number: 336
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Sent by us (4)
    Link-layer address type: Ethernet (1)
    Link-layer address length: 6
    Source: 5e:20:13:1c:14:20 (5e:20:13:1c:14:20)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 10.0.167.179, Dst: 10.0.191.102
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0xb343 (45891)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0xcd66 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 10.0.167.179
    Destination Address: 10.0.191.102
Transmission Control Protocol, Src Port: 50326, Dst Port: 4222, Seq: 2, Ack: 516, Len: 0
    Source Port: 50326
    Destination Port: 4222
    [Stream index: 42]
    [Conversation completeness: Complete, WITH_DATA (31)]
    [TCP Segment Len: 0]
    Sequence Number: 2    (relative sequence number)
    Sequence Number (raw): 2735317034
    [Next Sequence Number: 2    (relative sequence number)]
    Acknowledgment Number: 516    (relative ack number)
    Acknowledgment number (raw): 2334479124
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x010 (ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????A????]
    Window: 487
    [Calculated window size: 62336]
    [Window size scaling factor: 128]
    Checksum: 0x7b40 [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 1167893536: TSval 1167893536, TSecr 3448524287
            Timestamp echo reply: 3448524287
    [Timestamps]
        [Time since first frame in this TCP stream: 0.002506229 seconds]
        [Time since previous frame in this TCP stream: 0.000007795 seconds]
    [SEQ/ACK analysis]
        [This is an ACK to the segment in frame: 335]
        [The RTT to ACK the segment was: 0.000007795 seconds]
        [iRTT: 0.000228053 seconds]

Frame 337: 582 bytes on wire (4656 bits), 582 bytes captured (4656 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453425161 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453425161 seconds
    [Time delta from previous captured frame: 0.000015586 seconds]
    [Time delta from previous displayed frame: 0.000015586 seconds]
    [Time since reference or first frame: 5.828100435 seconds]
    Frame Number: 337
    Frame Length: 582 bytes (4656 bits)
    Capture Length: 582 bytes (4656 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp:data]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Loopback (772)
    Link-layer address length: 6
    Source: 00:00:00_00:00:00 (00:00:00:00:00:00)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 172.20.39.221, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 566
    Identification: 0x34cb (13515)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0x3f52 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 172.20.39.221
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 49548, Seq: 1, Ack: 2, Len: 514
    Source Port: 4222
    Destination Port: 49548
    [Stream index: 30]
    [Conversation completeness: Incomplete (0)]
    [TCP Segment Len: 514]
    Sequence Number: 1    (relative sequence number)
    Sequence Number (raw): 2822495754
    [Next Sequence Number: 515    (relative sequence number)]
    Acknowledgment Number: 2    (relative ack number)
    Acknowledgment number (raw): 823263248
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x018 (PSH, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 1... = Push: Set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...0 = Fin: Not set
        [TCP Flags: ???????AP???]
    Window: 512
    [Calculated window size: 65536]
    [Window size scaling factor: 128]
    Checksum: 0x87cd [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 2879055694: TSval 2879055694, TSecr 791642248
            Timestamp echo reply: 791642248
    [Timestamps]
        [Time since first frame in this TCP stream: 1.991758748 seconds]
        [Time since previous frame in this TCP stream: 1.991758748 seconds]
    [SEQ/ACK analysis]
        [Bytes in flight: 515]
        [Bytes sent since last PSH flag: 514]
    TCP payload (514 bytes)
Data (514 bytes)

0000  49 4e 46 4f 20 7b 22 73 65 72 76 65 72 5f 69 64   INFO {"server_id
0010  22 3a 22 4e 42 50 54 36 5a 4f 46 49 54 46 4c 44   ":"NBPT6ZOFITFLD
0020  45 59 41 35 4d 43 58 35 4a 4b 59 44 37 48 57 43   EYA5MCX5JKYD7HWC
0030  42 35 45 58 4a 41 52 32 35 50 33 56 4f 37 55 55   B5EXJAR25P3VO7UU
0040  58 59 32 52 44 48 47 50 32 54 50 22 2c 22 73 65   XY2RDHGP2TP","se
0050  72 76 65 72 5f 6e 61 6d 65 22 3a 22 6e 61 74 73   rver_name":"nats
0060  2d 65 33 33 66 2d 32 22 2c 22 76 65 72 73 69 6f   -e33f-2","versio
0070  6e 22 3a 22 32 2e 31 30 2e 32 32 22 2c 22 70 72   n":"2.10.22","pr
0080  6f 74 6f 22 3a 31 2c 22 67 69 74 5f 63 6f 6d 6d   oto":1,"git_comm
0090  69 74 22 3a 22 32 34 30 65 39 61 34 22 2c 22 67   it":"240e9a4","g
00a0  6f 22 3a 22 67 6f 31 2e 32 32 2e 38 22 2c 22 68   o":"go1.22.8","h
00b0  6f 73 74 22 3a 22 30 2e 30 2e 30 2e 30 22 2c 22   ost":"0.0.0.0","
00c0  70 6f 72 74 22 3a 34 32 32 32 2c 22 68 65 61 64   port":4222,"head
00d0  65 72 73 22 3a 74 72 75 65 2c 22 61 75 74 68 5f   ers":true,"auth_
00e0  72 65 71 75 69 72 65 64 22 3a 74 72 75 65 2c 22   required":true,"
00f0  6d 61 78 5f 70 61 79 6c 6f 61 64 22 3a 38 33 38   max_payload":838
0100  38 36 30 38 2c 22 6a 65 74 73 74 72 65 61 6d 22   8608,"jetstream"
0110  3a 74 72 75 65 2c 22 63 6c 69 65 6e 74 5f 69 64   :true,"client_id
0120  22 3a 36 36 2c 22 63 6c 69 65 6e 74 5f 69 70 22   ":66,"client_ip"
0130  3a 22 31 30 2e 30 2e 31 36 37 2e 31 37 39 22 2c   :"10.0.167.179",
0140  22 6e 6f 6e 63 65 22 3a 22 30 59 47 30 42 55 44   "nonce":"0YG0BUD
0150  4c 67 43 36 61 34 47 77 22 2c 22 63 6c 75 73 74   LgC6a4Gw","clust
0160  65 72 22 3a 22 6e 61 74 73 2d 65 33 33 66 22 2c   er":"nats-e33f",
0170  22 63 6f 6e 6e 65 63 74 5f 75 72 6c 73 22 3a 5b   "connect_urls":[
0180  22 31 30 2e 30 2e 31 39 31 2e 31 30 32 3a 34 32   "10.0.191.102:42
0190  32 32 22 2c 22 31 30 2e 30 2e 31 30 37 2e 31 33   22","10.0.107.13
01a0  36 3a 34 32 32 32 22 2c 22 31 30 2e 30 2e 32 32   6:4222","10.0.22
01b0  33 2e 31 31 37 3a 34 32 32 32 22 5d 2c 22 78 6b   3.117:4222"],"xk
01c0  65 79 22 3a 22 58 41 53 57 49 37 32 32 35 5a 45   ey":"XASWI7225ZE
01d0  4b 48 34 44 36 36 53 34 41 44 58 58 4f 37 5a 48   KH4D66S4ADXXO7ZH
01e0  55 54 55 41 33 37 36 55 50 46 36 5a 59 49 48 35   UTUA376UPF6ZYIH5
01f0  54 4f 4e 32 56 5a 57 42 43 58 4e 4b 5a 22 7d 20   TON2VZWBCXNKZ"}
0200  0d 0a                                             ..
    Data: 494e464f207b227365727665725f6964223a224e425054365a4f464954464c4445594135?
    [Length: 514]

Frame 339: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on interface any, id 0
    Section number: 1
    Interface id: 0 (any)
        Interface name: any
    Encapsulation type: Linux cooked-mode capture v1 (25)
    Arrival Time: Nov 22, 2024 03:12:54.453448406 UTC
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1732245174.453448406 seconds
    [Time delta from previous captured frame: 0.000011006 seconds]
    [Time delta from previous displayed frame: 0.000023245 seconds]
    [Time since reference or first frame: 5.828123680 seconds]
    Frame Number: 339
    Frame Length: 68 bytes (544 bits)
    Capture Length: 68 bytes (544 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: sll:ethertype:ip:tcp]
Linux cooked capture v1
    Packet type: Unicast to us (0)
    Link-layer address type: Loopback (772)
    Link-layer address length: 6
    Source: 00:00:00_00:00:00 (00:00:00:00:00:00)
    Unused: 0000
    Protocol: IPv4 (0x0800)
Internet Protocol Version 4, Src: 172.20.39.221, Dst: 10.0.167.179
    0100 .... = Version: 4
    .... 0101 = Header Length: 20 bytes (5)
    Differentiated Services Field: 0x00 (DSCP: CS0, ECN: Not-ECT)
        0000 00.. = Differentiated Services Codepoint: Default (0)
        .... ..00 = Explicit Congestion Notification: Not ECN-Capable Transport (0)
    Total Length: 52
    Identification: 0x34cc (13516)
    010. .... = Flags: 0x2, Don't fragment
        0... .... = Reserved bit: Not set
        .1.. .... = Don't fragment: Set
        ..0. .... = More fragments: Not set
    ...0 0000 0000 0000 = Fragment Offset: 0
    Time to Live: 127
    Protocol: TCP (6)
    Header Checksum: 0x4153 [validation disabled]
    [Header checksum status: Unverified]
    Source Address: 172.20.39.221
    Destination Address: 10.0.167.179
Transmission Control Protocol, Src Port: 4222, Dst Port: 49548, Seq: 515, Ack: 2, Len: 0
    Source Port: 4222
    Destination Port: 49548
    [Stream index: 30]
    [Conversation completeness: Incomplete (8)]
    [TCP Segment Len: 0]
    Sequence Number: 515    (relative sequence number)
    Sequence Number (raw): 2822496268
    [Next Sequence Number: 516    (relative sequence number)]
    Acknowledgment Number: 2    (relative ack number)
    Acknowledgment number (raw): 823263248
    1000 .... = Header Length: 32 bytes (8)
    Flags: 0x011 (FIN, ACK)
        000. .... .... = Reserved: Not set
        ...0 .... .... = Accurate ECN: Not set
        .... 0... .... = Congestion Window Reduced: Not set
        .... .0.. .... = ECN-Echo: Not set
        .... ..0. .... = Urgent: Not set
        .... ...1 .... = Acknowledgment: Set
        .... .... 0... = Push: Not set
        .... .... .0.. = Reset: Not set
        .... .... ..0. = Syn: Not set
        .... .... ...1 = Fin: Set
            [Expert Info (Chat/Sequence): Connection finish (FIN)]
                [Connection finish (FIN)]
                [Severity level: Chat]
                [Group: Sequence]
        [TCP Flags: ???????A???F]
            [Expert Info (Note/Sequence): This frame initiates the connection closing]
                [This frame initiates the connection closing]
                [Severity level: Note]
                [Group: Sequence]
    Window: 512
    [Calculated window size: 65536]
    [Window size scaling factor: 128]
    Checksum: 0x85cb [unverified]
    [Checksum Status: Unverified]
    Urgent Pointer: 0
    Options: (12 bytes), No-Operation (NOP), No-Operation (NOP), Timestamps
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - No-Operation (NOP)
            Kind: No-Operation (1)
        TCP Option - Timestamps
            Kind: Time Stamp Option (8)
            Length: 10
            Timestamp value: 2879055694: TSval 2879055694, TSecr 791642253
            Timestamp echo reply: 791642253
    [Timestamps]
        [Time since first frame in this TCP stream: 1.991781993 seconds]
        [Time since previous frame in this TCP stream: 0.000023245 seconds]

From this, it looks pretty clear that the NATS server is behaving according to its spec: when a client opens a TCP connection, immediately send an INFO payload to help setup the NATS connection. It is a server-first protocol, b/c the client isn't expected to send anything before receiving the INFO payload.

However, one thing that sticks out to me is that the linkerd proxy is sending a FIN ACK immediately after the connection is opened, before receiving any data from the server. That seems very odd...

@fullykubed fullykubed changed the title NATS Network Connectivity Blocked Network connectivity blocked for when connecting with an upstream that uses a server-first protocol Nov 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@fullykubed