Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

strange behavior on termux #16751

Open
stefanwouldgo opened this issue Aug 29, 2019 · 17 comments
Open

strange behavior on termux #16751

stefanwouldgo opened this issue Aug 29, 2019 · 17 comments

Comments

@stefanwouldgo
Copy link
Contributor

@stefanwouldgo stefanwouldgo commented Aug 29, 2019

Bitcoind seems to run ok, but anything that communicates with it via rpc such as lnd or bitcoin-cli is very slow/blocking for a long time. bitcoin-cli is blocking while waiting for bitcoind to answer. shutting down via bitcoin-cli stop (or even ctrl-c) doesn't terminate. bitcoind can only be finally shut down via kill -9.

bitcoind behaves normally when run on the same machine using ubuntu running in proot (with standard libraries like glibc) instead of pure termux with bionic.

here's a piece of debug log when doing bitcoin-cli stop:

`2019-08-29T08:49:20Z libevent: epoll_dispatch: epoll_wait reports 1
2019-08-29T08:49:20Z libevent: event_active: 0xb83355fc (fd 10), res 2, callback 0xb6a01141
2019-08-29T08:49:20Z libevent: event_process_active: event: 0xb83355fc, EV_READ call 0xb6a01141
2019-08-29T08:49:20Z libevent: evhttp_get_request_connection: new request from 127.0.0.1:59610 on 77

2019-08-29T08:49:20Z libevent: Attempting connection to 127.0.0.1:59610

2019-08-29T08:49:20Z libevent: event_del: 0xafcea858 (fd -1), callback 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_del: 0xafcea898 (fd -1), callback 0xb69f99b5
2019-08-29T08:49:20Z libevent: event_add: event: 0xafcea898 (fd 77), EV_WRITE call 0xb69f99b5
2019-08-29T08:49:20Z libevent: Epoll ADD(4) on fd 77 okay. Old events were 0; read change was 0 (none); write change was 1 (add); close change was 0 (none)
2019-08-29T08:49:20Z libevent: event_add: event: 0xafcea858 (fd 77), EV_READ call 0xb69f98c5
2019-08-29T08:49:20Z libevent: Epoll MOD(5) on fd 77 okay. Old events were 4; read change was 1 (add); write change was 0 (none); close change was 0 (none)
2019-08-29T08:49:20Z libevent: event_del: 0xafcea898 (fd 77), callback 0xb69f99b5
2019-08-29T08:49:20Z libevent: Epoll MOD(1) on fd 77 okay. Old events were 6; read change was 0 (none); write change was 2 (del); close change was 0 (none)
2019-08-29T08:49:20Z libevent: event_add: event: 0xafcea858 (fd 77), EV_READ EV_TIMEOUT call 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_add: event 0xafcea858, timeout in 30 seconds 0 useconds, call 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_del: 0xafcea898 (fd 77), callback 0xb69f99b5
2019-08-29T08:49:20Z libevent: event_add: event: 0xafcea858 (fd 77), EV_READ EV_TIMEOUT call 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_add: event 0xafcea858, timeout in 30 seconds 0 useconds, call 0xb69f98c5
2019-08-29T08:49:20Z libevent: timeout_next: event: 0xafcea858, in 30 seconds, 0 useconds
2019-08-29T08:49:20Z libevent: epoll_dispatch: epoll_wait reports 1
2019-08-29T08:49:20Z libevent: event_active: 0xafcea858 (fd 77), res 2, callback 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_process_active: event: 0xafcea858, EV_READ call 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_add: event: 0xafcea858 (fd 77), EV_READ EV_TIMEOUT call 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_add: event 0xafcea858, timeout in 279493 seconds 881162 useconds, call 0xb69f98c5
2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Host val: 127.0.0.1

2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Connection val: close

2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Authorization val: Basic XX...

2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Content-Length val: 37
2019-08-29T08:49:20Z libevent: evhttp_read_header: checking for post data on 77

2019-08-29T08:49:20Z libevent: evhttp_get_body_length: bytes to read: 37 (in buffer 37)

2019-08-29T08:49:20Z libevent: event_del: 0xafcea858 (fd 77), callback 0xb69f98c5
2019-08-29T08:49:20Z libevent: Epoll DEL(1) on fd 77 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)
2019-08-29T08:49:20Z libevent: event_del: 0xafcea858 (fd 77), callback 0xb69f98c5
2019-08-29T08:49:20Z libevent: event_del: 0xafcea858 (fd 77), callback 0xb69f98c5
2019-08-29T08:49:20Z Received a POST request for / from 127.0.0.1:59610
2019-08-29T08:49:20Z ThreadRPCServer method=stop user=cookie
2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Content-Type val: application/json

2019-08-29T08:49:20Z libevent: evhttp_add_header: key: Connection val: close

2019-08-29T08:49:20Z libevent: event_active: 0xafe37410 (fd -1), res 0, callback 0xb6d05e4d
2019-08-29T08:49:20Z Interrupting HTTP server
2019-08-29T08:49:20Z Interrupting HTTP RPC server
2019-08-29T08:49:20Z Interrupting RPC
2019-08-29T08:49:20Z tor: Thread interrupt
2019-08-29T08:49:20Z libevent: event_active: 0xafe376e0 (fd -1), res 1, callback 0xb69fc735
2019-08-29T08:49:20Z Shutdown: In progress...
2019-08-29T08:49:20Z Stopping HTTP RPC server
2019-08-29T08:49:20Z Unregistering HTTP handler for / (exactmatch 1)
2019-08-29T08:49:20Z Unregistering HTTP handler for /wallet/ (exactmatch 0)
2019-08-29T08:49:20Z addcon thread exit
2019-08-29T08:49:20Z net thread exit
2019-08-29T08:49:20Z Stopping RPC
2019-08-29T08:49:20Z msghand thread exit
2019-08-29T08:49:20Z RPC stopped.
2019-08-29T08:49:20Z Stopping HTTP server
2019-08-29T08:49:20Z Waiting for HTTP worker threads to exit
2019-08-29T08:49:20Z libevent: event_del: 0xb8335494 (fd 9), callback 0xb6a01141
2019-08-29T08:49:20Z libevent: Epoll DEL(1) on fd 9 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)
2019-08-29T08:49:20Z libevent: event_del: 0xb83355fc (fd 10), callback 0xb6a01141
2019-08-29T08:49:20Z libevent: Epoll DEL(1) on fd 10 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)
2019-08-29T08:49:20Z Waiting for HTTP event thread to exit
2019-08-29T08:49:21Z ERROR: Error while reading proxy response
2019-08-29T08:49:21Z opencon thread exit
`
and this is where both bitcoind and bitcoin-cli hang.

This can be reproduced every time: start bitcoind. do anything with bitcoin-cli.

this is a self-compiled version of v0.18.1 for termux, the same happens on v0.18.0.

The machine is a Sony Xperia Z android 5 smartphone running termux on flash media.

I suspect it might be because of the bionic libs or libevent(_pthread), which is also modified because the native termux package doesn't contain the pthread-library. I can provide details on the compilation process if that's helpful. Maybe @esotericnonsense has any ideas, since he seems to have run bitcoind on termux before, though seemingly in a chroot.

@ryanofsky

This comment has been minimized.

Copy link
Contributor

@ryanofsky ryanofsky commented Aug 29, 2019

I haven't used bitcoin on termux, but I do use termux, and you may want to experiment with termux-wake-lock: https://wiki.termux.com/wiki/Termux-wake-lock because by default android is very keen to put background processes to sleep, and also to turn of the wifi radio to conserve battery, and termux-wake-lock prevents this.

@laanwj laanwj added the Linux/Unix label Aug 29, 2019
@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Aug 29, 2019

Thanks, @ryanofsky, for pointing out the command line tool. I wasn't aware of it, always activating the wake-lock in the Android UI. That said, this is not the problem here.

Bitcoind works fine when I run it in a proot ubuntu jail within termux. Only when compiling it for natively running in termux are there these (very deterministic) issues.

@ryanofsky

This comment has been minimized.

Copy link
Contributor

@ryanofsky ryanofsky commented Aug 29, 2019

Oh, I didn't realize you were running with proot inside termux, not instead of termux. It sounds like there are two possibly related problems here: 1) RPC commands being slow and 2) bitcoin hanging on shutdown.

The hang on shutdown might be easy to debug with a stack trace. You could compile bitcoin with --enable-debug and run it in a debugger (gdb -ex run --args /path/to/bitcoind -your-args-here). Then when the hang happens you could ctrl-c to the GDB prompt and run thread apply all bt to get a trace with the state of all threads.

It also seems likely the shutdown hang is related to the ERROR: Error while reading proxy response, and maybe worth trying without the socks5 proxy, if possible.

RPC commands responding slowly might be harder to debug. Though from the timestamps in the posted log, it at least seems like the stop RPC is being dispatched pretty quickly.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Aug 30, 2019

Interesting: The debugger immediately tells me this directly at program start:
Program received signal SIGILL, Illegal instruction. │···································· 0xb6e753c0 in ?? () from /data/data/com.termux/files/usr/lib/libcrypto.so.1.1

@Grimler91

This comment has been minimized.

Copy link

@Grimler91 Grimler91 commented Sep 13, 2019

Interesting: The debugger immediately tells me this directly at program start:
Program received signal SIGILL, Illegal instruction. │···································· 0xb6e753c0 in ?? () from /data/data/com.termux/files/usr/lib/libcrypto.so.1.1

That happens because libcrypto probes for hardware capabilities. You can run handle SIGILL pass nostop noprint in gdb to make gdb ignore it, see this stackexchange question: https://stackoverflow.com/questions/15071625/gdb-ddd-program-received-signal-sigill#15126760

@xeffyr

This comment has been minimized.

Copy link

@xeffyr xeffyr commented Sep 18, 2019

Issue unreproducible for latest bitcoin build from termux-packages master branch.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 18, 2019

confirmed. issue doesn't arise in master-branch (build on android API 24), but does persist in the same build with API 20.

Easy test: start bitcoind, terminate (CTRL-C) after startup. In the Android 5 (API 20) version, this doesn't stop the process, but logs

2019-09-18T13:19:40Z tor: Thread interrupt
2019-09-18T13:19:40Z addcon thread exit
2019-09-18T13:19:40Z Shutdown: In progress...
2019-09-18T13:19:40Z net thread exit
2019-09-18T13:19:41Z ERROR: Error while reading proxy response
2019-09-18T13:19:41Z opencon thread exit
2019-09-18T13:19:50Z UpdateTip: new best=000000000000000000079c43fb770154f8d5783a78017532491a6787d6282a24 height=595445 version=0x20000000 log2_work=91.102336 tx=456382083 date='2019-09-18T13:14:36Z' progress=0.
999997 cache=0.5MiB(4736txo) warning='51 of last 100 blocks have unexpected version'
2019-09-18T13:19:50Z msghand thread exit
2019-09-18T13:59:38Z Potential stale tip detected, will try using extra outbound peer (last tip update: 2388 seconds ago)
2019-09-18T14:10:08Z Potential stale tip detected, will try using extra outbound peer (last tip update: 3018 seconds ago)
2019-09-18T14:20:38Z Potential stale tip detected, will try using extra outbound peer (last tip update: 3648 seconds ago)
2019-09-18T14:31:08Z Potential stale tip detected, will try using extra outbound peer (last tip update: 4278 seconds ago)
2019-09-18T14:41:38Z Potential stale tip detected, will try using extra outbound peer (last tip update: 4908 seconds ago)
2019-09-18T14:52:08Z Potential stale tip detected, will try using extra outbound peer (last tip update: 5538 seconds ago)
2019-09-18T15:02:38Z Potential stale tip detected, will try using extra outbound peer (last tip update: 6168 seconds ago)
2019-09-18T15:13:08Z Potential stale tip detected, will try using extra outbound peer (last tip update: 6798 seconds ago)
2019-09-18T15:23:38Z Potential stale tip detected, will try using extra outbound peer (last tip update: 7428 seconds ago)

This might give some insight into what thread stays alive.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 18, 2019

the logs suggest that scheduler thread interrupt doesn't happen in the faulty builds.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 23, 2019

The hang on shutdown might be easy to debug with a stack trace. You could compile bitcoin with --enable-debug and run it in a debugger (gdb -ex run --args /path/to/bitcoind -your-args-here). Then when the hang happens you could ctrl-c to the GDB prompt and run thread apply all bt to get a trace with the state of all threads.

Running in gdb (and skipping the illegal instruction) is interesting, because after sending signal 2 once, bitcoind hangs, but after sending a second signal 2 (from gdb), it actually terminates (unlike without gdb). Here's the state of all threads after hanging:

Thread 13 (LWP 15955):
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb14bc in __pthread_cond_timedwait_relative(pthread_cond_t*, pthread_mutex_t*, timespec const*) () from /system/lib/libc.so
#2  0x2a2f33d4 in leveldb::(anonymous namespace)::PosixEnv::BGThread (this=<optimized out>) at leveldb/util/env_posix.cc:649
#3  0x2a2f32bc in leveldb::(anonymous namespace)::PosixEnv::BGThreadWrapper (arg=0x0) at leveldb/util/env_posix.cc:564
#4  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#5  0xb6caf514 in __start_thread () from /system/lib/libc.so
#6  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 12 (LWP 15954):
#0  0xb6cd7634 in __epoll_pwait () from /system/lib/libc.so
#1  0xb6caf7b2 in epoll_pwait () from /system/lib/libc.so
#2  0xb6caf7c0 in epoll_wait () from /system/lib/libc.so
#3  0xb6db3e9e in ?? () from /data/data/com.termux/files/usr/lib/libzmq.so
#4  0xb6dd28e4 in ?? () from /data/data/com.termux/files/usr/lib/libzmq.so
#5  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#6  0xb6caf514 in __start_thread () from /system/lib/libc.so
#7  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 11 (LWP 15953):
#0  0xb6cd7634 in __epoll_pwait () from /system/lib/libc.so
#1  0xb6caf7b2 in epoll_pwait () from /system/lib/libc.so
#2  0xb6caf7c0 in epoll_wait () from /system/lib/libc.so
#3  0xb6db3e9e in ?? () from /data/data/com.termux/files/usr/lib/libzmq.so
#4  0xb6dd28e4 in ?? () from /data/data/com.termux/files/usr/lib/libzmq.so
#5  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#6  0xb6caf514 in __start_thread () from /system/lib/libc.so
#7  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 6 (LWP 15942):
#0  0xb6cd7634 in __epoll_pwait () from /system/lib/libc.so
#1  0xb6caf7b2 in epoll_pwait () from /system/lib/libc.so
#2  0xb6caf7c0 in epoll_wait () from /system/lib/libc.so
#3  0xb6e0bdc4 in ?? () from /data/data/com.termux/files/usr/lib/libevent-2.1.so
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 5 (LWP 15941):
--Type <RET> for more, q to quit, c to continue without paging--
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb14bc in __pthread_cond_timedwait_relative(pthread_cond_t*, pthread_mutex_t*, timespec const*) () from /system/lib/libc.so
#2  0xb6cb1500 in __pthread_cond_timedwait(pthread_cond_t*, pthread_mutex_t*, timespec const*, int) () from /system/lib/libc.so
#3  0x2a292770 in boost::condition_variable::do_wait_until (this=0x2a527bfc <scheduler+12>, m=..., timeout=...) at /data/data/com.termux/files/usr/include/boost/thread/pthread/condition_variable.hpp:122
#4  0x2a291210 in boost::condition_variable::wait_until<boost::chrono::system_clock, boost::chrono::duration<long long, boost::ratio<1ll, 1000000000ll> > > (this=0x2c, lock=..., t=...) at /data/data/com.termux/files/usr/include/boost/thread/pthread/condition_variable_fwd.hpp:271
#5  0x2a2908da in CScheduler::serviceQueue (this=0x2a527bf0 <scheduler>) at scheduler.cpp:66
#6  0x2a048602 in std::__ndk1::__bind<void (CScheduler::*)(), CScheduler*>::operator()<> (this=0xb4790d3c) at /home/builder/.termux-build/_cache/android5-r20-api-21-v1/bin/../sysroot/usr/include/c++/v1/functional:2677
#7  0x2a035d84 in TraceThread<std::__ndk1::function<void ()> >(char const*, std::__ndk1::function<void ()>) (name=0x2a468145 "scheduler", func=...) at ./util/system.h:332
#8  0x2a048a46 in std::__ndk1::__invoke<void (*&)(char const*, std::__ndk1::function<void ()>), char const*&, std::__ndk1::function<void ()>&> (__f=<optimized out>, __args=..., __args=...) at /home/builder/.termux-build/_cache/android5-r20-api-21-v1/bin/../sysroot/usr/include/c++/v1/type_traits:4353
#9  0x2a0489b2 in std::__ndk1::__bind<void (*)(char const*, std::__ndk1::function<void ()>), char const (&) [10], std::__ndk1::function<void ()>&>::operator()<> (this=0x2a6492c0) at /home/builder/.termux-build/_cache/android5-r20-api-21-v1/bin/../sysroot/usr/include/c++/v1/functional:2677
#10 0xb6fc0d48 in ?? () from /data/data/com.termux/files/usr/lib/libboost_thread.so.1.70.0
#11 0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#12 0xb6caf514 in __start_thread () from /system/lib/libc.so
#13 0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)


Thread 4 (LWP 15940):
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb14bc in __pthread_cond_timedwait_relative(pthread_cond_t*, pthread_mutex_t*, timespec const*) () from /system/lib/libc.so
#2  0x2a038486 in boost::condition_variable::wait (this=0x2a529200 <scriptcheckqueue+4>, m=...) at /data/data/com.termux/files/usr/include/boost/thread/pthread/condition_variable.hpp:79
#3  0x2a18116e in CCheckQueue<CScriptCheck>::Loop (this=0x2a5291fc <scriptcheckqueue>, fMaster=false) at ./checkqueue.h:99
#4  0xb6fc0d48 in ?? () from /data/data/com.termux/files/usr/lib/libboost_thread.so.1.70.0
#5  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#6  0xb6caf514 in __start_thread () from /system/lib/libc.so
#7  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 3 (LWP 15939):
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb14bc in __pthread_cond_timedwait_relative(pthread_cond_t*, pthread_mutex_t*, timespec const*) () from /system/lib/libc.so
#2  0x2a038486 in boost::condition_variable::wait (this=0x2a529200 <scriptcheckqueue+4>, m=...) at /data/data/com.termux/files/usr/include/boost/thread/pthread/condition_variable.hpp:79
#3  0x2a18116e in CCheckQueue<CScriptCheck>::Loop (this=0x2a5291fc <scriptcheckqueue>, fMaster=false) at ./checkqueue.h:99
#4  0xb6fc0d48 in ?? () from /data/data/com.termux/files/usr/lib/libboost_thread.so.1.70.0
#5  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
--Type <RET> for more, q to quit, c to continue without paging--
#6  0xb6caf514 in __start_thread () from /system/lib/libc.so
#7  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 2 (LWP 15938):
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb14bc in __pthread_cond_timedwait_relative(pthread_cond_t*, pthread_mutex_t*, timespec const*) () from /system/lib/libc.so
#2  0x2a038486 in boost::condition_variable::wait (this=0x2a529200 <scriptcheckqueue+4>, m=...) at /data/data/com.termux/files/usr/include/boost/thread/pthread/condition_variable.hpp:79
#3  0x2a18116e in CCheckQueue<CScriptCheck>::Loop (this=0x2a5291fc <scriptcheckqueue>, fMaster=false) at ./checkqueue.h:99
#4  0xb6fc0d48 in ?? () from /data/data/com.termux/files/usr/lib/libboost_thread.so.1.70.0
#5  0xb6cb15e8 in __pthread_start(void*) () from /system/lib/libc.so
#6  0xb6caf514 in __start_thread () from /system/lib/libc.so
#7  0x00000000 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 1 (LWP 15885):
#0  0xb6cada88 in syscall () from /system/lib/libc.so
#1  0xb6cb1bca in pthread_join () from /system/lib/libc.so
#2  0xb6d7a82c in ?? () from /data/data/com.termux/files/usr/lib/libc++_shared.so
#3  0x2a1c5834 in StopHTTPServer () at httpserver.cpp:468
#4  0x2a02ace6 in Shutdown (interfaces=...) at init.cpp:211
#5  0x2a0259e4 in AppInit (argc=<optimized out>, argv=<optimized out>) at bitcoind.cpp:185
#6  0x2a02558c in main (argc=-1268195320, argv=0x0) at bitcoind.cpp:201
`
@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 23, 2019

Btw, these are the logs around the shutdown. Looks to me as if the http event thread is the culprit.

2019-09-23T09:32:48Z Shutdown requested. Exiting.                                                        
2019-09-23T09:32:48Z Interrupting HTTP server                                                            
[LWP 15943 exited]                                                                                                                                                                                                 
[LWP 15950 exited]                                                                                                                                                                                                 
[LWP 15944 exited]                                                                                                                                                                                                 
[LWP 15949 exited]                                                                                                                                                                                                 
2019-09-23T09:32:48Z Interrupting HTTP RPC server                                                        
2019-09-23T09:32:48Z Interrupting RPC                                                                    
2019-09-23T09:32:48Z Shutdown: In progress...                                                            
2019-09-23T09:32:48Z Stopping HTTP RPC server                                                            
2019-09-23T09:32:48Z Unregistering HTTP handler for / (exactmatch 1)                                     
2019-09-23T09:32:48Z Unregistering HTTP handler for /wallet/ (exactmatch 0)                              
2019-09-23T09:32:48Z Stopping RPC                                                                        
2019-09-23T09:32:48Z RPC stopped.                                                                                                                                                                                  
2019-09-23T09:32:48Z Stopping HTTP server                                                                                                                                                                          
2019-09-23T09:32:48Z Waiting for HTTP worker threads to exit                                                                                                                                                       
2019-09-23T09:32:48Z libevent: event_del: 0x2a67d83c (fd 9), callback 0xb6e0a699                                                                                                                                   
2019-09-23T09:32:48Z libevent: Epoll DEL(1) on fd 9 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)                                                         
2019-09-23T09:32:48Z libevent: event_del: 0x2a67d9b4 (fd 10), callback 0xb6e0a699                        
2019-09-23T09:32:48Z libevent: Epoll DEL(1) on fd 10 okay. Old events were 2; read change was 2 (del); write change was 0 (none); close change was 0 (none)                                                        
2019-09-23T09:32:48Z Waiting for HTTP event thread to exit        

(gdb) signal 2
Continuing with signal SIGINT.
2019-09-23T09:45:03Z libevent: event_base_loop: no events registered.
2019-09-23T09:45:03Z Exited http event loop
2019-09-23T09:45:03Z libevent: event_base_free_: 0 events freed
2019-09-23T09:45:03Z Stopped HTTP server
[LWP 15942 exited]
2019-09-23T09:45:04Z scheduler thread interrupt
[LWP 15941 exited]
[LWP 15939 exited]
[LWP 15938 exited]
[LWP 15940 exited]
2019-09-23T09:45:04Z WriteBatch memory usage: db=index, before=0.1MiB, after=0.1MiB
2019-09-23T09:45:04Z Writing final batch of 0.00 MiB
2019-09-23T09:45:04Z WriteBatch memory usage: db=chainstate, before=4.0MiB, after=4.0MiB
2019-09-23T09:45:04Z Committed 0 changed transaction outputs (out of 0) to coin database...
2019-09-23T09:45:04Z WriteBatch memory usage: db=index, before=0.1MiB, after=0.1MiB
2019-09-23T09:45:04Z Writing final batch of 0.00 MiB
2019-09-23T09:45:04Z WriteBatch memory usage: db=chainstate, before=4.0MiB, after=4.0MiB
2019-09-23T09:45:04Z Committed 0 changed transaction outputs (out of 0) to coin database...
2019-09-23T09:45:04Z zmq: Shutdown notification interface
2019-09-23T09:45:04Z zmq: Shutdown notifier pubrawblock at tcp://127.0.0.1:28332
2019-09-23T09:45:04Z zmq: Close socket at address tcp://127.0.0.1:28332
2019-09-23T09:45:04Z zmq: Shutdown notifier pubrawtx at tcp://127.0.0.1:28333
2019-09-23T09:45:04Z zmq: Close socket at address tcp://127.0.0.1:28333
[LWP 15953 exited]
[LWP 15954 exited]
2019-09-23T09:45:04Z Shutdown: done
[LWP 15885 exited]
[Inferior 1 (process 15885) exited with code 01]
@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 24, 2019

Issue unreproducible for latest bitcoin build from termux-packages master branch.

The only noticeable difference between the master (ndk 24) and android-5 (ndk-21) builds that I have found so far is that ldd on android-5 gives
libboost_system.so.1.70.0 as an additional needed lib that doesn't seem to be needed in master. I don't know why that is, since the build recipes seem to be the same.

@xeffyr

This comment has been minimized.

Copy link

@xeffyr xeffyr commented Sep 24, 2019

@stefanwouldgo There noticeable differences in used libc on Android 5 and Android 7+ devices.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Sep 25, 2019

@stefanwouldgo There noticeable differences in used libc on Android 5 and Android 7+ devices.

I don't think libc should be the culprit, because the working builds for Android 5 (with all dependencies included from the bitcoin repo) still dynamically link to libc.

@laanwj laanwj added the Android label Sep 30, 2019
@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Oct 1, 2019

I've now tried to replace every dependency except openssl with the one in depends, with no apparent effect. So my current theory is that the problem is in openssl. Unfortunately, the earliest existing termux version of this is already beyond 1.0.1k from depends (and all versions are heavily patched), and I haven't been able to use only openssl from depends (but not the other dependencies).

@laanwj

This comment has been minimized.

Copy link
Member

@laanwj laanwj commented Oct 2, 2019

FWIW: OpenSSL is not a dependency of recent versions of Bitcoin Core, definitely not without the GUI, and recently not even with the GU unless --enable-bip70 is provided.

So I strongly doubt it can cause this behavior.

@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Oct 7, 2019

Problem persists on my arm/Android-5, but also doesn't appear on aarch-64/Android-6. Can anybody try and verify independently on arm/Android<7? All you need to do is install termux,

pkg update

pkg install bitcoin

(this should install 0.18.1-1 on arm, if it installs 0.18.1-3 then the termux-devs might have pulled my request including full static depends which doesn't have the issue)

 bitcoind 

 CTRL-C

then wait if bitcoind fully terminates or hangs at Shutdown: In progress...

stefanwouldgo added a commit to stefanwouldgo/termux-packages that referenced this issue Dec 19, 2019
openssl hasn't really been used when compiling without GUI for a long time. See bitcoin/bitcoin#16751 (comment)
@stefanwouldgo

This comment has been minimized.

Copy link
Contributor Author

@stefanwouldgo stefanwouldgo commented Dec 19, 2019

FWIW: OpenSSL is not a dependency of recent versions of Bitcoin Core, definitely not without the GUI, and recently not even with the GU unless --enable-bip70 is provided.

So I strongly doubt it can cause this behavior.

Yep, 0.19.0.1 does have the same issue, so openssl cannot be the culprit.

It also seems likely the shutdown hang is related to the ERROR: Error while reading proxy response, and maybe worth trying without the socks5 proxy, if possible.

That doesn't seem to be related. The same error crops up in a working build (with full dependencies), but doesn't lead to the described behavior.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.