[MERGED] osmo-gsm-tester[master]: Add microsecond accuracy to log timestamps

[Pau Espin Pedrol]

Pau Espin Pedrol has submitted this change and it was merged.

Change subject: Add microsecond accuracy to log timestamps
......................................................................


Add microsecond accuracy to log timestamps

This is useful while debugging and trying to check events across other
outputs such as pcap files, process logs, etc.

Change-Id: I43bb5c6e9977189251802bc2b078c52eb046bab8
---
M selftest/process_test.ok.ign
M src/osmo_gsm_tester/log.py
M src/osmo_gsm_tester/process.py
3 files changed, 7 insertions(+), 5 deletions(-)

Approvals:
  Neels Hofmeyr: Looks good to me, approved
  Harald Welte: Looks good to me, but someone else must approve
  Jenkins Builder: Verified



diff --git a/selftest/process_test.ok.ign b/selftest/process_test.ok.ign
index 0abd7d5..b817f5a 100644
--- a/selftest/process_test.ok.ign
+++ b/selftest/process_test.ok.ign
@@ -1,7 +1,7 @@
 PATH='[^']*'	PATH=[$PATH]
 /tmp/[^/ '"]*	[TMP]
 pid=[0-9]*	pid=[PID]
-....-..-.._..:..:..	[DATETIME]
+....-..-.._..:..:..\.......	[DATETIME]
 '[^']*/selftest/process_test/foo.py'	[$0]
 "[^"]*/selftest/process_test/foo.py"	[$0]
 , line [0-9]*	, line [LINE]
diff --git a/src/osmo_gsm_tester/log.py b/src/osmo_gsm_tester/log.py
index c4a6629..a9f16c2 100644
--- a/src/osmo_gsm_tester/log.py
+++ b/src/osmo_gsm_tester/log.py
@@ -23,6 +23,7 @@
 import traceback
 import contextlib
 import atexit
+from datetime import datetime # we need this for strftime as the one from time doesn't carry microsecond info
 from inspect import getframeinfo, stack
 
 from .util import is_dict
@@ -80,8 +81,8 @@
         target.log(origin, category, level, src, messages, named_items)
 
 
-LONG_DATEFMT = '%Y-%m-%d_%H:%M:%S'
-DATEFMT = '%H:%M:%S'
+LONG_DATEFMT = '%Y-%m-%d_%H:%M:%S.%f'
+DATEFMT = '%H:%M:%S.%f'
 
 # may be overridden by regression tests
 get_process_id = lambda: '%d-%d' % (os.getpid(), time.time())
@@ -105,7 +106,7 @@
     all_levels = None
 
     # redirected by logging test
-    get_time_str = lambda self: time.strftime(self.log_time_fmt)
+    get_time_str = lambda self: datetime.now().strftime(self.log_time_fmt)
 
     # sink that gets each complete logging line
     log_write_func = None
diff --git a/src/osmo_gsm_tester/process.py b/src/osmo_gsm_tester/process.py
index d24bf3d..4b68ef5 100644
--- a/src/osmo_gsm_tester/process.py
+++ b/src/osmo_gsm_tester/process.py
@@ -21,6 +21,7 @@
 import time
 import subprocess
 import signal
+from datetime import datetime
 
 from . import log, test, event_loop
 from .util import Dir
@@ -55,7 +56,7 @@
         path = self.run_dir.new_child(name)
         f = open(path, 'w')
         self.dbg(path)
-        f.write('(launched: %s)\n' % time.strftime(log.LONG_DATEFMT))
+        f.write('(launched: %s)\n' % datetime.now().strftime(log.LONG_DATEFMT))
         f.flush()
         self.outputs[name] = (path, f)
         return f

-- 
To view, visit https://gerrit.osmocom.org/3025
To unsubscribe, visit https://gerrit.osmocom.org/settings

Gerrit-MessageType: merged
Gerrit-Change-Id: I43bb5c6e9977189251802bc2b078c52eb046bab8
Gerrit-PatchSet: 2
Gerrit-Project: osmo-gsm-tester
Gerrit-Branch: master
Gerrit-Owner: Pau Espin Pedrol <pespin at sysmocom.de>
Gerrit-Reviewer: Harald Welte <laforge at gnumonks.org>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: Neels Hofmeyr <nhofmeyr at sysmocom.de>
Gerrit-Reviewer: Pau Espin Pedrol <pespin at sysmocom.de>