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

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]

src/osmo_gsm_tester/log.py

@@ -23,6 +23,7 @@ import time
 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 @@ def _log(messages=[], named_items={}, origin=None, category=None, level=L_LOG, s
         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 @@ class LogTarget:
     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

src/osmo_gsm_tester/process.py

@@ -21,6 +21,7 @@ import os
 import time
 import subprocess
 import signal
+from datetime import datetime
 
 from . import log, test, event_loop
 from .util import Dir
@@ -55,7 +56,7 @@ class Process(log.Origin):
         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