electrumx
electrumx copied to clipboard
Published
20 hours ago •
kyuupichan
kyuupichan
Random crash every ~30 minutes (BitcoinSV)
I am experience a very weird situation where electrumX is shutting down every ~30 minutes of operation with the following log/trace.
Coin: BitcoinSV ElectrumX: latest Services: RPC, WebSockets OS: Ubuntu 19.04 (in Docker)
2020-02-23 16:59:57,961:INFO:MemPool:9,722 txs 4.95 MB touching 16,060 addresses
2020-02-23 17:00:14,817:INFO:SessionManager:closing stale session ids 1188, 1189, 1191
2020-02-23 17:00:58,422:INFO:MemPool:10,057 txs 5.13 MB touching 16,714 addresses
2020-02-23 17:00:58,427:INFO:MemPool:compact fee histogram: [(1, 296155), (0, 4830318)]
2020-02-23 17:01:08,984:INFO:ElectrumX:[1355] WSS XXX.XXX.XXX.XXX:64322, 62 total
2020-02-23 17:01:14,818:INFO:SessionManager:closing stale session ids 1205, 1207, 1208
2020-02-23 17:01:17,312:INFO:ElectrumX:[1356] WSS XXX.XXX.XXX.XXX:58360, 56 total
2020-02-23 17:01:18,479:INFO:Prefetcher:new block height 623,338 hash 000000000000000001d98fc86bc30b4e213868b4ccbac220c22a72c99953d038
2020-02-23 17:01:19,646:INFO:DB:flush #981 took 0.1s. Height 623,338 txs: 360,376,515 (+3,083)
2020-02-23 17:01:19,646:INFO:BlockProcessor:processed 1 block size 2.66 MB in 1.0s
2020-02-23 17:01:20,507:INFO:ElectrumX:[1359] WSS XXX.XXX.XXX.XXX:59456, 59 total
2020-02-23 17:01:24,603:INFO:ElectrumX:[1283] notified of 1 address
2020-02-23 17:01:24,603:INFO:ElectrumX:[1308] notified of 1 address
2020-02-23 17:01:24,604:INFO:ElectrumX:[1314] notified of 1 address
2020-02-23 17:01:24,604:INFO:ElectrumX:[1336] notified of 1 address
2020-02-23 17:01:24,604:INFO:ElectrumX:[1340] notified of 1 address
2020-02-23 17:01:25,481:INFO:SessionManager:closing down server for ws://0.0.0.0:5104
2020-02-23 17:01:25,481:INFO:SessionManager:closing down server for rpc://0.0.0.0:2104
2020-02-23 17:01:25,481:INFO:SessionManager:closing down server for wss://0.0.0.0:6104
2020-02-23 17:01:29,907:INFO:Prefetcher:cancelled; prefetcher stopping
2020-02-23 17:01:29,908:INFO:BlockProcessor:flushing to DB for a clean shutdown...
2020-02-23 17:01:29,908:INFO:Controller:shutting down
2020-02-23 17:01:29,909:INFO:Controller:shutdown complete
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.7/dist-packages/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'")>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
Error in connection handler
Traceback (most recent call last):
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/server.py", line 191, in handler
await self.ws_handler(self, path)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 54, in ws_server
await transport.process_messages()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 72, in process_messages
await self.session.process_messages(self.recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 217, in process_messages
await self._group.spawn(self._process_messages, recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 195, in join
task = await self.next_done()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 161, in next_done
await self._done_event.wait()
File "/usr/lib/python3.7/asyncio/locks.py", line 293, in wait
await fut
concurrent.futures._base.CancelledError
Error in connection handler
Traceback (most recent call last):
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/server.py", line 191, in handler
await self.ws_handler(self, path)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 54, in ws_server
await transport.process_messages()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 72, in process_messages
await self.session.process_messages(self.recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 217, in process_messages
await self._group.spawn(self._process_messages, recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 195, in join
task = await self.next_done()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 161, in next_done
await self._done_event.wait()
File "/usr/lib/python3.7/asyncio/locks.py", line 293, in wait
await fut
concurrent.futures._base.CancelledError
Error in connection handler
Traceback (most recent call last):
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/server.py", line 191, in handler
await self.ws_handler(self, path)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 54, in ws_server
await transport.process_messages()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 72, in process_messages
await self.session.process_messages(self.recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 217, in process_messages
await self._group.spawn(self._process_messages, recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 195, in join
task = await self.next_done()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 161, in next_done
await self._done_event.wait()
File "/usr/lib/python3.7/asyncio/locks.py", line 293, in wait
await fut
concurrent.futures._base.CancelledError
2020-02-23 17:01:40,036:ERROR:electrumx:ElectrumX server terminated abnormally
Traceback (most recent call last):
File "electrumx_server", line 35, in main
asyncio.run(controller.run())
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
Also getting randomly the following exceptions, don't know if related.
2020-02-23 16:56:23,241:INFO:ElectrumX:[1296] WSS XXX.XXX.XXX.XXX:52886, 76 total
Task exception was never retrieved
future: <Task finished coro=<RPCSession._process_messages() done, defined at /usr/local/lib/python3.7/dist-packages/aiorpcx/session.py:432> exception=ConnectionClosedOK('code = 1000 (OK), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 435, in _process_messages
message = await recv_message()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 63, in recv_message
message = await self.websocket.recv()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 509, in recv
await self.ensure_open()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 812, in ensure_open
raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedOK: code = 1000 (OK), no reason
2020-02-23 16:56:25,560:INFO:ElectrumX:[1259] notified of 1 address
I'll continue investigating the issue. Any insights are welcome.
What is the version of your websockets? I'm using 7.0; not sure if newer or older, but yours seems incompatible
Was using websockets 8.1, went back to 7.0 Unfortunately crashed again.
$ pip3 show websockets
Name: websockets
Version: 7.0
Including the logs, maybe you see something interesting.
2020-02-23 23:10:20,552:INFO:Prefetcher:new block height 623,382 hash 00000000000000000192d405cab6e08401aaeef581dc8c0ca1ef3b64e0f625a6
2020-02-23 23:10:21,508:INFO:DB:flush #773 took 0.0s. Height 623,382 txs: 360,474,515 (+2,889)
2020-02-23 23:10:21,509:INFO:BlockProcessor:processed 1 block size 2.97 MB in 0.8s
2020-02-23 23:10:32,370:INFO:SessionManager:closing down server for rpc://0.0.0.0:2104
2020-02-23 23:10:32,370:INFO:SessionManager:closing down server for ws://0.0.0.0:5104
2020-02-23 23:10:32,370:INFO:SessionManager:closing down server for wss://0.0.0.0:6104
2020-02-23 23:10:33,540:INFO:Prefetcher:cancelled; prefetcher stopping
2020-02-23 23:10:33,540:INFO:BlockProcessor:flushing to DB for a clean shutdown...
2020-02-23 23:10:33,541:INFO:Controller:shutting down
2020-02-23 23:10:33,541:INFO:Controller:shutdown complete
Error in closing handshake
Traceback (most recent call last):
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/server.py", line 177, in handler
yield from self.close()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 561, in close
yield from asyncio.shield(self.close_connection_task)
concurrent.futures._base.CancelledError
Error in connection handler
Traceback (most recent call last):
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/server.py", line 169, in handler
yield from self.ws_handler(self, path)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 54, in ws_server
await transport.process_messages()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 72, in process_messages
await self.session.process_messages(self.recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 217, in process_messages
await self._group.spawn(self._process_messages, recv_message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 195, in join
task = await self.next_done()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 161, in next_done
await self._done_event.wait()
File "/usr/lib/python3.7/asyncio/locks.py", line 293, in wait
await fut
concurrent.futures._base.CancelledError
2020-02-23 23:10:33,568:ERROR:electrumx:ElectrumX server terminated abnormally
Traceback (most recent call last):
File "electrumx_server", line 35, in main
asyncio.run(controller.run())
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/electrumx/server/session.py", line 766, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Thanks
BSV always crashes recently, stops at block 622559, it runs in a docker container:
INFO:Controller:Python version: 3.7.2 (default, Mar 7 2019, 22:40:59)
[GCC 8.2.0]
INFO:Controller:software version: ElectrumX 1.9.5
INFO:Controller:aiorpcX version: 0.10.5
INFO:Controller:supported protocol versions: 1.2-1.4.1
INFO:Controller:event loop policy: None
INFO:Controller:reorg limit is 200 blocks
INFO:Daemon:daemon #1 at bsv:8332/ (current)
INFO:DB:switching current directory to /data
INFO:DB:using leveldb for DB backend
INFO:DB:opened UTXO DB (for sync: True)
INFO:DB:DB version: 6
INFO:DB:coin: BitcoinSV
INFO:DB:network: mainnet
INFO:DB:height: 622,559
INFO:DB:tip: 00000000000000000215d64ff5398461b2214daab9005edc246a4ab5782ac755
INFO:DB:tx count: 356,748,088
INFO:DB:flushing DB cache at 1,200 MB
INFO:History:history DB version: 0
INFO:History:flush count: 706
INFO:SessionManager:RPC server listening on 127.0.0.1:8088
INFO:Prefetcher:catching up to daemon height 623,677 (1,118 blocks behind)
INFO:BlockProcessor:flushing to DB for a clean shutdown...
INFO:SessionManager:closing down RPC listening servers
ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /electrumx/electrumx/server/controller.py:81> exception=AssertionError()>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/aiorpcx/util.py", line 119, in check_task
task.result()
File "/electrumx/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 240, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 207, in join
raise task.exception()
File "/electrumx/electrumx/server/block_processor.py", line 662, in fetch_and_process_blocks
await self.flush(True)
File "/electrumx/electrumx/server/block_processor.py", line 335, in flush
await self.run_in_thread_with_lock(flush)
File "/electrumx/electrumx/server/block_processor.py", line 191, in run_in_thread_with_lock
return await asyncio.shield(run_in_thread_locked())
File "/electrumx/electrumx/server/block_processor.py", line 190, in run_in_thread_locked
return await run_in_thread(func, *args)
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 68, in run_in_thread
return await get_event_loop().run_in_executor(None, func, *args)
File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/electrumx/electrumx/server/block_processor.py", line 334, in flush
self.estimate_txs_remaining)
File "/electrumx/electrumx/server/db.py", line 189, in flush_dbs
self.assert_flushed(flush_data)
File "/electrumx/electrumx/server/db.py", line 179, in assert_flushed
assert not flush_data.block_tx_hashes
AssertionError
Here is error message from another docker instance:
ERROR:MemPool:1 txs dropped
INFO:MemPool:100,694 txs touching 75,443 addresses
INFO:ElectrumX:[151600] TCP 172.21.0.1:55340, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151601] TCP 172.21.0.1:55538, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151602] TCP 172.21.0.1:55736, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151603] TCP 172.21.0.1:55930, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151604] TCP 172.21.0.1:56130, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151605] TCP 172.21.0.1:56318, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151606] TCP 172.21.0.1:56512, 1 total
ERROR:MemPool:1 txs dropped
INFO:MemPool:101,378 txs touching 75,916 addresses
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151607] TCP 172.21.0.1:56710, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151608] TCP 172.21.0.1:56902, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151609] TCP 172.21.0.1:57098, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151610] TCP 172.21.0.1:57298, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151611] TCP 172.21.0.1:57492, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151612] TCP 172.21.0.1:57690, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:MemPool:102,042 txs touching 76,375 addresses
INFO:ElectrumX:[151613] TCP 172.21.0.1:57888, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151614] TCP 172.21.0.1:58080, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151615] TCP 172.21.0.1:58268, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151616] TCP 172.21.0.1:58470, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151617] TCP 172.21.0.1:58664, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151618] TCP 172.21.0.1:58858, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151619] TCP 172.21.0.1:59058, 1 total
ERROR:MemPool:1 txs dropped
INFO:MemPool:102,667 txs touching 76,771 addresses
INFO:ElectrumX:[151620] TCP 172.21.0.1:59246, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151621] TCP 172.21.0.1:59436, 1 total
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151622] TCP 172.21.0.1:59636, 1 total
ERROR:MemPool:1 txs dropped
ERROR:MemPool:1 txs dropped
INFO:ElectrumX:[151623] TCP 172.21.0.1:59822, 1 total
ERROR:MemPool:1 txs dropped
INFO:Prefetcher:new block height 622,560 hash 0000000000000000017b858f02e0c873083b623562ba48f42cbefd61e4d7498c
INFO:ElectrumX:[151624] TCP 172.21.0.1:60016, 1 total
INFO:BlockProcessor:flushing to DB for a clean shutdown...
INFO:SessionManager:closing down RPC, TCP, SSL listening servers
ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /electrumx/electrumx/server/controller.py:81> exception=AssertionError()>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/aiorpcx/util.py", line 119, in check_task
task.result()
File "/electrumx/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 240, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 207, in join
raise task.exception()
File "/electrumx/electrumx/server/block_processor.py", line 662, in fetch_and_process_blocks
await self.flush(True)
File "/electrumx/electrumx/server/block_processor.py", line 335, in flush
await self.run_in_thread_with_lock(flush)
File "/electrumx/electrumx/server/block_processor.py", line 191, in run_in_thread_with_lock
return await asyncio.shield(run_in_thread_locked())
File "/electrumx/electrumx/server/block_processor.py", line 190, in run_in_thread_locked
return await run_in_thread(func, *args)
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 68, in run_in_thread
return await get_event_loop().run_in_executor(None, func, *args)
File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/electrumx/electrumx/server/block_processor.py", line 334, in flush
self.estimate_txs_remaining)
File "/electrumx/electrumx/server/db.py", line 189, in flush_dbs
self.assert_flushed(flush_data)
File "/electrumx/electrumx/server/db.py", line 179, in assert_flushed
assert not flush_data.block_tx_hashes
AssertionError
Restart the docker instance, the log messages are:
INFO:Controller:Python version: 3.7.2 (default, Mar 7 2019, 22:40:59)
[GCC 8.2.0]
INFO:Controller:software version: ElectrumX 1.9.5
INFO:Controller:aiorpcX version: 0.10.5
INFO:Controller:supported protocol versions: 1.2-1.4.1
INFO:Controller:event loop policy: None
INFO:Controller:reorg limit is 200 blocks
INFO:Daemon:daemon #1 at bsv:8332/ (current)
INFO:DB:switching current directory to /data
INFO:DB:using leveldb for DB backend
INFO:DB:opened UTXO DB (for sync: True)
INFO:DB:DB version: 6
INFO:DB:coin: BitcoinSV
INFO:DB:network: mainnet
INFO:DB:height: 622,559
INFO:DB:tip: 00000000000000000215d64ff5398461b2214daab9005edc246a4ab5782ac755
INFO:DB:tx count: 356,748,088
INFO:DB:flushing DB cache at 1,200 MB
INFO:History:history DB version: 0
INFO:History:flush count: 9,436
INFO:DB:deleted 2,538 stale undo entries
INFO:SessionManager:RPC server listening on 127.0.0.1:8088
INFO:Prefetcher:catching up to daemon height 623,678 (1,119 blocks behind)
INFO:BlockProcessor:flushing to DB for a clean shutdown...
INFO:SessionManager:closing down RPC listening servers
ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /electrumx/electrumx/server/controller.py:81> exception=AssertionError()>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/site-packages/aiorpcx/util.py", line 119, in check_task
task.result()
File "/electrumx/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 240, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 207, in join
raise task.exception()
File "/electrumx/electrumx/server/block_processor.py", line 662, in fetch_and_process_blocks
await self.flush(True)
File "/electrumx/electrumx/server/block_processor.py", line 335, in flush
await self.run_in_thread_with_lock(flush)
File "/electrumx/electrumx/server/block_processor.py", line 191, in run_in_thread_with_lock
return await asyncio.shield(run_in_thread_locked())
File "/electrumx/electrumx/server/block_processor.py", line 190, in run_in_thread_locked
return await run_in_thread(func, *args)
File "/usr/local/lib/python3.7/site-packages/aiorpcx/curio.py", line 68, in run_in_thread
return await get_event_loop().run_in_executor(None, func, *args)
File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
result = self.fn(*self.args, **self.kwargs)
File "/electrumx/electrumx/server/block_processor.py", line 334, in flush
self.estimate_txs_remaining)
File "/electrumx/electrumx/server/db.py", line 189, in flush_dbs
self.assert_flushed(flush_data)
File "/electrumx/electrumx/server/db.py", line 179, in assert_flushed
assert not flush_data.block_tx_hashes
AssertionError
Both docker instances stop at the same block height with the same error. They have been running for months until this crash last week.
I've compacted the fist docker instance and run it, still crashes.
It seems the BSV block #622559/622560 has some weird txs that could crash the electrumX.
Yes that is the problem, you need to be on 1.14 for Genesis. I'm not sure what the txs are but you may have to rebuild the DB from scratch.
Sorry kyuupichan, but what randydu is refering to has nothing to do with the issue i posted in the first place. I am still experience the same behaviour, crashing every now and then, with websocket 8.1 & websocket 7.
@angelix the error shown: "AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'" originates in the websocket package and refers to a problem within its data structures. I suspect your installation of the package is somehow corrupted.
https://github.com/aaugustin/websockets/blob/master/src/websockets/protocol.py#L278 is where it is defined, apparently
Downgraded to websockets v7, different exceptions are occurring. Don't know if a client message is doing this, but even that shouldn't bring down the server.
Latest log:
2020-02-26 14:05:23,423:INFO:ElectrumX:[47] WSS XXX.XXX.XXX.XXX:47172, 23 total
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
2020-02-26 14:05:29,238:INFO:MemPool:6,570 txs 3.07 MB touching 10,596 addresses
2020-02-26 14:06:05,313:INFO:Prefetcher:new block height 623,751 hash 00000000000000000250f4222ec97f93cadc2a2a1bde84cda5bd5ebb6789af53
2020-02-26 14:06:06,014:INFO:DB:flush #1,087 took 0.0s. Height 623,751 txs: 362,052,517 (+1,874)
2020-02-26 14:06:06,014:INFO:BlockProcessor:processed 1 block size 1.00 MB in 0.6s
2020-02-26 14:06:21,002:INFO:ElectrumX:[59] WSS XXX.XXX.XXX.XXX:3844, 22 total
2020-02-26 14:06:21,140:INFO:SessionManager:closing down server for ws://0.0.0.0:5104
2020-02-26 14:06:21,140:INFO:SessionManager:closing down server for rpc://0.0.0.0:2104
2020-02-26 14:06:21,140:INFO:SessionManager:closing down server for wss://0.0.0.0:6104
2020-02-26 14:06:21,999:INFO:Prefetcher:cancelled; prefetcher stopping
2020-02-26 14:06:21,999:INFO:BlockProcessor:flushing to DB for a clean shutdown...
2020-02-26 14:06:22,000:INFO:Controller:shutting down
2020-02-26 14:06:22,000:INFO:Controller:shutdown complete
2020-02-26 14:06:22,001:ERROR:electrumx:ElectrumX server terminated abnormally
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "electrumx_server", line 35, in main
asyncio.run(controller.run())
File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
return loop.run_until_complete(main)
File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
return future.result()
File "/electrumx/lib/server_base.py", line 125, in run
await server_task
File "/electrumx/lib/server_base.py", line 98, in serve
await self.serve(shutdown_event)
File "/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/session.py", line 611, in serve
await group.spawn(self._manage_servers())
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/electrumx/server/session.py", line 963, in notify
await self.send_notification('blockchain.headers.subscribe', args)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 534, in send_notification
await self._send_message(message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/session.py", line 153, in _send_message
await self.transport.write(message)
File "/usr/local/lib/python3.7/dist-packages/aiorpcx/websocket.py", line 85, in write
await self.websocket.send(framed_message)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 462, in send
yield from self.ensure_open()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 658, in ensure_open
) from self.transfer_data_exc
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
Future exception was never retrieved
future: <Future finished exception=ConnectionClosed('WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason')>
Traceback (most recent call last):
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 674, in transfer_data
message = yield from self.read_message()
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 742, in read_message
frame = yield from self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 815, in read_data_frame
frame = yield from self.read_frame(max_size)
File "/usr/local/lib/python3.7/dist-packages/websockets/protocol.py", line 884, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.7/dist-packages/websockets/framing.py", line 99, in read
data = yield from reader(2)
File "/usr/lib/python3.7/asyncio/streams.py", line 679, in readexactly
await self._wait_for_data('readexactly')
File "/usr/lib/python3.7/asyncio/streams.py", line 473, in _wait_for_data
await self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
websockets.exceptions.ConnectionClosed: WebSocket connection is closed: code = 1006 (connection closed abnormally [internal]), no reason
@kyuupichan i was able to reproduce it with artillery.io I will share the sample config of the stress test.
@kyuupichan here is the artillery.io script that we used for the stress test:
config:
target: "wss://XXXX:XXX"
plugins:
fuzzer: {}
phases:
- duration: 60
arrivalRate: 20
subprotocols:
- json
scenarios:
- engine: "ws"
flow:
- send: '{"id":0,"method":"server.version","params":["1.18.8-dev_289_android","1.4"]}'
- send: '{"id":1,"method":"blockchain.headers.subscribe"}'
- send: '{"id":2,"method":"blockchain.scripthash.subscribe","params":["963c7985bf4123e2d650c707458d6f731b2a0de6ffebbbcb3198f973aecb52c5"]}'
- send: '{"id":3,"method":"blockchain.scripthash.subscribe","params":["578b41ac4333609a6216b0595d88df72070e734fcbd6ec58c3f2b6900d1f14cf"]}'
- send: '{"id":4,"method":"blockchain.scripthash.subscribe","params":["6be90d7a1835ad86fa647e429e7e4f849c8da575abbcbf77178b4e80008217ba"]}'
- send: '{"id":5,"method":"blockchain.scripthash.subscribe","params":["fc9794b06359653b29a2425f16401dba7e18e2f59ba63275d8146f2e420b8f59"]}'
- send: '{"id":6,"method":"blockchain.scripthash.subscribe","params":["0f4137ef81c6ce2f533c65a79349faaa6a7a8f3602475bf2b0f4a5fc8a1ab592"]}'
- send: '{"id":7,"method":"blockchain.scripthash.subscribe","params":["46cfe715fdd8a2be46bf7cab5787f4900754b9d6f250aae16034e7a9259b66a6"]}'
- send: '{"id":8,"method":"blockchain.scripthash.subscribe","params":["acc65567fc97e2befcc52e072cce9e0806c78183b1cf1e6084cb3553337bbc63"]}'
- send: '{"id":9,"method":"blockchain.scripthash.subscribe","params":["3ba6d0060218fedafa08c3e18ae5bf563058a60f36d3215928cc1839156faf8b"]}'
- send: '{"id":10,"method":"blockchain.scripthash.subscribe","params":["8c6f50c964a993d07aec5873929ba9d77dae2daa7cc9318276f18d056dfbd302"]}'
- send: '{"id":11,"method":"blockchain.scripthash.subscribe","params":["ce8684902c923d671b4bcde5aeebe62b4017bf2e2680937874eebe8cfc9233e8"]}'
- send: '{"id":12,"method":"blockchain.scripthash.subscribe","params":["53c8835bba229b2d479e03d200e3ab188698c7ec232de3a1b78e2a0dd1118384"]}'
- send: '{"id":13,"method":"blockchain.scripthash.subscribe","params":["1327368ad941a4581871353259e24df70c7d96413b28071633a4607284684e7b"]}'
- send: '{"id":14,"method":"blockchain.scripthash.subscribe","params":["1173365fe38eb7c446952524491f0e3c05cf750b800d7e635189078cea1024c0"]}'
- send: '{"id":15,"method":"blockchain.scripthash.subscribe","params":["793528e69efd213c6acbc615fbd4ab4a1e3618550e8e23638cca1fb597a16d01"]}'
- send: '{"id":16,"method":"blockchain.scripthash.subscribe","params":["86247c9adaa4887b8ced359fbf5c401f7ef65eb53cc163c6bde38fe875ccb859"]}'
- send: '{"id":17,"method":"blockchain.scripthash.subscribe","params":["ebaec7981099a799a778a32e5e25605a4bc2d3a6a0e1681238320c4deb9d17b8"]}'
- send: '{"id":18,"method":"blockchain.scripthash.subscribe","params":["a685f4ff12d16351874b18802fa2151a2704672dc0ab469a0a60f99768f06c80"]}'
- send: '{"id":19,"method":"blockchain.scripthash.subscribe","params":["d7cf745dc807467a8578ca13dabac5546a1741b8f314bb0fe30c19d9db6187a8"]}'
- send: '{"id":20,"method":"blockchain.scripthash.subscribe","params":["1185fd57087cc0819b21d9f796a9d5c187b20b809ef5032338a4fa049f5fa19e"]}'
- send: '{"id":21,"method":"blockchain.scripthash.subscribe","params":["9a020bb0ce6401a199dc370b971e8de8792548f3bb1f47bb42912afbc0249ab5"]}'
- send: '{"id":22,"method":"blockchain.scripthash.subscribe","params":["08e5848ab80da860b2fc5dbe35d90ea6fdfcef157ed91932f5341aaaa84c4cc8"]}'
- send: '{"id":23,"method":"blockchain.scripthash.subscribe","params":["7b3fc453b63f226ac3a4e3a0fa985e3b9fd74fbde086ca8ff43d254da18def1c"]}'
- send: '{"id":24,"method":"blockchain.scripthash.subscribe","params":["cb9119431a300c5fd25cefc61e37ea935b1fc3f4bedcbeea90b745fe3ed05153"]}'
- send: '{"id":25,"method":"blockchain.scripthash.subscribe","params":["68260af453478e4442c159f4d95464ed8bc1a6f1daf7480892836d71d1bc9895"]}'
- send: '{"id":26,"method":"blockchain.scripthash.subscribe","params":["889b9cd69ef886a2006471c5c52a42a1bde6a3f14ab56d472cab4dd4df8e832f"]}'
- send: '{"id":27,"method":"blockchain.scripthash.subscribe","params":["4b79c94172c3997b4ddbee74b0863b4934b63d9657544f62db5e72b09b03cb71"]}'
- send: '{"id":28,"method":"blockchain.scripthash.subscribe","params":["b56ac7686fcdfb5588b265adc0e8f865b7caca73be383831b6c9ffa2a33f99d7"]}'
- send: '{"id":29,"method":"blockchain.scripthash.subscribe","params":["943fd31ccf312ac112855eb7dd6fd2154cff05a1bc624a031efacca82dc37bcc"]}'
- send: '{"id":30,"method":"blockchain.scripthash.subscribe","params":["da7915feb04dba1d249dad666c17678e865d897b2e11cd5bd2c9d46c3d060cf3"]}'
- send: '{"id":31,"method":"blockchain.scripthash.subscribe","params":["21ca93adc6f9ef1db034bc4ffcdecb262b3f703208576e48d7f42ecb996fb8ca"]}'
- send: '{"id":32,"method":"blockchain.scripthash.subscribe","params":["00e44d04c89e3b0619688058973d1f8e217b0869f403e61778e9078d3be185e6"]}'
- send: '{"id":33,"method":"blockchain.scripthash.subscribe","params":["2824474eb29f97279c271c70eadda42ebebc060b3d32e2c1183ca9c78c8d4a6f"]}'
- send: '{"id":34,"method":"blockchain.scripthash.subscribe","params":["1dcd606b7940cae0cf2f173288c0fa711d7d344901072a8b1e175a17f6d66755"]}'
- send: '{"id":35,"method":"blockchain.scripthash.subscribe","params":["d59e38c1240a78bd6f888d4a2ad83b4f981f37a17ce31b25fbfc1ab97486d3fb"]}'
- send: '{"id":36,"method":"blockchain.scripthash.subscribe","params":["5c2a06106d5dcc7b288fee1a8e78640ac111cd4469e2e6531be9307e7838b614"]}'
- send: '{"id":37,"method":"blockchain.scripthash.subscribe","params":["5ad8ca20949b168ec74f22875611313b940f4941ce2327e225b9aad55d09d40f"]}'
- send: '{"id":38,"method":"blockchain.scripthash.subscribe","params":["7ae9787644fefdb648835a20ecee085c2abd66952c4a58cbe7aee0fa066a072c"]}'
- send: '{"id":39,"method":"blockchain.scripthash.subscribe","params":["4ff3ae05a8285ec26aa7bd86e6346d668f31a345de099f4ad818740546c6754e"]}'
- send: '{"id":40,"method":"blockchain.scripthash.subscribe","params":["30648bcf72cfcf40af3b7a03e7a854e76035ef8e996e0210b0716bd5637373c5"]}'
- send: '{"id":41,"method":"blockchain.scripthash.subscribe","params":["86540f71b958421bb78f849b7fcdb9cf6b72ee06ec8188daa851263a2bfec7ae"]}'
- send: '{"id":42,"method":"blockchain.scripthash.subscribe","params":["f6559eee06eff11a371e40e2c0b5649dfd56df305ae9d9ad27f42b00b749eff3"]}'
- send: '{"id":43,"method":"blockchain.scripthash.subscribe","params":["ed030785921e1c9530c38e26c68afdc460a3cec1ccdee867f56663877401351d"]}'
- send: '{"id":44,"method":"blockchain.scripthash.subscribe","params":["d090a0d5f0efc77c3ab2eb3853359c583fc845d0f2d58ad575bd960e6231c4c4"]}'
- send: '{"id":45,"method":"blockchain.scripthash.subscribe","params":["48ad171d9ae4f0b96b13b1aa799c83da61dbee8e8b113a011d864572d593d027"]}'
- send: '{"id":46,"method":"blockchain.scripthash.subscribe","params":["287b85ba24fbf0a46d3be22c32cbea01d9906823e0569b6b8e71370b294d6473"]}'
- send: '{"id":47,"method":"blockchain.scripthash.subscribe","params":["53b16b8b88feb9175ee1e57af09a0431d8ecdc78835c302cc0cebb5576fbe0ac"]}'
- send: '{"id":48,"method":"blockchain.scripthash.subscribe","params":["c7b9ca59c52c278a5a6291da03bb5708d3e3ffefb2165b240542ec11b8ea1e68"]}'
- send: '{"id":49,"method":"blockchain.scripthash.subscribe","params":["79680920fd2dac3442f1c44e414a5707fda744d4271eb8294469f361b557246f"]}'
- send: '{"id":50,"method":"blockchain.scripthash.subscribe","params":["1bdbc4027c6f2eeadceed2943fd1323298e7dd71ef1652bce734916a3d27edf5"]}'
- send: '{"id":51,"method":"blockchain.scripthash.subscribe","params":["a29c9601952695a8f431e8ca1b84135a855eaceaf2ae28f805ff66da77089cb2"]}'
- send: '{"id":52,"method":"blockchain.scripthash.subscribe","params":["e28641a853e7616d1cf8e53d0e7ea8d6c876217deaca9598a8fd03bea3c8050b"]}'
- send: '{"id":53,"method":"blockchain.scripthash.subscribe","params":["2fb9881e8818110760e793ff266855423f2c61bf103ca5a3ad249ea4ccd86543"]}'
- send: '{"id":54,"method":"blockchain.scripthash.subscribe","params":["f57aa7784011b8079dd689d68687778999be6b4051b97e5e3809aa54a56de38d"]}'
- send: '{"id":55,"method":"blockchain.scripthash.subscribe","params":["0ba5f5cd04f5a664b58b7c7652c39a0f872758a34997aae10715017f87d72f1e"]}'
@kyuupichan We are still experience crashes almost every 1-2 hours. Is very difficult to debug or reproduce, but using the following artillery script was able to.
npm install -g artillery
vim test.yml # paste the content of the previous comment
artillery run test.yml
If you run it multiple times you can "bring" down a websocket electrumx server eg. BSV
I'm also having this issue, that "WebSocketServerProtocol" object has no attribute 'transfer_data_task'
This is my log:
ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py:81> exception=RuntimeError('task group is closed',)>
Traceback (most recent call last):
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/util.py", line 309, in check_task
task.result()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/mempool.py", line 335, in keep_synchronized
await group.spawn(self._logging(synchronized_event))
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/mempool.py", line 232, in _refresh_hashes
await self.api.on_mempool(touched, height)
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py", line 67, in on_mempool
await self._maybe_notify()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py", line 55, in _maybe_notify
await self.notify(height, touched)
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/session.py", line 758, in _notify_sessions
await self._task_group.spawn(session.notify, touched, height_changed)
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 148, in spawn
self._add_task(task)
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 123, in _add_task
raise RuntimeError('task group is closed')
RuntimeError: task group is closed
ERROR:asyncio:Task exception was never retrieved
future: <Task finished coro=<WebSocketCommonProtocol.close() done, defined at /usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py:653> exception=AttributeError("'WebSocketServerProtocol' object has no attribute 'transfer_data_task'",)>
Traceback (most recent call last):
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 698, in close
self.transfer_data_task,
AttributeError: 'WebSocketServerProtocol' object has no attribute 'transfer_data_task'
It appears randomly too. Sometimes in the next 12 hours, sometimes after 3 days. I'm not using artillery or something like that. I'm just using plain Ubuntu 18.04
I'm also having a different issue by "code = 1006 (connection closed abnormally [internal]), no reason" (other error output)
ERROR:root:task crashed: <Task finished coro=<Controller.serve() done, defined at /usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py:81> exception=ConnectionClosedError('code = 1006 (connection closed abnormally [internal]), no reason',)>
Traceback (most recent call last):
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 827, in transfer_data
message = await self.read_message()
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 895, in read_message
frame = await self.read_data_frame(max_size=self.max_size)
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 971, in read_data_frame
frame = await self.read_frame(max_size)
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 1051, in read_frame
extensions=self.extensions,
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/framing.py", line 105, in read
data = await reader(2)
File "/usr/lib/python3.6/asyncio/streams.py", line 674, in readexactly
yield from self._wait_for_data('readexactly')
File "/usr/lib/python3.6/asyncio/streams.py", line 464, in _wait_for_data
yield from self._waiter
concurrent.futures._base.CancelledError
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/util.py", line 309, in check_task
task.result()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/controller.py", line 134, in serve
await group.spawn(wait_for_catchup())
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/session.py", line 610, in serve
await group.spawn(self._manage_servers())
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 242, in __aexit__
await self.join()
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/curio.py", line 211, in join
raise task.exception()
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/session.py", line 1450, in notify
await super().notify(touched, height_changed)
File "/usr/local/lib/python3.6/dist-packages/electrumX-1.12.0-py3.6.egg/electrumx/server/session.py", line 979, in notify
await self.send_notification(method, (alias, status))
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/session.py", line 534, in send_notification
await self._send_message(message)
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/session.py", line 153, in _send_message
await self.transport.write(message)
File "/usr/local/lib/python3.6/dist-packages/aiorpcX-0.18.4-py3.6.egg/aiorpcx/websocket.py", line 85, in write
await self.websocket.send(framed_message)
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 555, in send
await self.ensure_open()
File "/usr/local/lib/python3.6/dist-packages/websockets-8.1-py3.6-linux-x86_64.egg/websockets/protocol.py", line 812, in ensure_open
raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: code = 1006 (connection closed abnormally [internal]), no reason
This appears randomly too. I'm not quite sure if this issue is related with this topic. (But it has still something to do with websocket)
My other mirror ElectrumX (WebSocket) Server seems to be fine with very very low activity. (around 3-4 Users each day)
The error from above seems to appear from my main ElectrumX Server which has much more activity, around 500 Users each day. (Of course not all at once).