Block Timestamps vs. Received Timestamp

Question

I've been logging local timestamps when I receive blocks on two separate geth nodes to see which (if any) is consistently faster. But I just stumbled across something that I don't understand - in my logs it seems that every block's timestamp is off from my local timestamp substantially. What's more, for any block, its timestamp is roughly equal to the locally recorded timestamp of the previous block (+/- 1 second). I've included a sample of the logs below. On geth 1.8.22, querying with python web3.

Block #, Received Timestamp, Block Timestamp
7452986,1553721231,1553721228
7452987,1553721232,1553721231
7452988,1553721243,1553721232
7452989,1553721250,1553721243
7452990,1553721266,1553721250
7452991,1553721267,1553721266
7452992,1553721270,1553721267
7452993,1553721291,1553721270
7452994,1553721305,1553721291
7452995,1553721310,1553721305
7452996,1553721313,1553721312
7452997,1553721314,1553721313
7452998,1553721319,1553721314
7452999,1553721328,1553721319
7453000,1553721339,1553721327
7453001,1553721352,1553721338
7453002,1553721356,1553721351
7453003,1553721427,1553721356
7453004,1553721429,1553721426
7453005,1553721433,1553721428
7453005,1553721434,1553721429
7453006,1553721467,1553721434
...

Am I missing something obvious? Is there a node setting that I can change? Any help would be appreciated.

Answer 1

I also found it doing precisely the same analysis,

I think the reason is:

Taking the next blocks as an example:

Block #, Received Timestamp, Block Timestamp
7452987,1553721232,1553721231
7452988,1553721243,1553721232

1. Block number 7452987 is published in the second 1553721232 s, the next miner (Miner_n+1) takes this block at time 1553721232 s, Miner_n+1 computes all transactions it has at the time 1553721232 s, generating the block 7452988 and starts mining the block (the hash race).

2. It takes 11 seconds to mine it and at time 1553721243 publish it, but with a time stamp of 1553721232 s.

That explains why the block timestamp of block n is very similar to the Received Timestamp of block n-1 of your list (it also happened in my list).

But it doesn't explain why Etherscan says that 7452988 took just 1 second to be mined, and that is the block 7452989, the one that took 11 s https://etherscan.io/block/7452988 . It looks like Etherscan is one block delayed with in the mining time.

Not sure...

Edit: I found a source that confirms my explanation: https://github.com/ethereum/go-ethereum/issues/21784#issuecomment-722254187 . But still, it didn't explain why Etherscan differ in one block when showing the timing time.