kyuupichan / aiorpcX

Generic async RPC implementation, including JSON-RPC
MIT License
27 stars 23 forks source link

session._recalc_concurrency can raise ZeroDivisionError #26

Closed SomberNight closed 5 years ago

SomberNight commented 5 years ago

Trace:

Traceback (most recent call last):
  File "...\electrum\electrum\util.py", line 988, in wrapper
    return await func(*args, **kwargs)
  File "...\electrum\electrum\interface.py", line 334, in wrapper_func
    return await func(self, *args, **kwargs)
  File "...\electrum\electrum\interface.py", line 358, in run
    await self.open_session(ssl_context)
  File "...\electrum\electrum\interface.py", line 465, in open_session
    await group.spawn(self.monitor_connection)
  File "...\aiorpcX\aiorpcx\curio.py", line 242, in __aexit__
    await self.join()
  File "...\aiorpcX\aiorpcx\curio.py", line 208, in join
    await self.cancel_remaining()
  File "...\aiorpcX\aiorpcx\curio.py", line 221, in cancel_remaining
    await task
  File "...\electrum\electrum\synchronizer.py", line 81, in _start_tasks
    await group.spawn(self.main())
  File "...\aiorpcX\aiorpcx\curio.py", line 242, in __aexit__
    await self.join()
  File "...\aiorpcX\aiorpcx\curio.py", line 211, in join
    raise task.exception()
  File "...\electrum\electrum\synchronizer.py", line 109, in subscribe_to_address
    await self.session.subscribe('blockchain.scripthash.subscribe', [h], self.status_queue)
  File "...\electrum\electrum\interface.py", line 137, in subscribe
    result = await self.send_request(method, params)
  File "...\electrum\electrum\interface.py", line 115, in send_request
    timeout)
  File "C:\Users\User\AppData\Local\Programs\Python\Python37\lib\asyncio\tasks.py", line 388, in wait_for
    return await fut
  File "...\aiorpcX\aiorpcx\session.py", line 525, in send_request
    return await self._send_concurrent(message, future, 1)
  File "...\aiorpcX\aiorpcx\session.py", line 503, in _send_concurrent
    self._recalc_concurrency()
  File "...\aiorpcX\aiorpcx\session.py", line 423, in _recalc_concurrency
    target = int(0.5 + max(floor, min(cap, current * self.target_response_time / avg)))
ZeroDivisionError: float division by zero

The cause is that two subsequent close time.time() calls can have identical results. On Windows, this seems quite likely actually:

PS Q:\prog\misc\electrum_ws\electrum> python3.7-64
Python 3.7.3 (v3.7.3:ef4ec6ed12, Mar 25 2019, 22:22:05) [MSC v.1916 64 bit (AMD64)] on win32
Type "help", "copyright", "credits" or "license" for more information.
>>> import time
>>> [time.time() for i in range(10)]
[1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693, 1572379481.460693]
>>> 10 * [_[0]] == _
True

but even on Ubuntu, it sometimes happens:

$ python3
Python 3.6.8 (default, Oct  7 2019, 12:59:55) 
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import time
>>> [time.time() for i in range(10)]
[1572379591.2279305, 1572379591.227931, 1572379591.2279315, 1572379591.2279317, 1572379591.2279317, 1572379591.2279322, 1572379591.2279325, 1572379591.2279327, 1572379591.227933, 1572379591.2279334]
>>> _[3] == _[4]
True