fastsync stuck at a forked block 51e48f5b (height 74,673)

[garyyu]

Aug 31 09:59:12.460 DEBG process_block: orphan: 51e48f5b, # orphans 129
Aug 31 09:59:12.472 DEBG process_block: orphan: 51e48f5b, # orphans 129
Aug 31 09:59:12.478 DEBG process_block: orphan: 51e48f5b, # orphans 129
Aug 31 09:59:12.482 DEBG process_block: orphan: 51e48f5b, # orphans 129
Aug 31 09:59:12.486 DEBG process_block: orphan: 51e48f5b, # orphans 129
Aug 31 09:59:12.495 DEBG process_block: orphan: 51e48f5b, # orphans 129

and a lot of above same log:

$ grep -c "process_block: orphan: 51e48f5b" ~/.grin/grin-server.log
9680

check this block and find it's a forked block at height 74,673

will investigate root cause later.

[garyyu]

root cause addressed, it's because block 74,673's parent is also a forked block!

The detail analysis:

1. There 3 forks at height 74,673:

Height	Hash	Age	Difficulty	Kernels	Inputs	Outputs
74,673	46507359ff119e9d1d91bb8538f8f95a0fda42784631b70675020ba34d58e93a	2h 25m	87	1	0	1
74,673	51e48f5b8116b285a6ce40d1d8e6027aa1ab6ee2c052457e1473ed2bb9bd4cff	52m 18s	87	1	0	1
74,673	7f5b51adcee93197e6a263a458f3428a59101f488c2af05220839d3a4a200f50	1h 2m	58	1	0	1

2. At first, I receive the forked block 51e48f5b and save it into the orphans queue:

   Aug 31 09:52:21.887 DEBG handle_payload: received compact block: msg_len: 1260
   Aug 31 09:52:21.887 DEBG Received compact_block 51e48f5b at 74673 from 185.170.114.201:13414, outputs: 1, kernels: 1, kern_ids: 0, going to process.
   Aug 31 09:52:21.887 DEBG pipe: process_block 51e48f5b at 74673 with 0 inputs, 1 outputs, 1 kernels
   Aug 31 09:52:21.887 DEBG process_block: orphan: 51e48f5b, # orphans 21

3. Then, by the HeaderSync, I received the block header of height 74,673:

   Aug 31 09:52:50.878 DEBG sync head 2f2f7dd1 @ 74672
   Aug 31 09:52:50.881 DEBG pipe: sync_block_header: 46507359 at 74673

4. Then, in BodySync, I requested this

   Aug 31 09:56:14.608 DEBG body_sync: body_head - ed5c27fd, 74547, header_head - 1726cb26, 74777, sync_head - 1726cb26, 74777
   Aug 31 09:56:14.611 DEBG block_sync: 74547/74777 requesting blocks [..., 46507359, ...] from 12 peers
   ...
   Aug 31 09:56:14.618 DEBG Requesting block 46507359 from peer 165.227.109.134:13414.

5. Then, I received this block 46507359 (the right one in longest chain):

   Aug 31 09:56:49.838 DEBG handle_payload: received block: msg_len: 1252
   Aug 31 09:56:49.838 DEBG Received block 46507359 at 74673 from 108.196.200.233:13414, inputs: 0, outputs: 1, kernels: 1, going to process.
   Aug 31 09:56:49.839 DEBG pipe: process_block 46507359 at 74673 with 0 inputs, 1 outputs, 1 kernels
   Aug 31 09:56:49.839 DEBG process_block: orphan: 46507359, # orphans 85

6. Then, once we received the parent block 74,672 and accepted it, and go to process check_orphans(), then, problem happen here!

   Aug 31 09:58:04.963 DEBG pipe: chain head 2f2f7dd1 @ 74672
   Aug 31 09:58:04.965 DEBG pipe: process_block 51e48f5b at 74673 with 0 inputs, 1 outputs, 1 kernels
   Aug 31 09:58:04.965 DEBG process_block: orphan: 51e48f5b, # orphans 126

   When process_block() on 51e48f5b, we check whether its parent exist:

       match ctx.store.block_exists(&b.header.previous) {
           Ok(true) => {}
           Ok(false) => {
               return Err(ErrorKind::Orphan.into());
           }
           Err(e) => {
               return Err(ErrorKind::StoreErr(e, "pipe get previous".to_owned()).into());
           }
       }

but because this 51e48f5b's parent 50adbd8d is also a forked block, and of course we don't have it in the ctx.store, then we return error Err(ErrorKind::Orphan.into()).

and in function check_orphans():

        loop {
            if let Some(orphans) = self.orphans.remove_by_height(&height) {
                for orphan in orphans {
                    ...
                    let res = self.process_block_no_orphans(orphan.block, orphan.opts);
                    if let Ok((_, Some(b))) = res {
                        height = b.header.height + 1;
                    } else {
                        break;         <<<< problem here!  we don't increase height, infinite loop!
                    }
                    ...

[garyyu]

sorry for the noise, the step 3) 4) and 5) are irrelevant. It's enough to just read 1) 2) 6) .

[garyyu]

Fix ready in https://github.com/mimblewimble/grin/pull/1452

[garyyu]

closed by #1452