devinbost commented on issue #6306: (Flaky-test) UnAcknowledgedMessagesTimeoutTest.testSharedSingleAckedPartitionedTopic - assertion failure URL: https://github.com/apache/pulsar/issues/6306#issuecomment-585519230 I found the problem. Some messages are being received more than once. ``` 00:54:01.166 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-0 -- msgId: 5:0:1 00:54:01.174 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-1 -- msgId: 4:0:2 00:54:01.176 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-2 -- msgId: 3:0:0 00:54:01.178 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-3 -- msgId: 5:1:1 00:54:01.180 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-4 -- msgId: 4:1:2 00:54:01.181 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-5 -- msgId: 3:1:0 00:54:01.183 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-6 -- msgId: 5:2:1 00:54:01.184 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-7 -- msgId: 4:2:2 00:54:01.186 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-8 -- msgId: 3:2:0 00:54:01.187 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-9 -- msgId: 5:3:1 00:54:01.189 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-10 -- msgId: 4:3:2 00:54:01.191 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-11 -- msgId: 3:3:0 00:54:01.192 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-12 -- msgId: 5:4:1 00:54:01.194 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-13 -- msgId: 4:4:2 00:54:01.195 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-14 -- msgId: 3:4:0 00:54:01.197 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-15 -- msgId: 5:5:1 00:54:01.199 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-16 -- msgId: 4:5:2 00:54:01.200 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-17 -- msgId: 3:5:0 00:54:01.203 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-18 -- msgId: 5:6:1 00:54:01.206 INFO Message produced: my-message-testSharedSingleAckedPartitionedTopic-19 -- msgId: 4:6:2 00:54:01.206 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-0 00:54:01.206 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-1 00:54:01.206 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-2 00:54:01.206 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-6 00:54:01.206 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-9 00:54:01.207 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-10 00:54:01.207 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-13 00:54:01.207 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-11 00:54:01.207 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-14 00:54:01.210 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-18 00:54:05.906 INFO ModularLoadManagerImpl - Writing local data to ZooKeeper because maximum change 44.2170649766922% exceeded threshold 10%; time since last report written is 5.001 seconds 00:54:05.907 INFO ZooKeeperDataCache - [MockZookeeper] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/loadbalance/brokers/localhost:41395 00:54:06.210 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-3 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-4 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-7 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-5 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-8 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-12 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-15 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-17 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-16 00:54:06.211 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-19 00:54:07.108 WARN UnAckedMessageTracker - [ConsumerBase{subscription='my-shared-subscription-testSharedSingleAckedPartitionedTopic', consumerName='Consumer-1', topic='persistent://prop/ns-abc/topic-testSharedSingleAckedPartitionedTopic'}] 10 messages have timed-out 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-0 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-6 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-9 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-18 00:54:08.100 INFO ConnectionHandler - [persistent://pulsar/partitionedNs-falseocykmbmxffjbpdud/dummyTopic] [r1-0-35] Reconnecting after connection was closed 00:54:08.100 WARN HttpClient - [http://localhost:44623/lookup/v2/topic/persistent/pulsar/partitionedNs-falseocykmbmxffjbpdud/dummyTopic] Failed to perform http request: finishConnect(..) failed: Connection refused: localhost/127.0.0.1:44623 00:54:08.101 WARN ConnectionHandler - [persistent://pulsar/partitionedNs-falseocykmbmxffjbpdud/dummyTopic] [r1-0-35] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException: java.net.ConnectException: finishConnect(..) failed: Connection refused: localhost/127.0.0.1:44623 00:54:08.101 WARN ConnectionHandler - [persistent://pulsar/partitionedNs-falseocykmbmxffjbpdud/dummyTopic] [r1-0-35] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException: java.net.ConnectException: finishConnect(..) failed: Connection refused: localhost/127.0.0.1:44623 -- Will try again in 57.719 s 00:54:12.157 INFO testSharedSingleAckedPartitionedTopic messageCountNoAck = 10 00:54:12.157 INFO testSharedSingleAckedPartitionedTopic messageCountYesAck = 14 00:54:12.157 INFO testSharedSingleAckedPartitionedTopic ackCountNoAck = 0 00:54:12.157 INFO testSharedSingleAckedPartitionedTopic ackCountYesAck = 14 ``` The additional messages that were received, ``` 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-0 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-6 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-9 00:54:07.156 INFO Consumer received my-message-testSharedSingleAckedPartitionedTopic-18 ``` , represent the exact difference between the number of expected messages and the actual number of received messages.
---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services
