search

dipdup-io / dipdup

Modular framework for creating selective indexers and featureful backends for dapps
https://dipdup.io
MIT License
92 stars 52 forks source link

Realtime message queue not invalidates on reconnection #353

Closed Karantezsure closed 2 years ago

Karantezsure commented 2 years ago

Steps to reproduce:

Environment

Error

Traceback (most recent call last):
  File "/usr/local/bin/dipdup", line 8, in <module>
    sys.exit(cli())
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 1150, in __call__
    return anyio.run(self._main, main, args, kwargs, **({"backend":_anyio_backend} if _anyio_backend is not None else {}))
  File "/usr/local/lib/python3.10/site-packages/anyio/_core/_eventloop.py", line 56, in run
    return asynclib.run(func, *args, **backend_options)
  File "/usr/local/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 233, in run
    return native_run(wrapper(), debug=debug)
  File "/usr/local/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.10/asyncio/base_events.py", line 646, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.10/site-packages/anyio/_backends/_asyncio.py", line 228, in wrapper
    return await func(*args)
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 1153, in _main
    return await main(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 1074, in main
    rv = await self.invoke(ctx)
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 1684, in invoke
    return await _process_result(await sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 1420, in invoke
    return await ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python3.10/site-packages/asyncclick/core.py", line 774, in invoke
    rv = await rv
  File "/usr/local/lib/python3.10/site-packages/dipdup/cli.py", line 89, in wrapper
    await fn(*args, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/dipdup/cli.py", line 229, in run
    await dipdup.run()
  File "/usr/local/lib/python3.10/site-packages/dipdup/dipdup.py", line 415, in run
    await gather(*tasks)
  File "/usr/local/lib/python3.10/site-packages/dipdup/dipdup.py", line 88, in run
    await gather(*tasks)
  File "/usr/local/lib/python3.10/site-packages/dipdup/dipdup.py", line 116, in _run
    await gather(*tasks)
  File "/usr/local/lib/python3.10/site-packages/dipdup/index.py", line 232, in process
    await self._process_queue()
  File "/usr/local/lib/python3.10/site-packages/dipdup/index.py", line 642, in _process_queue
    await self._process_level_big_maps(big_maps)
  File "/usr/local/lib/python3.10/site-packages/dipdup/index.py", line 733, in _process_level_big_maps
    raise RuntimeError(f'Level of big map batch must be higher than index state level: {batch_level} <= {index_level}')
RuntimeError: Level of big map batch must be higher than index state level: 2389978 <= 2389980
droserasprout commented 2 years ago

Please, provide some logs before the crash occurred.

Karantezsure commented 2 years ago 

INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.index         assetMap_bigmap: 2389967: `on_asset_update` handler matched!
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389969 -> 2389970
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389969 -> 2389970
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389970 -> 2389971
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389970 -> 2389971
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389971 -> 2389972
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389971 -> 2389972
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389972 -> 2389973
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389972 -> 2389973
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389973 -> 2389974
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389973 -> 2389974
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389974 -> 2389975
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389974 -> 2389975
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389975 -> 2389976
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389975 -> 2389976
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389976 -> 2389977
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389976 -> 2389977
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389977 -> 2389978
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389977 -> 2389978
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389978 -> 2389979
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389978 -> 2389979
WARNING  pysignalr.transport  Connection closed: no close frame received or sent
INFO     pysignalr.transport  State change: connected -> reconnecting
INFO     dipdup.tzkt          tzkt_mainnet: Realtime connection lost
INFO     dipdup.tzkt          tzkt_mainnet: Subscribing to 6 channels
INFO     pysignalr.transport  State change: reconnecting -> disconnected
INFO     dipdup.tzkt          tzkt_mainnet: Realtime connection lost
INFO     pysignalr.transport  State change: disconnected -> connecting
INFO     pysignalr.transport  Performing negotiation, URL: `https://api.tzkt.io/v1/events/negotiate?id=Nxt8NvldF2HPA-OHYOtiyQ`
INFO     pysignalr.transport  Negotiation completed
INFO     pysignalr.transport  Sending handshake to server
INFO     pysignalr.transport  Awaiting handshake from server
INFO     pysignalr.transport  State change: connecting -> connected
INFO     dipdup.tzkt          tzkt_mainnet: Realtime connection established
INFO     dipdup.tzkt          tzkt_mainnet: Subscribed to 6 channels
INFO     dipdup.index         tzbtc_holders_mainnet: Index is behind datasource level, syncing: 2389855 -> 2389980
INFO     dipdup.index         tzbtc_holders_mainnet: Synchronizing index to level 2389980
INFO     dipdup.index         ovens_bigmap: Index is behind datasource level, syncing: 2389977 -> 2389980
INFO     dipdup.index         ovens_bigmap: Synchronizing index to level 2389980
INFO     dipdup.index         assetMap_bigmap: Index is behind datasource level, syncing: 2389977 -> 2389980
INFO     dipdup.index         assetMap_bigmap: Synchronizing index to level 2389980
INFO     dipdup.index         tzbtc_holders_mainnet: Fetching operations from level 2389856 to 2389980
INFO     dipdup.index         ovens_bigmap: Fetching big map diffs from level 2389978 to 2389980
INFO     dipdup.index         assetMap_bigmap: Fetching big map diffs from level 2389978 to 2389980
INFO     dipdup.index         ovens_bigmap: Index is synchronized to level 2389980
INFO     dipdup.index         assetMap_bigmap: Index is synchronized to level 2389980
INFO     dipdup.index         tzbtc_holders_mainnet: Index is synchronized to level 2389980
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: head, DATA, 2389979 -> 2389980
INFO     dipdup.tzkt          tzkt_mainnet: Realtime message received: big_map, DATA, 2389979 -> 2389980 ```
droserasprout commented 2 years ago

Thanks. The reason behind this issue is that DipDup is not processing WebSocket reconnection events correctly. However, indexed data does not corrupt when this issue occurs; you're safe to continue with an existing database.