You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/01/20 05:40:22 UTC

[GitHub] [pulsar] lhotari opened a new issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

lhotari opened a new issue #13849:
URL: https://github.com/apache/pulsar/issues/13849


   ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers fails sporadically.
   
   [example failure](https://github.com/apache/pulsar/runs/4877678504?check_suite_focus=true#step:11:748)
   
   ```
   2022-01-20 05:08:14.347 INFO  [139723758618368] ProducerTest:208 | Closing
   2022-01-20 05:08:14.347 INFO  [139723758618368] ProducerImpl:621 | [persistent://public/default/testProducerIsConnectedPartitioned-1642655293-partition-7, standalone-0-401] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1642655293-partition-7
   2022-01-20 05:08:14.347 INFO  [139723758618368] ProducerTest:210 | Close called
   2022-01-20 05:08:14.347 INFO  [139724043835136] ProducerImpl:664 | [persistent://public/default/testProducerIsConnectedPartitioned-1642655293-partition-7, standalone-0-401] Closed producer
   2022-01-20 05:08:14.347 INFO  [139723758618368] ProducerTest:215 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:236: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers (3431 ms)
   [----------] 1 test from ProducerTest (3431 ms total)
   
   [----------] Global test environment tear-down
   [==========] 1 test from 1 test case ran. (3435 ms total)
   [  PASSED  ] 0 tests.
   [  FAILED  ] 1 test, listed below:
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   ```
   
   full logs at https://gist.github.com/lhotari/f37aefd7919f030399f3a5b7020baa23


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1078668057


   Another error.
   
   ```
   2022-03-25 13:24:26.779 INFO  [0x1011f4600] ProducerTest:167 | Start of run 0
   2022-03-25 13:24:26.814 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:26.814 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:26.815 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55382 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:26.817 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858660-partition-0, ] Getting connection from pool
   2022-03-25 13:24:26.848 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858660-partition-0, ] Created producer on broker [127.0.0.1:55382 -> 127.0.0.1:6650] 
   2022-03-25 13:24:26.860 INFO  [0x70001090f000] ProducerTest:209 | Closing
   2022-03-25 13:24:26.860 INFO  [0x70001090f000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858660-partition-0, standalone-0-781] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858660-partition-0
   2022-03-25 13:24:26.860 INFO  [0x70001090f000] ProducerTest:211 | Close called
   2022-03-25 13:24:26.861 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858660-partition-0, standalone-0-781] Closed producer
   2022-03-25 13:24:26.861 INFO  [0x70001090f000] ProducerTest:216 | Closed
   2022-03-25 13:24:26.861 INFO  [0x70001088c000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:26.977 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:26.977 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55382 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:26.977 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55382 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:26.977 INFO  [0x1011f4600] ProducerTest:242 | End of run 0
   2022-03-25 13:24:26.977 INFO  [0x1011f4600] ProducerTest:167 | Start of run 1
   2022-03-25 13:24:27.008 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.009 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.010 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55384 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.011 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858661-partition-4, ] Getting connection from pool
   2022-03-25 13:24:27.042 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858661-partition-4, ] Created producer on broker [127.0.0.1:55384 -> 127.0.0.1:6650] 
   2022-03-25 13:24:27.054 INFO  [0x700010992000] ProducerTest:209 | Closing
   2022-03-25 13:24:27.055 INFO  [0x700010992000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858661-partition-4, standalone-0-782] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858661-partition-4
   2022-03-25 13:24:27.055 INFO  [0x700010992000] ProducerTest:211 | Close called
   2022-03-25 13:24:27.056 INFO  [0x70001090f000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:27.057 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858661-partition-4, standalone-0-782] Closed producer
   2022-03-25 13:24:27.057 INFO  [0x700010992000] ProducerTest:216 | Closed
   2022-03-25 13:24:27.172 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:27.172 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55384 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:27.172 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55384 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:27.172 INFO  [0x1011f4600] ProducerTest:242 | End of run 1
   2022-03-25 13:24:27.172 INFO  [0x1011f4600] ProducerTest:167 | Start of run 2
   2022-03-25 13:24:27.204 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.204 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.205 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55386 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.208 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858672-partition-3, ] Getting connection from pool
   2022-03-25 13:24:27.237 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858672-partition-3, ] Created producer on broker [127.0.0.1:55386 -> 127.0.0.1:6650] 
   2022-03-25 13:24:27.249 INFO  [0x700010a15000] ProducerTest:209 | Closing
   2022-03-25 13:24:27.250 INFO  [0x700010a15000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858672-partition-3, standalone-0-783] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858672-partition-3
   2022-03-25 13:24:27.250 INFO  [0x700010a15000] ProducerTest:211 | Close called
   2022-03-25 13:24:27.251 INFO  [0x700010992000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:27.251 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858672-partition-3, standalone-0-783] Closed producer
   2022-03-25 13:24:27.251 INFO  [0x700010a15000] ProducerTest:216 | Closed
   2022-03-25 13:24:27.367 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:27.367 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55386 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:27.367 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55386 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:27.367 INFO  [0x1011f4600] ProducerTest:242 | End of run 2
   2022-03-25 13:24:27.368 INFO  [0x1011f4600] ProducerTest:167 | Start of run 3
   2022-03-25 13:24:27.398 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.398 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.399 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55388 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.401 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858673-partition-7, ] Getting connection from pool
   2022-03-25 13:24:27.432 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858673-partition-7, ] Created producer on broker [127.0.0.1:55388 -> 127.0.0.1:6650] 
   2022-03-25 13:24:27.444 INFO  [0x700010a98000] ProducerTest:209 | Closing
   2022-03-25 13:24:27.444 INFO  [0x700010a98000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858673-partition-7, standalone-0-784] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858673-partition-7
   2022-03-25 13:24:27.444 INFO  [0x700010a98000] ProducerTest:211 | Close called
   2022-03-25 13:24:27.445 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858673-partition-7, standalone-0-784] Closed producer
   2022-03-25 13:24:27.445 INFO  [0x700010a98000] ProducerTest:216 | Closed
   2022-03-25 13:24:27.445 INFO  [0x700010a15000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:27.560 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:27.560 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55388 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:27.560 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55388 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:27.560 INFO  [0x1011f4600] ProducerTest:242 | End of run 3
   2022-03-25 13:24:27.560 INFO  [0x1011f4600] ProducerTest:167 | Start of run 4
   2022-03-25 13:24:27.593 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.594 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.595 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55393 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.597 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858674-partition-9, ] Getting connection from pool
   2022-03-25 13:24:27.628 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858674-partition-9, ] Created producer on broker [127.0.0.1:55393 -> 127.0.0.1:6650] 
   2022-03-25 13:24:27.640 INFO  [0x700010b1b000] ProducerTest:209 | Closing
   2022-03-25 13:24:27.641 INFO  [0x700010b1b000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858674-partition-9, standalone-0-785] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858674-partition-9
   2022-03-25 13:24:27.641 INFO  [0x700010b1b000] ProducerTest:211 | Close called
   2022-03-25 13:24:27.642 INFO  [0x700010a98000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:27.643 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858674-partition-9, standalone-0-785] Closed producer
   2022-03-25 13:24:27.643 INFO  [0x700010b1b000] ProducerTest:216 | Closed
   2022-03-25 13:24:27.757 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:27.757 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55393 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:27.757 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55393 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:27.757 INFO  [0x1011f4600] ProducerTest:242 | End of run 4
   2022-03-25 13:24:27.757 INFO  [0x1011f4600] ProducerTest:167 | Start of run 5
   2022-03-25 13:24:27.789 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.789 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.790 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55395 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.793 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858675-partition-0, ] Getting connection from pool
   2022-03-25 13:24:27.822 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858675-partition-0, ] Created producer on broker [127.0.0.1:55395 -> 127.0.0.1:6650] 
   2022-03-25 13:24:27.835 INFO  [0x700010b9e000] ProducerTest:209 | Closing
   2022-03-25 13:24:27.835 INFO  [0x700010b9e000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858675-partition-0, standalone-0-786] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858675-partition-0
   2022-03-25 13:24:27.835 INFO  [0x700010b9e000] ProducerTest:211 | Close called
   2022-03-25 13:24:27.836 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858675-partition-0, standalone-0-786] Closed producer
   2022-03-25 13:24:27.836 INFO  [0x700010b9e000] ProducerTest:216 | Closed
   2022-03-25 13:24:27.836 INFO  [0x700010b1b000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:27.952 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:27.952 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55395 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:27.953 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55395 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:27.953 INFO  [0x1011f4600] ProducerTest:242 | End of run 5
   2022-03-25 13:24:27.953 INFO  [0x1011f4600] ProducerTest:167 | Start of run 6
   2022-03-25 13:24:27.982 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:27.982 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:27.983 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55397 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:27.985 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858676-partition-3, ] Getting connection from pool
   2022-03-25 13:24:28.017 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858676-partition-3, ] Created producer on broker [127.0.0.1:55397 -> 127.0.0.1:6650] 
   2022-03-25 13:24:28.029 INFO  [0x700010c21000] ProducerTest:209 | Closing
   2022-03-25 13:24:28.029 INFO  [0x700010c21000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858676-partition-3, standalone-0-787] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858676-partition-3
   2022-03-25 13:24:28.029 INFO  [0x700010c21000] ProducerTest:211 | Close called
   2022-03-25 13:24:28.030 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858676-partition-3, standalone-0-787] Closed producer
   2022-03-25 13:24:28.030 INFO  [0x700010b9e000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:28.030 INFO  [0x700010c21000] ProducerTest:216 | Closed
   2022-03-25 13:24:28.146 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:28.147 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55397 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:28.147 INFO  [0x1011f4600] ProducerTest:242 | End of run 6
   2022-03-25 13:24:28.147 INFO  [0x1011f4600] ProducerTest:167 | Start of run 7
   2022-03-25 13:24:28.179 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:28.179 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:28.181 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55399 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:28.183 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858687-partition-3, ] Getting connection from pool
   2022-03-25 13:24:28.213 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858687-partition-3, ] Created producer on broker [127.0.0.1:55399 -> 127.0.0.1:6650] 
   2022-03-25 13:24:28.225 INFO  [0x700010ca4000] ProducerTest:209 | Closing
   2022-03-25 13:24:28.225 INFO  [0x700010ca4000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858687-partition-3, standalone-0-788] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858687-partition-3
   2022-03-25 13:24:28.225 INFO  [0x700010ca4000] ProducerTest:211 | Close called
   2022-03-25 13:24:28.226 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858687-partition-3, standalone-0-788] Closed producer
   2022-03-25 13:24:28.226 INFO  [0x700010ca4000] ProducerTest:216 | Closed
   2022-03-25 13:24:28.226 INFO  [0x700010c21000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:28.341 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:28.341 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55399 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:28.341 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55399 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:28.341 INFO  [0x1011f4600] ProducerTest:242 | End of run 7
   2022-03-25 13:24:28.341 INFO  [0x1011f4600] ProducerTest:167 | Start of run 8
   2022-03-25 13:24:28.372 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:28.372 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:28.373 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55401 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:28.375 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858688-partition-6, ] Getting connection from pool
   2022-03-25 13:24:28.407 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858688-partition-6, ] Created producer on broker [127.0.0.1:55401 -> 127.0.0.1:6650] 
   2022-03-25 13:24:28.419 INFO  [0x700010d27000] ProducerTest:209 | Closing
   2022-03-25 13:24:28.420 INFO  [0x700010d27000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858688-partition-6, standalone-0-789] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858688-partition-6
   2022-03-25 13:24:28.420 INFO  [0x700010d27000] ProducerTest:211 | Close called
   2022-03-25 13:24:28.420 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858688-partition-6, standalone-0-789] Closed producer
   2022-03-25 13:24:28.420 INFO  [0x700010ca4000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:28.421 INFO  [0x700010d27000] ProducerTest:216 | Closed
   2022-03-25 13:24:28.536 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:28.536 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55401 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:28.536 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55401 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:28.536 INFO  [0x1011f4600] ProducerTest:242 | End of run 8
   2022-03-25 13:24:28.537 INFO  [0x1011f4600] ProducerTest:167 | Start of run 9
   2022-03-25 13:24:28.569 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:28.569 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:28.570 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55403 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:28.572 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858689-partition-2, ] Getting connection from pool
   2022-03-25 13:24:28.603 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858689-partition-2, ] Created producer on broker [127.0.0.1:55403 -> 127.0.0.1:6650] 
   2022-03-25 13:24:28.615 INFO  [0x700010daa000] ProducerTest:209 | Closing
   2022-03-25 13:24:28.615 INFO  [0x700010daa000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858689-partition-2, standalone-0-790] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-16481858689-partition-2
   2022-03-25 13:24:28.615 INFO  [0x700010daa000] ProducerTest:211 | Close called
   2022-03-25 13:24:28.616 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-16481858689-partition-2, standalone-0-790] Closed producer
   2022-03-25 13:24:28.616 INFO  [0x700010d27000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:28.616 INFO  [0x700010daa000] ProducerTest:216 | Closed
   2022-03-25 13:24:28.730 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:28.731 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55403 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:28.731 INFO  [0x1011f4600] ProducerTest:242 | End of run 9
   2022-03-25 13:24:28.731 INFO  [0x70000fcc7000] ClientConnection:263 | [127.0.0.1:55403 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:28.731 INFO  [0x1011f4600] ProducerTest:167 | Start of run 10
   2022-03-25 13:24:28.764 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:28.764 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:28.765 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55408 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:28.768 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586810-partition-6, ] Getting connection from pool
   2022-03-25 13:24:28.797 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586810-partition-6, ] Created producer on broker [127.0.0.1:55408 -> 127.0.0.1:6650] 
   2022-03-25 13:24:28.809 INFO  [0x700010e2d000] ProducerTest:209 | Closing
   2022-03-25 13:24:28.809 INFO  [0x700010e2d000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586810-partition-6, standalone-0-791] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586810-partition-6
   2022-03-25 13:24:28.809 INFO  [0x700010e2d000] ProducerTest:211 | Close called
   2022-03-25 13:24:28.810 INFO  [0x700010daa000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:28.811 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586810-partition-6, standalone-0-791] Closed producer
   2022-03-25 13:24:28.811 INFO  [0x700010e2d000] ProducerTest:216 | Closed
   2022-03-25 13:24:28.926 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:28.927 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55408 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:28.927 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55408 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:28.927 INFO  [0x1011f4600] ProducerTest:242 | End of run 10
   2022-03-25 13:24:28.927 INFO  [0x1011f4600] ProducerTest:167 | Start of run 11
   2022-03-25 13:24:28.959 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:28.959 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:28.960 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55410 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:28.962 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586811-partition-7, ] Getting connection from pool
   2022-03-25 13:24:28.992 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586811-partition-7, ] Created producer on broker [127.0.0.1:55410 -> 127.0.0.1:6650] 
   2022-03-25 13:24:29.005 INFO  [0x700010eb0000] ProducerTest:209 | Closing
   2022-03-25 13:24:29.005 INFO  [0x700010eb0000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586811-partition-7, standalone-0-792] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586811-partition-7
   2022-03-25 13:24:29.005 INFO  [0x700010eb0000] ProducerTest:211 | Close called
   2022-03-25 13:24:29.006 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586811-partition-7, standalone-0-792] Closed producer
   2022-03-25 13:24:29.006 INFO  [0x700010eb0000] ProducerTest:216 | Closed
   2022-03-25 13:24:29.006 INFO  [0x700010e2d000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:29.122 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:29.122 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55410 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:29.122 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55410 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:29.122 INFO  [0x1011f4600] ProducerTest:242 | End of run 11
   2022-03-25 13:24:29.122 INFO  [0x1011f4600] ProducerTest:167 | Start of run 12
   2022-03-25 13:24:29.154 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:29.154 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:29.155 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55412 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:29.158 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586912-partition-4, ] Getting connection from pool
   2022-03-25 13:24:29.187 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586912-partition-4, ] Created producer on broker [127.0.0.1:55412 -> 127.0.0.1:6650] 
   2022-03-25 13:24:29.199 INFO  [0x700010f33000] ProducerTest:209 | Closing
   2022-03-25 13:24:29.199 INFO  [0x700010f33000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586912-partition-4, standalone-0-793] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586912-partition-4
   2022-03-25 13:24:29.199 INFO  [0x700010f33000] ProducerTest:211 | Close called
   2022-03-25 13:24:29.200 INFO  [0x700010eb0000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:29.201 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586912-partition-4, standalone-0-793] Closed producer
   2022-03-25 13:24:29.201 INFO  [0x700010f33000] ProducerTest:216 | Closed
   2022-03-25 13:24:29.315 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:29.316 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55412 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:29.316 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55412 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:29.316 INFO  [0x1011f4600] ProducerTest:242 | End of run 12
   2022-03-25 13:24:29.316 INFO  [0x1011f4600] ProducerTest:167 | Start of run 13
   2022-03-25 13:24:29.348 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:29.348 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:29.349 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55414 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:29.351 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586913-partition-5, ] Getting connection from pool
   2022-03-25 13:24:29.382 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586913-partition-5, ] Created producer on broker [127.0.0.1:55414 -> 127.0.0.1:6650] 
   2022-03-25 13:24:29.394 INFO  [0x700010fb6000] ProducerTest:209 | Closing
   2022-03-25 13:24:29.394 INFO  [0x700010fb6000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586913-partition-5, standalone-0-794] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586913-partition-5
   2022-03-25 13:24:29.394 INFO  [0x700010fb6000] ProducerTest:211 | Close called
   2022-03-25 13:24:29.395 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586913-partition-5, standalone-0-794] Closed producer
   2022-03-25 13:24:29.395 INFO  [0x700010f33000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:29.395 INFO  [0x700010fb6000] ProducerTest:216 | Closed
   2022-03-25 13:24:29.511 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:29.511 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55414 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:29.511 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55414 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:29.511 INFO  [0x1011f4600] ProducerTest:242 | End of run 13
   2022-03-25 13:24:29.512 INFO  [0x1011f4600] ProducerTest:167 | Start of run 14
   2022-03-25 13:24:29.544 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:29.544 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:29.545 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55416 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:29.548 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586914-partition-0, ] Getting connection from pool
   2022-03-25 13:24:29.578 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586914-partition-0, ] Created producer on broker [127.0.0.1:55416 -> 127.0.0.1:6650] 
   2022-03-25 13:24:29.590 INFO  [0x700011039000] ProducerTest:209 | Closing
   2022-03-25 13:24:29.590 INFO  [0x700011039000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586914-partition-0, standalone-0-795] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586914-partition-0
   2022-03-25 13:24:29.591 INFO  [0x700011039000] ProducerTest:211 | Close called
   2022-03-25 13:24:29.591 INFO  [0x700010fb6000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:29.592 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586914-partition-0, standalone-0-795] Closed producer
   2022-03-25 13:24:29.592 INFO  [0x700011039000] ProducerTest:216 | Closed
   2022-03-25 13:24:29.707 INFO  [0x1011f4600] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-03-25 13:24:29.707 INFO  [0x1011f4600] ClientConnection:1559 | [127.0.0.1:55416 -> 127.0.0.1:6650] Connection closed
   2022-03-25 13:24:29.707 INFO  [0x1011f4600] ClientConnection:263 | [127.0.0.1:55416 -> 127.0.0.1:6650] Destroyed connection
   2022-03-25 13:24:29.708 INFO  [0x1011f4600] ProducerTest:242 | End of run 14
   2022-03-25 13:24:29.708 INFO  [0x1011f4600] ProducerTest:167 | Start of run 15
   2022-03-25 13:24:29.739 INFO  [0x1011f4600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-03-25 13:24:29.739 INFO  [0x1011f4600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-03-25 13:24:29.740 INFO  [0x70000fcc7000] ClientConnection:375 | [127.0.0.1:55418 -> 127.0.0.1:6650] Connected to broker
   2022-03-25 13:24:29.742 INFO  [0x70000fcc7000] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586915-partition-0, ] Getting connection from pool
   2022-03-25 13:24:29.772 INFO  [0x70000fcc7000] ProducerImpl:188 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586915-partition-0, ] Created producer on broker [127.0.0.1:55418 -> 127.0.0.1:6650] 
   2022-03-25 13:24:29.783 INFO  [0x7000110bc000] ProducerTest:209 | Closing
   2022-03-25 13:24:29.783 INFO  [0x7000110bc000] ProducerImpl:682 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586915-partition-0, standalone-0-796] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-164818586915-partition-0
   2022-03-25 13:24:29.783 INFO  [0x7000110bc000] ProducerTest:211 | Close called
   2022-03-25 13:24:29.784 INFO  [0x700011039000] ProducerTest:199 | closedAt set to 10
   2022-03-25 13:24:29.785 INFO  [0x70000fcc7000] ProducerImpl:725 | [persistent://public/default/testProducerIsConnectedPartitioned-164818586915-partition-0, standalone-0-796] Closed producer
   2022-03-25 13:24:29.786 INFO  [0x7000110bc000] ProducerTest:216 | Closed
   pulsar-client-cpp/tests/ProducerTest.cc:229: Failure
   Expected equality of these values:
     true
     promises[i].isComplete()
       Which is: false
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers (3121 ms)
   ```


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1017187508


   I'll take a look when I'm free.
   
   BTW, this flaky test might be introduced from https://github.com/apache/pulsar/pull/11570, it would be better if @Vanlightly could take a look first.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1079098248


   I found this test is just wrong. See https://github.com/apache/pulsar/blob/aef5f6d5e2d44f84c9c358f1d9dd9db1108a9d99/pulsar-client-cpp/tests/ProducerTest.cc#L236-L238
   
   If we changed the code to
   
   ```c++
               if (i >= closedAt) {
                   ASSERT_EQ(ResultAlreadyClosed, res);
               } else {
                   ASSERT_EQ(ResultOk, res);
               }
   ```
   
   The test will fail because the send results are all `ResultAlreadyClosed`, not only for `i >= closedAt`.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1077708472


   Finally I have time for this issue now. 😂 Hope I could figure out the reason soon.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1021243003


   I also encountered this flaky test in my PR
   
   ```
   2022-01-25 14:11:15.451 INFO  [139754441005824] ProducerTest:167 | Start of run 0
   2022-01-25 14:11:15.490 INFO  [139754441005824] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-25 14:11:15.490 INFO  [139754441005824] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-25 14:11:15.494 INFO  [139754318866176] ClientConnection:368 | [127.0.0.1:32906 -> 127.0.0.1:6650] Connected to broker
   2022-01-25 14:11:15.496 INFO  [139754318866176] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, ] Getting connection from pool
   2022-01-25 14:11:15.533 INFO  [139754318866176] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, ] Created producer on broker [127.0.0.1:32906 -> 127.0.0.1:6650]
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerTest:209 | Closing
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, standalone-0-374] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerTest:211 | Close called
   2022-01-25 14:11:15.553 INFO  [139754192496384] ProducerTest:199 | closedAt set to 10
   2022-01-25 14:11:15.555 INFO  [139754318866176] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, standalone-0-374] Closed producer
   2022-01-25 14:11:15.555 INFO  [139754175715072] ProducerTest:216 | Closed
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientConnection:1548 | [127.0.0.1:32906 -> 127.0.0.1:6650] Connection closed
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientConnection:256 | [127.0.0.1:32906 -> 127.0.0.1:6650] Destroyed connection
   2022-01-25 14:11:15.666 INFO  [139754441005824] ProducerTest:242 | End of run 0
   2022-01-25 14:11:15.666 INFO  [139754441005824] ProducerTest:167 | Start of run 1
   {"reason":"This topic already exists"}2022-01-25 14:11:15.681 INFO  [139754441005824] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-25 14:11:15.681 INFO  [139754441005824] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-25 14:11:15.694 INFO  [139754209277696] ClientConnection:368 | [127.0.0.1:32922 -> 127.0.0.1:6650] Connected to broker
   2022-01-25 14:11:15.698 INFO  [139754209277696] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, ] Getting connection from pool
   2022-01-25 14:11:15.732 INFO  [139754209277696] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, ] Created producer on broker [127.0.0.1:32922 -> 127.0.0.1:6650]
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerTest:209 | Closing
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, standalone-0-390] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerTest:211 | Close called
   2022-01-25 14:11:16.747 INFO  [139754209277696] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, standalone-0-390] Closed producer
   2022-01-25 14:11:16.747 INFO  [139754007951104] ProducerTest:216 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:237: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   ```
   
   I will take a look at this flaky test soon.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1078632551


   I debugged it with `lldb` and sometimes I found an `EXC_BAD_ACCESS`.
   
   ```
   Process 67307 stopped
   * thread #58, stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
       frame #0: 0x00000001043a6fcc libpulsar.2.10.0-SNAPSHOT.dylib`boost::asio::detail::io_object_impl<boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >, boost::asio::any_io_executor>::get_service(this=0x0000000000000000) at io_object_impl.hpp:116:13
      113 	  // Get the service associated with the I/O object.
      114 	  service_type& get_service()
      115 	  {
   -> 116 	    return *service_;
      117 	  }
      118 	
      119 	  // Get the service associated with the I/O object.
   Target 0: (main) stopped.
   ```
   
   The command is
   
   ```bash
   (lldb) r --gtest_filter='*Concurrent*LazyProducers' --gtest_repeat=5
   ```
   
   The frame is
   
   ```
   * thread #58, stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
     * frame #0: 0x00000001043a6fcc libpulsar.2.10.0-SNAPSHOT.dylib`boost::asio::detail::io_object_impl<boost::asio::detail::deadline_timer_service<boost::asio::time_traits<boost::posix_time::ptime> >, boost::asio::any_io_executor>::get_service(this=0x0000000000000000) at io_object_impl.hpp:116:13
       frame #1: 0x00000001043a23da libpulsar.2.10.0-SNAPSHOT.dylib`boost::asio::basic_deadline_timer<boost::posix_time::ptime, boost::asio::time_traits<boost::posix_time::ptime>, boost::asio::any_io_executor>::expires_from_now(this=0x0000000000000000, expiry_time=0x0000700011a632f8) at basic_deadline_timer.hpp:547:27
       frame #2: 0x000000010474b866 libpulsar.2.10.0-SNAPSHOT.dylib`pulsar::ProducerImpl::sendAsyncWithStatsUpdate(this=0x0000000103101418, msg=0x0000700011a63ed0, callback=0x0000700011a639c0)> const&) at ProducerImpl.cc:477:26
       frame #3: 0x000000010474abf9 libpulsar.2.10.0-SNAPSHOT.dylib`pulsar::ProducerImpl::sendAsync(this=0x0000000103101418, msg=0x0000700011a63ed0, callback=pulsar::SendCallback @ 0x0000700011a63c20)>) at ProducerImpl.cc:392:5
       frame #4: 0x00000001046e6823 libpulsar.2.10.0-SNAPSHOT.dylib`pulsar::PartitionedProducerImpl::sendAsync(this=0x0000000101f33598, msg=0x0000700011a63ed0, callback=pulsar::SendCallback @ 0x0000700011a63cc0)>) at PartitionedProducerImpl.cc:209:15
       frame #5: 0x0000000104734d6a libpulsar.2.10.0-SNAPSHOT.dylib`pulsar::Producer::sendAsync(this=0x00007ff7bfefef78, msg=0x0000700011a63ed0, callback=pulsar::SendCallback @ 0x0000700011a63ef0)>) at Producer.cc:68:12
       frame #6: 0x00000001002adcd8 main`ProducerTest_testSendAsyncCloseAsyncConcurrentlyWithLazyProducers_Test::TestBody(this=0x00006000017008c8)::$_0::operator()() const at ProducerTest.cc:202:26
   ```


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1021243003


   I also encountered this flaky test in my PR
   
   ```
   2022-01-25 14:11:15.451 INFO  [139754441005824] ProducerTest:167 | Start of run 0
   2022-01-25 14:11:15.490 INFO  [139754441005824] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-25 14:11:15.490 INFO  [139754441005824] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-25 14:11:15.494 INFO  [139754318866176] ClientConnection:368 | [127.0.0.1:32906 -> 127.0.0.1:6650] Connected to broker
   2022-01-25 14:11:15.496 INFO  [139754318866176] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, ] Getting connection from pool
   2022-01-25 14:11:15.533 INFO  [139754318866176] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, ] Created producer on broker [127.0.0.1:32906 -> 127.0.0.1:6650]
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerTest:209 | Closing
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, standalone-0-374] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5
   2022-01-25 14:11:15.552 INFO  [139754175715072] ProducerTest:211 | Close called
   2022-01-25 14:11:15.553 INFO  [139754192496384] ProducerTest:199 | closedAt set to 10
   2022-01-25 14:11:15.555 INFO  [139754318866176] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-5, standalone-0-374] Closed producer
   2022-01-25 14:11:15.555 INFO  [139754175715072] ProducerTest:216 | Closed
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientConnection:1548 | [127.0.0.1:32906 -> 127.0.0.1:6650] Connection closed
   2022-01-25 14:11:15.666 INFO  [139754441005824] ClientConnection:256 | [127.0.0.1:32906 -> 127.0.0.1:6650] Destroyed connection
   2022-01-25 14:11:15.666 INFO  [139754441005824] ProducerTest:242 | End of run 0
   2022-01-25 14:11:15.666 INFO  [139754441005824] ProducerTest:167 | Start of run 1
   {"reason":"This topic already exists"}2022-01-25 14:11:15.681 INFO  [139754441005824] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-25 14:11:15.681 INFO  [139754441005824] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-25 14:11:15.694 INFO  [139754209277696] ClientConnection:368 | [127.0.0.1:32922 -> 127.0.0.1:6650] Connected to broker
   2022-01-25 14:11:15.698 INFO  [139754209277696] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, ] Getting connection from pool
   2022-01-25 14:11:15.732 INFO  [139754209277696] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, ] Created producer on broker [127.0.0.1:32922 -> 127.0.0.1:6650]
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerTest:209 | Closing
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, standalone-0-390] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6
   2022-01-25 14:11:16.746 INFO  [139754007951104] ProducerTest:211 | Close called
   2022-01-25 14:11:16.747 INFO  [139754209277696] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643119875-partition-6, standalone-0-390] Closed producer
   2022-01-25 14:11:16.747 INFO  [139754007951104] ProducerTest:216 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:237: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   ```
   
   I will take a look at this flaky test soon.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] BewareMyPower commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1025116945


   Another failure: https://github.com/apache/pulsar/runs/4996173778?check_suite_focus=true
   
   ```
   [ RUN      ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   2022-01-30 10:31:24.887 INFO  [139625035234048] ProducerTest:167 | Start of run 0
   2022-01-30 10:31:24.918 INFO  [139625035234048] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-30 10:31:24.918 INFO  [139625035234048] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-30 10:31:24.927 INFO  [139624913094400] ClientConnection:368 | [127.0.0.1:48718 -> 127.0.0.1:6650] Connected to broker
   2022-01-30 10:31:24.929 INFO  [139624913094400] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538684-partition-0, ] Getting connection from pool
   2022-01-30 10:31:24.966 INFO  [139624913094400] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538684-partition-0, ] Created producer on broker [127.0.0.1:48718 -> 127.0.0.1:6650]
   2022-01-30 10:31:24.978 INFO  [139624689170176] ProducerTest:209 | Closing
   2022-01-30 10:31:24.978 INFO  [139624689170176] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538684-partition-0, standalone-0-372] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643538684-partition-0
   2022-01-30 10:31:24.979 INFO  [139624689170176] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538684-partition-0, standalone-0-372] Closed producer
   2022-01-30 10:31:24.979 INFO  [139624689170176] ProducerTest:211 | Close called
   2022-01-30 10:31:24.979 INFO  [139624689170176] ProducerTest:216 | Closed
   2022-01-30 10:31:24.980 INFO  [139624789825280] ProducerTest:199 | closedAt set to 10
   2022-01-30 10:31:25.077 INFO  [139625035234048] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-01-30 10:31:25.077 INFO  [139625035234048] ClientConnection:1548 | [127.0.0.1:48718 -> 127.0.0.1:6650] Connection closed
   2022-01-30 10:31:25.078 INFO  [139625035234048] ProducerTest:242 | End of run 0
   2022-01-30 10:31:25.078 INFO  [139625035234048] ProducerTest:167 | Start of run 1
   2022-01-30 10:31:25.109 INFO  [139625035234048] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-01-30 10:31:25.109 INFO  [139625035234048] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-01-30 10:31:25.110 INFO  [139624689170176] ClientConnection:368 | [127.0.0.1:48724 -> 127.0.0.1:6650] Connected to broker
   2022-01-30 10:31:25.113 INFO  [139624689170176] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538685-partition-4, ] Getting connection from pool
   2022-01-30 10:31:25.143 INFO  [139624689170176] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538685-partition-4, ] Created producer on broker [127.0.0.1:48724 -> 127.0.0.1:6650]
   2022-01-30 10:31:26.143 INFO  [139624672388864] ProducerTest:209 | Closing
   2022-01-30 10:31:26.143 INFO  [139624672388864] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538685-partition-4, standalone-0-374] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1643538685-partition-4
   2022-01-30 10:31:26.143 INFO  [139624672388864] ProducerTest:211 | Close called
   2022-01-30 10:31:26.143 INFO  [139624689170176] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1643538685-partition-4, standalone-0-374] Closed producer
   2022-01-30 10:31:26.144 INFO  [139624672388864] ProducerTest:216 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:237: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers (1257 ms)
   [----------] 1 test from ProducerTest (1257 ms total)
   
   [----------] Global test environment tear-down
   [==========] 1 test from 1 test case ran. (1257 ms total)
   [  PASSED  ] 0 tests.
   [  FAILED  ] 1 test, listed below:
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   ```


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] lhotari commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
lhotari commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1017138912


   @BewareMyPower Do you have a chance to check this?


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] github-actions[bot] commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1068653716


   The issue had no activity for 30 days, mark with Stale label.


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] RobertIndie commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
RobertIndie commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1038178803


   Another failure: https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:646
   
   ```
   [ RUN      ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   2022-02-13 13:42:55.629 INFO  [139735466076928] ProducerTest:167 | Start of run 0
   2022-02-13 13:42:55.656 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.656 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.662 INFO  [139735343937280] ClientConnection:368 | [127.0.0.1:57358 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.668 INFO  [139735343937280] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16447[597](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:597)75-partition-0, ] Getting connection from pool
   2022-02-13 13:42:55.706 INFO  [139735343937280] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, ] Created producer on broker [127.0.0.1:57358 -> 127.0.0.1:6650]
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerTest:209 | Closing
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-382] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerTest:211 | Close called
   2022-02-13 13:42:55.725 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:55.728 INFO  [139735343937280] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-382] Closed producer
   2022-02-13 13:42:55.728 INFO  [139735200687872] ProducerTest:216 | Closed
   2022-02-13 13:42:55.827 INFO  [13973546[607](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:607)6928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:55.827 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57358 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:55.827 INFO  [139735466076928] ProducerTest:242 | End of run 0
   2022-02-13 13:42:55.827 INFO  [139735466076928] ProducerTest:167 | Start of run 1
   {"reason":"This topic already exists"}2022-02-13 13:42:55.841 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.841 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.846 INFO  [139735200687872] ClientConnection:368 | [127.0.0.1:57364 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.848 INFO  [139735200687872] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1[644](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:644)759775-partition-0, ] Getting connection from pool
   2022-02-13 13:42:55.850 INFO  [139735200687872] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, ] Created producer on broker [127.0.0.1:57364 -> 127.0.0.1:6[650](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:650)]
   2022-02-13 13:42:55.860 INFO  [139735183906560] ProducerTest:209 | Closing
   2022-02-13 13:42:55.861 INFO  [139735183906560] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-384] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0
   2022-02-13 13:42:55.861 INFO  [139735183906560] ProducerTest:211 | Close called
   2022-02-13 13:42:55.861 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:55.864 INFO  [139735200687872] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-384] Closed producer
   2022-02-13 13:42:55.864 INFO  [139735183906560] ProducerTest:216 | Closed
   2022-02-13 13:42:55.961 INFO  [139735466076928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:55.961 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57364 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:55.962 INFO  [139735466076928] ProducerTest:242 | End of run 1
   2022-02-13 13:42:55.962 INFO  [139735466076928] ProducerTest:167 | Start of run 2
   {"reason":"This topic already exists"}2022-02-13 13:42:55.974 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.974 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.974 INFO  [139735183906560] ClientConnection:368 | [127.0.0.1:57368 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.976 INFO  [139735183906560] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, ] Getting connection from pool
   2022-02-13 13:42:56.001 INFO  [139735183906560] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, ] Created producer on broker [127.0.0.1:57368 -> 127.0.0.1:6650]
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerTest:209 | Closing
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, standalone-0-385] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerTest:211 | Close called
   2022-02-13 13:42:56.012 INFO  [139735183906560] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, standalone-0-385] Closed producer
   2022-02-13 13:42:56.012 INFO  [139734881924864] ProducerTest:216 | Closed
   2022-02-13 13:42:56.012 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:56.123 INFO  [139735466076928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:56.123 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57368 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:56.123 INFO  [139735466076928] ProducerTest:242 | End of run 2
   2022-02-13 13:42:56.123 INFO  [139735466076928] ProducerTest:167 | Start of run 3
   2022-02-13 13:42:56.168 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:56.168 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:56.184 INFO  [139734881924864] ClientConnection:368 | [127.0.0.1:57382 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:56.188 INFO  [139734881924864] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, ] Getting connection from pool
   2022-02-13 13:42:56.227 INFO  [139734881924864] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, ] Created producer on broker [127.0.0.1:57382 -> 127.0.0.1:6650]
   2022-02-13 13:42:57.235 INFO  [1397348[651](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:651)43552] ProducerTest:209 | Closing
   2022-02-13 13:42:57.235 INFO  [139734865143552] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, standalone-0-401] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3
   2022-02-13 13:42:57.235 INFO  [139734865143552] ProducerTest:211 | Close called
   2022-02-13 13:42:57.236 INFO  [139734881924864] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, standalone-0-401] Closed producer
   2022-02-13 13:42:57.236 INFO  [139734865143552] ProducerTest:216 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:237: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers (1607 ms)
   [----------] 1 test from ProducerTest (1607 ms total)
   
   [----------] Global test environment tear-down
   [==========] 1 test from 1 test case ran. (1607 ms total)
   [  PASSED  ] 0 tests.
   [  FAILED  ] 1 test, listed below:
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   ```


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [pulsar] RobertIndie commented on issue #13849: Flaky-test: C++ ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers

Posted by GitBox <gi...@apache.org>.
RobertIndie commented on issue #13849:
URL: https://github.com/apache/pulsar/issues/13849#issuecomment-1038178803


   Another failure: https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:646
   
   ```
   [ RUN      ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   2022-02-13 13:42:55.629 INFO  [139735466076928] ProducerTest:167 | Start of run 0
   2022-02-13 13:42:55.656 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.656 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.662 INFO  [139735343937280] ClientConnection:368 | [127.0.0.1:57358 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.668 INFO  [139735343937280] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-16447[597](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:597)75-partition-0, ] Getting connection from pool
   2022-02-13 13:42:55.706 INFO  [139735343937280] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, ] Created producer on broker [127.0.0.1:57358 -> 127.0.0.1:6650]
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerTest:209 | Closing
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-382] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0
   2022-02-13 13:42:55.724 INFO  [139735200687872] ProducerTest:211 | Close called
   2022-02-13 13:42:55.725 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:55.728 INFO  [139735343937280] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-382] Closed producer
   2022-02-13 13:42:55.728 INFO  [139735200687872] ProducerTest:216 | Closed
   2022-02-13 13:42:55.827 INFO  [13973546[607](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:607)6928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:55.827 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57358 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:55.827 INFO  [139735466076928] ProducerTest:242 | End of run 0
   2022-02-13 13:42:55.827 INFO  [139735466076928] ProducerTest:167 | Start of run 1
   {"reason":"This topic already exists"}2022-02-13 13:42:55.841 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.841 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.846 INFO  [139735200687872] ClientConnection:368 | [127.0.0.1:57364 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.848 INFO  [139735200687872] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1[644](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:644)759775-partition-0, ] Getting connection from pool
   2022-02-13 13:42:55.850 INFO  [139735200687872] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, ] Created producer on broker [127.0.0.1:57364 -> 127.0.0.1:6[650](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:650)]
   2022-02-13 13:42:55.860 INFO  [139735183906560] ProducerTest:209 | Closing
   2022-02-13 13:42:55.861 INFO  [139735183906560] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-384] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0
   2022-02-13 13:42:55.861 INFO  [139735183906560] ProducerTest:211 | Close called
   2022-02-13 13:42:55.861 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:55.864 INFO  [139735200687872] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-0, standalone-0-384] Closed producer
   2022-02-13 13:42:55.864 INFO  [139735183906560] ProducerTest:216 | Closed
   2022-02-13 13:42:55.961 INFO  [139735466076928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:55.961 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57364 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:55.962 INFO  [139735466076928] ProducerTest:242 | End of run 1
   2022-02-13 13:42:55.962 INFO  [139735466076928] ProducerTest:167 | Start of run 2
   {"reason":"This topic already exists"}2022-02-13 13:42:55.974 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:55.974 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:55.974 INFO  [139735183906560] ClientConnection:368 | [127.0.0.1:57368 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:55.976 INFO  [139735183906560] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, ] Getting connection from pool
   2022-02-13 13:42:56.001 INFO  [139735183906560] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, ] Created producer on broker [127.0.0.1:57368 -> 127.0.0.1:6650]
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerTest:209 | Closing
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, standalone-0-385] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8
   2022-02-13 13:42:56.011 INFO  [139734881924864] ProducerTest:211 | Close called
   2022-02-13 13:42:56.012 INFO  [139735183906560] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759775-partition-8, standalone-0-385] Closed producer
   2022-02-13 13:42:56.012 INFO  [139734881924864] ProducerTest:216 | Closed
   2022-02-13 13:42:56.012 INFO  [139735217469184] ProducerTest:199 | closedAt set to 10
   2022-02-13 13:42:56.123 INFO  [139735466076928] ClientImpl:496 | Closing Pulsar client with 1 producers and 0 consumers
   2022-02-13 13:42:56.123 INFO  [139735466076928] ClientConnection:1548 | [127.0.0.1:57368 -> 127.0.0.1:6650] Connection closed
   2022-02-13 13:42:56.123 INFO  [139735466076928] ProducerTest:242 | End of run 2
   2022-02-13 13:42:56.123 INFO  [139735466076928] ProducerTest:167 | Start of run 3
   2022-02-13 13:42:56.168 INFO  [139735466076928] ClientConnection:182 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-02-13 13:42:56.168 INFO  [139735466076928] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-02-13 13:42:56.184 INFO  [139734881924864] ClientConnection:368 | [127.0.0.1:57382 -> 127.0.0.1:6650] Connected to broker
   2022-02-13 13:42:56.188 INFO  [139734881924864] HandlerBase:64 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, ] Getting connection from pool
   2022-02-13 13:42:56.227 INFO  [139734881924864] ProducerImpl:189 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, ] Created producer on broker [127.0.0.1:57382 -> 127.0.0.1:6650]
   2022-02-13 13:42:57.235 INFO  [1397348[651](https://github.com/apache/pulsar/runs/5173936162?check_suite_focus=true#step:11:651)43552] ProducerTest:209 | Closing
   2022-02-13 13:42:57.235 INFO  [139734865143552] ProducerImpl:686 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, standalone-0-401] Closing producer for topic persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3
   2022-02-13 13:42:57.235 INFO  [139734865143552] ProducerTest:211 | Close called
   2022-02-13 13:42:57.236 INFO  [139734881924864] ProducerImpl:729 | [persistent://public/default/testProducerIsConnectedPartitioned-1644759776-partition-3, standalone-0-401] Closed producer
   2022-02-13 13:42:57.236 INFO  [139734865143552] ProducerTest:216 | Closed
   /pulsar/pulsar-client-cpp/tests/ProducerTest.cc:237: Failure
   Value of: res
     Actual: Ok
   Expected: ResultAlreadyClosed
   Which is: AlreadyClosed
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers (1607 ms)
   [----------] 1 test from ProducerTest (1607 ms total)
   
   [----------] Global test environment tear-down
   [==========] 1 test from 1 test case ran. (1607 ms total)
   [  PASSED  ] 0 tests.
   [  FAILED  ] 1 test, listed below:
   [  FAILED  ] ProducerTest.testSendAsyncCloseAsyncConcurrentlyWithLazyProducers
   ```


-- 
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.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org