Frozen (for 15 minutes) on shutdown [dnsseed thread]

dooglus commented at 11:51 am on April 14, 2017: contributor

Built the 0.14 branch (ccb47bf83036f60dbef04f90aa06dd0f9c1917ac - well, I really built from a UASF fork, b0c9b332340341d7aa67cdc3c0cd5eb50dc72582, but it is functionally the same as that revision for now I think), without wallet support. It hung when I tried to shutdown.

Here’s the end of debug.log:

2017-04-14 11:33:50 UpdateTip: new best=0000000000000000017ae4b096e8c04705269760db371dfa10c7bc29108351d5 height=461466 version=0x20000000 log2_work=86.267575 tx=212456868 date='2017-04-11 18:02:48' progress=0.996460 cache=17.3MiB(17113tx)
2017-04-14 11:33:51 connect() to [2001:0:9d38:6ab8:c32:3462:e763:4c90]:8333 failed: Network is unreachable (101)
2017-04-14 11:33:51 connect() to 81.169.150.217:8333 failed after select(): Connection refused (111)
2017-04-14 11:33:53 tor: Thread interrupt
2017-04-14 11:33:53 addcon thread exit
2017-04-14 11:33:53 torcontrol thread exit
2017-04-14 11:33:53 net thread exit
2017-04-14 11:34:00 scheduler thread interrupt
2017-04-14 11:34:27 UpdateTip: new best=000000000000000001b4904ab88cb6f13b1f8ccbb9f183db51894cc521fabf23 height=461467 version=0x20000002 log2_work=86.267608 tx=212458675 date='2017-04-11 18:23:05' progress=0.996478 cache=18.5MiB(21415tx)
2017-04-14 11:34:27 Shutdown: In progress...
2017-04-14 11:34:27 opencon thread exit
2017-04-14 11:34:27 msghand thread exit

And the stack traces:

(gdb) thread apply all where

Thread 3 (Thread 0x7fbdf8ff9700 (LWP 21708)):
[#0](/bitcoin-bitcoin/0/)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
[#1](/bitcoin-bitcoin/1/)  0x00005626d2e807fb in BGThread (this=0x5626d3a33980) at leveldb/util/env_posix.cc:574
[#2](/bitcoin-bitcoin/2/)  leveldb::(anonymous namespace)::PosixEnv::BGThreadWrapper (arg=0x5626d3a33980) at leveldb/util/env_posix.cc:521
[#3](/bitcoin-bitcoin/3/)  0x00007fbe059e7184 in start_thread (arg=0x7fbdf8ff9700) at pthread_create.c:312
[#4](/bitcoin-bitcoin/4/)  0x00007fbe0571437d in __ecvt_r (value=9.532824124368238e-130, ndigit=0, decpt=0x0, sign=0x0, buf=0x7fbdf8ff99c0 "\220\202\277\005\276\177", len=140453903046400) at efgcvt_r.c:218
[#5](/bitcoin-bitcoin/5/)  0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fbdc3093700 (LWP 21739)):
[#0](/bitcoin-bitcoin/0/)  0x00007fbe059ee73d in connect () at ../sysdeps/unix/syscall-template.S:81
[#1](/bitcoin-bitcoin/1/)  0x00007fbdd40fe306 in send_vc (statp=statp@entry=0x7fbdc3093db8, buf=buf@entry=0x7fbdc3090cb0 "m0\001", buflen=buflen@entry=42, buf2=buf2@entry=0x7fbdc3090cdc "\016L\001", buflen2=buflen2@entry=42, ansp=ansp@entry=0x7fbdc3090b38, anssizp=anssizp@entry=0x7fbdc3090c80, terrno=terrno@entry=0x7fbdc3090b40, ns=ns@entry=0, anscp=anscp@entry=0x7fbdc3092130, ansp2=ansp2@entry=0x7fbdc3092140, anssizp2=anssizp2@entry=0x7fbdc30920f0, resplen2=resplen2@entry=0x7fbdc3092100, ansp2_malloced=ansp2_malloced@entry=0x7fbdc3092110) at res_send.c:793
[#2](/bitcoin-bitcoin/2/)  0x00007fbdd40ff7a7 in __libc_res_nsend (statp=statp@entry=0x7fbdc3093db8, buf=buf@entry=0x7fbdc3090cb0 "m0\001", buflen=42, buf2=buf2@entry=0x7fbdc3090cdc "\016L\001", buflen2=buflen2@entry=42, ans=ans@entry=0x7fbdc30918c0 "\016L\203\200", anssiz=anssiz@entry=2048, ansp=ansp@entry=0x7fbdc3092130, ansp2=ansp2@entry=0x7fbdc3092140, nansp2=nansp2@entry=0x7fbdc30920f0, resplen2=resplen2@entry=0x7fbdc3092100, ansp2_malloced=ansp2_malloced@entry=0x7fbdc3092110) at res_send.c:566
[#3](/bitcoin-bitcoin/3/)  0x00007fbdd40fce2c in __GI___libc_res_nquery (statp=statp@entry=0x7fbdc3093db8, name=0x7fbda4000ff8 "x9.seed.bitcoinstats.com", class=class@entry=1, type=type@entry=62321, answer=answer@entry=0x7fbdc30918c0 "\016L\203\200", anslen=anslen@entry=2048, answerp=answerp@entry=0x7fbdc3092130, answerp2=answerp2@entry=0x7fbdc3092140, nanswerp2=nanswerp2@entry=0x7fbdc30920f0, resplen2=resplen2@entry=0x7fbdc3092100, answerp2_malloced=answerp2_malloced@entry=0x7fbdc3092110) at res_query.c:227
[#4](/bitcoin-bitcoin/4/)  0x00007fbdd40fd863 in __libc_res_nquerydomain (domain=0x0, answerp2_malloced=0x7fbdc3092110, resplen2=0x7fbdc3092100, nanswerp2=0x7fbdc30920f0, answerp2=0x7fbdc3092140, answerp=0x7fbdc3092130, anslen=2048, answer=0x7fbdc30918c0 "\016L\203\200", type=62321, class=1, name=0x7fbda4000ff8 "x9.seed.bitcoinstats.com", statp=0x7fbdc3093db8) at res_query.c:591
[#5](/bitcoin-bitcoin/5/)  __GI___libc_res_nsearch (statp=0x7fbdc3093db8, name=name@entry=0x7fbda4000ff8 "x9.seed.bitcoinstats.com", class=class@entry=1, type=type@entry=62321, answer=answer@entry=0x7fbdc30918c0 "\016L\203\200", anslen=anslen@entry=2048, answerp=answerp@entry=0x7fbdc3092130, answerp2=answerp2@entry=0x7fbdc3092140, nanswerp2=nanswerp2@entry=0x7fbdc30920f0, resplen2=resplen2@entry=0x7fbdc3092100, answerp2_malloced=answerp2_malloced@entry=0x7fbdc3092110) at res_query.c:381
[#6](/bitcoin-bitcoin/6/)  0x00007fbdf80ddc73 in _nss_dns_gethostbyname4_r (name=0x7fbda4000ff8 "x9.seed.bitcoinstats.com", pat=0x7fbdc3092780, buffer=0x7fbdc30921e0 "4\036\261\060", buflen=1064, errnop=0x7fbdc3092750, herrnop=0x7fbdc30927a0, ttlp=0x0) at nss_dns/dns-host.c:315
[#7](/bitcoin-bitcoin/7/)  0x00007fbe056e6607 in gaih_inet (name=0x5 <error: Cannot access memory at address 0x5>, service=0x7fbda4000d00, req=0x7fbdf80ddb70 <_nss_dns_gethostbyname4_r>, pai=0x7fbdc30927a0, naddrs=0x2a) at ../sysdeps/posix/getaddrinfo.c:321
[#8](/bitcoin-bitcoin/8/)  0x00007fbe056e9cbd in match_prefix (default_val=2147483647, list=0x5bc30927d0, in6=0x7fbdc3090b38) at ../sysdeps/posix/getaddrinfo.c:1499
[#9](/bitcoin-bitcoin/9/)  get_label (in6=0x9) at ../sysdeps/posix/getaddrinfo.c:1525
[#10](/bitcoin-bitcoin/10/) rfc3484_sort (p1=<optimized out>, p2=<optimized out>, arg=0x7fbda4000ff8) at ../sysdeps/posix/getaddrinfo.c:1618
[#11](/bitcoin-bitcoin/11/) 0x00007fbda4000020 in ?? ()
[#12](/bitcoin-bitcoin/12/) 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fbe078f1780 (LWP 21696)):
[#0](/bitcoin-bitcoin/0/)  0x00007fbe059e865b in pthread_join (threadid=140452997707520, thread_return=0x0) at pthread_join.c:92
[#1](/bitcoin-bitcoin/1/)  0x00007fbe061ca857 in std::thread::join() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
[#2](/bitcoin-bitcoin/2/)  0x00005626d2c87e3d in CConnman::Stop (this=this@entry=0x5626d38a6490) at net.cpp:2343
[#3](/bitcoin-bitcoin/3/)  0x00005626d2c87eea in CConnman::~CConnman (this=0x5626d38a6490, __in_chrg=<optimized out>) at net.cpp:2390
[#4](/bitcoin-bitcoin/4/)  0x00005626d2c4ceb3 in operator() (this=<optimized out>, __ptr=0x5626d38a6490) at /usr/include/c++/4.8/bits/unique_ptr.h:67
[#5](/bitcoin-bitcoin/5/)  reset (__p=0x5626d38a6490, this=0x5626d3225570 <g_connman>) at /usr/include/c++/4.8/bits/unique_ptr.h:262
[#6](/bitcoin-bitcoin/6/)  Shutdown () at init.cpp:209
[#7](/bitcoin-bitcoin/7/)  0x00005626d2c41587 in AppInit (argc=<optimized out>, argv=<optimized out>) at bitcoind.cpp:184
[#8](/bitcoin-bitcoin/8/)  0x00005626d2c3875f in main (argc=1, argv=0x7ffde3d1fe88) at bitcoind.cpp:196
(gdb)

dooglus commented at 11:53 am on April 14, 2017: contributor

Oh. 15 minutes later it shut down!

2017-04-14 11:34:27 UpdateTip: new best=000000000000000001b4904ab88cb6f13b1f8ccbb9f183db51894cc521fabf23 height=461467 version=0x20000002 log2_work=86.267608 tx=212458675 date='2017-04-11 18:23:05' progress=0.996478 cache=18.5MiB(21415tx)
2017-04-14 11:34:27 Shutdown: In progress...
2017-04-14 11:34:27 opencon thread exit
2017-04-14 11:34:27 msghand thread exit
2017-04-14 11:49:50 119 addresses found from DNS seeds
2017-04-14 11:49:50 dnsseed thread exit
2017-04-14 11:49:51 Shutdown: done

dooglus renamed this:
~~Frozen on shutdown~~
Frozen (for 15 minutes) on shutdown
on Apr 14, 2017

sipa commented at 11:58 am on April 14, 2017: member

Looks like a duplicate of #10209.

dooglus commented at 12:00 pm on April 14, 2017: contributor

Possibly, though the stack traces look quite different.

MarcoFalke commented at 12:02 pm on April 14, 2017: member

This one is on the 0.14 branch. Jonas saw it on master.

TheBlueMatt commented at 8:35 pm on April 14, 2017: member

The hanging thread here is the dnsseed thread. Because glibc’s async dns lookup is horribly broken (see https://sourceware.org/bugzilla/show_bug.cgi?id=20874), we stopped using it in #9229. #10215 will make the dnsseed thread exit a bit faster, but until we move to libevent’s dns lookup, we’re stuck with this as the best we can do.

jonasschnelli added the label Bug on Apr 19, 2017

eklitzke commented at 7:15 am on March 10, 2018: contributor

What value do you have dbcache set to?

dooglus commented at 2:44 pm on March 10, 2018: contributor

dbcache=4000

(but I think this is a DNS timeout issue, not a Berkeley DB issue)

eklitzke commented at 3:11 pm on March 10, 2018: contributor

dbcache=4000 is way too high and I would not recommend that setting. That means that you may need to flush up to 4GB of data to disk when shutting down. In practice the utxo cache is flushed every 24 hr, but that still works out to about 1 GB of data for a synced node. It regularly takes my cloud nodes ~5 min to shut down with dbcache=2048. You also have a LevelDB compaction thread in your back trace which is consistent with a flush to disk happening.

If this happens to you again more useful than a GDB backtrace would be to strace all of the threads to completion, which would make it more obvious what is blocking on what. And I would suggest lowering the dbcache setting anyway.

MarcoFalke renamed this:
~~Frozen (for 15 minutes) on shutdown~~
Frozen (for 15 minutes) on shutdown [dnsseed thread]
on Apr 12, 2018

adamjonas commented at 10:15 pm on December 16, 2020: member

The flurry of issues of this kind (e.g. #10209 and #10140) that popped up on 0.14 seem to have been addressed by #10215 and #10228. This can probably be closed since there haven’t been any further reports.

MarcoFalke closed this on Dec 17, 2020

DrahtBot locked this on Feb 15, 2022

Frozen (for 15 minutes) on shutdown [dnsseed thread] #10210