Can’t seem to rejoin the main chain: Bitcoind stuck at block 422168. “Timestamp too far in future.” #8476

issue nathaniel-mahieu openend this issue on August 6, 2016
  1. nathaniel-mahieu commented at 6:44 pm on August 6, 2016: contributor

    I’m not sure what is relevant so I’m including a lot of information. I’d be happy to take suggestions for ways to fix this. I’m also posting here on the chance this is a bug or behavior that could be improved.

    A log message in debug.log dated 2016-08-06 12:22:19 corresponds to about Sat Aug 6 13:22:37 CDT 2016 on my local time (date) while the corresponding hwtime shows Sat 06 Aug 2016 01:22:47 PM CDT .

     0Ubuntu 14.04.5 LTS
 1
 2bitcoin-cli getinfo
 3{
 4  "version": 120100,
 5  "protocolversion": 70012,
 6  "blocks": 422168,
 7  "timeoffset": -26,
 8  "connections": 20,
 9  "proxy": "",
10  "difficulty": 213492501107.5134,
11  "testnet": false,
12  "relayfee": 0.00001000,
13  "errors": ""
14}

    A few weeks ago I dropped off the main chain.

    0bitcoin-cli getblockcount
1422168

    Here is the debug log from around that time.

     02016-07-25 03:31:17 UpdateTip: 3 of last 100 blocks have unexpected version
 12016-07-25 03:31:18 UpdateTip: new best=00000000000000000304f0c7db28c15cc4226dfc491d4c4f0d8b9ae48744453a  height=422168  log2_work=85.035791  tx=144585606  date=2016-07-25 05:26:32 progress=1.000042  cache=211.6MiB(136697tx)
 22016-07-25 03:31:18 UpdateTip: 3 of last 100 blocks have unexpected version
 32016-07-25 03:31:18 ERROR: CheckBlockHeader(): block timestamp too far in the future
 42016-07-25 03:31:18 InvalidChainFound: invalid block=000000000000000001f4de9d78ed4c2015cb676440e58069f67319ae31e71c75  height=422169  log2_work=85.035824  date=2016-07-25 05:38:02
 52016-07-25 03:31:18 InvalidChainFound:  current best=00000000000000000304f0c7db28c15cc4226dfc491d4c4f0d8b9ae48744453a  height=422168  log2_work=85.035791  date=2016-07-25 05:26:32
 62016-07-25 03:31:18 ERROR: ConnectTip(): ConnectBlock 000000000000000001f4de9d78ed4c2015cb676440e58069f67319ae31e71c75 failed
 72016-07-25 03:31:18 InvalidChainFound: invalid block=000000000000000001f4de9d78ed4c2015cb676440e58069f67319ae31e71c75  height=422169  log2_work=85.035824  date=2016-07-25 05:38:02
 82016-07-25 03:31:18 InvalidChainFound:  current best=00000000000000000304f0c7db28c15cc4226dfc491d4c4f0d8b9ae48744453a  height=422168  log2_work=85.035791  date=2016-07-25 05:26:32
 92016-07-25 03:31:18 mapBlockIndex.size() = 422233
102016-07-25 03:31:18 nBestHeight = 422168

    I have since updated my local time and hwtime (I’m not sure it was ever wrong) and restarted but I do not rejoin the main chain.

    If my system clock gets out of sync and I later fix it, will I automatically rejoin the previously rejected chain? Should this be the default behavior?

    Random recent log near ‘invalid header’:

     02016-07-29 01:09:26 ERROR: CheckBlockHeader(): block timestamp too far in the future
 12016-07-29 01:09:26 ERROR: invalid header received
 22016-07-29 01:09:26 ProcessMessages(headers, 82 bytes) FAILED peer=33
 32016-07-29 01:09:59 ERROR: CheckBlockHeader(): block timestamp too far in the future
 42016-07-29 01:09:59 ERROR: invalid header received
 52016-07-29 01:09:59 ProcessMessages(headers, 82 bytes) FAILED peer=625
 62016-07-29 01:10:32 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=422693, us=68.184.202.88:8333, peer=878
 72016-07-29 01:10:32 AdvertizeLocal: advertizing address 68.184.202.88:8333
 82016-07-29 01:11:04 receive version message: /Snoopy:0.2.1/: version 70001, blocks=0, us=68.184.202.88:8333, peer=879
 92016-07-29 01:11:04 AdvertizeLocal: advertizing address td6iaq6jpck24fxx.onion:8333
102016-07-29 01:14:25 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=422694, us=68.184.202.88:8333, peer=880
112016-07-29 01:14:25 AdvertizeLocal: advertizing address td6iaq6jpck24fxx.onion:8333
122016-07-29 01:15:00 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=422694, us=68.184.202.88:8333, peer=881
132016-07-29 01:15:00 AdvertizeLocal: advertizing address td6iaq6jpck24fxx.onion:8333
142016-07-29 01:15:10 ERROR: CheckBlockHeader(): block timestamp too far in the future
152016-07-29 01:15:10 ERROR: invalid header received
162016-07-29 01:15:10 ProcessMessages(headers, 82 bytes) FAILED peer=33
172016-07-29 01:15:36 ERROR: CheckBlockHeader(): block timestamp too far in the future
182016-07-29 01:15:36 ERROR: invalid header received
192016-07-29 01:15:36 ProcessMessages(headers, 82 bytes) FAILED peer=625

    Log after a restart, still at 422168:

      02016-08-06 18:29:09 Bitcoin version v0.12.1 (2016-04-11 13:01:43 +0200)
  12016-08-06 18:29:09 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
  22016-08-06 18:29:09 Default data directory /home/b/.bitcoin
  32016-08-06 18:29:09 Using data directory /home/b/.bitcoin
  42016-08-06 18:29:09 Using config file /home/b/.bitcoin/bitcoin.conf
  52016-08-06 18:29:09 Using at most 125 connections (1024 file descriptors available)
  62016-08-06 18:29:09 Using 4 threads for script verification
  72016-08-06 18:29:09 scheduler thread start
  82016-08-06 18:29:09 HTTP: creating work queue of depth 16
  92016-08-06 18:29:09 Config options rpcuser and rpcpassword will soon be deprecated. Locally-run instances may remove rpcuser to use cookie-based auth, or may be replaced with rpcauth. Please see share/rpcuser for rpcauth auth generation.
 102016-08-06 18:29:09 HTTP: starting 4 worker threads
 112016-08-06 18:29:09 Bound to [::]:8333
 122016-08-06 18:29:09 Bound to 0.0.0.0:8333
 132016-08-06 18:29:09 Cache configuration:
 142016-08-06 18:29:09 * Using 2.0MiB for block index database
 152016-08-06 18:29:09 * Using 257.5MiB for chain state database
 162016-08-06 18:29:09 * Using 740.5MiB for in-memory UTXO set
 172016-08-06 18:29:09 init message: Loading block index...
 182016-08-06 18:29:09 Opening LevelDB in /home/b/.bitcoin/blocks/index
 192016-08-06 18:29:10 Opened LevelDB successfully
 202016-08-06 18:29:10 Using obfuscation key for /home/b/.bitcoin/blocks/index: 0000000000000000
 212016-08-06 18:29:10 Opening LevelDB in /home/b/.bitcoin/chainstate
 222016-08-06 18:29:10 Opened LevelDB successfully
 232016-08-06 18:29:10 Using obfuscation key for /home/b/.bitcoin/chainstate: 0000000000000000
 242016-08-06 18:29:23 LoadBlockIndexDB: last block file = 579
 252016-08-06 18:29:23 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=155, size=126842528, heights=422025...422178, time=2016-07-24...2016-07-25)
 262016-08-06 18:29:23 Checking all blk files are present...
 272016-08-06 18:29:23 LoadBlockIndexDB: transaction index disabled
 282016-08-06 18:29:23 LoadBlockIndexDB: hashBestChain=00000000000000000304f0c7db28c15cc4226dfc491d4c4f0d8b9ae48744453a height=422168 date=2016-07-25 05:26:32 progress=0.993518
 292016-08-06 18:29:24 init message: Verifying blocks...
 302016-08-06 18:29:24 Verifying last 288 blocks at level 3
 312016-08-06 18:35:14 No coin database inconsistencies in last 289 blocks (435545 transactions)
 322016-08-06 18:35:15  block index          365687ms
 332016-08-06 18:35:15 No wallet support compiled in!
 342016-08-06 18:35:15 init message: Activating best chain...
 352016-08-06 18:35:15 mapBlockIndex.size() = 422233
 362016-08-06 18:35:15 nBestHeight = 422168
 372016-08-06 18:35:15 init message: Loading addresses...
 382016-08-06 18:35:15 torcontrol thread start
 392016-08-06 18:35:15 tor: Reading cached private key from /home/b/.bitcoin/onion_private_key
 402016-08-06 18:35:15 tor: Succesfully connected!
 412016-08-06 18:35:15 tor: Connected to Tor version 0.2.8.6
 422016-08-06 18:35:15 tor: Supported authentication method: COOKIE
 432016-08-06 18:35:15 tor: Supported authentication method: SAFECOOKIE
 442016-08-06 18:35:15 tor: Using SAFECOOKIE authentication, reading cookie authentication from /var/run/tor/control.authcookie
 452016-08-06 18:35:15 tor: SAFECOOKIE authentication challenge succesful
 462016-08-06 18:35:15 tor: AUTHCHALLENGE ServerHash fce8296710d767170c325e4f411fb9bc5f34e56481cbe59dcd31b49de7ee0914 ServerNonce b284aa41a9c892e071d7431b17bbac572059de09f3fa6866006c2f18a78a1cea
 472016-08-06 18:35:15 tor: Authentication succesful
 482016-08-06 18:35:15 tor: ADD_ONION succesful
 492016-08-06 18:35:15 tor: Got service ID td6iaq6jpck24fxx, advertizing service td6iaq6jpck24fxx.onion:8333
 502016-08-06 18:35:15 tor: Cached service private key to /home/b/.bitcoin/onion_private_key
 512016-08-06 18:35:15 AddLocal(td6iaq6jpck24fxx.onion:8333,4)
 522016-08-06 18:35:15 Loaded 10651 addresses from peers.dat  276ms
 532016-08-06 18:35:15 init message: Done loading
 542016-08-06 18:35:15 addcon thread start
 552016-08-06 18:35:15 opencon thread start
 562016-08-06 18:35:15 msghand thread start
 572016-08-06 18:35:15 dnsseed thread start
 582016-08-06 18:35:15 net thread start
 592016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=1
 602016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=2
 612016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=3
 622016-08-06 18:35:15 receive version message: /ViaBTC:bitpeer.0.2.0/: version 70012, blocks=0, us=0.0.0.0:0, peer=4
 632016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=5
 642016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=6
 652016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=7
 662016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=8
 672016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=9
 682016-08-06 18:35:15 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=424011, us=68.184.202.88:8333, peer=10
 692016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=11
 702016-08-06 18:35:15 receive version message: /Satoshi:0.11.2/: version 70002, blocks=423129, us=68.184.202.88:8333, peer=12
 712016-08-06 18:35:15 socket send error Bad file descriptor (9)
 722016-08-06 18:35:15 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=424012, us=68.184.202.88:8333, peer=13
 732016-08-06 18:35:15 receive version message: /Satoshi:0.11.2/: version 70002, blocks=422168, us=68.184.202.88:8333, peer=14
 742016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=15
 752016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=16
 762016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=17
 772016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=18
 782016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=19
 792016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=20
 802016-08-06 18:35:15 socket send error Bad file descriptor (9)
 812016-08-06 18:35:15 receive version message: /Snoopy:0.2.1/: version 70001, blocks=0, us=68.184.202.88:8333, peer=21
 822016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=22
 832016-08-06 18:35:15 socket send error Bad file descriptor (9)
 842016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=23
 852016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=24
 862016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=25
 872016-08-06 18:35:15 socket send error Bad file descriptor (9)
 882016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=26
 892016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=27
 902016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=28
 912016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=29
 922016-08-06 18:35:15 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=31
 932016-08-06 18:35:15 receive version message: /btcnodes.org-seeder:0.01/: version 60000, blocks=230000, us=68.184.202.88:8333, peer=32
 942016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=230000, us=68.184.202.88:8333, peer=33
 952016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=34
 962016-08-06 18:35:15 socket send error Bad file descriptor (9)
 972016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=35
 982016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=36
 992016-08-06 18:35:15 socket send error Bad file descriptor (9)
1002016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=37
1012016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=38
1022016-08-06 18:35:15 receive version message: /Satoshi:0.9.99/: version 70002, blocks=-1, us=68.184.202.88:8333, peer=39
1032016-08-06 18:35:15 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=424012, us=68.184.202.88:8333, peer=40
1042016-08-06 18:35:15 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=41
1052016-08-06 18:35:17 receive version message: /Satoshi:0.11.2/ljr:20151118/: version 70002, blocks=424015, us=68.184.202.88:39816, peer=42
1062016-08-06 18:35:21 connect() to 62.34.146.14:8333 failed after select(): No route to host (113)
1072016-08-06 18:35:26 P2P peers available. Skipped DNS seeding.
1082016-08-06 18:35:26 dnsseed thread exit
1092016-08-06 18:35:44 SOCKS5 connecting 6sgukxaz6m6qigtk.onion
1102016-08-06 18:36:02 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=230000, us=68.184.202.88:8333, peer=43
1112016-08-06 18:36:04 ERROR: Error reading proxy response
1122016-08-06 18:36:04 connect() to [2601:5c9:0:a400::1]:8333 failed: Network is unreachable (101)
1132016-08-06 18:36:05 receive version message: /Satoshi:0.10.2/: version 70002, blocks=424015, us=68.184.202.88:34278, peer=44
1142016-08-06 18:36:11 connect() to 104.139.88.49:8333 failed after select(): Connection refused (111)
1152016-08-06 18:36:18 receive version message: /Satoshi:0.12.1/: version 70012, blocks=424015, us=68.184.202.88:35966, peer=45
1162016-08-06 18:36:24 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=47
1172016-08-06 18:36:30 SOCKS5 connecting pjghcivzkoersesd.onion
1182016-08-06 18:36:34 SOCKS5 connected pjghcivzkoersesd.onion
1192016-08-06 18:36:34 receive version message: /Satoshi:0.12.1/: version 70012, blocks=424015, us=0.0.0.0:0, peer=48
1202016-08-06 18:36:43 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=49
1212016-08-06 18:36:46 receive version message: /Satoshi:0.10.0/: version 70002, blocks=424015, us=68.184.202.88:34941, peer=50
1222016-08-06 18:36:46 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=51
1232016-08-06 18:36:47 receive version message: /Satoshi:0.12.1/: version 70012, blocks=424015, us=68.184.202.88:37247, peer=52
1242016-08-06 18:36:49 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=53
1252016-08-06 18:36:53 connect() to 213.140.88.188:8333 failed after select(): Connection refused (111)
1262016-08-06 18:37:06 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=424014, us=td6iaq6jpck24fxx.onion:8333, peer=54
1272016-08-06 18:37:11 receive version message: /Satoshi:0.12.99/: version 70013, blocks=424015, us=68.184.202.88:48672, peer=55
1282016-08-06 18:37:14 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=56
1292016-08-06 18:37:25 receive version message: /Satoshi:0.12.1/: version 70012, blocks=424013, us=68.184.202.88:46594, peer=57
1302016-08-06 18:37:30 receive version message: /Snoopy:0.2.1/: version 70001, blocks=0, us=68.184.202.88:8333, peer=58
1312016-08-06 18:38:15 receive version message: /bitcoinj:0.12.2/: version 70001, blocks=424015, us=127.0.0.1:8333, peer=59
1322016-08-06 18:38:17 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=60
1332016-08-06 18:38:42 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=61
1342016-08-06 18:38:44 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=62
1352016-08-06 18:38:54 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=63
1362016-08-06 18:38:59 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=64
1372016-08-06 18:39:12 receive version message: /Satoshi:0.11.0/: version 70002, blocks=375495, us=68.184.202.88:8333, peer=65
1382016-08-06 18:39:20 receive version message: /Satoshi:0.12.1/: version 70012, blocks=374602, us=68.184.202.88:8333, peer=66
  2. nathaniel-mahieu commented at 6:57 pm on August 6, 2016: contributor

    After running

    0 bitcoin-cli reconsiderblock 00000000000000000304f0c7db28c15cc4226dfc491d4c4f0d8b9ae48744453a

    I am again downloading blocks. So it seems like after rejecting a block due to timestamping one has to manually rejoin the main chain. Could a miner cause some portion of the network to fall off the chain in this manner? I guess we assume clocks are well synced. Could this be an attack vector against a node is one could change their system time?

    Additionally, nothing around block 422168 changed wrt my node, so the cause of this is still unknown.

     02016-08-06 18:52:17 UpdateTip: new best=000000000000000001f4de9d78ed4c2015cb676440e58069f67319ae31e71c75  height=422169  log2_work=85.035824  tx=144587363  date=2016-07-25 05:38:02 progress=0.993514  cache=36.9MiB(17785tx)
 12016-08-06 18:52:19 UpdateTip: new best=0000000000000000000d5cfd54279cb7be1a9b887b28e8884b4aacfdd73a1421  height=422170  log2_work=85.035858  tx=144589379  date=2016-07-25 05:38:35 progress=0.993514  cache=45.5MiB(23339tx)
 22016-08-06 18:52:20 UpdateTip: new best=000000000000000003d7e112fbc1aebf4613551290985ebdec276ca6e97ad04a  height=422171  log2_work=85.035891  tx=144591190  date=2016-07-25 05:46:06 progress=0.993517  cache=51.8MiB(28183tx)
 32016-08-06 18:52:21 UpdateTip: new best=00000000000000000309a6d5c4afa5a14a9dfe180e508ba95120576871da8313  height=422172  log2_work=85.035924  tx=144592662  date=2016-07-25 05:47:05 progress=0.993517  cache=55.9MiB(32215tx)
 42016-08-06 18:52:23 UpdateTip: new best=00000000000000000216dc225d4cbd9d8518b4ad82558d5a8e551aa7290c0da5  height=422173  log2_work=85.035958  tx=144593727  date=2016-07-25 05:52:22 progress=0.993519  cache=67.4MiB(35366tx)
 52016-08-06 18:52:24 UpdateTip: new best=0000000000000000042b75880a26fb457e86fe62fde458aad5a3969ea4b71f50  height=422174  log2_work=85.035991  tx=144595236  date=2016-07-25 06:00:58 progress=0.993522  cache=70.2MiB(38386tx)
 62016-08-06 18:52:25 UpdateTip: new best=0000000000000000000639f06ff3d0cfac19d5dc124efac8082fdaa249025027  height=422175  log2_work=85.036024  tx=144597506  date=2016-07-25 06:14:27 progress=0.993527  cache=72.7MiB(42227tx)
 72016-08-06 18:52:26 UpdateTip: new best=000000000000000003322fd7f65df3c951eb7dc0d12eb2452b1b582ceb4ae6bd  height=422176  log2_work=85.036058  tx=144598669  date=2016-07-25 06:20:34 progress=0.993529  cache=74.1MiB(44110tx)
 82016-08-06 18:52:27 UpdateTip: new best=000000000000000005194f58664b9eca668d75813264e8e181a0d57d02a68b33  height=422177  log2_work=85.036091  tx=144599579  date=2016-07-25 06:23:57 progress=0.993531  cache=79.0MiB(46237tx)
 92016-08-06 18:52:28 UpdateTip: new best=000000000000000002e6b94f5623aa48e1a82705281368b8dc3936084512229f  height=422178  log2_work=85.036124  tx=144600185  date=2016-07-25 06:26:36 progress=0.993532  cache=79.3MiB(47199tx)
102016-08-06 18:52:28 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=140
112016-08-06 18:52:28 receive version message: /bitcoinj:0.14.1/: version 70001, blocks=0, us=127.0.0.1:8333, peer=141
122016-08-06 18:52:34 receive version message: /Snoopy:0.2.1/: version 70001, blocks=0, us=68.184.202.88:8333, peer=142
132016-08-06 18:52:43 receive version message: /bitnodes.21.co:0.1/: version 70002, blocks=424015, us=68.184.202.88:8333, peer=143
142016-08-06 18:52:46 receive version message: /bitcoin-seeder:0.01/: version 60000, blocks=350000, us=68.184.202.88:8333, peer=144
152016-08-06 18:52:46   nActualTimespan = 1279095  before bounds
162016-08-06 18:52:46 GetNextWorkRequired RETARGET
172016-08-06 18:52:46 params.nPowTargetTimespan = 1209600    nActualTimespan = 1279095
182016-08-06 18:52:46 Before: 18052669  0000000000000000052669000000000000000000000000000000000000000000
192016-08-06 18:52:46 After:  18057228  000000000000000005722817c64c64c64c64c64c64c64c64c64c64c64c64c64c
202016-08-06 18:52:49 UpdateTip: new best=000000000000000000bce7c7f4ab9a6e40eb076e3bb1d9e505354491f82c20ca  height=422179  log2_work=85.036158  tx=144601270  date=2016-07-25 06:31:02 progress=0.993533  cache=84.9MiB(49710tx)
212016-08-06 18:52:50 UpdateTip: new best=000000000000000002bfba561e2d609528687d4093c5066c5f12d3e3cbdce01a  height=422180  log2_work=85.036191  tx=144601381  date=2016-07-25 06:34:35 progress=0.993534  cache=85.1MiB(50360tx)
222016-08-06 18:52:51 UpdateTip: new best=00000000000000000057c0b5022cc6add2ededb896d38565175e0224542c7abf  height=422181  log2_work=85.036225  tx=144602722  date=2016-07-25 06:39:44 progress=0.993536  cache=93.3MiB(52342tx)
232016-08-06 18:52:52 UpdateTip: new best=00000000000000000303b94f10aec9ab4405318e7aeb3b74ec296c6b6b68bcb7  height=422182  log2_work=85.036258  tx=144604070  date=2016-07-25 07:00:04 progress=0.993544  cache=94.8MiB(56177tx)
242016-08-06 18:52:54 UpdateTip: new best=000000000000000001f8a8d3b6f03bc2fabcfe6d4408861b5b8d0ecfafcf32c7  height=422183  log2_work=85.036291  tx=144605603  date=2016-07-25 07:21:29 progress=0.993551  cache=96.3MiB(59989tx)
252016-08-06 18:52:54 Leaving block file 579: CBlockFileInfo(blocks=163, size=133634206, heights=422025...422214, time=2016-07-24...2016-07-25)
262016-08-06 18:52:54 Pre-allocating up to position 0x1000000 in blk00580.dat
  3. ghost commented at 7:24 pm on August 6, 2016: none
    Did you try deleting last block and -rescan?
  4. sipa commented at 11:01 pm on August 6, 2016: member

    Did you try deleting last block and -rescan?

    Please ignore that advice.

    You can’t delete a block without corrupting the database, and -rescan has only an effect on the wallet. The problem here seems to be with the block downloading logic.

  5. NicolasDorier commented at 1:21 am on August 7, 2016: contributor
    @nathaniel-mahieu I saw this “bug” last week in the source code, but I have been unable to reproduce it on regtest, so I assumed it was just me not reading the code correctly. (My test fired the rule violation, waited 10 sec, re broadcasted, and checked if the node reconsidered, and it worked fine)
  6. NicolasDorier commented at 1:22 am on August 7, 2016: contributor
    Might be related to #8411 (comment) (not about this particular rule though)
  7. rebroad commented at 3:48 am on August 7, 2016: contributor
    I’m not sure that this is a bug, although I do think that it could be quite simple to get bitcoind to automatically reconsider the highest block upon startup, or whenever invalid blocks are seen. Either of these solutions would fix this, I think. @nathaniel-mahieu regarding attack vectors, yes, I think there may be a risk here in that with eclipse attacks the adjusted time could be influenced and cause a node to stop updating. With various fixes around, such as #8282 to help improve address management, and perhaps this combined with having the “adjusted time” influenced only by outbound connections (perhaps this is already what is done?), then this scenario would be much less likely to happen as far as I can see.
  8. jonasschnelli added the label P2P on Aug 8, 2016
  9. jonasschnelli added the label Block storage on Aug 8, 2016
  10. jdevora commented at 8:40 pm on November 3, 2016: none

    I think I just got hit by the same problem. After hours without been able to download any block and after many restarts I only saw those messages in the logs:

     02016-11-03 19:47:19 Discover: IPv4 ham0: 25.88.66.204
 12016-11-03 19:47:19 dnsseed thread start
 22016-11-03 19:47:19 init message: Done loading
 32016-11-03 19:47:19 addcon thread start
 42016-11-03 19:47:19 opencon thread start
 52016-11-03 19:47:19 msghand thread start
 62016-11-03 19:47:19 net thread start
 72016-11-03 19:47:21 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:60766, peer=1
 82016-11-03 19:47:21 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:39896, peer=2
 92016-11-03 19:47:22 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:33342, peer=3
102016-11-03 19:47:22 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:51032, peer=4
112016-11-03 19:47:29 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:40190, peer=5
122016-11-03 19:47:29 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:38504, peer=6
132016-11-03 19:47:30 P2P peers available. Skipped DNS seeding.
142016-11-03 19:47:30 dnsseed thread exit
152016-11-03 19:47:30 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:45654, peer=7
162016-11-03 19:47:42 receive version message: /Satoshi:0.13.99/: version 70014, blocks=437231, us=85.155.227.237:51032, peer=8
172016-11-03 19:47:46 connect() to 51.254.105.6:8333 failed after select(): Connection refused (111)
182016-11-03 19:49:15 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:47136, peer=9
192016-11-03 19:52:59 connect() to 104.238.169.64:8333 failed after select(): Connection refused (111)
202016-11-03 20:00:38 socket send error Bad file descriptor (9)
212016-11-03 20:00:38 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437231, us=85.155.227.237:60626, peer=10
222016-11-03 20:03:22 socket send error Bad file descriptor (9)
232016-11-03 20:03:22 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437232, us=85.155.227.237:40064, peer=11
242016-11-03 20:04:07 connect() to 178.162.199.143:8333 failed after select(): Connection refused (111)
252016-11-03 20:08:59 connect() to 78.2.117.157:8333 failed after select(): Connection refused (111)
262016-11-03 20:13:06 connect() to 202.241.172.43:8333 failed after select(): Connection refused (111)
272016-11-03 20:16:55 socket send error Bad file descriptor (9)
282016-11-03 20:16:55 receive version message: /Satoshi:0.13.1/: version 70014, blocks=437235, us=85.155.227.237:51432, peer=12
292016-11-03 20:28:06 connect() to 27.4.113.163:8333 failed after select(): No route to host (113)
302016-11-03 20:29:46 connect() to 79.225.37.228:8333 failed after select(): No route to host (113)

    But after issue the command bitcoin-cli reconsiderblock 0000000000000000147716b9f8b7d2c6d561482b9276a0d58027216c271af975

    It started to download blocks again

     02016-11-03 20:31:10 Pre-allocating up to position 0x100000 in rev00218.dat
 12016-11-03 20:31:10 UpdateTip: new best=00000000000000000aa3088921f21a80d578f27019a79b5248ca0babcc68cd23 height=338782 version=0x00000002 log2_work=81.995802 tx=
 256623259 date='2015-01-13 14:52:10' progress=0.408759 cache=13.6MiB(3784tx)
 32016-11-03 20:31:20 UpdateTip: new best=000000000000000003be9c4ea1d3235450fb915b86d034d8ccb495f10566ec81 height=338783 version=0x00000002 log2_work=81.995858 tx=
 456624576 date='2015-01-13 15:16:00' progress=0.408777 cache=17.5MiB(6497tx)
 52016-11-03 20:31:38 UpdateTip: new best=000000000000000018b06ec167b4ad799cff83670ea9e6157bb66cb1838460b4 height=338784 version=0x00000002 log2_work=81.995915 tx=
 656626095 date='2015-01-13 15:33:26' progress=0.408794 cache=24.9MiB(9499tx)
 72016-11-03 20:32:00 UpdateTip: new best=0000000000000000147cee6831f40434155d3be889e9e09ac06c68b4339c17cf height=338785 version=0x00000002 log2_work=81.995971 tx=
 856627733 date='2015-01-13 15:57:49' progress=0.408815 cache=55.5MiB(13791tx)
 92016-11-03 20:32:06 UpdateTip: new best=000000000000000016ec5849453a107b2dbbc02244b6de99a9ef23235d57d855 height=338786 version=0x00000002 log2_work=81.996028 tx=
1056628175 date='2015-01-13 16:02:54' progress=0.408820 cache=57.3MiB(15283tx)
  11. MarcoFalke closed this on May 8, 2020
  12. MarcoFalke commented at 6:31 pm on May 8, 2020: member
    Is this still an issue with a recent version of Bitcoin Core? If yes, what are the steps to reproduce?
  13. DrahtBot locked this on Feb 15, 2022


nathaniel-mahieu ghost sipa NicolasDorier rebroad jdevora MarcoFalke

Labels
P2P Block storage

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2024-12-21 18:12 UTC
This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me