Feature dtcenter/METplus-Internal#34 set the log time to UTC/GMT (#1793)

metplus/util/config_metplus.py

@@ -13,7 +13,8 @@
 import re
 import sys
 import logging
-import datetime
+from datetime import datetime, timezone
+import time
 import shutil
 from configparser import ConfigParser, NoOptionError
 from pathlib import Path
@@ -80,6 +81,9 @@
     'metplus_logging.conf'
 ]
 
+# set all loggers to use UTC
+logging.Formatter.converter = time.gmtime
+
 def setup(args, logger=None, base_confs=None):
     """!The METplus setup function.
         @param args list of configuration files or configuration
@@ -213,7 +217,7 @@ def launch(config_list):
 
     # set config variable for current time
     config.set('config', 'CLOCK_TIME',
-               datetime.datetime.now().strftime('%Y%m%d%H%M%S'))
+               datetime.now().strftime('%Y%m%d%H%M%S'))
 
     config_format_list = []
     # Read in and parse all the conf files and overrides
@@ -279,17 +283,12 @@ def _set_logvars(config, logger=None):
     log_timestamp_template = config.getstr('config', 'LOG_TIMESTAMP_TEMPLATE',
                                            '')
     if config.getbool('config', 'LOG_TIMESTAMP_USE_DATATIME', False):
-        if util.is_loop_by_init(config):
-            loop_by = 'INIT'
-        else:
-            loop_by = 'VALID'
-
-        date_t = datetime.datetime.strptime(
-            config.getstr('config', f'{loop_by}_BEG'),
-            config.getstr('config', f'{loop_by}_TIME_FMT')
-        )
+        loop_by = 'INIT' if util.is_loop_by_init(config) else 'VALID'
+        time_str = config.getraw('config', f'{loop_by}_BEG')
+        time_fmt = config.getraw('config', f'{loop_by}_TIME_FMT')
+        date_t = datetime.strptime(time_str, time_fmt)
     else:
-        date_t = datetime.datetime.now()
+        date_t = datetime.now(timezone.utc)
 
     log_filenametimestamp = date_t.strftime(log_timestamp_template)
 
@@ -385,14 +384,23 @@ def get_logger(config, sublog=None):
         if not os.path.exists(dir_name):
             util.mkdir_p(dir_name)
 
-        # set up the filehandler and the formatter, etc.
-        # The default matches the oformat log.py formatter of produtil
-        # So terminal output will now match log files.
+        # do not send logs up to root logger handlers
+        logger.propagate = False
+
+        # create log formatter from config settings
         formatter = METplusLogFormatter(config)
+
+        # set up the file logging
         file_handler = logging.FileHandler(metpluslog, mode='a')
         file_handler.setFormatter(formatter)
         logger.addHandler(file_handler)
 
+        # set up console logging
+        stream_handler = logging.StreamHandler()
+        stream_handler.setFormatter(formatter)
+        logger.addHandler(stream_handler)
+
+
     # set add the logger to the config
     config.logger = logger
     return logger

metplus/util/met_util.py

@@ -1,7 +1,7 @@
 import os
 import shutil
 import sys
-import datetime
+from datetime import datetime, timedelta, timezone
 import re
 import gzip
 import bz2
@@ -191,15 +191,14 @@ def post_run_cleanup(config, app_name, total_errors):
     log_message = (f"Check the log file for more information: "
                    f"{config.getstr('config', 'LOG_METPLUS')}")
 
-    start_clock_time = datetime.datetime.strptime(config.getstr('config',
-                                                                'CLOCK_TIME'),
-                                                  '%Y%m%d%H%M%S')
+    start_clock_time = datetime.strptime(config.getstr('config', 'CLOCK_TIME'),
+                                         '%Y%m%d%H%M%S')
 
     # rewrite final conf so it contains all of the default values used
     write_final_conf(config)
 
     # compute time it took to run
-    end_clock_time = datetime.datetime.now()
+    end_clock_time = datetime.now()
     total_run_time = end_clock_time - start_clock_time
     logger.debug(f"{app_name} took {total_run_time} to run.")
 
@@ -484,7 +483,7 @@ def log_runtime_banner(config, time_input, process):
 
 def add_to_time_input(time_input, clock_time=None, instance=None, custom=None):
     if clock_time:
-        clock_dt = datetime.datetime.strptime(clock_time, '%Y%m%d%H%M%S')
+        clock_dt = datetime.strptime(clock_time, '%Y%m%d%H%M%S')
         time_input['now'] = clock_dt
 
     # if instance is set, use that value, otherwise use empty string
@@ -621,7 +620,8 @@ def handle_lead_seq(config, lead_strings, lead_min=None, lead_max=None):
     if lead_min is None and lead_max is None:
         return leads
 
-    now_time = datetime.datetime.now()
+    # add current time to leads to approximate month and year length
+    now_time = datetime.now()
     lead_min_approx = now_time + lead_min
     lead_max_approx = now_time + lead_max
     for lead in leads:
@@ -858,8 +858,8 @@ def shift_time_seconds(time_str, shift):
         Returns:
             New time in format %Y%m%d%H%M%S
     """
-    return (datetime.datetime.strptime(time_str, "%Y%m%d%H%M%S") +
-            datetime.timedelta(seconds=shift)).strftime("%Y%m%d%H%M%S")
+    return (datetime.strptime(time_str, "%Y%m%d%H%M%S") +
+            timedelta(seconds=shift)).strftime("%Y%m%d%H%M%S")
 
 def get_threshold_via_regex(thresh_string):
     """!Ensure thresh values start with >,>=,==,!=,<,<=,gt,ge,eq,ne,lt,le and then a number

metplus/wrappers/command_runner.py

@@ -36,7 +36,7 @@
 import os
 from produtil.run import exe, run
 import shlex
-from datetime import datetime
+from datetime import datetime, timezone
 
 class CommandRunner(object):
     """! Class for Creating and Running External Programs

parm/metplus_config/defaults.conf

@@ -108,10 +108,10 @@ LOG_MET_VERBOSITY = 2
 ###############################################################################
 
 
-LOG_LINE_FORMAT = %(asctime)s.%(msecs)03d %(name)s (%(filename)s:%(lineno)d) %(levelname)s: %(message)s
+LOG_LINE_FORMAT = %(asctime)s.%(msecs)03dZ %(name)s (%(filename)s:%(lineno)d) %(levelname)s: %(message)s
 LOG_ERR_LINE_FORMAT = {LOG_LINE_FORMAT}
 LOG_DEBUG_LINE_FORMAT = {LOG_LINE_FORMAT}
-LOG_INFO_LINE_FORMAT = %(asctime)s.%(msecs)03d %(name)s %(levelname)s: %(message)s
+LOG_INFO_LINE_FORMAT = %(asctime)s.%(msecs)03dZ %(name)s %(levelname)s: %(message)s
 
 LOG_LINE_DATE_FORMAT = %m/%d %H:%M:%S