Skip to content

Commit

Permalink
BF: tools/dtime to handle log line having non-increment timestamp
Browse files Browse the repository at this point in the history
Apparently can happen, likely due to multithreading and different threads
doing their own timestamping.  Interestingly Python seems to not handle
negative time delta "intuitively":

    (Pdb) p t
    datetime.datetime(2024, 5, 14, 19, 39, 12, 800000)
    (Pdb) p prevt
    datetime.datetime(2024, 5, 14, 19, 39, 12, 801000)
    (Pdb) p t - prevt
    datetime.timedelta(days=-1, seconds=86399, microseconds=999000)
    *(Pdb) p prevt -t
    datetime.timedelta(microseconds=1000)

but since python 2.7 there is "total_seconds" which is behaving as desired and
anyways we need those, so we can just use and thus operate correctly also
whenever crossing some days boundary (hopefully never).
  • Loading branch information
yarikoptic committed May 15, 2024
1 parent fda2048 commit c9beb93
Showing 1 changed file with 9 additions and 1 deletion.
10 changes: 9 additions & 1 deletion tools/dtime
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ reg = re.compile('^\d{4}-\d{2}-\d{1,2} \d{1,2}:\d{1,2}:\d{1,2},\d{1,3}')
prevt = None
maxl = 0
prevl = None
warned_negative = False

if len(sys.argv) <= 1:
in_ = sys.stdin
Expand All @@ -30,7 +31,14 @@ for l in in_:
t = datetime.strptime(l[:end], '%Y-%m-%d %H:%M:%S,%f')
if prevt is not None:
dt = t - prevt
ms = dt.microseconds // 1000 + dt.seconds*1000
secs = dt.total_seconds()
# negative dt has very weird form of -1 day + huge number of seconds
if secs < 0:
if not warned_negative:
sys.stderr.write(f"Negative delta of {secs} seconds detected. Might be due to threading etc\n")
warned_negative = True

ms = secs * 1000
dtstr = ("%5d" % ms if ms else ' 0')

maxl = max(maxl, len(dtstr))
Expand Down

0 comments on commit c9beb93

Please sign in to comment.