Client Initialization may be blocked indefinitely

[ihsandemir]

The hazelcast client initialization seems to be blocked on the getnameinfo call. The log: https://hazelcast-l337.ci.cloudbees.com/view/Clients/job/cpp-play/84/console

When looking at the thread stack traces we observe the following:

(gdb) info threads
5 Thread 0xf0ea9b90 (LWP 4459) 0xffffe410 in __kernel_vsyscall ()
4 Thread 0xf7cb3b90 (LWP 4460) 0xffffe410 in __kernel_vsyscall ()
3 Thread 0xf36abb90 (LWP 4461) 0xffffe410 in __kernel_vsyscall ()
2 Thread 0xf54adb90 (LWP 4462) 0xffffe410 in __kernel_vsyscall ()

• 1 Thread 0xf7cb48e0 (LWP 3761) 0xffffe410 in __kernel_vsyscall ()
  (gdb) bt
  #0 0xffffe410 in __kernel_vsyscall ()
  test issue #1 0x003f1776 in nanosleep () from /lib/libc.so.6
  Added missing executeonX tests for Map. #2 0x0042c7dc in usleep () from /lib/libc.so.6
  request and response classes and related hooks of old client protocol are deleted #3 0xf7ea037b in hazelcast::util::sleepmillis (milliseconds=1000) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Util.cpp:54
  Decrement Pending packets for events also #4 0xf7ea0351 in hazelcast::util::sleep (seconds=1) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Util.cpp:47
  Changes in Map getAll/putAll implementation #5 0xf7ea1a53 in hazelcast::util::CountDownLatch::await (this=0xffbd0234) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/CountDownLatch.cpp:54
  Reconnecting to instance on same address should preserve member list correctly #6 0xf7e05f89 in hazelcast::client::spi::ClusterService::start (this=0xffbd0228) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/spi/ClusterService.cpp:52
  Serialization resolution order #7 0xf7df94e5 in hazelcast::client::spi::LifecycleService::start (this=0xffbcfed8) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/spi/LifecycleService.cpp:50
  Add tests for serialization #8 0xf7e24e7a in hazelcast::client::HazelcastClient::HazelcastClient (this=0xffbcfe00, config=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/HazelcastClient.cpp:49
  Listener service should listen for events after clusterService has been started to prevent receiving duplicate events #9 0x0816fe52 in hazelcast::client::test::ClusterTest::testListenersWhenClusterDown (this=0xffbd1490) at /root/jenkins/workspace/cpp-play/hazelcast/test/cluster/ClusterTest.cpp:233
  Fixing release scripts #10 0x08116092 in iTest::iTestFixturehazelcast::client::test::ClusterTest::executeTests (this=0xffbd1490) at /root/jenkins/workspace/cpp-play/hazelcast/include/iTest/iTestFixture.h:97
  New client protocol implementation #11 0x08111cd6 in unitTests (address=0x818f1e7 "127.0.0.1") at /root/jenkins/workspace/cpp-play/hazelcast/test/main.cpp:65
  Add All The Java Predicates To C++ #12 0x08112880 in main (argc=1, argv=0xffbd18d4) at /root/jenkins/workspace/cpp-play/hazelcast/test/main.cpp:99

(gdb) thread 2
[Switching to thread 2 (Thread 0xf54adb90 (LWP 4462))]#0 0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x004c8839 in __lll_lock_wait () from /lib/libpthread.so.0
#2 0x004c3e9f in _L_lock_885 () from /lib/libpthread.so.0
#3 0x004c3d66 in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0xf7fcb50c in _nss_files_gethostbyaddr_r () from /lib/libnss_files.so.2
#5 0x004499f7 in gethostbyaddr_r@@GLIBC_2.1.2 () from /lib/libc.so.6
#6 0x00451efd in getnameinfo () from /lib/libc.so.6
#7 0xf7e9dd0e in hazelcast::client::Socket::getAddress (this=0x95ef148) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/Socket.cpp:170
#8 0xf7e2d550 in hazelcast::client::connection::Connection::connect (this=0x95ef100, timeoutInMillis=5000) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/Connection.cpp:69
#9 0xf7e358ab in hazelcast::client::connection::ConnectionManager::connectTo (this=0xffbcff98, address=..., ownerConnection=true) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/ConnectionManager.cpp:306
#10 0xf7e2f2c3 in hazelcast::client::connection::OwnerConnectionFuture::createNew (this=0xffbd01fc, address=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/OwnerConnectionFuture.cpp:42
#11 0xf7e33669 in hazelcast::client::connection::ConnectionManager::createOwnerConnection (this=0xffbcff98, address=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/ConnectionManager.cpp:98
#12 0xf7e06cc3 in hazelcast::client::spi::ClusterService::connectToOne (this=0xffbd0228) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/spi/ClusterService.cpp:170
#13 0xf7e42730 in hazelcast::client::connection::ClusterListenerThread::run (this=0xffbd022c, currentThread=0xf6c010a0) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/ClusterListenerThread.cpp:56
#14 0xf7e4268d in hazelcast::client::connection::ClusterListenerThread::staticRun (args=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/ClusterListenerThread.cpp:44
#15 0xf7ea3823 in hazelcast::util::Thread::controlledThread (args=0xf6c010d8) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Thread.cpp:193
#16 0x004c1912 in start_thread () from /lib/libpthread.so.0
#17 0x0043347e in clone () from /lib/libc.so.6

(gdb) thread 3
[Switching to thread 3 (Thread 0xf36abb90 (LWP 4461))]#0 0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x003f1776 in nanosleep () from /lib/libc.so.6
#2 0x0042c7dc in usleep () from /lib/libc.so.6
#3 0xf7ea037b in hazelcast::util::sleepmillis (milliseconds=10000) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Util.cpp:54
#4 0xf7ea0351 in hazelcast::util::sleep (seconds=10) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Util.cpp:47
#5 0xf7ea370f in hazelcast::util::Thread::interruptibleSleep (this=0xf6c0ab08, seconds=10) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Thread.cpp:167
#6 0xf7e3c33e in hazelcast::client::connection::HeartBeater::run (this=0xffbd01cc, currentThread=0xf6c0ab08) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/HeartBeater.cpp:81
#7 0xf7e3c021 in hazelcast::client::connection::HeartBeater::staticStart (args=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/HeartBeater.cpp:54
#8 0xf7ea3823 in hazelcast::util::Thread::controlledThread (args=0xf6c01050) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Thread.cpp:193
#9 0x004c1912 in start_thread () from /lib/libpthread.so.0
#10 0x0043347e in clone () from /lib/libc.so.6

(gdb) thread 4
[Switching to thread 4 (Thread 0xf7cb3b90 (LWP 4460))]#0 0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x0042bf41 in select () from /lib/libc.so.6
#2 0xf7e3f4c0 in hazelcast::client::connection::OutSelector::listenInternal (this=0xffbd00b4) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/OutSelector.cpp:59
#3 0xf7e3cd48 in hazelcast::client::connection::IOSelector::listen (this=0xffbd00b4) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/IOSelector.cpp:68
#4 0xf7e3c7e7 in hazelcast::client::connection::IOSelector::staticListen (args=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/IOSelector.cpp:47
#5 0xf7ea3823 in hazelcast::util::Thread::controlledThread (args=0xf6c0aac8) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Thread.cpp:193
#6 0x004c1912 in start_thread () from /lib/libpthread.so.0
#7 0x0043347e in clone () from /lib/libc.so.6

(gdb) thread 5
[Switching to thread 5 (Thread 0xf0ea9b90 (LWP 4459))]#0 0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x0042bf41 in select () from /lib/libc.so.6
#2 0xf7e3fc4f in hazelcast::client::connection::InSelector::listenInternal (this=0xffbd000c) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/InSelector.cpp:51
#3 0xf7e3cd48 in hazelcast::client::connection::IOSelector::listen (this=0xffbd000c) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/IOSelector.cpp:68
#4 0xf7e3c7e7 in hazelcast::client::connection::IOSelector::staticListen (args=...) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/client/connection/IOSelector.cpp:47
#5 0xf7ea3823 in hazelcast::util::Thread::controlledThread (args=0xf6c0aa50) at /root/jenkins/workspace/cpp-play/hazelcast/src/hazelcast/util/Thread.cpp:193
#6 0x004c1912 in start_thread () from /lib/libpthread.so.0
#7 0x0043347e in clone () from /lib/libc.so.6

[jerrinot]

interesting, isn't there another thread calling getnameinfo() (or anything else related to a resolver)?

I reckon the 0xf54adb90 thread is trying to acquire a lock here (or close to here, pre-processor sucks): https://github.com/agx/nspr-debian/blob/master/nspr/pr/src/misc/prnetdb.c#L1067

The other threads does not appear to be involved in this.

[ihsandemir]

Nope, that is the only thread. This was stuck in the build, i logged into to server and got stack trace for the process and put the stack traces of the threads. Shall research further. Something seems very innocent, who would think such a name resolution call would acquire a lock :)

[ihsandemir]

This is a duplicate of issue #18