BewareMyPower opened a new issue #14665: URL: https://github.com/apache/pulsar/issues/14665
C++ ClientTest.testConnectTimeout is flaky. It fails sporadically. [example failure](https://github.com/apache/pulsar/runs/5511302507?check_suite_focus=true) ``` 2022-03-11 13:30:11.237 INFO [140244727245568] ClientConnection:[189](https://github.com/apache/pulsar/runs/5511302507?check_suite_focus=true#step:11:189) | [<none> -> pulsar://[192](https://github.com/apache/pulsar/runs/5511302507?check_suite_focus=true#step:11:192).0.2.1:1234] Create ClientConnection, timeout=1000 [202](https://github.com/apache/pulsar/runs/5511302507?check_suite_focus=true#step:11:202)2-03-11 13:30:11.237 INFO [140244727245568] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:30:11.239 INFO [140244727245568] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=10000 2022-03-11 13:30:11.239 INFO [140244727245568] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:30:12.239 ERROR [140244605105920] ClientConnection:554 | [<none> -> pulsar://192.0.2.1:1234] Connection was not established in 1000 ms, close the socket 2022-03-11 13:30:12.239 WARN [140244605105920] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled 2022-03-11 13:30:12.239 INFO [140244605105920] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:30:12.239 ERROR [140244605105920] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:30:12.239 INFO [140244605105920] ClientConnection:263 | [<none> -> pulsar://192.0.2.1:1234] Destroyed connection 2022-03-11 13:30:12.249 INFO [140244727245568] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:30:12.249 INFO [140244727245568] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:30:12.249 INFO [140244727245568] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:30:12.249 WARN [140244571543296] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled 2022-03-11 13:30:12.249 ERROR [140244727245568] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError [142/284] ClientTest.testConnectTimeout returned/aborted with exit code -11 (1336 ms) ``` ``` 2022-03-11 13:30:09.768 INFO [140600834464512] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=1000 2022-03-11 13:30:09.768 INFO [140600834464512] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:30:09.770 INFO [140600834464512] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=10000 2022-03-11 13:30:09.770 INFO [140600834464512] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:30:10.770 ERROR [140600712324864] ClientConnection:554 | [<none> -> pulsar://192.0.2.1:1234] Connection was not established in 1000 ms, close the socket 2022-03-11 13:30:10.770 WARN [140600712324864] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled 2022-03-11 13:30:10.770 INFO [140600712324864] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:30:10.770 ERROR [140600712324864] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:30:10.770 INFO [140600712324864] ClientConnection:263 | [<none> -> pulsar://192.0.2.1:1234] Destroyed connection 2022-03-11 13:30:10.781 INFO [140600834464512] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:30:10.781 INFO [140600834464512] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:30:10.781 INFO [140600834464512] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:30:10.781 ERROR [140600834464512] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:30:10.781 WARN [140600678762240] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled [135/284] ClientTest.testConnectTimeout returned/aborted with exit code -11 (1483 ms) ``` [another example failure](https://github.com/apache/pulsar/runs/5511296607?check_suite_focus=true) ``` 2022-03-11 13:26:54.037 INFO [140550691101440] ClientConnection:189 | [<none> -> pulsar://[192](https://github.com/apache/pulsar/runs/5511296607?check_suite_focus=true#step:11:192).0.2.1:1234] Create ClientConnection, timeout=1000 [202](https://github.com/apache/pulsar/runs/5511296607?check_suite_focus=true#step:11:202)2-03-11 13:26:54.037 INFO [140550691101440] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:26:54.038 INFO [140550691101440] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=10000 2022-03-11 13:26:54.038 INFO [140550691101440] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:26:55.038 ERROR [140550568961792] ClientConnection:554 | [<none> -> pulsar://192.0.2.1:1234] Connection was not established in 1000 ms, close the socket 2022-03-11 13:26:55.038 WARN [140550568961792] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled 2022-03-11 13:26:55.038 INFO [140550568961792] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:26:55.039 ERROR [140550568961792] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:26:55.039 INFO [140550568961792] ClientConnection:263 | [<none> -> pulsar://192.0.2.1:1234] Destroyed connection 2022-03-11 13:26:55.049 INFO [140550691101440] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:26:55.049 INFO [140550691101440] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:26:55.049 INFO [140550691101440] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:26:55.049 ERROR [140550691101440] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:26:55.049 WARN [140550535399168] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled [ OK ] ClientTest.testConnectTimeout (1013 ms) [143/284] ClientTest.testConnectTimeout returned/aborted with exit code -11 (1330 ms) ``` ``` 2022-03-11 13:26:52.609 INFO [140700052847360] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=1000 2022-03-11 13:26:52.609 INFO [140700052847360] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:26:52.611 INFO [140700052847360] ClientConnection:189 | [<none> -> pulsar://192.0.2.1:1234] Create ClientConnection, timeout=10000 2022-03-11 13:26:52.611 INFO [140700052847360] ConnectionPool:96 | Created connection for pulsar://192.0.2.1:1234 2022-03-11 13:26:53.612 ERROR [140699930707712] ClientConnection:554 | [<none> -> pulsar://192.0.2.1:1234] Connection was not established in 1000 ms, close the socket 2022-03-11 13:26:53.612 WARN [140699930707712] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled 2022-03-11 13:26:53.612 INFO [140699930707712] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:26:53.612 ERROR [140699930707712] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:26:53.612 INFO [140699930707712] ClientConnection:263 | [<none> -> pulsar://192.0.2.1:1234] Destroyed connection 2022-03-11 13:26:53.623 INFO [140700052847360] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:26:53.623 INFO [140700052847360] ClientImpl:496 | Closing Pulsar client with 0 producers and 0 consumers 2022-03-11 13:26:53.623 INFO [140700052847360] ClientConnection:1560 | [<none> -> pulsar://192.0.2.1:1234] Connection closed 2022-03-11 13:26:53.623 ERROR [140700052847360] ClientImpl:192 | Error Checking/Getting Partition Metadata while creating producer on persistent://public/default/test-connect-timeout -- ConnectError 2022-03-11 13:26:53.623 WARN [140699897145088] ClientConnection:436 | [<none> -> pulsar://192.0.2.1:1234] Failed to establish connection: Operation canceled [135/284] ClientTest.testConnectTimeout returned/aborted with exit code -11 (1432 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: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
