gridcoin-community / Gridcoin-Research

Gridcoin-Research
MIT License
585 stars 173 forks source link

ERROR: AcceptBlock: invalid proof-of-stake for block <...> and 100% CPU usage #2759

Closed Yamakuzure closed 3 months ago

Yamakuzure commented 3 months ago

Bug Report

Current behavior After some minutes the CPU usage of gridcoinresearch starts rising, until it reaches constant ~100% on one VCPU.

Meanwhile the debug.log starts filling with the same line over and over again:

(line breaks by me for readability)

2024-04-08T07:02:14Z ERROR: AcceptBlock: invalid proof-of-stake for
    block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7,
    prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T07:02:14Z ERROR: ProcessBlock() : AcceptBlock FAILED
2024-04-08T07:02:14Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T07:02:14Z ERROR: AcceptBlock: invalid proof-of-stake for
    block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7,
    prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T07:02:14Z ERROR: ProcessBlock() : AcceptBlock FAILED

Expected behavior If AcceptBlock failed, and the chain is valid nevertheless, I would expect the failed block to be discarded.

Steps to reproduce: When this first happened I deleted accrual, blk*.dat and txleveldb so the program had to re-sync from scratch, but the above problem reappeared after a few hour.

The interesting part is, that it is always the same block after the same prev. So this seems to be a real broken block in the global chain and not some sync error on my machine.

Gridcoin version 5.4.7.0-leisure

Machine specs

Extra information

 $ grep "invalid proof-of-stake for block" ~/.GridcoinResearch/debug.log | wc -l
1953
 $ # 1,953 lines at the moment. It keeps filling until the debug.log is reset.
 $
 $ grep "invalid proof-of-stake for block" ~/.GridcoinResearch/debug.log | cut -d ':' -f 4- | sort -u
 AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
 $ # As you can see, this is always the same line
 $
 $ grep "a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7" ~/.GridcoinResearch/debug.log | head
2024-04-08T00:01:05Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T00:01:05Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T00:01:09Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T00:01:09Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T00:01:16Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T00:01:16Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T00:01:25Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T00:01:25Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T00:01:35Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T00:01:35Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
 $ # As you can see I keep receiving the invalid block every few seconds.
 $
 $ # However, this is not the only symptom. All other blocks are marked as orphaned in between:
 $ tail ~/GridcoinResearch/debug.log
2024-04-08T07:20:40Z  Received block 1d8bdbf265c27d5a2cb4d65388cacc97694f3134936fbe0f4a63641a21a67611; 
2024-04-08T07:20:40Z ProcessBlock: ORPHAN BLOCK, prev=49423fe69f83ef93de52c067afc5719047ffe9cb9543c2366ec97bd53289d7f7
2024-04-08T07:20:45Z  Received block 49423fe69f83ef93de52c067afc5719047ffe9cb9543c2366ec97bd53289d7f7; 
2024-04-08T07:20:45Z ProcessBlock: ORPHAN BLOCK, prev=47ccc399add42bc341e10c76b61f0daec06e775173ec06a4dec7de4ce1fb4626
2024-04-08T07:20:50Z  Received block 47ccc399add42bc341e10c76b61f0daec06e775173ec06a4dec7de4ce1fb4626; 
2024-04-08T07:20:50Z ProcessBlock: ORPHAN BLOCK, prev=1499ae728793ddb6c76c32d31eb481316796c3513a951983772f439cbea8d734
2024-04-08T07:20:56Z  Received block 1499ae728793ddb6c76c32d31eb481316796c3513a951983772f439cbea8d734; 
2024-04-08T07:20:56Z ProcessBlock: ORPHAN BLOCK, prev=fc8905523dc61d357d6365aab6f3c1965a504e9dee6dc5cac32b007b8c8ae6e2
2024-04-08T07:20:59Z UPnP Port Mapping successful.
2024-04-08T07:21:02Z  Received block fc8905523dc61d357d6365aab6f3c1965a504e9dee6dc5cac32b007b8c8ae6e2; 
2024-04-08T07:21:02Z ProcessBlock: ORPHAN BLOCK, prev=224da8dc6e21f0387209498aaeb0d68da26b7b057a48954f917beda09028dff4
2024-04-08T07:21:08Z  Received block 224da8dc6e21f0387209498aaeb0d68da26b7b057a48954f917beda09028dff4; 
2024-04-08T07:21:08Z ProcessBlock: ORPHAN BLOCK, prev=265f4be6f1d3ef7c31c83a6e26b19c71790d3f07d990fb5b073e4c29ae89d3df
2024-04-08T07:21:11Z  Received block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7; 
2024-04-08T07:21:11Z ERROR: AcceptBlock: invalid proof-of-stake for block a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7, prev d953913c4804e59ce673dc886d7dbd1a817755a78cfd214d9164782206840c35
2024-04-08T07:21:11Z ERROR: ProcessBlock() : AcceptBlock FAILED
div72 commented 3 months ago

@Yamakuzure Can you grep with context or publish your full debug.log? a840be400407818a7a05e2ec2afee0f5661e0f98d6e59054edb79690507b69a7 does not seem to be in the main chain.

Yamakuzure commented 3 months ago

Sure! I will start GridCoin and let it run for 30 minutes, to get a fresh not-too-long (the old had ~800MB) debug.log.

@div72 : https://pastebin.com/zbfj78pV

div72 commented 3 months ago

Can you re-compile your node with the following patch and post a new debug.log?

diff --git a/src/gridcoin/staking/kernel.cpp b/src/gridcoin/staking/kernel.cpp
index 7f1952140..158bbbd48 100644
--- a/src/gridcoin/staking/kernel.cpp
+++ b/src/gridcoin/staking/kernel.cpp
@@ -603,21 +603,21 @@ bool GRC::CheckProofOfStakeV8(
     CTransaction txPrev;

     if (!ReadStakedInput(txdb, prevout.hash, header, txPrev, pindexPrev))
-        return tx.DoS(1, error("%s: read staked input failed", __func__));
+        return tx.DoS(10, error("%s: read staked input failed", __func__));

     if (!VerifySignature(txPrev, tx, 0, 0))
         return tx.DoS(100, error("%s: VerifySignature failed on coinstake %s", __func__, tx.GetHash().ToString()));

     // Check times
     if (tx.nTime < txPrev.nTime)
-        return error("%s: nTime violation", __func__);
+        return tx.DoS(100, error("%s: nTime violation", __func__));

     if (header.nTime + nStakeMinAge > tx.nTime)
-        return error("%s: min age violation", __func__);
+        return tx.DoS(100, error("%s: min age violation", __func__));

     if (Block.nVersion >= 12) {
         if (tx.nTime != MaskStakeTime(tx.nTime)) {
-            return error("%s: mask violation", __func__);
+            return tx.DoS(100, error("%s: mask violation", __func__));
         }
     }

@@ -649,5 +649,9 @@ bool GRC::CheckProofOfStakeV8(
              );

     // Now check if proof-of-stake hash meets target protocol
-    return bnHashProof <= bnTarget;
+    if (bnHashProof <= bnTarget) {
+        return true;
+    }
+
+    return tx.DoS(100, error("%s: invalid proof (proof: %s, target: %s)", __func__, bnHashProof.GetHex(), bnTarget.GetHex()));
 }
div72 commented 3 months ago

Also please make sure debug=net is present in your config file.

Yamakuzure commented 3 months ago

The patched version was compiled successfully and is now installed. Currently syncing...

I'll let it run for 30 minutes and will post another debug.log.

@div72 : The log is too big for pastebin, so I attach it here. debug-20240409.log.zip

jamescowens commented 3 months ago

This patch was added to #2758.