Sometimes Panic happens during tests for TestRealtimeChannel_RTL6c2_PublishEnqueue

[Rosalita]

The test TestRealtimeChannel_RTL6c2_PublishEnqueue contains a number of sub-tests which test for different connection and channel states. Sometimes this test fails with the message panic: Ack called but queue is empty. however the failure does not always occur for the same sub-test.

For example in this run the panic happened while the 9th sub-test was running for integration-test (1.17, json) https://github.com/ably/ably-go/runs/6514937687?check_suite_focus=true

ci log

=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_INITIALIZED,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_CONNECTING,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_CONNECTING,_channel_is_ATTACHING
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_ATTACHING
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_ATTACHED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_DETACHING
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_DETACHED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_CONNECTING,_channel_is_ATTACHED
panic: Ack called but queue is empty.

goroutine 2516 [running]:
github.com/ably/ably-go/ably.(*pendingEmitter).Ack(0xc00019a598, 0xc00020ad20, 0x0)
	/home/runner/work/ably-go/ably-go/ably/state.go:154 +0x7d9
github.com/ably/ably-go/ably.(*Connection).eventloop(0xc00019a500)
	/home/runner/work/ably-go/ably-go/ably/realtime_conn.go:724 +0x928
created by github.com/ably/ably-go/ably.(*Connection).connectWith

Link to test observability server for this run:
https://test-observability.herokuapp.com/repos/ably/ably-go/uploads/8edbf9c8-93f6-4610-9bb4-fea75d5c484e

On another occasion, the panic happened while the 7th sub-test was running. This was the test run for integration-test (1.18, msgpack https://github.com/ably/ably-go/runs/6692532981?check_suite_focus=true

ci log

=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_INITIALIZED,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_CONNECTING,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_CONNECTING,_channel_is_ATTACHING
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_INITIALIZED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_ATTACHING
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_ATTACHED
=== RUN   TestRealtimeChannel_RTL6c2_PublishEnqueue/when_connection_is_DISCONNECTED,_channel_is_DETACHING
panic: Ack called but queue is empty.

goroutine 2384 [running]:
github.com/ably/ably-go/ably.(*pendingEmitter).Ack(0xc00084ee58, 0xc00021f260, 0x0)
	/home/runner/work/ably-go/ably-go/ably/state.go:154 +0x811
github.com/ably/ably-go/ably.(*Connection).eventloop(0xc00084edc0)
	/home/runner/work/ably-go/ably-go/ably/realtime_conn.go:724 +0x916
created by github.com/ably/ably-go/ably.(*Connection).connectWith
	/home/runner/work/ably-go/ably-go/ably/realtime_conn.go:384 +0x61a

This issue has been seen for both Go version 1.17 and 1.18 and both json and msgpack protocols. It has also been seen on a CI run for a branch which only contained a whitespace change.

Investigation is needed to get to the bottom of this panic.

┆Issue is synchronized with this Jira Task by Unito