[SERVER-58106] oldestRequiredTimestampForCrashRecovery FTDC metric swaps t for i Created: 26/Jun/21  Updated: 29/Jun/21  Resolved: 29/Jun/21

Status: Closed
Project: Core Server
Component/s: Internal Code
Affects Version/s: 4.2.14, 4.4.6, 5.0.0-rc4, 5.0.0-rc5
Fix Version/s: None

Type: Bug Priority: Minor - P4
Reporter: Scott Kurowski Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: FTDC
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Steps To Reproduce:

repro.py

#!/usr/bin/env python2
import sys
from readers import read_ftdc
# https://github.com/10gen/t2/blob/master/scripts/readers.py
ftdc = [ ('serverStatus', 'storageEngine', 'oldestRequiredTimestampForCrashRecovery', 't'),
         ('serverStatus', 'storageEngine', 'oldestRequiredTimestampForCrashRecovery', 'i')]
for chunk in read_ftdc(sys.argv[1]):
    values = chunk.values()
    assert all(len(values[0])==len(v) for v in values)
    for key in ftdc:
        print( key )
        print( values[chunk.keys().index( key )] )

// 5.0, 4.4, 4.2 FTDC metrics files
$ python2 repro.py metrics50.bson 
reading metrics50.bson
('serverStatus', 'storageEngine', 'oldestRequiredTimestampForCrashRecovery', 't')
[1, 1, 1, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 61, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 121, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 181, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 241, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301, 301]
('serverStatus', 'storageEngine', 'oldestRequiredTimestampForCrashRecovery', 'i')
[1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785, 1623804785]

Participants:

 Description   

FTDC for oldestRequiredTimestampForCrashRecovery is collected here.

While testing swapping of t and i values, the repro become intermittent. Reconsidering this as a possible parsed BSON odict behavior.



 Comments   
Comment by Scott Kurowski [ 29/Jun/21 ]

The serverStatus.storageEngine timestamps have been fine. We can explain the swap in the BSON parser.

        elif bson_type==17: # timestamp
            v = BSON()
            v['t'] = int(_uint32.unpack_from(buf, at)[0]) # seconds
            v['i'] = int(_uint32.unpack_from(buf, at+4)[0]) # increment

Looks like the at+4 offset should instead be on v['t'] for uint64 endian. Closing as unreproducible.

Comment by Daniel Gottlieb (Inactive) [ 27/Jun/21 ]

I'm seeing the metric being returned by server status as a Timestamp object (as expected):

	"oldestRequiredTimestampForCrashRecovery" : Timestamp(1624760853, 5),

So I suspect this is a bug/misuse of the read_ftdc package. scott.kurowski, in an effort to isolate the problem, have you observed serverStatus reporting anything that would suggest the t/i fields are swapped?

Generated at Thu Feb 08 05:43:36 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.