binarysculptor / wallet

Experience crypto freedom!
https://www.liberty-coin.com/
MIT License
6 stars 2 forks source link

Linux daemon failing to start #37

Closed ghost closed 5 years ago

ghost commented 5 years ago

Describe the issue

Linux 5.0.72 wallet failing to start with error:

terminate called after throwing an instance of 'std::runtime_error'
  what():  tinyformat: Too many conversion specifiers in format string

Can you reliably reproduce the issue?

No, but I have one MN where I'm seeing this error on every start now.

Expected behavior

Wallet starts and syncs

Actual behavior

Wallet starts and after a few seconds the daemon stops

What version of Liberty Coin are you using?

Official 5.0.72, upgraded from official 5.0.58

Machine specs:

Any extra information that might be useful in the debugging process.

debug.log contents:

root@v01:~# libertyd; tail -f .liberty/debug.log
Liberty server starting
2018-12-31 22:16:18 AppInit2 : parameter interaction: -listen=0 -> setting -upnp=0
2018-12-31 22:16:18 AppInit2 : parameter interaction: -listen=0 -> setting -discover=0
2018-12-31 22:16:18 AppInit2 : parameter interaction: -listen=0 -> setting -listenonion=0
2018-12-31 22:16:18

2018-12-31 22:16:18 Liberty version v5.0.72.0-20cda2b (2018-12-30 19:12:47 -0600)
2018-12-31 22:16:18 Using OpenSSL version OpenSSL 1.0.1k 8 Jan 2015
2018-12-31 22:16:18 Using BerkeleyDB version Berkeley DB 4.8.30: (April  9, 2010)
2018-12-31 22:16:18 Default data directory /root/.liberty
2018-12-31 22:16:18 Using data directory /root/.liberty
2018-12-31 22:16:18 Using config file /root/.liberty/liberty.conf
2018-12-31 22:16:18 Using at most 125 connections (64000 file descriptors available)
2018-12-31 22:16:18 Using 0 threads for script verification
2018-12-31 22:16:18 HTTP: creating work queue of depth 16
2018-12-31 22:16:18 HTTP: starting 4 worker threads
2018-12-31 22:16:18 Creating backup of "/root/.liberty/wallet.dat" -> "/root/.liberty/backups/wallet.dat.2018-12-31-22-16"
2018-12-31 22:16:18 scheduler thread start
2018-12-31 22:16:18 Old backup deleted: "/root/.liberty/backups/wallet.dat.2018-11-18-07-45"
2018-12-31 22:16:18 Using wallet wallet.dat
2018-12-31 22:16:18 init message: Verifying wallet...
2018-12-31 22:16:18 CDBEnv::Open: LogDir=/root/.liberty/database ErrorFile=/root/.liberty/db.log
2018-12-31 22:16:18 AddLocal(45.63.115.200:10417,4)
2018-12-31 22:16:18 init message: Loading block index...
2018-12-31 22:16:18 Opening LevelDB in /root/.liberty/zerocoin
2018-12-31 22:16:18 Opened LevelDB successfully
2018-12-31 22:16:18 Opening LevelDB in /root/.liberty/sporks
2018-12-31 22:16:18 Opened LevelDB successfully
2018-12-31 22:16:18 Opening LevelDB in /root/.liberty/blocks/index
2018-12-31 22:16:18 Opened LevelDB successfully
2018-12-31 22:16:18 Opening LevelDB in /root/.liberty/chainstate
2018-12-31 22:16:18 Opened LevelDB successfully
2018-12-31 22:16:18 init message: Loading sporks...
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_2_SWIFTTX found in database
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_3_SWIFTTX_BLOCK_FILTERING found in database
2018-12-31 22:16:18 LoadSporksFromDB : loaded spork SPORK_5_MAX_VALUE with value 100001
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_7_MASTERNODE_SCANNING found in database
2018-12-31 22:16:18 LoadSporksFromDB : loaded spork SPORK_8_MASTERNODE_PAYMENT_ENFORCEMENT with value 0
2018-12-31 22:16:18 LoadSporksFromDB : loaded spork SPORK_9_MASTERNODE_BUDGET_ENFORCEMENT with value 0
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_10_MASTERNODE_PAY_UPDATED_NODES found in database
2018-12-31 22:16:18 LoadSporksFromDB : loaded spork SPORK_13_ENABLE_SUPERBLOCKS with value 0
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_14_NEW_PROTOCOL_ENFORCEMENT found in database
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_15_NEW_PROTOCOL_ENFORCEMENT_2 found in database
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_16_ZEROCOIN_MAINTENANCE_MODE found in database
2018-12-31 22:16:18 LoadSporksFromDB : no previous value for SPORK_17_PROPOSAL_VETO found in database
2018-12-31 22:16:18 init message: Loading block index...
2018-12-31 22:16:27 LoadBlockIndexDB: last block file = 1
2018-12-31 22:16:27 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=20890, size=76336520, heights=49901...70570, time=2018-12-17...2018-12-31)
2018-12-31 22:16:27 Checking all blk files are present...
2018-12-31 22:16:27 LoadBlockIndexDB: Last shutdown was prepared: false
2018-12-31 22:16:27 LoadBlockIndexDB(): transaction index enabled
2018-12-31 22:16:27 LoadBlockIndexDB(): hashBestChain=007d8dd508f1d6c4e4cae6bf54f552bb39ba75224a78b0af884ad175f9138b2c height=70570 date=2018-12-31 22:07:19 progress=0.999744
2018-12-31 22:16:27 init message: Verifying blocks...
2018-12-31 22:16:27 Verifying last 100 blocks at level 4
2018-12-31 22:16:31 No coin database inconsistencies in last 101 blocks (215 transactions)
2018-12-31 22:16:31  block index           12741ms
2018-12-31 22:16:31 init message: Loading wallet...
2018-12-31 22:16:31 nFileVersion = 5007200
2018-12-31 22:16:31 Keys: 1016 plaintext, 0 encrypted, 1016 w/ metadata, 1016 total
2018-12-31 22:16:31  wallet                   86ms
2018-12-31 22:16:31 init message: Syncing XLIBz wallet...
2018-12-31 22:16:31 GenerateMintPool : n=8 nStop=27
2018-12-31 22:16:31 SyncWithChain: Mintpool size=27
2018-12-31 22:16:31 init message: Loading masternode cache...
2018-12-31 22:16:32 init message: Loading budget cache...
2018-12-31 22:16:32 init message: Loading masternode payment cache...
2018-12-31 22:16:32 IS MASTER NODE
2018-12-31 22:16:32  addr 45.63.115.200:10417
2018-12-31 22:16:32 Locking Masternodes:
2018-12-31 22:16:32 fLiteMode 0
2018-12-31 22:16:32 nSwiftTXDepth 5
2018-12-31 22:16:32 Anonymize Liberty Amount 2
2018-12-31 22:16:32 Budget Mode auto
2018-12-31 22:16:32 mapBlockIndex.size() = 71305
2018-12-31 22:16:32 chainActive.Height() = 70570
2018-12-31 22:16:32 setKeyPool.size() = 1001
2018-12-31 22:16:32 mapWallet.size() = 14
2018-12-31 22:16:32 mapAddressBook.size() = 4
2018-12-31 22:16:32 init message: Loading addresses...
2018-12-31 22:16:32 Loaded 4700 addresses from peers.dat  31ms
2018-12-31 22:16:32 dnsseed thread start
2018-12-31 22:16:32 init message: Done loading
2018-12-31 22:16:32 stakemint thread start
2018-12-31 22:16:32 ThreadStakeMinter started
2018-12-31 22:16:32 LibertyMiner started
2018-12-31 22:16:32 msghand thread start
2018-12-31 22:16:32 keypool reserve 16
2018-12-31 22:16:32 opencon thread start
2018-12-31 22:16:32 addcon thread start
2018-12-31 22:16:32 net thread start
2018-12-31 22:16:33 Misbehaving: 178.128.69.18:10417 (0 -> 1)
2018-12-31 22:16:33 ProcessMessage(getsporks, 0 bytes) FAILED peer=1
2018-12-31 22:16:33 asking peer for sporks
2018-12-31 22:16:33 receive version message: /Liberty Core:5.0.58/: version 71026, blocks=70572, us=45.63.115.200:58442, peer=1
2018-12-31 22:16:33 Added time data, samples 2, offset +0 (+0 minutes)
terminate called after throwing an instance of 'std::runtime_error'
  what():  tinyformat: Too many conversion specifiers in format string
binarysculptor commented 5 years ago

I was unable to reproduce the described behavior and it is related to a rogue logging statement that passes more params than what the statement allows. That said, after some additional sidebar conversation with @mnzone-dev this is apparently encountered when there are some missing acc checkpoints. Recalculating the checkpoints is all that is required but, unfortunately, the code that was forked had an offset issue that needed to be fixed first.

Here's the updated daemon

Run with reindexmoneysupply and reindexaccumulators one time (this may take a few minutes) and see if the issue is fixed.

binarysculptor commented 5 years ago

Here's another build that will not cause the application to exit for a badly formatted string. When running this, please monitor your log file as it should show the culprit.

Here's the updated daemon - build 74

ghost commented 5 years ago

Spot on! With build 74 I'm no longer seeing the daemon crash. I can share with you the debug.log if it's helpful. Thank you

ghost commented 5 years ago

I'm seeing these messages show up in the shell when the daemon is running in the background:

root@v01:~# libertyd
Liberty server starting
root@v01:~# too many conversion specifiers in format string: %s'

too many conversion specifiers in format string: %s

too many conversion specifiers in format string: %s'

too many conversion specifiers in format string: %s

too many conversion specifiers in format string: %s'

too many conversion specifiers in format string: %s

too many conversion specifiers in format string: %s'

too many conversion specifiers in format string: %s
binarysculptor commented 5 years ago

Build 5.1.1 will have fixes for the incorrectly formatted strings.

binarysculptor commented 5 years ago

Haven't heard any complaints on this since the 5.1.1 release so I'm closing it.