ProcessBlock: ORPHAN BLOCK in debug.log – Meaning?

ViktorP

newbie

Activity: 1

Merit: 0

Hello, I was curious about it too. I'm quite new to all the Bitcoin network stuff, but it looks to me that due to some synchronization problems due to parallel download some peers (nodes) send you the blocks, that points to previous block you have never seen before (too young in the block chain). Bitcoin client stores these blocks in memory. It is referred in the debug file as "ORPHAN BLOCK ##".
When you download block that can be connected to the top of your chain, the Bitcoin client checks if some orphan block "fits" to the top of the chain. Then the orphan block is processed (consuming CPU resources) and appended to you block chain copy.
Check the piece of my debug log:
15:43:00 block pointing to previous block "2aaa53..." was downloaded, but I don't have this block, so I don't know what consecutive number the block should have. So, it is orphan block nr. 16 now.
15:43:28 last orphan block was downloaded
15:44:20 "2aaa53..." block was properly downloaded and the orphan block nr. 16 is consumed from the memory.
15:56:04 almost all 504 orphan blocks were consumed (appended to the top of block chain)
15:56:08 another line of orphan block is being downloaded.

BTW. It looks that from version 0.9.3 is number of orphan blocks in memory limited to 751 blocks.

Code:

2014-10-28 15:42:59 ProcessBlock: ORPHAN BLOCK 14, prev=0000000000000000151ed7f65c21ec546fbad349d6dbb0eb1eccaee2be7fa41f
2014-10-28 15:42:59 UpdateTip: new best=000000000000000010305db8a34360bf1c8ba3a4b70e2d2ee3baa8f51a76111c  height=309668  log2_work=79.596869  tx=42100519  date=2014-07-07 20:54:56 progress=0.655304
2014-10-28 15:42:59 ProcessBlock: ACCEPTED
2014-10-28 15:43:00 ProcessBlock: ORPHAN BLOCK 15, prev=00000000000000001a54bfaed695430eec2aa6bcabceae526b609ac6fe0d6bed
2014-10-28 15:43:00 ProcessBlock: ORPHAN BLOCK 16, prev=00000000000000002aaa53aef033969d68cc70405a7906cef9dd842944bb8d6d
2014-10-28 15:43:00 ProcessBlock: ORPHAN BLOCK 17, prev=00000000000000000d4d6d2d74b180bdba480eb1e711d9a2dea149b4122f177c
2014-10-28 15:43:00 ProcessBlock: ORPHAN BLOCK 18, prev=00000000000000000859685a6b93e5b0e740ac6be3d842063e4dd861e1f9f9db

<516 LINES INTENTIONALLY DELETED>

2014-10-28 15:43:28 ProcessBlock: ORPHAN BLOCK 502, prev=0000000000000000097a74b21052bfda6f6a45be233c7f2ca3e6c37846c5b298
2014-10-28 15:43:28 ProcessBlock: ORPHAN BLOCK 503, prev=000000000000000041518eea5d76f9ea54e57a5bba1cd1445cfe82b58a12a10c
2014-10-28 15:43:28 ProcessBlock: ORPHAN BLOCK 504, prev=00000000000000003252284a5ee503fe2c7a3d4ded8be64d6ebba13cd2df6199
2014-10-28 15:43:39 Pre-allocating up to position 0x1100000 in rev00154.dat
2014-10-28 15:43:41 UpdateTip: new best=00000000000000001599ef1d3fe2eb7b875c2a3f9ecb2975e6e1d53a750f8252  height=309675  log2_work=79.597667  tx=42102453  date=2014-07-07 21:29:57 progress=0.655385
2014-10-28 15:43:41 ProcessBlock: ACCEPTED
2014-10-28 15:43:43 receive version message: /bitcoinseeder:0.01/: version 60000, blocks=230000, us=147.32.163.22:8333, them=0.0.0.0:0, peer=172.245.62.102:39692
2014-10-28 15:43:54 receive version message: /bitcoinseeder:0.01/: version 60000, blocks=230000, us=147.32.163.22:8333, them=0.0.0.0:0, peer=178.18.90.41:52828
2014-10-28 15:43:58 receive version message: /bitcoinseeder:0.01/: version 60000, blocks=230000, us=147.32.163.22:8333, them=0.0.0.0:0, peer=199.127.225.195:60942
2014-10-28 15:44:16 UpdateTip: new best=0000000000000000359900b3a4005fbe1a3be35582917a3459a772d8320ac5e2  height=309676  log2_work=79.597781  tx=42104029  date=2014-07-07 22:01:04 progress=0.655456
2014-10-28 15:44:16 ProcessBlock: ACCEPTED
2014-10-28 15:44:17 UpdateTip: new best=00000000000000001a54bfaed695430eec2aa6bcabceae526b609ac6fe0d6bed  height=309677  log2_work=79.597895  tx=42104104  date=2014-07-07 22:00:10 progress=0.655456
2014-10-28 15:44:17 Leaving block file 154: CBlockFileInfo(blocks=619, size=133861902, heights=309059...309677, time=2014-07-03...2014-07-07)
2014-10-28 15:44:17 Pre-allocating up to position 0x1000000 in blk00155.dat
2014-10-28 15:44:20 Pre-allocating up to position 0x100000 in rev00155.dat
2014-10-28 15:44:20 UpdateTip: new best=00000000000000002aaa53aef033969d68cc70405a7906cef9dd842944bb8d6d  height=309678  log2_work=79.598009  tx=42105346  date=2014-07-07 22:29:32 progress=0.655518
2014-10-28 15:44:23 UpdateTip: new best=00000000000000000d4d6d2d74b180bdba480eb1e711d9a2dea149b4122f177c  height=309679  log2_work=79.598123  tx=42105738  date=2014-07-07 22:34:16 progress=0.655532
2014-10-28 15:44:24 UpdateTip: new best=00000000000000000859685a6b93e5b0e740ac6be3d842063e4dd861e1f9f9db  height=309680  log2_work=79.598237  tx=42106198  date=2014-07-07 22:40:03 progress=0.655548
2014-10-28 15:44:26 UpdateTip: new best=000000000000000037b028a7d1214852e2701a153ab3364765e087795bace9d4  height=309681  log2_work=79.59835  tx=42106791  date=2014-07-07 22:50:46 progress=0.655573
2014-10-28 15:44:26 UpdateTip: new best=0000000000000000291140c22622d3bf88469fde1d97f3ee9ca1c77157e0ab88  height=309682  log2_work=79.598464  tx=42106842  date=2014-07-07 22:54:51 progress=0.655580
2014-10-28 15:44:29 UpdateTip: new best=000000000000000009175843bda6c59f7b72f683b0c4747a4f414881a1c9466f  height=309683  log2_work=79.598578  tx=42107652  date=2014-07-07 23:09:05 progress=0.655614

<535 LINES INTENTIONALLY DELETED>

2014-10-28 15:56:01 UpdateTip: new best=000000000000000041518eea5d76f9ea54e57a5bba1cd1445cfe82b58a12a10c  height=310165  log2_work=79.65244  tx=42316553  date=2014-07-11 01:46:53 progress=0.665481
2014-10-28 15:56:03 UpdateTip: new best=00000000000000003252284a5ee503fe2c7a3d4ded8be64d6ebba13cd2df6199  height=310166  log2_work=79.65255  tx=42317117  date=2014-07-11 02:02:11 progress=0.665512
2014-10-28 15:56:04 UpdateTip: new best=0000000000000000073d29de427832df5fd440251c5b91a39d9cc0fd6da8203f  height=310167  log2_work=79.65266  tx=42317207  date=2014-07-11 02:03:51 progress=0.665516
2014-10-28 15:56:04 ProcessBlock: ACCEPTED
2014-10-28 15:56:05 Peer 50.170.60.31:8333 is stalling block download, disconnecting
2014-10-28 15:56:08 ProcessBlock: ORPHAN BLOCK 15, prev=0000000000000000103d879cc863d881ac97b1a0351e47a1611565272f74f60f
2014-10-28 15:56:08 ProcessBlock: ORPHAN BLOCK 16, prev=000000000000000011eb4744c76822d8b01db3a0041316b59fb988cc85d2a9f4
2014-10-28 15:56:08 UpdateTip: new best=000000000000000000ebfad7343754ae4d4ea19178de72529df5e167adfbded0  height=310168  log2_work=79.652769  tx=42317240  date=2014-07-11 02:04:38 progress=0.665517
2014-10-28 15:56:08 ProcessBlock: ACCEPTED
2014-10-28 15:56:11 Pre-allocating up to position 0x1100000 in rev00155.dat
2014-10-28 15:56:11 UpdateTip: new best=00000000000000002860ae698960e908573190f0ca1fb76637f3ae7103e4c06c  height=310169  log2_work=79.652879  tx=42317884  date=2014-07-11 02:25:19 progress=0.665557
2014-10-28 15:56:11 ProcessBlock: ACCEPTED

cr1776

legendary

Activity: 4130

Merit: 1307

I did something similar - just adjusted maxconnections in bitcoin.conf.

:-)

Fujireloaded

newbie

Activity: 12

Merit: 0

Yes, it's definitely an issue. It slows down the syncing terribly.

You get all those orphaned blocks when they get sent to you in parallel by the peers you're connected to (that's what I read and I still don't really get what's going on).

Apparently it's been fixed and it will make it into 0.9.3.

But if you can't wait here's how I went around it. Just launch bitcoind with -maxconnections=3.
Since the parallelism is lower this reduces the amount of orphans dramatically. I find the speed still pretty good with 3 connections.

After you're done with the syncing, leave out this parameter cause the more connections you have the better. There shouldn't be orphans after the syncing.

Hope it helps.

cr1776

legendary

Activity: 4130

Merit: 1307

It is funny you posted this, I was noticing the same thing with a new node I was bringing online today - FWIW, I see it on Ubuntu 14.04. It seems to be relatively normal right now with the code as it is, but starting and stopping bitcoind seems to have helped performance since it was bumping up to the 751 ceiling. What you link to seems to explain it somewhat obscurely.

Fujireloaded

newbie

Activity: 12

Merit: 0

In my debug.log I see a lot of the following messages (with different orphan block number):

2014-08-19 19:04:23 ProcessBlock: ORPHAN BLOCK 631, prev=00000000000000005ee64e8321c3c428a91f5acc60b3ee02eaf1159c68e7e95b

It even blocked the sync of my bitcoind for several hours until I manually restarted it.

I've found this thread about it, and it seems to be a real issue/bug: https://github.com/bitcoin/bitcoin/issues/4353

However, I don't really understand exactly what the problem is and if there is something I can do about it.

The bitcoind was running on a Mac Mini 2.3Ghz i7, 4GB RAM, 1TB HD. It was run after a fresh reboot and most of the HD is free.

Does anybody know what's going on there?

Edit: Actually, I just noticed the orphan block number is now always 751. It looks like it reached like a sort of maximum value.

Topic: ProcessBlock: ORPHAN BLOCK in debug.log – Meaning? (Read 3253 times)