bmon icon indicating copy to clipboard operation
bmon copied to clipboard

Determine why logwatcher is reading truncated lines

Open jamesob opened this issue 1 year ago • 0 comments

Occasionally, the bitcoind-watcher process surfaces errors that look like

bitcoind-watcher_1      | 2022-10-07 06:08:24,228 bmon.logparse ERROR    Failed to process line "2022-10-07T06:08:24.227608Z [] UpdateTip: new best=00000000000000000000042697715d779b50cc0a7d1afdf3e5d5a49f3dae4e62 height=757481 version=0x26a6c000 log2_work=93.770429 tx=770271020 date='2022-10-07T06:08:00Z' progress=1.000000 cache=38."
bitcoind-watcher_1      | Traceback (most recent call last):
bitcoind-watcher_1      |   File "/src/bmon/logparse.py", line 31, in watch_logs
bitcoind-watcher_1      |     got = cb_listener.process_line(line)
bitcoind-watcher_1      |           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
bitcoind-watcher_1      |   File "/src/bmon/logparse.py", line 274, in process_line
bitcoind-watcher_1      |     cachesize_txo=float(matchgroups['cachesize_txo']),
bitcoind-watcher_1      |                         ~~~~~~~~~~~^^^^^^^^^^^^^^^^^
bitcoind-watcher_1      | KeyError: 'cachesize_txo'

and it subsequently misses ConnectBlock* events.

Apparently, read_logfile_forever is somehow yielding incomplete lines. Figure out what's going on here and fix.

It is worth noting that the corresponding bitcoind debug.log line looks complete:

(.venv) vagrant@b3:~/bmon$ docker-compose logs bitcoind | grep -A 4 height=757538

bitcoind_1              | 2022-10-07T14:39:57.300744Z [] UpdateTip: new best=00000000000000000002fdcbe93ff28b3040f6a349d5f86088589ef9a2e9bde1 height=757538 version=0x20000000 log2_work=93.771085 tx=770375653 date='2022-10-07T14:39:49Z' progress=1.000000 cache=80.0MiB(593550txo) warning='87 of last 100 blocks have unexpected version'
bitcoind_1              | 2022-10-07T14:39:57.301429Z []   - Connect postprocess: 9.51ms [5.70s (48.70ms/blk)]
bitcoind_1              | 2022-10-07T14:39:57.301807Z [] - Connect block: 33.46ms [16.58s (141.68ms/blk)]
bitcoind_1              | 2022-10-07T14:39:57.307974Z [] received: headers (82 bytes) peer=24

jamesob avatar Oct 07 '22 15:10 jamesob