googleinterns/step224-2020

[Cloudprober] Investigate flaky tests

Opened this issue · 2 comments

There are some strange errors occurring infrequently when testing client gRPCs.

INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc000419470, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00027e380, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00027ea90, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{localhost:9314 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] blockingPicker: the picked transport is not ready, loop back to repick
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "localhost:9314" to connect
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015baa0, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to READY
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015baa0, {READY }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to READY
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015b670, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00061b5f0, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc000907470, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x11dfe83]

goroutine 81 [running]:
github.com/google/cloudprober/prober.(*Prober).RemoveProbe(0xc0006203f0, 0x177a240, 0xc000866f60, 0xc000866f90, 0x0, 0x0, 0x0)
/usr/local/google/home/espendlove/go/src/github.com/google/cloudprober/prober/serviceimpl.go:60 +0x143
github.com/google/cloudprober/prober/proto._Cloudprober_RemoveProbe_Handler(0x148aea0, 0xc0006203f0, 0x177a240, 0xc000866f60, 0xc0007641e0, 0x0, 0x177a240, 0xc000866f60, 0xc0001186a0, 0x10)
/usr/local/google/home/espendlove/go/src/github.com/google/cloudprober/prober/proto/service.pb.go:657 +0x214
google.golang.org/grpc.(*Server).processUnaryRPC(0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400, 0xc000276720, 0x1ecb6f8, 0x0, 0x0, 0x0)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:1193 +0x522
google.golang.org/grpc.(*Server).handleStream(0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400, 0x0)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:1516 +0xd05
google.golang.org/grpc.(*Server).serveStreams.func1.2(0xc00053c9f0, 0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:856 +0xa5
created by google.golang.org/grpc.(*Server).serveStreams.func1
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:854 +0x1fd
exit status 2
FAIL github.com/googleinterns/step224-2020/cmd 0.210s

INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc000419470, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00027e380, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00027ea90, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{localhost:9314 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] blockingPicker: the picked transport is not ready, loop back to repick
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "localhost:9314" to connect
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015baa0, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to READY
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015baa0, {READY }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to READY
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00015b670, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc00061b5f0, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
INFO: 2020/09/01 12:56:32 [core] parsed scheme: ""
INFO: 2020/09/01 12:56:32 [core] scheme "" not registered, fallback to default scheme
INFO: 2020/09/01 12:56:32 [core] ccResolverWrapper: sending update to cc: {[{logging.googleapis.com:443 0 }] }
INFO: 2020/09/01 12:56:32 [core] ClientConn switching balancer to "pick_first"
INFO: 2020/09/01 12:56:32 [core] Channel switches to new LB policy "pick_first"
INFO: 2020/09/01 12:56:32 [core] Subchannel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] pickfirstBalancer: UpdateSubConnState: 0xc000907470, {CONNECTING }
INFO: 2020/09/01 12:56:32 [core] Channel Connectivity change to CONNECTING
INFO: 2020/09/01 12:56:32 [core] Subchannel picks a new address "logging.googleapis.com:443" to connect
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x11dfe83]

goroutine 81 [running]:
github.com/google/cloudprober/prober.(*Prober).RemoveProbe(0xc0006203f0, 0x177a240, 0xc000866f60, 0xc000866f90, 0x0, 0x0, 0x0)
/usr/local/google/home/espendlove/go/src/github.com/google/cloudprober/prober/serviceimpl.go:60 +0x143
github.com/google/cloudprober/prober/proto._Cloudprober_RemoveProbe_Handler(0x148aea0, 0xc0006203f0, 0x177a240, 0xc000866f60, 0xc0007641e0, 0x0, 0x177a240, 0xc000866f60, 0xc0001186a0, 0x10)
/usr/local/google/home/espendlove/go/src/github.com/google/cloudprober/prober/proto/service.pb.go:657 +0x214
google.golang.org/grpc.(*Server).processUnaryRPC(0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400, 0xc000276720, 0x1ecb6f8, 0x0, 0x0, 0x0)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:1193 +0x522
google.golang.org/grpc.(*Server).handleStream(0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400, 0x0)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:1516 +0xd05
google.golang.org/grpc.(*Server).serveStreams.func1.2(0xc00053c9f0, 0xc0001b9500, 0x178e5a0, 0xc000793500, 0xc00061d400)
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:856 +0xa5
created by google.golang.org/grpc.(*Server).serveStreams.func1
/usr/local/google/home/espendlove/go/src/google.golang.org/grpc/server.go:854 +0x1fd
exit status 2
FAIL github.com/googleinterns/step224-2020/cmd 0.210s