grpc / grpc-go

The Go language implementation of gRPC. HTTP/2 based RPC
https://grpc.io
Apache License 2.0
21.13k stars 4.4k forks source link

Flaky test: 2/10k GlobalBinaryLoggingOptions #5815

Closed easwars closed 1 year ago

easwars commented 2 years ago
--- FAIL: Test (166.58s)
    --- FAIL: Test/GlobalBinaryLoggingOptions (0.07s)
        tlogger.go:116: INFO server.go:631 [core] [Server #992] Server created  (t=+502.496µs)
        tlogger.go:116: INFO clientconn.go:105 [core] [Channel #993] Channel created  (t=+809.394µs)
        tlogger.go:116: INFO clientconn.go:1547 [core] [Channel #993] original dial target is: "whatever:///127.0.0.1:46143"  (t=+934.093µs)
        tlogger.go:116: INFO server.go:819 [core] [Server #992 ListenSocket #994] ListenSocket created  (t=+1.155992ms)
        tlogger.go:116: INFO clientconn.go:1554 [core] [Channel #993] parsed dial target is: {Scheme:whatever Authority: Endpoint:127.0.0.1:46143 URL:{Scheme:whatever Opaque: User: Host: Path:/127.0.0.1:46143 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}  (t=+2.353[183](https://github.com/grpc/grpc-go/actions/runs/3503743424/jobs/5868990699#step:8:184)ms)
        tlogger.go:116: INFO clientconn.go:263 [core] [Channel #993] Channel authority set to "127.0.0.1:46143"  (t=+2.550882ms)
        tlogger.go:116: INFO resolver_conn_wrapper.go:175 [core] [Channel #993] Resolver state updated: {
              "Addresses": [
                {
                  "Addr": "127.0.0.1:46143",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": null,
                  "Type": 0,
                  "Metadata": null
                }
              ],
              "ServiceConfig": null,
              "Attributes": null
            } (resolver returned new addresses)  (t=+2.877579ms)
        tlogger.go:116: INFO balancer_conn_wrappers.go:274 [core] [Channel #993] Channel switches to new LB policy "pick_first"  (t=+3.134477ms)
        tlogger.go:116: INFO clientconn.go:725 [core] [Channel #993 SubChannel #995] Subchannel created  (t=+3.400075ms)
        tlogger.go:116: INFO clientconn.go:1100 [core] [Channel #993 SubChannel #995] Subchannel Connectivity change to CONNECTING  (t=+3.676273ms)
        tlogger.go:116: INFO clientconn.go:1211 [core] [Channel #993 SubChannel #995] Subchannel picks a new address "127.0.0.1:46143" to connect  (t=+3.872572ms)
        tlogger.go:116: INFO clientconn.go:418 [core] [Channel #993] Channel Connectivity change to CONNECTING  (t=+4.415168ms)
        tlogger.go:116: INFO clientconn.go:1100 [core] [Channel #993 SubChannel #995] Subchannel Connectivity change to READY  (t=+5.389861ms)
        tlogger.go:116: INFO clientconn.go:418 [core] [Channel #993] Channel Connectivity change to READY  (t=+5.661659ms)
        end2end_test.go:8266: want 8 server side binary logging events, got 7
        tlogger.go:116: INFO clientconn.go:418 [core] [Channel #993] Channel Connectivity change to SHUTDOWN  (t=+11.934114ms)
        tlogger.go:116: INFO clientconn.go:1100 [core] [Channel #993 SubChannel #995] Subchannel Connectivity change to SHUTDOWN  (t=+12.38491ms)
        tlogger.go:116: INFO clientconn.go:1425 [core] [Channel #993 SubChannel #995] Subchannel deleted  (t=+12.580909ms)
        tlogger.go:116: INFO clientconn.go:1055 [core] [Channel #993] Channel deleted  (t=+12.72[210](https://github.com/grpc/grpc-go/actions/runs/3503743424/jobs/5868990699#step:8:211)8ms)
        tlogger.go:116: INFO server.go:770 [core] [Server #992 ListenSocket #994] ListenSocket deleted  (t=+13.179005ms)
        tlogger.go:116: INFO types.go:68 [channelz] attempt to delete child with id 995 from a parent (id=993) that doesn't currently exist  (t=+14.737493ms)
        tlogger.go:116: INFO types.go:68 [channelz] attempt to delete child with id 995 from a parent (id=993) that doesn't currently exist  (t=+15.17219ms)
FAIL
FAIL    google.golang.org/grpc/test 397.167s
easwars commented 2 years ago

https://github.com/grpc/grpc-go/actions/runs/3503743424/jobs/5868990699

zasweq commented 1 year ago

2/10k runs on google3: http://sponge2/7cd2eb65-f0e1-4655-8dce-c9e97ac8756b.

easwars commented 1 year ago

https://github.com/grpc/grpc-go/actions/runs/3653052107/jobs/6172087903

Also complains of a data race.

easwars commented 1 year ago

Another data race: https://github.com/grpc/grpc-go/actions/runs/4009066075/jobs/6883989735

zasweq commented 1 year ago

https://github.com/grpc/grpc-go/actions/runs/4309542021/jobs/7517050414

easwars commented 1 year ago

https://github.com/grpc/grpc-go/actions/runs/4309542021/jobs/7517050414