sarama icon indicating copy to clipboard operation
sarama copied to clipboard

TestReadOnlyAndAllCommittedMessages sometimes fails on main (6d970c751edfe80a21c91376ce749070541e4352)

Open k-wall opened this issue 3 years ago • 2 comments

Versions

main today (6d970c751edfe80a21c91376ce749070541e4352)

Configuration
go version go1.17.6 darwin/amd64
podman version
Client:
Version:      3.4.4
API Version:  3.4.4
Go Version:   go1.17.3
Built:        Wed Dec  8 18:41:11 2021
OS/Arch:      darwin/amd64

Server:
Version:      3.4.4
API Version:  3.4.4
Go Version:   go1.16.8
Built:        Wed Dec  8 21:45:07 2021
OS/Arch:      linux/amd64

podman machine list
NAME                     VM TYPE     CREATED       LAST UP            CPUS        MEMORY      DISK SIZE
podman-machine-default*  qemu        21 hours ago  Currently running  2           4.295GB     10.74GB
Problem Description

Running :

GOFLAGS="-tags=functional" go test -p 1  -run TestReadOnlyAndAllCommittedMessages -count 1 

I sometimes (~1 time in 6) see the following failure.

--- FAIL: TestReadOnlyAndAllCommittedMessages (3.39s)
    functional_consumer_test.go:234: uncommitted message 1 to uncommitted-topic-test-4-0 at offset 0
    functional_consumer_test.go:235: uncommitted message 2 to uncommitted-topic-test-4-0 at offset 1
    functional_consumer_test.go:253: Committed 1 to uncommitted-topic-test-4-0 at offset 2
    functional_consumer_test.go:253: Committed 2 to uncommitted-topic-test-4-0 at offset 3
    functional_consumer_test.go:253: Committed 3 to uncommitted-topic-test-4-0 at offset 4
    functional_consumer_test.go:253: Committed 4 to uncommitted-topic-test-4-0 at offset 5
    functional_consumer_test.go:253: Committed 5 to uncommitted-topic-test-4-0 at offset 6
    functional_consumer_test.go:253: Committed 6 to uncommitted-topic-test-4-0 at offset 7
    functional_consumer_test.go:278: Received uncommitted message 1 from uncommitted-topic-test-4-0 at offset 0
    functional_consumer_test.go:279:
        	Error Trace:	functional_consumer_test.go:279
        	Error:      	Not equal:
        	            	expected: "Committed 1"
        	            	actual  : "uncommitted message 1"

        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1 +1 @@
        	            	-Committed 1
        	            	+uncommitted message 1
        	Test:       	TestReadOnlyAndAllCommittedMessages
FAIL

Anyone know anything about this failure?

k-wall avatar Feb 19 '22 13:02 k-wall

Yes, so I recently ported TestReadOnlyAndAllCommittedMessages to use a sarama implementation for both producer and consumer — previously it was using a custom .jar to provide the commit+rollback of transactional operations

However, I haven't yet determined why this failure periodically happens — the consumer subscribes with config.Consumer.IsolationLevel = ReadCommitted so it shouldn't ever pass the uncommitted messages to the Messages channel

dnwe avatar Feb 19 '22 17:02 dnwe

Thanks. I spent a bit of time trying to work out where the bug lies, without success, largely out of curiosity. I agree the test sends "uncommitted" messages are sent within a transaction, which is then aborted and the sarama.FetchRequest is sent with ReadCommitted so shouldn't be able to read those. All looks sound.

I did happen to notice that the consumer's sarama.OffsetRequest is sent with IsolationLevel 0 (false) regardless of config.Consumer.IsolationLevel setting which seems to differ org.apache.kafka.clients.consumer.internals.Fetcher#sendListOffsetRequest which appears to honour isolation.level. This doesn't seem to be material to this test failure however.

k-wall avatar Feb 21 '22 10:02 k-wall

Thank you for taking the time to raise this issue. However, it has not had any activity on it in the past 90 days and will be closed in 30 days if no updates occur. Please check if the main branch has already resolved the issue since it was raised. If you believe the issue is still valid and you would like input from the maintainers then please comment to ask for it to be reviewed.

github-actions[bot] avatar Aug 18 '23 10:08 github-actions[bot]

We haven't seen this fail for a while now, so closing as resolved

dnwe avatar Aug 18 '23 20:08 dnwe