Flaky test: ConnectedMetric_Reconnection
P1
Logs:
<Details>
```
--- FAIL: Test (30.43s)
--- FAIL: Test/ConnectedMetric_Reconnection (20.03s)
metrics_test.go:653: Created new snapshot cache...
tlogger.go:133: INFO server.go:732 [core] [Server #124] Server created (t=+295.665µs)
metrics_test.go:653: Registered Aggregated Discovery Service (ADS)...
metrics_test.go:653: xDS management server serving at: 127.0.0.1:34223...
tlogger.go:133: INFO restartable_listener.go:84 [testutils] Stopping restartable listener "127.0.0.1:34223" (t=+357.619µs)
tlogger.go:133: INFO server.go:928 [core] [Server #124 ListenSocket #125] ListenSocket created (t=+426.032µs)
server.go:230: Created new resource snapshot...
logging.go:30: setting snapshot for node d3d23b34-2b48-4e1a-a7c8-6dab7558adba
server.go:236: Updated snapshot cache with resource snapshot...
tlogger.go:133: INFO clientconn.go:1837 [core] original dial target is: "127.0.0.1:34223" (t=+549.177µs)
tlogger.go:133: INFO clientconn.go:516 [core] [Channel #126] Channel created for target "127.0.0.1:34223" (t=+569.007µs)
tlogger.go:133: INFO clientconn.go:247 [core] [Channel #126] parsed dial target is: resolver.Target{URL:url.URL{Scheme:"dns", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/127.0.0.1:34223", Fragment:"", RawQuery:"", RawPath:"", RawFragment:"", ForceQuery:false, OmitHost:false}} (t=+590.078µs)
tlogger.go:133: INFO clientconn.go:248 [core] [Channel #126] Channel authority set to "127.0.0.1:34223" (t=+603.879µs)
tlogger.go:133: INFO restartable_listener.go:97 [testutils] Restarting listener "127.0.0.1:34223" (t=+708.877µs)
tlogger.go:133: INFO clientconn.go:620 [core] [Channel #126] Channel Connectivity change to CONNECTING (t=+786.905µs)
tlogger.go:133: INFO resolver_wrapper.go:211 [core] [Channel #126] Resolver state updated: {
"Addresses": [
{
"Addr": "127.0.0.1:34223",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Endpoints": [
{
"Addresses": [
{
"Addr": "127.0.0.1:34223",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Attributes": null
}
],
"ServiceConfig": null,
"Attributes": null
} (resolver returned new addresses) (t=+858.032µs)
tlogger.go:133: INFO balancer_wrapper.go:121 [core] [Channel #126] Channel switches to new LB policy "pick_first" (t=+894.417µs)
tlogger.go:133: INFO clientconn.go:923 [core] [Channel #126 SubChannel #127] Subchannel created (t=+946.956µs)
tlogger.go:133: INFO clientconn.go:421 [core] [Channel #126] Channel exiting idle mode (t=+974.417µs)
tlogger.go:133: INFO clientconn.go:1303 [core] [Channel #126 SubChannel #127] Subchannel Connectivity change to CONNECTING (t=+1.010121ms)
tlogger.go:133: INFO clientconn.go:1471 [core] [Channel #126 SubChannel #127] Subchannel picks a new address "127.0.0.1:34223" to connect (t=+1.03638ms)
tlogger.go:133: INFO clientconn.go:1303 [core] [Channel #126 SubChannel #127] Subchannel Connectivity change to READY (t=+1.486638ms)
tlogger.go:133: INFO clientconn.go:620 [core] [Channel #126] Channel Connectivity change to READY (t=+1.582723ms)
logging.go:30: respond type.googleapis.com/envoy.config.listener.v3.Listener (requested [test-listener-resource]) version "" with version "1" and resources [test-listener-resource]
metrics_test.go:774: XDSClientConnected check failed after 1st NewStream - got: timeout waiting for specific metric: context deadline exceeded, want 1
tlogger.go:129: WARNING ads_stream.go:452 [xds] [xds-client 0x11407e244be0] [xds-channel 0x11407ebe1900] [ads-stream 0x11407e244d20] ADS stream closed: rpc error: code = Canceled desc = context canceled (t=+10.009395397s)
tlogger.go:133: INFO ads_stream.go:165 [xds] [xds-client 0x11407e244be0] [xds-channel 0x11407ebe1900] [ads-stream 0x11407e244d20] Shutdown ADS stream (t=+10.009448887s)
tlogger.go:133: INFO clientconn.go:620 [core] [Channel #126] Channel Connectivity change to SHUTDOWN (t=+10.009480805s)
tlogger.go:133: INFO resolver_wrapper.go:112 [core] [Channel #126] Closing the name resolver (t=+10.009495558s)
tlogger.go:133: INFO balancer_wrapper.go:159 [core] [Channel #126] ccBalancerWrapper: closing (t=+10.009509629s)
tlogger.go:133: INFO clientconn.go:1303 [core] [Channel #126 SubChannel #127] Subchannel Connectivity change to SHUTDOWN (t=+10.009564421s)
tlogger.go:133: INFO clientconn.go:1710 [core] [Channel #126 SubChannel #127] Subchannel deleted (t=+10.009575247s)
tlogger.go:133: INFO clientconn.go:1232 [core] [Channel #126] Channel deleted (t=+10.009743921s)
tlogger.go:133: INFO channel.go:143 [xds] [xds-client 0x11407e244be0] [xds-channel 0x11407ebe1900] Shutdown (t=+10.009783992s)
tlogger.go:133: INFO xdsclient.go:210 [xds] [xds-client 0x11407e244be0] Shutdown (t=+10.009800577s)
tlogger.go:133: INFO server.go:864 [core] [Server #124 ListenSocket #125] ListenSocket deleted (t=+10.009852114s)
grpctest.go:45: Leaked goroutine: goroutine 635 [select]:
google.golang.org/grpc/internal/xds/clients/xdsclient/test_test.s.TestConnectedMetric_Reconnection.func2({0x12cd110?, 0x1ddafe0?}, 0x0?, 0x1?, 0x1a?)
/home/runner/work/grpc-go/grpc-go/internal/xds/clients/xdsclient/test/metrics_test.go:663 +0x68
github.com/envoyproxy/go-control-plane/pkg/server/v3.CallbackFuncs.OnStreamResponse(...)
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/v3/server.go:131
github.com/envoyproxy/go-control-plane/pkg/server/sotw/v3.(*streamWrapper).send(0x11407e0bf890, {0x12d9938, 0x11407e41a1e0})
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/sotw/v3/server.go:147 +0x1dd
github.com/envoyproxy/go-control-plane/pkg/server/sotw/v3.(*server).process(0x11407e4e3560, {0x7fe9808a3388, 0x11407ec981d0}, 0x11407e112850, {0x0, 0x0})
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/sotw/v3/xds.go:158 +0x9b6
github.com/envoyproxy/go-control-plane/pkg/server/sotw/v3.(*server).StreamHandler(0x11407e4e3560, {0x7fe9808a3388, 0x11407ec981d0}, {0x0, 0x0})
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/sotw/v3/server.go:182 +0xca
github.com/envoyproxy/go-control-plane/pkg/server/v3.(*server).StreamHandler(...)
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/v3/server.go:186
github.com/envoyproxy/go-control-plane/pkg/server/v3.(*server).StreamAggregatedResources(0x11407e246990?, {0x12dbf00?, 0x11407ec981d0?})
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane@v0.14.0/pkg/server/v3/server.go:190 +0x4b
github.com/envoyproxy/go-control-plane/envoy/service/discovery/v3._AggregatedDiscoveryService_StreamAggregatedResources_Handler({0x11ef620?, 0x11407e246990}, {0x12d97d0, 0x11407e632000})
/home/runner/go/pkg/mod/github.com/envoyproxy/go-control-plane/envoy@v1.37.0/service/discovery/v3/ads_grpc.pb.go:137 +0xd8
google.golang.org/grpc.(*Server).processStreamingRPC(0x11407e4e8b48, {0x12cd1f0, 0x11407e584a80}, 0x11407e45c000, 0x11407e246b10, 0x1d9e9c0, 0x0)
/home/runner/work/grpc-go/grpc-go/server.go:1727 +0x1774
google.golang.org/grpc.(*Server).handleStream(0x11407e4e8b48, {0x12d2298, 0x11407e4a4000}, 0x11407e45c000)
/home/runner/work/grpc-go/grpc-go/server.go:1854 +0xd30
google.golang.org/grpc.(*Server).serveStreams.func2.1()
/home/runner/work/grpc-go/grpc-go/server.go:1076 +0x89
created by google.golang.org/grpc.(*Server).serveStreams.func2 in goroutine 770
/home/runner/work/grpc-go/grpc-go/server.go:1087 +0x185
grpctest.go:77: Goroutine leak check disabled for future tests
FAIL
```
</Details>
Failing run: https://github.com/grpc/grpc-go/actions/runs/26292349579/job/77395648987?pr=9125
This test was introduced recently in https://github.com/grpc/grpc-go/pull/8807
0 条评论