Difficulty flushing to DB right after allocating a new block file.

[presstab]

Describe the issue

Certain clients and operating systems have difficulty flushing to DB right after allocating a new block file.

Actual behavior

2017-04-28 01:53:09 Leaving block file 2: CBlockFileInfo(blocks=189787, size=134209466, heights=392677...582451, time=2016-11-20...2017-04-02)
2017-04-28 01:53:09 Pre-allocating up to position 0x1000000 in blk00003.dat
2017-04-28 01:53:09 Pre-allocating up to position 0x100000 in rev00003.dat
2017-04-28 01:53:11 *** System error while flushing: CDB : Error -30974, can't open database
2017-04-28 01:53:15 ERROR: ProcessNewBlock : ActivateBestChain failed
2017-04-28 01:53:15 ConnectBlock: hashPrev=525bc3028ffb1aa06c7f519f2356ed11aa4cc7aafa5cc91c615dfa645846b70b view=c71f2128a0cdc44f90771a8a4df294ad58a5a010e67280f5040af109ba415eb2
2017-04-28 01:54:25 AppInit2 : parameter interaction: -listen=0 -> setting -discover=0

What version of PIVX Core are you using?

2.2+

[sugar84]

Using latest pre-release build.
Pivx-qt starts well, syncs then works fine for a while.
After a work of about a hour wallet crashes.

Here some logs from debug.log:

2017-04-28 15:20:38 *** System error while flushing: CDB : Error -30974, can't open database 
2017-04-28 15:40:37 Cannot connect to enph4kaavaav773l.onion:51472: unsupported network
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:40:38 socket sending timeout: 1201s
2017-04-28 15:53:00 ERROR: ProcessNewBlock : ActivateBestChain failed
2017-04-28 15:53:00 socket send error Неправильный дескриптор файла (9)
2017-04-28 15:53:00 ResendWalletTransactions()
2017-04-28 15:53:00 msghand thread interrupt
2017-04-28 15:53:00 dumpaddr thread stop
2017-04-28 15:53:00 opencon thread interrupt
2017-04-28 15:53:00 addcon thread interrupt
2017-04-28 15:53:00 net thread interrupt
2017-04-28 15:53:00 PrepareShutdown: In progress...
2017-04-28 15:53:00 StopNode()
2017-04-28 15:53:00 Verifying mncache.dat format...
2017-04-28 15:53:00 Loaded info from mncache.dat  108ms
2017-04-28 15:53:00   Masternodes: 1855, peers who asked us for Masternode list: 0, peers we asked for Masternode list: 9, entries in Masternode list we asked for: 0, nDsqCount: 0
2017-04-28 15:53:00 Writting info to mncache.dat...
2017-04-28 15:53:01 Written info to mncache.dat  74ms
2017-04-28 15:53:01   Masternodes: 1942, peers who asked us for Masternode list: 0, peers we asked for Masternode list: 5, entries in Masternode list we asked for: 0, nDsqCount: 0
2017-04-28 15:53:01 Masternode dump finished  184ms
2017-04-28 15:53:01 Verifying budget.dat format...
2017-04-28 15:53:01 Loaded info from budget.dat  35ms
2017-04-28 15:53:01   Proposals: 16, Budgets: 0, Seen Budgets: 16, Seen Budget Votes: 3976, Seen Final Budgets: 0, Seen Final Budget Votes: 0
2017-04-28 15:53:01 Writting info to budget.dat...
2017-04-28 15:53:01 Written info to budget.dat  33ms
2017-04-28 15:53:01 Budget dump finished  70ms
2017-04-28 15:53:01 Verifying mnpayments.dat format...
2017-04-28 15:53:01 Loaded info from mnpayments.dat  74ms
2017-04-28 15:53:01   Votes: 16175, Blocks: 1904
2017-04-28 15:53:01 Writting info to mnpayments.dat...
2017-04-28 15:53:01 Written info to mnpayments.dat  74ms
2017-04-28 15:53:01 Budget dump finished  151ms
2017-04-28 15:53:01 *** System error while flushing: CDB : Error -30974, can't open database 
2017-04-28 15:53:02 GUI: QXcbConnection: XCB error: 3 (BadWindow), sequence: 1558, resource id: 36194741, major code: 40 (TranslateCoords), minor code: 0
2017-04-28 15:53:02 CDBEnv::EnvShutdown : Error -30974 shutting down database environment: DB_RUNRECOVERY: Fatal error, run database recovery
2017-04-28 15:53:02 Shutdown: done

After this Pivx-qt starts well without -forcestart

What version of PIVX Core are you using?
2.2.99
System details
CPU: Intel i3 quad-core
Mem: 8Gb
Disk: HDD 50Gb
OS: Linux OpenSuse 13.2, x86_64, 3.16.7-53-default #1 SMP

[presstab]

@sugar84 are you syncing from scratch, deleting all files except wallet.dat? Or are you using mix and matching files, maybe using a blockchain snapshot, or a backup you have that was synced with a wallet that was not compiled by you?

[sugar84]

@presstab yep, i synced blockchain from old backup, made on 2.1.6
mb try to download whole blockchain from scratch?
and what files i should flush?

all other files i updated when updated Pivx-qt to 2.2.0

[presstab]

@sugar84 try removing all files from the .pivx directory except for your wallet.dat and your pivx.conf. Rename wallet.dat to wallet-backup.dat or something like that so that it will not be active on your resync. See if it gets past the error. If it does sync up to the current block, then stop the wallet and rename your wallet.dat and see if it works. Make sure to keep a good backup of your wallet.dat too of course.

[sugar84]

@presstab thank you for instructions
ok, i did all you mentioded then started Piv-qt 2.2.99.
I ll wait full sync and post results here

ps this wallet.dat has about 0.33 pivx, it's ok to lost it =) and i have backups

[Mrs-X]

BTW, your issue can also happen when someone else (a user via command line, another wallet instance using the same folder, etc) accesses the wallet.dat file, so before you do anything with the wallet.dat file double check that no pivxd or pivx-qt is using it.

[sugar84]

@Mrs-X thank you for mentions. no one else, nor me did not do something with wallet.dat.
ok, i ll double check what pivx(d/-qt) is stopped before do something with wallet.dat.

Got new issuse with test build 2.2.99.
Blockchain updated correctly. Wallet worked fine for a while. But after 1-2 hours Pivx-qt crashed with message to console:

ivx-qt: malloc.c:2369: sysmalloc: Assertion `(old_top == (((mbinptr) (((char *) &((av)->bins[((1) - 1) * 2])) - __builtin_offsetof (struct malloc_chunk, fd)))) && old_size == 0) || ((unsigned long) (old_size) >= (unsigned long)((((__builtin_offsetof (struct malloc_chunk, fd_nextsize))+((2 *(sizeof(size_t))) - 1)) & ~((2 *(sizeof(size_t))) - 1))) && ((old_top)->size & 0x1) && ((unsigned long) old_end & pagemask) == 0)' failed.

I can suppose only memory leak here.

After that I tried to launch pivx-qt without -forcerestart, but got Pivx-qt crashed with dump to console: https://pastebin.com/rJ87xe9Z

Right now pivx-qt started with option -forcerestart. Blockchain synced. I'll let test build work more.

[sugar84]

Sorry, didnt pay attention, -forcerestart didnt help.
I got segmentaion fault with error in debug.log:

2017-04-29 04:40:10 Opened LevelDB successfully
2017-04-29 04:40:57 LoadBlockIndexDB: last block file = 3
2017-04-29 04:40:57 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=78, size=39588518, heights=582461...620152, time=2017-04-02...2017-04-29)
2017-04-29 04:40:57 Checking all blk files are present...
2017-04-29 04:40:57 LoadBlockIndexDB: Last shutdown was prepared: true
2017-04-29 04:40:57 LoadBlockIndexDB(): transaction index enabled
2017-04-29 04:40:58 LoadBlockIndexDB(): hashBestChain=d7bbe7a6d784d177b5576053ebd8c19bc2554dae809424422360cfae1dffcd12 height=620152 date=2017-04-29 03:47:23 progress=0.999742
2017-04-29 04:40:58 init message: Verifying blocks...
2017-04-29 04:40:58 Verifying last 500 blocks at level 3
2017-04-29 04:40:58 ERROR: ReadBlockFromDisk : Deserialize or I/O error - non-canonical ReadCompactSize()
2017-04-29 04:40:58 ERROR: VerifyDB() : *** ReadBlockFromDisk failed at 620058, hash=fdd84a7db7e21f9f543f5f733a4f89b3590e50639a67a85653f0ce4775d4f348
2017-04-29 04:49:41 GUI: QXcbConnection: XCB error: 3 (BadWindow), sequence: 661, resource id: 37215981, major code: 40 (TranslateCoords), minor code: 0
2017-04-29 04:49:41 init message: Loading block index...
2017-04-29 04:49:42 Wiping LevelDB in /home/sugar/.pivx/blocks/index
2017-04-29 04:49:42 Opening LevelDB in /home/sugar/.pivx/blocks/index
2017-04-29 04:49:42 Opened LevelDB successfully
2017-04-29 04:49:42 Wiping LevelDB in /home/sugar/.pivx/chainstate
2017-04-29 04:49:42 Opening LevelDB in /home/sugar/.pivx/chainstate
2017-04-29 04:49:42 Opened LevelDB successfully
2017-04-29 04:49:42 Initializing databases...
2017-04-29 04:49:42 init message: Verifying blocks...
2017-04-29 04:49:42  block index             820ms
2017-04-29 04:49:42 init message: Loading wallet...
2017-04-29 04:49:43 nFileVersion = 2029900
2017-04-29 04:49:43 Keys: 1001 plaintext, 0 encrypted, 1001 w/ metadata, 1001 total
2017-04-29 04:49:43  wallet                  295ms
2017-04-29 04:49:43 Waiting for genesis block to be imported...
2017-04-29 04:49:43 Reindexing block file blk00000.dat...
2017-04-29 04:49:50 AppInit2 : parameter interaction: -listen=0 -> setting -discover=0
2017-04-29 04:49:50 

And now bin/pivx-qt -forcestart crashes with segmentation fault and error in debug.log:

2017-04-29 04:49:51 Opened LevelDB successfully
2017-04-29 04:49:51 LoadBlockIndexDB: last block file = 0
2017-04-29 04:49:51 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=0, size=0, heights=0...0, time=1970-01-01...1970-01-01)
2017-04-29 04:49:51 Checking all blk files are present...
2017-04-29 04:49:51 LoadBlockIndexDB: Last shutdown was prepared: true
2017-04-29 04:49:51 LoadBlockIndexDB(): transaction index enabled
2017-04-29 04:49:51 Initializing databases...
2017-04-29 04:49:51 init message: Verifying blocks...
2017-04-29 04:49:51  block index             278ms
2017-04-29 04:49:51 init message: Loading wallet...
2017-04-29 04:49:51 nFileVersion = 2029900
2017-04-29 04:49:51 Keys: 1001 plaintext, 0 encrypted, 1001 w/ metadata, 1001 total
2017-04-29 04:49:51  wallet                  176ms
2017-04-29 04:49:51 Waiting for genesis block to be imported...
2017-04-29 04:49:51 Reindexing block file blk00000.dat...
2017-04-29 04:50:22 AppInit2 : parameter interaction: -listen=0 -> setting -discover=0
2017-04-29 04:50:22

[Fuzzbawls]

-reindex was only recently fixed in #154, so if your build was done before that was merged then that is why you are seeing segfaults at the moment

[presstab]

@sugar84 can we conclude that the issue that is the topic is solved as being caused by mixing and matching DB's?

This has not re-occured for you?
2017-04-28 01:53:09 Pre-allocating up to position 0x1000000 in blk00003.dat 2017-04-28 01:53:09 Pre-allocating up to position 0x100000 in rev00003.dat 2017-04-28 01:53:11 *** System error while flushing: CDB : Error -30974, can't open database

[sugar84]

@presstab
#156 (comment)
this and later faults occured after i flushed all files from ~/.pivx
right now Pivx-qt crashes with segmentaion fault. Latest records db.log:

2017-04-30 03:24:30 Opened LevelDB successfully
2017-04-30 03:24:30 LoadBlockIndexDB: last block file = 0
2017-04-30 03:24:30 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=0, size=0, heights=0...0, time=1970-01-01...1970-01-01)
2017-04-30 03:24:30 Checking all blk files are present...
2017-04-30 03:24:30 LoadBlockIndexDB: Last shutdown was prepared: true
2017-04-30 03:24:30 LoadBlockIndexDB(): transaction index enabled
2017-04-30 03:24:30 Initializing databases...
2017-04-30 03:24:30 init message: Verifying blocks...
2017-04-30 03:24:30  block index             300ms
2017-04-30 03:24:30 init message: Loading wallet...
2017-04-30 03:24:30 nFileVersion = 2029900
2017-04-30 03:24:30 Keys: 1001 plaintext, 0 encrypted, 1001 w/ metadata, 1001 total
2017-04-30 03:24:30  wallet                  171ms
2017-04-30 03:24:30 Waiting for genesis block to be imported...
2017-04-30 03:24:30 Reindexing block file blk00000.dat...

-forcestart and -reindex dont work too.
So right now i cannot test wallet.

If you provide me new build, as @Fuzzbawls said, with merged #154 bugfix, so i could test it.

[sugar84]

@presstab i got this issuse on updated files prior to 2.2.99

Right now Pivx-qt crashes with segfault on start. Start with -forcestart or -reindex gets same result.
Latest lines from debg.log:

2017-04-30 03:24:30 Opened LevelDB successfully
2017-04-30 03:24:30 LoadBlockIndexDB: last block file = 0
2017-04-30 03:24:30 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=0, size=0, heights=0...0, time=1970-01-01...1970-01-01)
2017-04-30 03:24:30 Checking all blk files are present...
2017-04-30 03:24:30 LoadBlockIndexDB: Last shutdown was prepared: true
2017-04-30 03:24:30 LoadBlockIndexDB(): transaction index enabled
2017-04-30 03:24:30 Initializing databases...
2017-04-30 03:24:30 init message: Verifying blocks...
2017-04-30 03:24:30  block index             300ms
2017-04-30 03:24:30 init message: Loading wallet...
2017-04-30 03:24:30 nFileVersion = 2029900
2017-04-30 03:24:30 Keys: 1001 plaintext, 0 encrypted, 1001 w/ metadata, 1001 total
2017-04-30 03:24:30  wallet                  171ms
2017-04-30 03:24:30 Waiting for genesis block to be imported...
2017-04-30 03:24:30 Reindexing block file blk00000.dat...

As @Fuzzbawls said mb i got these crashes because that build is not on latest master.
So if you provide latest pre-release build I could test it and post test report here.