kyuupichan / electrumx

Alternative implementation of spesmilo/electrum-server
Other
724 stars 733 forks source link

Can't run with nuitka #855

Closed spiccioli closed 5 years ago

spiccioli commented 5 years ago

On a fedora 29, I can build electrumx ok with nuitka ( https://nuitka.net/ )

 $ dnf list nuitka
 nuitka.noarch         0.6.4-5.1

 $ python3 -m nuitka electrumx_server -o electrumx_server.bin --follow-imports

while trying to squeeze out my pc some more, I have a lot of timeouts when clients go past 800-1000 even with two-three cores doing nothing, but when I run the resulting binary file it stops nearly immediatly with:

Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:electrumx:ElectrumX server starting Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:electrumx:logging level: INFO Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:Python version: 3.7.3 (default, May 11 2019, 00:45:16) [GCC 8.3.1 20190223 (Red Hat 8.3.1-2)] Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:software version: ElectrumX 1.12 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:aiorpcX version: 0.18.3 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:supported protocol versions: 1.4-1.4.2 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:event loop policy: None Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Controller:reorg limit is 200 blocks Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:Daemon:daemon #1 at 10.2.1.23:8332/ (current) Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:switching current directory to /home/electrumx/db Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:using leveldb for DB backend Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:opened UTXO DB (for sync: True) Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:DB version: 6 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:coin: BitcoinSegwit Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:network: mainnet Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:height: 583,454 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:tip: 00000000000000000020347221eab352d82a9261140bc059dbb6b5ee01e79d80 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:tx count: 430,704,560 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:flushing DB cache at 1,200 MB Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:History:history DB version: 0 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:History:flush count: 10,422 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:deleted 4 stale undo entries Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:BlockProcessor:caught up to height 583454 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:closing DBs to re-open for serving Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:opened UTXO DB (for sync: False) Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:DB version: 6 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:coin: BitcoinSegwit Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:network: mainnet Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:height: 583,454 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:tip: 00000000000000000020347221eab352d82a9261140bc059dbb6b5ee01e79d80 Jul 2 15:15:57 fedora electrumx_server.bin[5289]: INFO:DB:tx count: 430,704,560 Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:History:history DB version: 0 Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:History:flush count: 10,422 Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:DB:populating header merkle cache... Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:MemPool:beginning processing of daemon mempool. This can take some time... Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:SessionManager:RPC server listening on localhost:8000 Jul 2 15:15:58 fedora electrumx_server.bin[5289]: INFO:Prefetcher:caught up to daemon height 583,454 Jul 2 15:16:00 fedora electrumx_server.bin[5289]: INFO:DB:header merkle cache populated in 2.6s Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:MemPool:synced in 29.12s Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:MemPool:compact fee histogram: [(178, 114819), (122, 95789), (100, 170919), (97, 102886), (93, 167813), (90, 132330), (87, 232994), (83, 130784), (80, 232029), (78, 371236), (76, 288823), (75, 458646), (74, 54265), (69, 248857), (63, 398303), (55, 412667), (47, 447577), (45, 3189911), (44, 45116), (43, 17846), (42, 4675), (41, 7234), (21, 677104), (16, 851672), (11, 1173114), (9, 1225991), (5, 1200172), (2, 2337105), (1, 8416595)] Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:MemPool:25,433 txs 23.21 MB touching 116,028 addresses Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:max session count: 900 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:session timeout: 500 seconds Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:session cost hard limit 0 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:session cost soft limit 0 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:bandwidth unit cost 5,000 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:request sleep 0ms Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:request timeout 30s Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:initial concurrent 1 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:max response size 1,000,000 bytes Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:advertising service ssl://electrumx......:50002 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:SSL server listening on all_interfaces:50002 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:peer discovery: ON Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:announce ourself: True Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:my clearnet self: electrumx....... Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:force use of proxy: False Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:beginning peer discovery... Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:trying to detect proxy on "localhost" ports [9050, 9150, 1080] Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer electrumx....... from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer btc.smsys.me from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer E-X.not.fyi from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer electrum.vom-stausee.de from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer electrum.hsmiths.com from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer helicarrier.bauerj.eu from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:PeerManager:accepted new peer node.arihanc.com from env Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:closing down server for ssl://all_interfaces:50002 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: INFO:SessionManager:closing down server for rpc://localhost:8000 Jul 2 15:16:27 fedora electrumx_server.bin[5289]: ERROR:Prefetcher:ignoring unexpected exception Jul 2 15:16:27 fedora electrumx_server.bin[5289]: Traceback (most recent call last): Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/home/electrumx/electrumx/electrumx/server/block_processor.py", line 55, in main_loop Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await asyncio.sleep(self.polling_delay) Jul 2 15:16:27 fedora electrumx_server.bin[5289]: RuntimeError: cannot reuse already awaited coroutine Jul 2 15:16:27 fedora electrumx_server.bin[5289]: ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /home/electrumx/electrumx/electrumx/server/controller.py:81> exception=RuntimeError('cannot reuse already awaited coroutine')> Jul 2 15:16:27 fedora electrumx_server.bin[5289]: Traceback (most recent call last): Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/util.py", line 309, in check_task Jul 2 15:16:27 fedora electrumx_server.bin[5289]: task.result() Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/home/electrumx/electrumx/electrumx/server/controller.py", line 131, in serve Jul 2 15:16:27 fedora electrumx_server.bin[5289]: async with TaskGroup() as group: Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 242, in aexit Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await self.join() Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 208, in join Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await self.cancel_remaining() Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 221, in cancel_remaining Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await task Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/home/electrumx/electrumx/electrumx/server/mempool.py", line 332, in keep_synchronized Jul 2 15:16:27 fedora electrumx_server.bin[5289]: async with TaskGroup() as group: Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 242, in aexit Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await self.join() Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 208, in join Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await self.cancel_remaining() Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 221, in cancel_remaining Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await task Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/home/electrumx/electrumx/electrumx/server/mempool.py", line 138, in _refresh_histogram Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await sleep(self.coin.MEMPOOL_HISTOGRAM_REFRESH_SECS) Jul 2 15:16:27 fedora electrumx_server.bin[5289]: RuntimeError: cannot reuse already awaited coroutine Jul 2 15:17:51 fedora electrumx_server.bin[5289]: WARNING:Controller:received SIGTERM signal, initiating shutdown Jul 2 15:17:51 fedora electrumx_server.bin[5289]: INFO:Controller:shutting down Jul 2 15:17:51 fedora electrumx_server.bin[5289]: INFO:Controller:shutdown complete Jul 2 15:17:51 fedora electrumx_server.bin[5289]: INFO:electrumx:ElectrumX server terminated normally

I'm reporting this just as a FYI issue while I was playing around with nuitka.

BTW, running it with PyPy memory consumption keeps growing past the available memory on my PC, 32GB, so I had to revert back to plain python.

SomberNight commented 5 years ago

Well it seems the error is with asyncio.sleep.

...
Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 221, in cancel_remaining
Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await task
Jul 2 15:16:27 fedora electrumx_server.bin[5289]: File "/home/electrumx/electrumx/electrumx/server/mempool.py", line 138, in _refresh_histogram
Jul 2 15:16:27 fedora electrumx_server.bin[5289]: await sleep(self.coin.MEMPOOL_HISTOGRAM_REFRESH_SECS)
Jul 2 15:16:27 fedora electrumx_server.bin[5289]: RuntimeError: cannot reuse already awaited coroutine

I don't see how that sleep coroutine would be reused, or why this does not raise using CPython. This is probably specific to nuitka. In fact, is this https://github.com/Nuitka/Nuitka/issues/213 ?

spiccioli commented 5 years ago

Hi,

thanks for the info it seems to be #213, but sadly the proposed solution, that is include asyncio does not work here:

$ python3 --version Python 3.7.3

$ python3 -m nuitka electrumx_server -o electrumx_server.bin --follow-imports --include-package=asyncio

builds OK but fails similarly:

Jul 3 13:08:12 fedora electrumx_server.bin[28700]: INFO:BlockProcessor:flushing to DB for a clean shutdown... Jul 3 13:08:12 fedora electrumx_server.bin[28700]: ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /home/electrumx/electrumx/electrumx/server/controller.py:81> exception=RuntimeError('cannot reuse already awaited compiled_coroutine')> Jul 3 13:08:12 fedora electrumx_server.bin[28700]: Traceback (most recent call last): Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/util.py", line 309, in check_task Jul 3 13:08:12 fedora electrumx_server.bin[28700]: task.result() Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/home/electrumx/electrumx/electrumx/server/controller.py", line 131, in serve Jul 3 13:08:12 fedora electrumx_server.bin[28700]: async with TaskGroup() as group: Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 242, in aexit Jul 3 13:08:12 fedora electrumx_server.bin[28700]: await self.join() Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 208, in join Jul 3 13:08:12 fedora electrumx_server.bin[28700]: await self.cancel_remaining() Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 221, in cancel_remaining Jul 3 13:08:12 fedora electrumx_server.bin[28700]: await task Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/home/electrumx/electrumx/electrumx/server/block_processor.py", line 663, in fetch_and_process_blocks Jul 3 13:08:12 fedora electrumx_server.bin[28700]: async with TaskGroup() as group: Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 242, in aexit Jul 3 13:08:12 fedora electrumx_server.bin[28700]: await self.join() Jul 3 13:08:12 fedora electrumx_server.bin[28700]: File "/usr/local/lib64/python3.7/site-packages/aiorpcx/curio.py", line 208, in join Jul 3 13:08:12 fedora electrumx_server.bin[28700]: await self.cancel_remaining() Jul 3 13:08:12 fedora electrumx_server.bin[28700]: RuntimeError: cannot reuse already awaited compiled_coroutine Jul 3 13:11:10 fedora electrumx_server.bin[28700]: WARNING:Controller:received SIGTERM signal, initiating shutdown