[1.17] flakey certification tests - state.cassandra #4179
Description
https://github.com/dapr/components-contrib/actions/runs/21047913930/job/60526999164#step:19:538
708939Z" level=info msg="Internal gRPC server is running on :43355" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:08:48.276774652Z" level=info msg="actors: state store is not configured - this is okay for clients but services with hosted actors will fail to initialize!" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:08:48.276798076Z" level=info msg="dapr initialized. Status: Running. Init Elapsed 329ms" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
flow.go:228: Completed step: cassandra-sidecar-dockerDefault
flow.go:220: Running step: wait
flow.go:228: Completed step: wait
flow.go:220: Running step: Run TTL related test
dapr client initializing for: 127.0.0.1:37369
time="2026-01-15T22:09:19.114081222Z" level=info msg="gRPC API Called" code=13 duration=163 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:09:19.286480221Z" level=info msg="gRPC API Called" code=0 duration=171 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:09:19.451007522Z" level=info msg="gRPC API Called" code=0 duration=163 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:09:19.625898617Z" level=info msg="gRPC API Called" code=0 duration=173 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:09:24.792985362Z" level=info msg="gRPC API Called" code=0 duration=166 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
flow.go:228: Completed step: Run TTL related test
flow.go:220: Running step: interrupt network
sudo tc qdisc show | grep "netem"
sudo tc qdisc add dev eth0 handle 10: root htb
sudo tc class add dev eth0 parent 10: classid 10:1 htb rate 1000000kbit
sudo tc class add dev eth0 parent 10:1 classid 10:10 htb rate 1000000kbit
sudo tc qdisc add dev eth0 parent 10:10 handle 100: netem loss 100.00%
Packet rules setup...
Run `sudo tc -s qdisc` to double check
Run `/tmp/go-build2668364953/b002/cassandra.test --stop` to reset
sudo tc qdisc show | grep "netem"
sudo tc qdisc del dev eth0 handle 10: root
Packet rules stopped...
Run `sudo tc -s qdisc` to double check
Run `/tmp/go-build2668364953/b002/cassandra.test` to start
flow.go:228: Completed step: interrupt network
flow.go:220: Running step: wait
flow.go:228: Completed step: wait
flow.go:220: Running step: Run basic test again to verify reconnection occurred
dapr client initializing for: 127.0.0.1:37369
time="2026-01-15T22:10:05.346153817Z" level=info msg="gRPC API Called" code=0 duration=164 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:10:05.517703895Z" level=info msg="gRPC API Called" code=0 duration=170 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:10:05.682273308Z" level=info msg="gRPC API Called" code=0 duration=162 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:10:05.848746089Z" level=info msg="gRPC API Called" code=0 duration=165 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:10:05.854446639Z" level=info msg="gRPC API Called" code=0 duration=4 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/DeleteState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
flow.go:228: Completed step: Run basic test again to verify reconnection occurred
flow.go:220: Running step: stop cassandra server
2026/01/15 22:10:15 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54098->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:15 gocql: control unable to register events: read tcp 127.0.0.1:54098->127.0.0.1:9044: read: connection reset by peer
dockercompose.go:113: time="2026-01-15T22:10:05Z" level=warning msg="/home/runner/work/components-contrib/components-contrib/tests/certification/state/cassandra/docker-compose-single.yml: the attribute `version` is obsolete, it will be ignored, please remove it to avoid potential confusion"
Container cassandra-cassandra-1 Stopping
Container cassandra-cassandra-1 Stopped
flow.go:228: Completed step: stop cassandra server
flow.go:220: Running step: start cassandra server
dockercompose.go:94: time="2026-01-15T22:10:16Z" level=warning msg="/home/runner/work/components-contrib/components-contrib/tests/certification/state/cassandra/docker-compose-single.yml: the attribute `version` is obsolete, it will be ignored, please remove it to avoid potential confusion"
Container cassandra-cassandra-1 Starting
Container cassandra-cassandra-1 Started
flow.go:228: Completed step: start cassandra server
flow.go:220: Running step: wait
2026/01/15 22:10:19 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54120->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:19 gocql: control unable to register events: read tcp 127.0.0.1:54120->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:20 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54134->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:20 gocql: control unable to register events: read tcp 127.0.0.1:54134->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:21 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54148->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:21 gocql: control unable to register events: read tcp 127.0.0.1:54148->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:22 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54156->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:22 gocql: control unable to register events: read tcp 127.0.0.1:54156->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:23 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54164->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:23 gocql: control unable to register events: read tcp 127.0.0.1:54164->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:24 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54166->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:24 gocql: control unable to register events: read tcp 127.0.0.1:54166->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:25 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:54172->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:25 gocql: control unable to register events: read tcp 127.0.0.1:54172->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:26 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:40778->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:26 gocql: control unable to register events: read tcp 127.0.0.1:40778->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:27 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:40782->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:27 gocql: control unable to register events: read tcp 127.0.0.1:40782->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:28 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:40796->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:10:28 gocql: control unable to register events: read tcp 127.0.0.1:40796->127.0.0.1:9044: read: connection reset by peer
flow.go:228: Completed step: wait
flow.go:220: Running step: Get Values Saved Earlier And Not Expired, after Cassandra restart
dapr client initializing for: 127.0.0.1:37369
time="2026-01-15T22:11:16.512601015Z" level=info msg="gRPC API Called" code=0 duration=173 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
flow.go:228: Completed step: Get Values Saved Earlier And Not Expired, after Cassandra restart
flow.go:220: Running step: Run basic test
dapr client initializing for: 127.0.0.1:37369
time="2026-01-15T22:11:16.69164949Z" level=info msg="gRPC API Called" code=0 duration=177 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:11:16.858384441Z" level=info msg="gRPC API Called" code=0 duration=166 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:11:17.024666339Z" level=info msg="gRPC API Called" code=0 duration=165 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/SaveState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:11:17.1886254Z" level=info msg="gRPC API Called" code=0 duration=163 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/GetState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
time="2026-01-15T22:11:17.19166155Z" level=info msg="gRPC API Called" code=0 duration=2 instance=runnervmvatxw method=/dapr.proto.runtime.v1.Dapr/DeleteState scope=dapr.runtime.grpc.api-info type=log useragent="dapr-sdk-go/v1.10.0 grpc-go/1.73.0" ver=unknown
flow.go:228: Completed step: Run basic test
flow.go:220: Running step: cassandra-sidecar-dockerDefault2
time="2026-01-15T22:11:17.192427784Z" level=info msg="Enabled features: ServiceInvocationStreaming SchedulerReminders Resiliency" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.192465294Z" level=info msg="metric spec: {\"enabled\":true}" instance=runnervmvatxw scope=dapr.runtime.diagnostics type=log ver=unknown
time="2026-01-15T22:11:17.19249549Z" level=info msg="Using default latency distribution buckets: [1 2 3 4 5 6 8 10 13 16 20 25 30 40 50 65 80 100 130 160 200 250 300 400 500 650 800 1000 2000 5000 10000 20000 50000 100000]" instance=runnervmvatxw scope=dapr.runtime.diagnostics type=log ver=unknown
time="2026-01-15T22:11:17.192669415Z" level=warning msg="The default value for 'spec.metric.http.increasedCardinality' will change to 'false' in Dapr 1.15 or later" instance=runnervmvatxw scope=dapr.runtime.diagnostics type=log ver=unknown
time="2026-01-15T22:11:17.193058261Z" level=warning msg="Actor runtime disabled: api error: code = Unavailable desc = placement service is not configured. Actors and Workflow APIs will be unavailable" instance=runnervmvatxw scope=dapr.runtime.actor type=log ver=unknown
dapr client initializing for: 127.0.0.1:37371
time="2026-01-15T22:11:17.193205556Z" level=info msg="Actor runtime disabled: api error: code = Unavailable desc = placement service is not configured" instance=runnervmvatxw scope=dapr.runtime.actor type=log ver=unknown
time="2026-01-15T22:11:17.193230673Z" level=info msg="standalone mode configured" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.193238959Z" level=info msg="app id: cassandra-sidecar-dockerDefault2" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.193252429Z" level=warning msg="No scheduler host addresses provided. Scheduler disabled" instance=runnervmvatxw scope=dapr.runtime.scheduler.watchhosts type=log ver=unknown
time="2026-01-15T22:11:17.193307587Z" level=info msg="Dapr trace sampler initialized: ParentBased{root:TraceIDRatioBased{0.0001},remoteParentSampled:AlwaysOnSampler,remoteParentNotSampled:AlwaysOffSampler,localParentSampled:AlwaysOnSampler,localParentNotSampled:AlwaysOffSampler}" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.19347676Z" level=info msg="metrics server started on :0/" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.193770423Z" level=info msg="local service entry announced: cassandra-sidecar-dockerDefault2 -> 10.1.0.139:45391" component="nr (mdns/v1)" instance=runnervmvatxw scope=dapr.contrib type=log ver=unknown
time="2026-01-15T22:11:17.19379003Z" level=info msg="Initialized name resolution to mdns" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.193854711Z" level=info msg="Loading components…" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.194229931Z" level=info msg="Waiting for all outstanding components to be processed…" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697089863Z" level=info msg="Component loaded: statestorefactorfail (state.cassandra/v1)" instance=runnervmvatxw scope=dapr.runtime.processor type=log ver=unknown
time="2026-01-15T22:11:17.697127132Z" level=info msg="All outstanding components processed" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697139375Z" level=info msg="Loading endpoints…" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697438794Z" level=info msg="Waiting for all outstanding http endpoints to be processed…" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697462539Z" level=info msg="All outstanding http endpoints processed" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697472127Z" level=info msg="Loading Declarative Subscriptions…" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.697792395Z" level=warning msg="App channel is not initialized. Did you configure an app-port?" instance=runnervmvatxw scope=dapr.runtime.channels type=log ver=unknown
time="2026-01-15T22:11:17.697899655Z" level=error msg="Failed to listen for gRPC server on TCP address 127.0.0.1:37371 with error: listen tcp 127.0.0.1:37371: bind: address already in use" instance=runnervmvatxw scope=dapr.runtime.grpc.api type=log ver=unknown
time="2026-01-15T22:11:17.698077497Z" level=info msg="stopping mDNS server for app id: cassandra-sidecar-dockerDefault2" component="nr (mdns/v1)" instance=runnervmvatxw scope=dapr.contrib type=log ver=unknown
time="2026-01-15T22:11:17.698074406Z" level=info msg="Dapr is shutting down" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.698396743Z" level=info msg="Shutting down component statestorefactorfail (state.cassandra/v1)" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:17.698511397Z" level=info msg="Dapr runtime stopped" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
flow.go:228: Completed step: cassandra-sidecar-dockerDefault2
flow.go:230: Fatal error in step cassandra-sidecar-dockerDefault2: sidecar is not ready
time="2026-01-15T22:11:37.257133612Z" level=error msg="error on shutdown: failed to start API gRPC server: could not listen on any endpoint" instance=runnervmvatxw scope=dapr.contrib type=log ver=unknown
time="2026-01-15T22:11:37.257643675Z" level=info msg="Dapr is shutting down" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:37.257659164Z" level=info msg="Closing HTTP server …" instance=runnervmvatxw scope=dapr.runtime.http type=log ver=unknown
time="2026-01-15T22:11:37.257681085Z" level=info msg="Shutting down component statestore (state.cassandra/v1)" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:37.257648656Z" level=info msg="stopping mDNS server for app id: cassandra-sidecar-dockerDefault" component="nr (mdns/v1)" instance=runnervmvatxw scope=dapr.contrib type=log ver=unknown
time="2026-01-15T22:11:37.257707915Z" level=info msg="Dapr runtime stopped" instance=runnervmvatxw scope=dapr.runtime type=log ver=unknown
time="2026-01-15T22:11:37.25767196Z" level=info msg="Closing HTTP server 127.0.0.1:37371…" instance=runnervmvatxw scope=dapr.runtime.http type=log ver=unknown
2026/01/15 22:11:37 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:44590->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:11:37 gocql: control unable to register events: read tcp 127.0.0.1:44590->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:11:40 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:44614->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:11:40 gocql: control unable to register events: read tcp 127.0.0.1:44614->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:11:41 gocql: unable to dial control conn 127.0.0.1:9044: read tcp 127.0.0.1:44628->127.0.0.1:9044: read: connection reset by peer
2026/01/15 22:11:41 gocql: control unable to register events: read tcp 127.0.0.1:44628->127.0.0.1:9044: read: connection reset by peer
dockercompose.go:75: time="2026-01-15T22:11:37Z" level=warning msg="/home/runner/work/components-contrib/components-contrib/tests/certification/state/cassandra/docker-compose-single.yml: the attribute `version` is obsolete, it will be ignored, please remove it to avoid potential confusion"
Container cassandra-cassandra-1 Stopping
Container cassandra-cassandra-1 Stopped
Container cassandra-cassandra-1 Removing
Container cassandra-cassandra-1 Removed
Volume cassandra_cassandra_data Removing
Network cassandra_default Removing
Volume cassandra_cassandra_data Removed
Network cassandra_default Removed
=== FAIL: state/cassandra TestCassandra (267.36s)
RELEASE NOTE: FIX: Bug in state.cassandra certification tests