Zcashd 3.0.0 - CopyPreviousWitness problem

ChileBob · May 29, 2020, 2:43pm

Getting this error on startup :-

zcashd: wallet/wallet.cpp:1080: void CopyPreviousWitnesses(NoteDataMap&, int, int64_t) [with NoteDataMap = std::map<SaplingOutPoint, SaplingNoteData>; int64_t = long int]: Assertion `(nd->witnessHeight == -1) || (nd->witnessHeight == indexHeight - 1)’ failed.
Aborted

Doing a reindex to see if that clears it.

EDIT: Still reindexing, just in case its useful here are the last unusual lines of debug.log just before it borked -

Leaving InitialBLockDownload (latching to false)
ERROR: ContextualCheckTransaction(): transaction is expired
ERROR: AcceptToMemoryPool: ContextualCheckTransaction failed

EDIT: Re-indexing cleared the error.

anon16456014 · May 29, 2020, 7:00pm

github.com/zcash/zcash

zcashd assertion failure CopyPreviousWitnesses() Assertion (nd->witnessHeight == -1) || (nd->witnessHeight == indexHeight - 1)

opened 09:02PM - 14 Jan 20 UTC

closed 02:07PM - 09 Jul 20 UTC

LarryRuane

C-bug

While running a debug build (`CONFIGURE_FLAGS='--enable-debug'`) on testnet, rec…ent `master` branch (latest commit 2f8cf61a2a0407f4d6232e82f3a9b5ddbea25832 Jan 9 2020) zcashd crashed while starting up (but it was recently synced) with the following assert message: ``` (...) [Press Ctrl+C to exit] [Set 'showmetrics=0' to hide] zcashd: wallet/wallet.cpp:1065: void CopyPreviousWitnesses(NoteDataMap&, int, int64_t) [with NoteDataMap = std::map<JSOutPoint, SproutNoteData>; int64_t = long int]: Assertion `(nd->witnessHeight == -1) || (nd->witnessHeight == indexHeight - 1)' failed. ``` The assertion is 100% reproducible. Before this crash, the zcashd had asserted with a lock ordering potential deadlock assert (I no longer have the exact assertion text), so it may be that this assertion left the data directory in an inconsistent state (lack of clean shutdown), causing zcashd to fail on startup every time. I had never seen this failure before. I think the lock ordering assertion is a known (non-critical) problem; this ticket is not about that failure. I started zcashd again using `gdb`, and here are the most recent set of stack frames, and then the variables involved in the assertion: ``` (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 #1 0x00007ffff68b6801 in __GI_abort () at abort.c:79 #2 0x00007ffff68a639a in __assert_fail_base (fmt=0x7ffff6a2d7d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55555631f3e0 "(nd->witnessHeight == -1) || (nd->witnessHeight == indexHeight - 1)", file=file@entry=0x55555631d427 "wallet/wallet.cpp", line=line@entry=1065, function=function@entry=0x55555632cec0 <void CopyPreviousWitnesses<std::map<JSOutPoint, SproutNoteData, std::less<JSOutPoint>, std::allocator<std::pair<JSOutPoint const, SproutNoteData> > > >(std::map<JSOutPoint, SproutNoteData, std::less<JSOutPoint>, std::allocator<std::pair<JSOutPoint const, SproutNoteData> > >&, int, long)::__PRETTY_FUNCTION__> "void CopyPreviousWitnesses(NoteDataMap&, int, int64_t) [with NoteDataMap = std::map<JSOutPoint, SproutNoteData>; int64_t = long int]") at assert.c:92 #3 0x00007ffff68a6412 in __GI___assert_fail ( assertion=0x55555631f3e0 "(nd->witnessHeight == -1) || (nd->witnessHeight == indexHeight - 1)", file=0x55555631d427 "wallet/wallet.cpp", line=1065, function=0x55555632cec0 <void CopyPreviousWitnesses<std::map<JSOutPoint, SproutNoteData, std::less<JSOutPoint>, std::allocator<std::pair<JSOutPoint const, SproutNoteData> > > >(std::map<JSOutPoint, SproutNoteData, std::less<JSOutPoint>, std::allocator<std::pair<JSOutPoint const, SproutNoteData> > >&, int, long)::__PRETTY_FUNCTION__> "void CopyPreviousWitnesses(NoteDataMap&, int, int64_t) [with NoteDataMap = std::map<JSOutPoint, SproutNoteData>; int64_t = long int]") at assert.c:101 #4 0x0000555555ad7ef0 in CopyPreviousWitnesses<std::map<JSOutPoint, SproutNoteData, std::less<JSOutPoint>, std::allocator<std::pair<JSOutPoint const, SproutNoteData> > > > (noteDataMap=std::map with 1 element = {...}, indexHeight=763309, nWitnessCacheSize=100) at wallet/wallet.cpp:1065 #5 0x0000555555aac3f6 in CWallet::IncrementNoteWitnesses (this=0x5555ab39ccd0, pindex=0x7fff8c013c30, pblockIn=0x7fffb32414e0, sproutTree=..., saplingTree=...) at wallet/wallet.cpp:1143 #6 0x0000555555aa9062 in CWallet::ChainTipAdded (this=0x5555ab39ccd0, pindex=0x7fff8c013c30, pblock=0x7fffb32414e0, sproutTree=..., saplingTree=...) at wallet/wallet.cpp:571 #7 0x0000555555aa915c in CWallet::ChainTip (this=0x5555ab39ccd0, pindex=0x7fff8c013c30, pblock=0x7fffb32414e0, added=...) at wallet/wallet.cpp:580 #8 0x00005555559c0fd4 in boost::_mfi::mf3<void, CValidationInterface, CBlockIndex const*, CBlock const*, boost::optional<std::pair<libzcash::IncrementalMerkleTree<29ul, libzcash::SHA256Compress>, libzcash::IncrementalMerkleTree<32ul, libzcash::PedersenHash> > > >::operator() (this=0x5555a96ea700, p=0x5555ab39cff8, a1=0x7fff8c013c30, a2=0x7fffb32414e0, a3=...) at /home/larry/zcash/depends/x86_64-unknown-linux-gnu/share/../include/boost/bind/mem_fn_template.hpp:393 (...) (gdb) p nd->witnessHeight $3 = 763278 (gdb) p indexHeight $4 = 763309 (gdb) ``` (I can add more stack frames if needed.) The testnet block height at the time was approximately 763684. I uploaded the full `debug.log` file since startup here: https://gist.github.com/LarryRuane/ed4f4e5c061b3407e9bf8c736b8f033f I also saved a copy of the entire `testnet3` directory (3.0 gb) and can provide that if needed. In my view, it's likely that anyone can reproduce the problem using this data directory and a debug build. Here are the relevant lines from the `zcash.conf` file (I started `zcashd` with no command-line arguments): ``` testnet=1 addnode=testnet.z.cash txindex=1 experimentalfeatures=1 insightexplorer=1 addressindex=1 spentindex=1 timestampindex=1 migration=1 ```

ChileBob · May 30, 2020, 2:47pm

Not sure if this helps but I’ve been experimenting, starting & stopping zcashd every few minutes :-

while :
do
zcashd --daemon
sleep 300
zcash-cli stop
sleep 120
done

Its survived 24 hours (lots of cycles), I’m seeing an error “ContextualCheckTransaction(): transaction is expired” in the debug.log BUT its not causing zcashd to abort on startup and everything still works.

Doing the same with ycashd (which I think has the same problem?) and am seeing the same, I’ll leave it running…

So… ‘ctrl-C’ bad, ‘zcash-cli stop’ good ?

Shawn · May 30, 2020, 2:59pm

I always use -stop as opposed to ctl-c to close Zcashd. Think of it like a PC, stop is choosing “shutdown my PC”, where ctl-c is like holding the power button on your PC and can cause errors next time it starts…

ChileBob · May 30, 2020, 3:06pm

Absolutely, when you run it in a terminal it says ‘Ctrl-C to exit’, so there’s that…

I’m just playing with ideas & sharing here. Maybe some subtle timing thing on signal handling is causing a bad shutdown so asking the RPC server nicely could address that.

If its still going on Monday I’ll cycle it with ctrl-C like shutdowns & see what happens.