PoS testing: another seized node (#302) · Issues · Crown / crown-core

PoS testing: another seized node

Summary

SN seized up with debug.log containing repeated

2019-02-01 22:57:44 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 22:59:29 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 22:59:33 CActiveSystemnode::SendSystemnodePing() - Relay Systemnode Ping vin = CTxIn(COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1), scriptSig=)

Node doesn't respond to crown-cli commands, isn't generating blocks.

Steps to reproduce

Unknown

Expected behavior

Nodes shouldn't seize up

Problematic behavior

Node has seized up. Different debug.log symptoms to other occurrences.

Crown-core environment info

Ubuntu 16.04

Crown-core application info

Crown version v0.12.7.3-2cf48571

Relevant logs, dumps and/or screenshots

2019-02-01 21:51:22 CreateCoinStake: Found valid kernel for mn/sn collateral COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1)
2019-02-01 21:51:22 CreateCoinStake: OutPoint: d2263ba9e58bae086add7b402e8ab6e77ce56d13455b62994f9f8d2ba14f7eed:2 Modifier=abe6cb17ee51011d135ac6c7d670353facbf2f45d3f2c9fb6c50501288ab3785 timeblockfrom=1548789632 time=1549057888 amount=500
2019-02-01 21:51:22 Masternode payment to tCRWFtG1oYWVqb3Z1tZjmBFkGehjucruFV1ip
2019-02-01 21:51:22 Systemnode payment to tCRWXFxbcFRbqBmgjhYQWgTTnBVzePC7fa1w9
2019-02-01 21:51:22 CreateNewBlock(): total size 1000
2019-02-01 21:51:22 CheckProofOfStake : OutPoint: d2263ba9e58bae086add7b402e8ab6e77ce56d13455b62994f9f8d2ba14f7eed:2 Modifier=abe6cb17ee51011d135ac6c7d670353facbf2f45d3f2c9fb6c50501288ab3785 timeblockfrom=1548789632 time=1549057888 amount=500
2019-02-01 21:51:22 CBlock(hash=c41a0bf9b8dcdf8dc287cd1b192871b1b31728740a4135cc1927b9290c71de57, ver=1442306, hashPrevBlock=f6f09bbae7768af7c1e0d20ebdbe3c043fbdb03c297dc7986098adf57595de4b, hashMerkleRoot=ac9685fe61962b037e2188e33b15a76da3ac378a27b4cbbcab3b870a9c764d39, nTime=1549057888, nBits=1d154514, nNonce=0, vtx=2)
  CTransaction(hash=77a17dcea3, ver=1, vin.size=1, vout.size=3, nLockTime=0)
    CTxIn(COutPoint(0000000000000000000000000000000000000000000000000000000000000000, 4294967295), coinbase 02487500)
    CTxOut(nValue=0.00000000, scriptPubKey=)
    CTxOut(nValue=4.50000000, scriptPubKey=OP_DUP OP_HASH160 1fbff4676e84)
    CTxOut(nValue=0.90000000, scriptPubKey=OP_DUP OP_HASH160 c864741980d5)

  CTransaction(hash=46d066e1ae, ver=1, vin.size=1, vout.size=1, nLockTime=0)
    CTxIn(COutPoint(0000000000000000000000000000000000000000000000000000000000000000, 4294967295), coinbase c002487500)
    CTxOut(nValue=3.60000000, scriptPubKey=OP_DUP OP_HASH160 ed66a4bcd1e9)

  vMerkleTree:  77a17dcea32edbaba3df21a901733dd570015ce47154923126289dc25a805974 46d066e1ae9d816f48e437164cdb326282a9b6fb4030a7e5c826a9357a4cde09 ac9685fe61962b037e2188e33b15a76da3ac378a27b4cbbcab3b870a9c764d39

2019-02-01 21:51:22 generated 0.00
2019-02-01 21:51:22 keypool keep 243
2019-02-01 21:51:22 CheckProofOfStake : OutPoint: d2263ba9e58bae086add7b402e8ab6e77ce56d13455b62994f9f8d2ba14f7eed:2 Modifier=abe6cb17ee51011d135ac6c7d670353facbf2f45d3f2c9fb6c50501288ab3785 timeblockfrom=1548789632 time=1549057888 amount=500
2019-02-01 21:51:22 UpdateTip: new best=c41a0bf9b8dcdf8dc287cd1b192871b1b31728740a4135cc1927b9290c71de57  height=30024  log2_work=42.570074  tx=50574  date=2019-02-01 21:51:28 progress=1.000003  cache=0.4MiB(1945tx)
...
2019-02-01 22:54:33 CActiveSystemnode::SendSystemnodePing() - Relay Systemnode Ping vin = CTxIn(COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1), scriptSig=)
2019-02-01 22:56:24 socket send error Broken pipe (32)
2019-02-01 22:56:29 socket send error Broken pipe (32)
2019-02-01 22:57:04 socket send error Broken pipe (32)
2019-02-01 22:57:09 socket send error Broken pipe (32)
2019-02-01 22:57:44 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 22:59:29 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 22:59:33 CActiveSystemnode::SendSystemnodePing() - Relay Systemnode Ping vin = CTxIn(COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1), scriptSig=)
2019-02-01 23:01:14 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 23:02:59 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-01 23:04:34 CActiveSystemnode::SendSystemnodePing() - Relay Systemnode Ping vin = CTxIn(COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1), scriptSig=)
...
2019-02-02 06:20:18 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-02 06:22:03 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-02 06:25:24 CMasternodeSync::GetNextAsset - Sync has finished
2019-02-02 06:26:13 CActiveSystemnode::SendSystemnodePing() - Relay Systemnode Ping vin = CTxIn(COutPoint(1ae8552ef970d98eea05d4e3156e560935431fa6ea8194a9e86ec80254962e45, 1), scriptSig=)
2019-02-02 06:27:09 CMasternodeSync::GetNextAsset - Sync has finished

Uploaded 20190201_walkjivefly_SN_PSN03_seize.log to https://nextcloud.crown.tech/nextcloud/s/znd8HiiAsRX3C6B

A quick gdb shows

crown@Crown-Testnet:~/.crown/testnet3$ sudo gdb -pid=21534
GNU gdb (Ubuntu 7.11.1-0ubuntu1~16.5) 7.11.1
Copyright (C) 2016 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 21534
[New LWP 21537]
[New LWP 21538]
[New LWP 21539]
[New LWP 21540]
[New LWP 21541]
[New LWP 21542]
[New LWP 21543]
[New LWP 21544]
[New LWP 21545]
[New LWP 21546]
[New LWP 21547]
[New LWP 21548]
[New LWP 21550]
[New LWP 21551]
[New LWP 21553]
[New LWP 21554]
[New LWP 21555]
[New LWP 21556]
[New LWP 21557]
[New LWP 21558]
[New LWP 21559]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
185	../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S: No such file or directory.
(gdb) info thread
  Id   Target Id         Frame 
* 1    Thread 0x7f4291652740 (LWP 21534) "crownd" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  2    Thread 0x7f4290193700 (LWP 21537) "crownd" pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  3    Thread 0x7f428f992700 (LWP 21538) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  4    Thread 0x7f428f191700 (LWP 21539) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  5    Thread 0x7f428e990700 (LWP 21540) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  6    Thread 0x7f428e18f700 (LWP 21541) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  7    Thread 0x7f428d98e700 (LWP 21542) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  8    Thread 0x7f428d18d700 (LWP 21543) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  9    Thread 0x7f428c98c700 (LWP 21544) "crown-scriptch" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  10   Thread 0x7f428c18b700 (LWP 21545) "crownd" pthread_cond_timedwait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  11   Thread 0x7f428b98a700 (LWP 21546) "crownd" 0x00007f429029ba13 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
  12   Thread 0x7f428b189700 (LWP 21547) "crownd" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  13   Thread 0x7f428a988700 (LWP 21548) "crownd" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  14   Thread 0x7f426bfff700 (LWP 21550) "crownd" pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  15   Thread 0x7f426b7fe700 (LWP 21551) "crown-legacysig" pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  16   Thread 0x7f426a7fc700 (LWP 21553) "crown-net" __lll_lock_wait ()
    at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  17   Thread 0x7f4269ffb700 (LWP 21554) "crown-addcon" pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  18   Thread 0x7f42697fa700 (LWP 21555) "crown-opencon" pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  19   Thread 0x7f4268ff9700 (LWP 21556) "crown-msghand" __lll_lock_wait ()
    at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  20   Thread 0x7f4263fff700 (LWP 21557) "crown-dumpaddr" pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
  21   Thread 0x7f42637fe700 (LWP 21558) "crown-miner" __lll_lock_wait ()
    at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  22   Thread 0x7f4262ffd700 (LWP 21559) "crown-wallet" pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:225
(gdb) thread 21
[Switching to thread 21 (Thread 0x7f42637fe700 (LWP 21558))]
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
135	../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S: No such file or directory.
(gdb) bt
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007f4290567e42 in __GI___pthread_mutex_lock (mutex=0xe874c0 <cs_main>)
    at ../nptl/pthread_mutex_lock.c:115
#2  0x0000000000451535 in CMutexLock<AnnotatedMixin<boost::recursive_mutex> >::CMutexLock(AnnotatedMixin<boost::recursive_mutex>&, char const*, char const*, int, bool) ()
#3  0x00000000004987b9 in GetTransaction(uint256 const&, CTransaction&, uint256&, bool) ()
#4  0x00000000006db110 in IsBudgetCollateralValid(uint256, uint256, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, long&, int&) ()
#5  0x00000000006dba32 in CBudgetProposal::IsValid(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >&, bool) const ()
#6  0x00000000006e2229 in CBudgetManager::CheckAndRemove() ()
#7  0x00000000006e255e in CBudgetManager::NewBlock() ()
#8  0x00000000004ae320 in ProcessNewBlock(CValidationState&, CNode*, CBlock*, CDiskBlockPos*) ()
#9  0x00000000004eeb31 in ProcessBlockFound(CBlock*, CWallet&, CReserveKey&) ()
#10 0x00000000004f2816 in BitcoinMiner(CWallet*, bool) ()
#11 0x00000000004fc817 in ThreadStakeMiner() ()
#12 0x0000000000512db8 in void TraceThread<void (*)()>(char const*, void (*)())
    ()
#13 0x00000000007c8da2 in thread_proxy ()
#14 0x00007f42905656ba in start_thread (arg=0x7f42637fe700)
    at pthread_create.c:333
#15 0x00007f429029b41d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb) quit

Possible fixes

(Any comments on what you think might be responsible for the problem, if you have particular insight.)

/cc @artem

To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information