Description
--- FAIL: Test (11.13s)
--- FAIL: Test/ServerFailureMetrics_AfterResponseRecv (0.06s)
metrics_test.go:221: Created new snapshot cache...
tlogger.go:116: INFO server.go:690 [core] [Server #491]Server created (t=+1.218943ms)
metrics_test.go:221: Registered Aggregated Discovery Service (ADS)...
metrics_test.go:221: xDS management server serving at: 127.0.0.1:40479...
tlogger.go:116: INFO server.go:886 [core] [Server #491 ListenSocket #492]ListenSocket created (t=+1.808593ms)
server.go:230: Created new resource snapshot...
server.go:[236](https://github.com/grpc/grpc-go/actions/runs/15213212977/job/42792266891?pr=8329#step:8:237): Updated snapshot cache with resource snapshot...
tlogger.go:116: INFO clientconn.go:1687 [core] original dial target is: "127.0.0.1:40479" (t=+8.377595ms)
tlogger.go:116: INFO clientconn.go:333 [core] [Channel #493]Channel created (t=+8.756241ms)
tlogger.go:116: INFO clientconn.go:207 [core] [Channel #493]parsed dial target is: resolver.Target{URL:url.URL{Scheme:"dns", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/127.0.0.1:40479", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}} (t=+9.056651ms)
tlogger.go:116: INFO clientconn.go:208 [core] [Channel #493]Channel authority set to "127.0.0.1:40479" (t=+9.293713ms)
tlogger.go:116: INFO resolver_wrapper.go:210 [core] [Channel #493]Resolver state updated: {
"Addresses": [
{
"Addr": "127.0.0.1:40479",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Endpoints": [
{
"Addresses": [
{
"Addr": "127.0.0.1:40479",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Attributes": null
}
],
"ServiceConfig": null,
"Attributes": null
} (resolver returned new addresses) (t=+10.377024ms)
tlogger.go:116: INFO balancer_wrapper.go:122 [core] [Channel #493]Channel switches to new LB policy "pick_first" (t=+10.750891ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to CONNECTING (t=+11.13622ms)
tlogger.go:116: INFO clientconn.go:866 [core] [Channel #493 SubChannel #494]Subchannel created (t=+11.43637ms)
tlogger.go:116: INFO clientconn.go:333 [core] [Channel #493]Channel exiting idle mode (t=+11.84394ms)
tlogger.go:116: INFO clientconn.go:1233 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to CONNECTING (t=+12.314768ms)
tlogger.go:116: INFO clientconn.go:1352 [core] [Channel #493 SubChannel #494]Subchannel picks a new address "127.0.0.1:40479" to connect (t=+12.561829ms)
tlogger.go:116: INFO clientconn.go:1233 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to READY (t=+20.139932ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to READY (t=+20.488943ms)
tlogger.go:116: WARNING server.go:1995 [core] Unsupported codec "grpctransport.bytecodec". Defaulting to "proto" for now. This will start to fail in future releases. (t=+24.182557ms)
logging.go:30: nodeID "a8947155-3345-492d-8e6a-d19309281129" requested type.googleapis.com/envoy.config.listener.v3.Listener[test-listener-resource] and known map[]. Diff [test-listener-resource]
logging.go:30: respond type.googleapis.com/envoy.config.listener.v3.Listener[test-listener-resource] version "" with version "1"
logging.go:30: nodeID "a8947155-3345-492d-8e6a-d19309281129" requested type.googleapis.com/envoy.config.listener.v3.Listener[test-listener-resource] and known map[test-listener-resource:{}]. Diff []
logging.go:30: open watch 1 for type.googleapis.com/envoy.config.listener.v3.Listener[test-listener-resource] from nodeID "a8947155-3345-492d-8e6a-d19309281129", version "1"
tlogger.go:116: INFO restartable_listener.go:84 [testutils] Stopping restartable listener "127.0.0.1:40479" (t=+34.9[237](https://github.com/grpc/grpc-go/actions/runs/15213212977/job/42792266891?pr=8329#step:8:238)85ms)
tlogger.go:116: INFO clientconn.go:1233 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to IDLE (t=+35.411305ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to IDLE (t=+35.752842ms)
tlogger.go:116: WARNING ads_stream.go:496 [xds] [xds-client 0x40004e4000] [xds-channel 0x4000626d20] [ads-stream 0x4000022580] ADS stream closed: rpc error: code = Unavailable desc = error reading from server: EOF (t=+37.564993ms)
tlogger.go:116: INFO clientconn.go:1233 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to CONNECTING (t=+37.989745ms)
tlogger.go:116: INFO clientconn.go:1352 [core] [Channel #493 SubChannel #494]Subchannel picks a new address "127.0.0.1:40479" to connect (t=+38.134335ms)
tlogger.go:116: WARNING authority.go:195 [xds] [xds-client 0x40004e4000] [authority ""] Watchers not notified since ADS stream failed after having received at least one response: rpc error: code = Unavailable desc = error reading from server: EOF (t=+38.671967ms)
tlogger.go:116: INFO restartable_listener.go:97 [testutils] Restarting listener "127.0.0.1:40479" (t=+38.789406ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to CONNECTING (t=+38.982326ms)
tlogger.go:116: WARNING clientconn.go:1414 [core] [Channel #493 SubChannel #494]grpc: addrConn.createTransport failed to connect to {Addr: "127.0.0.1:40479", ServerName: "127.0.0.1:40479", BalancerAttributes: {"<%!p(pickfirstleaf.managedByPickfirstKeyType={})>": "<%!p(bool=true)>" }}. Err: write tcp 127.0.0.1:49956->127.0.0.1:40479: write: broken pipe (t=+41.2991ms)
tlogger.go:116: INFO clientconn.go:1235 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to TRANSIENT_FAILURE, last error: write tcp 127.0.0.1:49956->127.0.0.1:40479: write: broken pipe (t=+41.538958ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to TRANSIENT_FAILURE (t=+41.801647ms)
tlogger.go:116: WARNING ads_stream.go:234 [xds] [xds-client 0x40004e4000] [xds-channel 0x4000626d20] [ads-stream 0x400002[258](https://github.com/grpc/grpc-go/actions/runs/15213212977/job/42792266891?pr=8329#step:8:259)0] Failed to create a new ADS streaming RPC: rpc error: code = Unavailable desc = write tcp 127.0.0.1:49956->127.0.0.1:40479: write: broken pipe (t=+42.062905ms)
metrics_test.go:282: tmr.WaitForInt64Count(ctx, mdWant) succeeded when expected to timeout.
tlogger.go:116: INFO ads_stream.go:155 [xds] [xds-client 0x40004e4000] [xds-channel 0x4000626d20] [ads-stream 0x4000022580] Shutdown ADS stream (t=+43.541753ms)
tlogger.go:116: INFO clientconn.go:563 [core] [Channel #493]Channel Connectivity change to SHUTDOWN (t=+44.558199ms)
tlogger.go:116: INFO resolver_wrapper.go:111 [core] [Channel #493]Closing the name resolver (t=+44.969867ms)
tlogger.go:116: INFO balancer_wrapper.go:160 [core] [Channel #493]ccBalancerWrapper: closing (t=+45.316493ms)
tlogger.go:116: INFO clientconn.go:1233 [core] [Channel #493 SubChannel #494]Subchannel Connectivity change to SHUTDOWN (t=+45.828197ms)
tlogger.go:116: INFO clientconn.go:1560 [core] [Channel #493 SubChannel #494]Subchannel deleted (t=+46.104343ms)
tlogger.go:116: INFO clientconn.go:333 [core] [Channel #493]Channel deleted (t=+46.320756ms)
tlogger.go:116: INFO channel.go:142 [xds] [xds-client 0x40004e4000] [xds-channel 0x4000626d20] Shutdown (t=+46.597[262](https://github.com/grpc/grpc-go/actions/runs/15213212977/job/42792266891?pr=8329#step:8:263)ms)
tlogger.go:116: INFO xdsclient.go:207 [xds] [xds-client 0x40004e4000] Shutdown (t=+46.854682ms)
tlogger.go:116: INFO server.go:822 [core] [Server #491 ListenSocket #492]ListenSocket deleted (t=+47.211177ms)
https://github.com/grpc/grpc-go/actions/runs/15213212977/job/42792266891?pr=8329