Flaky test: Test/PickFirstMetrics

[arjan-bal]

Sample Run: https://github.com/grpc/grpc-go/actions/runs/23181181226/job/67354270340?pr=8977

Logs

--- FAIL: Test (9.18s)
    --- FAIL: Test/PickFirstMetrics (0.01s)
        tlogger.go:133: INFO server.go:718 [core] [Server #209] Server created  (t=+1.4851ms)
        tlogger.go:133: INFO clientconn.go:1799 [core] original dial target is: "whatever:///"  (t=+1.590506ms)
        tlogger.go:133: INFO clientconn.go:514 [core] [Channel #210] Channel created for target "whatever:///"  (t=+1.625904ms)
        tlogger.go:133: INFO server.go:914 [core] [Server #209 ListenSocket #211] ListenSocket created  (t=+1.710904ms)
        tlogger.go:133: INFO clientconn.go:245 [core] [Channel #210] parsed dial target is: resolver.Target{URL:url.URL{Scheme:"whatever", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/", Fragment:"", RawQuery:"", RawPath:"", RawFragment:"", ForceQuery:false, OmitHost:false}}  (t=+1.762374ms)
        tlogger.go:133: INFO clientconn.go:246 [core] [Channel #210] Channel authority set to ""  (t=+1.801686ms)
        tlogger.go:133: INFO clientconn.go:618 [core] [Channel #210] Channel Connectivity change to CONNECTING  (t=+1.840167ms)
        tlogger.go:133: INFO resolver_wrapper.go:211 [core] [Channel #210] Resolver state updated: {
              "Addresses": [
                {
                  "Addr": "127.0.0.1:39567",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": null,
                  "Metadata": null
                }
              ],
              "Endpoints": [
                {
                  "Addresses": [
                    {
                      "Addr": "127.0.0.1:39567",
                      "ServerName": "",
                      "Attributes": null,
                      "BalancerAttributes": null,
                      "Metadata": null
                    }
                  ],
                  "Attributes": null
                }
              ],
              "ServiceConfig": {
                "Config": {
                  "Config": null,
                  "Methods": {}
                },
                "Err": null
              },
              "Attributes": null
            } (service config updated; resolver returned new addresses)  (t=+2.298316ms)
        tlogger.go:133: INFO balancer_wrapper.go:121 [core] [Channel #210] Channel switches to new LB policy "pick_first"  (t=+2.34143ms)
        tlogger.go:133: INFO clientconn.go:921 [core] [Channel #210 SubChannel #212] Subchannel created  (t=+3.00827ms)
        tlogger.go:133: INFO clientconn.go:1295 [core] [Channel #210 SubChannel #212] Subchannel Connectivity change to CONNECTING  (t=+3.148021ms)
        tlogger.go:133: INFO clientconn.go:1463 [core] [Channel #210 SubChannel #212] Subchannel picks a new address "127.0.0.1:39567" to connect  (t=+3.174206ms)
        tlogger.go:133: INFO clientconn.go:419 [core] [Channel #210] Channel exiting idle mode  (t=+3.48693ms)
        tlogger.go:133: INFO clientconn.go:1295 [core] [Channel #210 SubChannel #212] Subchannel Connectivity change to READY  (t=+5.754811ms)
        tlogger.go:133: INFO clientconn.go:618 [core] [Channel #210] Channel Connectivity change to READY  (t=+6.000713ms)
        metrics_test.go:107: Unexpected data for metric grpc.subchannel.connection_attempts_succeeded, got: 0, want: 1
        metrics_test.go:116: Unexpected data for metric grpc.subchannel.open_connections, got: 0, want: 1
        tlogger.go:133: INFO server.go:850 [core] [Server #209 ListenSocket #211] ListenSocket deleted  (t=+6.288479ms)
        tlogger.go:133: INFO clientconn.go:1295 [core] [Channel #210 SubChannel #212] Subchannel Connectivity change to IDLE  (t=+6.416597ms)
        tlogger.go:133: INFO clientconn.go:618 [core] [Channel #210] Channel Connectivity change to IDLE  (t=+6.473996ms)
        tlogger.go:133: INFO clientconn.go:618 [core] [Channel #210] Channel Connectivity change to SHUTDOWN  (t=+6.495873ms)
        tlogger.go:133: INFO resolver_wrapper.go:112 [core] [Channel #210] Closing the name resolver  (t=+6.51261ms)
        tlogger.go:133: INFO balancer_wrapper.go:159 [core] [Channel #210] ccBalancerWrapper: closing  (t=+6.530914ms)
        tlogger.go:133: INFO clientconn.go:1295 [core] [Channel #210 SubChannel #212] Subchannel Connectivity change to SHUTDOWN  (t=+6.571557ms)
        tlogger.go:133: INFO clientconn.go:1672 [core] [Channel #210 SubChannel #212] Subchannel deleted  (t=+6.60147ms)
        tlogger.go:133: INFO clientconn.go:1230 [core] [Channel #210] Channel deleted  (t=+6.617687ms)

The test was updated in #8738