For a few days I have been collecting timestamps of generated blocks the moment my system noticed a new generated block. A short while ago I learned that I can extract timestamp information from the p2p network itself. After some manual analysis of my data and the data extracted from the p2p network, I noticed that durations between generated blocks were almost accurate, but in several cases my system's calculations were off by as many as several minutes. I determined this may be caused due to some blocks being generated by nodes in which it takes longer for information of a block being generated from reaching my or all other nodes, however I am uncertain.
To determine timestamp data from the p2p network I used the following:
cat ~/.bitcoin/debug.log > out
bitcoin -printblock
I executed this at three separate total generated blocks. Here's some comparing information from the headers of each log.
68,845 (32963420 bytes total)
Loaded 9173 addresses
LoadBlockIndex(): hashBestChain=00000000000394ae height=68844
mapBlockIndex.size() = 68880
nBestHeight = 68844
68,858 (32771350 bytes total)
Loaded 9190 addresses
LoadBlockIndex(): hashBestChain=00000000000052ff height=68857
mapBlockIndex.size() = 68893
nBestHeight = 68857
68,943 (32837629 bytes total)
Loaded 9407 addresses
LoadBlockIndex(): hashBestChain=00000000015364ae height=68942
mapBlockIndex.size() = 68978
nBestHeight = 68942
I determined that in the log datas that each line beginning with "CBlock" and containing "nTime" were information regarding block generation. However it seemed strange to me that the output produced from 68,858 was less data than from 68,845.
68,845 log output has 69,402 CBlock lines. (557 CBlock lines more than blocks generated)
68,858 log output has 68,893 CBlock lines. (35 CBlock lines more than blocks generated)
68,943 log output has 68,978 CBlock lines. (35 CBlock lines more than blocks generated)
In both logs for 68,858 and 68,943 the number of CBlock lines matches mapBlockIndex.size(), but not for 68,845. Is my log data inaccurate or is there another explanation for this?
-
After obtaining this data, I parsed it using the following:
grep CBlock logfile|cut -b 99-108|sort
This provided sequential timestamp information that I used to compare my log data to the official datas produced by Bitcoin p2p system.
As a note, I noticed some of the timestamps were not unique, and duplicated.
# grep CBlock debug.log.68943 |cut -b 99-108|sort|wc -l
68978
death .bitcoin # grep CBlock debug.log.68943 |cut -b 99-108|sort|uniq|wc -l
68938
However, it is impossible for the log for 68,943 blocks to only have data for 68,938 (less) blocks, so I conclude that some blocks were generated at the same timestamp as a previously generated block and this debunk's gavin's suggestions that timestamps will be unique [
http://bitcointalk.org/index.php?topic=457.msg4042#msg4042 ].
Comparing my system log data to the data output from log data for 68,858 I found a pattern in durations between block generation and was able to match up which timestamp was associated with which block being generated. The log data from `bitcoin -printblock` does not indicate which block is associated with a timestamp. Therefore I had to either assume or use my existing data, which I did. However, because there are more CBlock lines then actual generated blocks in all log files, I am uncertain as to how to proceed in excluding a certain CBlock line from my further analysis to match up timestamps with generated blocks. I do notice that both logs for 68,858 and 68,943 have only 35 CBlock lines more, and that may be helpful to understanding which CBlocks are unrelated/something else, but for now I ask the community/devs if they can help explain this better.
<necrodearia> I have determined that some generated blocks have the same timestamp as a previously generated block:
http://bitcointalk.org/index.php?topic=464.0<necrodearia> Where does the timestamp information come from?
<ArtForz> don't forget -printblock also prints "deadend" blocks
<lfm> prolly from the orginating PC clock
<ArtForz> PC clock +- offset averaged from peers
<necrodearia> ArtForz, I didn't know that. you should answer that question in the thread so others know also
<necrodearia> What is a deadend block? Or, if you elaborate more in forum thread, I'll read it there.
<ArtForz> well, when 2 clients near-simultaneously find a hash, *both* blocks get spread over the network
<ArtForz> so we have 2 blocks with the same hashPrevBlock
<ArtForz> and basically the overall network "decides" which block is the "real" one, which gets used as hashPrevBlock for the next block
<ArtForz> but those "deadend" blocks still stay in the db, and -printblocks dumps em
ArtForz contributed this chunk of code which extracts timestamp information from blk0001.dat
#!/usr/bin/env python
import struct
import hashlib
def uint256_deser(s):
r = 0L
for i in xrange(8):
t = struct.unpack("<I", s[i*4:i*4+4])[0]
r += t << (i * 32)
return r
def uint256_ser(u):
rs = ""
for i in xrange(8):
rs += struct.pack("<I", u & 0xFFFFFFFFL)
u >>= 32
return rs
def uint256_from_compact(c):
nbytes = (c >> 24) & 0xFF
v = (c & 0xFFFFFFL) << (8 * (nbytes - 3))
return v
def get_difficulty(c):
return float(uint256_from_compact(0x1D00FFFF) * 1000 // uint256_from_compact(c)) / 1000.
class CBlock:
def deserialize(self, s):
self.nVersion = struct.unpack("<i", s[0:4])[0]
self.hashPrevBlock = uint256_deser(s[4:36])
self.hashMerkleRoot = uint256_deser(s[36:68])
self.nTime = struct.unpack("<I", s[68:72])[0]
self.nBits = struct.unpack("<I", s[72:76])[0]
self.nNonce = struct.unpack("<I", s[76:80])[0]
h1 = hashlib.sha256(s[0:80]).digest()
self.hash = uint256_deser(hashlib.sha256(h1).digest())
if self.hash > uint256_from_compact(self.nBits):
raise ValueError("bad hash in %s" % repr(self))
self.next = []
self.blocknum = -1
def __repr__(self):
return "CBlock{ver=%08x hp=%064x hm=%064x nt=%08x nb=%08x nn=%08x h=%064x, n=%i}" % (self.nVersion, self.hashPrevBlock, self.hashMerkleRoot, self.nTime, self.nBits, self.nNonce, self.hash, self.blocknum)
def get_chain_len(blk):
r = 1
while len(blk.next) == 1:
blk = blk.next[0]
r += 1
if len(blk.next) > 1:
bestchainlen = 0
for nextblk in blk.next:
chainlen = get_chain_len(nextblk)
if chainlen > bestchainlen:
bestchainlen = chainlen
r += bestchainlen
return r
def readblocks(filename):
f = open(filename, "rb")
blocks = []
idxmap = {}
while True:
try:
magic = f.read(4)
if magic != "\xf9\xbe\xb4\xd9":
break
blklen = struct.unpack("<i", f.read(4))[0]
if blklen < 80:
break
blkdata = f.read(blklen)
if len(blkdata) != blklen:
break
except:
break
blk = CBlock()
blk.deserialize(blkdata)
blocks.append(blk)
idxmap[blk.hash] = blk
if blk.hashPrevBlock:
prevblk = idxmap[blk.hashPrevBlock]
blk.prev = prevblk
prevblk.next.append(blk)
f.close()
rootblk = blocks[0]
del blocks
del idxmap
blk = rootblk
curblkidx = 0
while True:
blk.blocknum = curblkidx
if len(blk.next) == 0:
blk.next = None
break
if len(blk.next) > 1:
bestnextblk = None
bestchainlen = 0
for nextblk in blk.next:
chainlen = get_chain_len(nextblk)
if chainlen > bestchainlen:
bestchainlen = chainlen
bestnextblk = nextblk
elif chainlen == bestchainlen:
if nextblk.nTime < bestnextblk.nTime:
bestchainlen = chainlen
bestnextblk = nextblk
blk.next = [bestnextblk]
blk.next = blk.next[0]
curblkidx += 1
blk = blk.next
blk = rootblk
while blk:
#print "%i %i %.3f 0x%08X" % (blk.blocknum, blk.nTime, get_difficulty(blk.nBits), blk.nBits)
avghashes = 2**256 / uint256_from_compact(blk.nBits)
print "%i %i %i" % (blk.blocknum, blk.nTime, avghashes)
blk = blk.next
if __name__ == "__main__":
readblocks("/home/necro/.bitcoin/blk0001.dat")
