Added script to parse structlogs and get traditional messages or sele…

…ct fields/keys and improved log initialization and consolidated handler's setup

Using booleans True/False instead of 1/0 in rollover control in logSupport
Reverted manual_glidein_submit.py to use std Python logging (it is and standalone script not using the framework log files)
Added documentation and adapted unit tests
Consolidated also is_true() to lib/util.py
Cleaned up some docstrings and comments

CHANGELOG.md

@@ -10,6 +10,7 @@ Changes since the last release
 ### New features / functionalities
 
 - Added support for Debian 11 and Ubuntu 22 worker nodes (PR #320)
+- Added structured logging. It is a hybrid format with some fields followed by a JSON dictionary. The exact format of the messages may change in the future, and we plan for it to become the default. Now it is disabled by default. Add `structured="True"` to all `<process_log>` elements (PR #327)
 
 ### Changed defaults / behaviours
 

build/packaging/rpm/glideinwms.spec

@@ -185,11 +185,13 @@ Requires: python3-pyyaml
 Requires: python3-jwt
 Requires: python3-cryptography
 Requires: python3-m2crypto
+#Requires: python3-structlog
 %else
 Requires: PyYAML
 Requires: python36-jwt
 Requires: python36-cryptography
 Requires: python36-m2crypto
+Requires: python36-structlog
 %endif
 Requires: python3-rrdtool
 %description libs

creation/lib/cWParamDict.py

@@ -1,12 +1,6 @@
 # SPDX-FileCopyrightText: 2009 Fermi Research Alliance, LLC
 # SPDX-License-Identifier: Apache-2.0
 
-#
-# Project:
-# glideinWMS
-#
-# File Version:
-#
 # Description:
 # Frontend creation module
 # Classes and functions needed to handle dictionary files
@@ -17,12 +11,9 @@
 
 import os.path
 
-from . import cWConsts, cWDictFile
-
+from glideinwms.lib.util import is_true
 
-def is_true(s):
- """Case insensitive string parsing helper. Return True for true (case insensitive matching), False otherwise."""
- return type(s) == str and s.lower() == "true"
+from . import cWConsts, cWDictFile
 
 
 def has_file_wrapper(dicts):

creation/lib/cWParams.py

@@ -1,21 +1,8 @@
 # SPDX-FileCopyrightText: 2009 Fermi Research Alliance, LLC
 # SPDX-License-Identifier: Apache-2.0
 
-#
-# Project:
-# glideinWMS
-#
-# File Version:
-#
 # Description:
 # This module contains the generic params classes
-#
-# Extracted from:
-# cgWParams.py
-#
-# Author:
-# Igor Sfiligoi
-#
 
 import copy
 import os
@@ -95,6 +82,7 @@ def validate(self, base, path_text):
 
  """
  for k in self.data:
+ # TODO: MMBFIX is the next line doing anything? should it be removed? check history?
  self.data
  if k not in base:
  # element not in base, report
@@ -663,7 +651,7 @@ def shorten_text(text, width):
 
 
 def defdict2string(defaults, indent, width=80):
- """Convert defualts to a string
+ """Convert defaults to a string
 
  Args:
  defaults:

creation/lib/cgWParamDict.py

@@ -1,11 +1,6 @@
 # SPDX-FileCopyrightText: 2009 Fermi Research Alliance, LLC
 # SPDX-License-Identifier: Apache-2.0
 
-# Project:
-# glideinWMS
-#
-# File Version:
-#
 # Description:
 # Glidein creation module
 # Classes and functions needed to handle dictionary files

creation/lib/cgWParams.py

@@ -1,18 +1,8 @@
 # SPDX-FileCopyrightText: 2009 Fermi Research Alliance, LLC
 # SPDX-License-Identifier: Apache-2.0
 
-#
-# Project:
-# glideinWMS
-#
-# File Version:
-#
 # Desscription:
 # This module contains the create_glidein params class
-#
-# Author:
-# Igor Sfiligoi
-#
 
 import copy
 import os
@@ -29,10 +19,6 @@
 
 from . import cWParams
 
-# import types
-# import traceback
-# from collections import OrderedDict
-
 
 ######################################################
 class GlideinParams(cWParams.CommonParams):
@@ -297,6 +283,7 @@ def init_defaults(self):
  self.defaults["monitor_footer"] = monitor_footer_defaults
 
  process_log_defaults = copy.deepcopy(one_log_retention_defaults)
+ process_log_defaults["structured"] = ["False", "Bool", "True to use structured logs", None]
  process_log_defaults["extension"] = ["all", "string", "name of the log extention", None]
  process_log_defaults["msg_types"] = ["INFO, WARN, ERR", "string", "types of log messages", None]
  process_log_defaults["backup_count"] = ["5", "string", "Number of backup logs to keep", None]

creation/lib/cvWParams.py

@@ -406,6 +406,7 @@ def init_defaults(self):
  self.defaults["work"] = work_defaults
 
  process_log_defaults = cWParams.CommentedOrderedDict()
+ process_log_defaults["structured"] = ["False", "Bool", "True to use structured logs", None]
  process_log_defaults["min_days"] = [
  "3.0",
  "days",

creation/lib/factory_defaults.xml

@@ -10,7 +10,7 @@ SPDX-License-Identifier: Apache-2.0
  <job_logs max_days="7.0" max_mbytes="100.0" min_days="2.0"/>
  <summary_logs max_days="31.0" max_mbytes="100.0" min_days="3.0"/>
  <process_logs>
- <process_log max_days="7.0" max_mbytes="100.0" min_days="3.0" backup_count="5" compression="" extension="all" msg_types="INFO, WARN, ERR"/>
+ <process_log structured="False" max_days="7.0" max_mbytes="100.0" min_days="3.0" backup_count="5" compression="" extension="all" msg_types="INFO, WARN, ERR"/>
  </process_logs>
  </log_retention>
  <!-- hard coding rpm paths for now -->

creation/reconfig_glidein

@@ -61,31 +61,7 @@ def logReconfig(msg):
  # Set the Log directory
  logSupport.log_dir = os.path.join(glideinDescript.data["LogDir"], "factory")
  # Configure factory process logging
- process_logs = eval(glideinDescript.data["ProcessLogs"])
- for plog in process_logs:
- if "ADMIN" in plog["msg_types"]:
- logSupport.add_processlog_handler(
- "factoryadmin",
- logSupport.log_dir,
- "DEBUG,INFO,WARN,ERR",
- plog["extension"],
- int(float(plog["max_days"])),
- int(float(plog["min_days"])),
- int(float(plog["max_mbytes"])),
- plog["compression"],
- )
- else:
- logSupport.add_processlog_handler(
- "factoryadmin",
- logSupport.log_dir,
- plog["msg_types"],
- plog["extension"],
- int(float(plog["max_days"])),
- int(float(plog["min_days"])),
- int(float(plog["max_mbytes"])),
- plog["compression"],
- )
- logSupport.log = logSupport.getLogger("factoryadmin")
+ logSupport.log = logSupport.get_logger_with_handlers("factoryadmin", logSupport.log_dir, glideinDescript.data)
  logSupport.log.info("Reconfiguring factory: %s" % msg)
 
 

doc/factory/configuration.html

@@ -170,9 +170,9 @@ <h2>Example Configuration</h2>
  <a href="#">&lt;process_logs &gt;</a><br />
  <blockquote>
  <a href="#process_logs"
- >&lt;process_log extension="info" max_days="7.0"
- max_mbytes="100.0" min_days="3.0" msg_types="INFO"
- backup_count="5" compression="gz" /&gt;</a
+ >&lt;process_log structured="True" extension="info"
+ max_days="7.0" max_mbytes="100.0" min_days="3.0"
+ msg_types="INFO" backup_count="5" compression="gz" /&gt;</a
  ><br />
  <a href="#process_logs"
  >&lt;process_log extension="debug" max_days="7.0"
@@ -611,6 +611,12 @@ <h3 class="western"><a name="args_global"></a>Global arguments</h3>
  with other message types.
  </li>
  </ul>
+ If any of the logs has <i>structured=True</i>, then the logs are
+ written in structured format. It is actuallly a hybrid format, with
+ some initial field and a JSON dictionary. Since all logs share the
+ same logger, it is not possible to have some in structured and some
+ in classic format. In the future we plan for the structured format
+ to become the default. <br /><br />
  The extension is added to the log name to create separate logs.
  <br /><br />
  <b>Log Retention and Rotation Policy:</b>

doc/frontend/configuration.html

@@ -159,14 +159,14 @@ <h2>Example Configuration</h2>
  <a href="#">&lt;process_logs &gt;</a><br />
  <blockquote>
  <a href="#process_logs"
- >&lt;process_log extension="info" max_days="7.0"
- max_mbytes="100.0" min_days="3.0" msg_types="INFO"
- backup_count="5" compression="gz" /&gt;</a
+ >&lt;process_log structured="False" extension="info"
+ max_days="7.0" max_mbytes="100.0" min_days="3.0"
+ msg_types="INFO" backup_count="5" compression="gz" /&gt;</a
  ><br />
  <a href="#process_logs"
- >&lt;process_log extension="debug" max_days="7.0"
- max_mbytes="100.0" min_days="3.0" msg_types="DEBUG,ERR,WARN"
- backup_count="5" /&gt;</a
+ >&lt;process_log structured="False" extension="debug"
+ max_days="7.0" max_mbytes="100.0" min_days="3.0"
+ msg_types="DEBUG,ERR,WARN" backup_count="5" /&gt;</a
  ><br />
  </blockquote>
  <a href="#">&lt;/process_logs &gt;</a><br />
@@ -518,9 +518,10 @@ <h2 class="western"><a name="management"></a>Frontend Configuration</h2>
  <a name="process_logs" />
  <div class="xml">
  &lt;frontend&gt;&lt;log_retention&gt;&lt;process_logs&gt;&lt;process_log
- max_days=&quot;<i>max days</i>&quot; min_days=&quot;<i>min days</i
- >&quot; max_bytes=&quot;<i>max bytes</i>&quot;
- backup_count=&quot;<i>backup count</i>&quot;
+ structured="True" max_days=&quot;<i>max days</i>&quot;
+ min_days=&quot;<i>min days</i>&quot; max_bytes=&quot;<i
+ >max bytes</i
+ >&quot; backup_count=&quot;<i>backup count</i>&quot;
  type=&quot;<i>ALL</i>&quot; compression=&quot;<i>gz</i>&quot;/&gt;
  </div>
  <p>
@@ -541,6 +542,12 @@ <h2 class="western"><a name="management"></a>Frontend Configuration</h2>
  that don't necessarily cause abnormal execution.
  </li>
  </ul>
+ If any of the logs has <i>structured=True</i>, then the logs are
+ written in structured format. It is actuallly a hybrid format, with
+ some initial field and a JSON dictionary. Since all logs share the
+ same logger, it is not possible to have some in structured and some
+ in classic format. In the future we plan for the structured format
+ to become the default. <br /><br />
  The extension is added to the log name to create separate logs.
  <br /><br />
  <b>Log Retention and Rotation Policy:</b>

factory/glideFactory.py

@@ -847,33 +847,7 @@ def main(startup_dir):
  logSupport.log_dir = os.path.join(glideinDescript.data["LogDir"], "factory")
 
  # Configure factory process logging
- process_logs = eval(glideinDescript.data["ProcessLogs"])
- for plog in process_logs:
- if "ADMIN" in plog["msg_types"].upper():
- logSupport.add_processlog_handler(
- "factoryadmin",
- logSupport.log_dir,
- "DEBUG,INFO,WARN,ERR",
- plog["extension"],
- int(float(plog["max_days"])),
- int(float(plog["min_days"])),
- int(float(plog["max_mbytes"])),
- int(float(plog["backup_count"])),
- plog["compression"],
- )
- else:
- logSupport.add_processlog_handler(
- "factory",
- logSupport.log_dir,
- plog["msg_types"],
- plog["extension"],
- int(float(plog["max_days"])),
- int(float(plog["min_days"])),
- int(float(plog["max_mbytes"])),
- int(float(plog["backup_count"])),
- plog["compression"],
- )
- logSupport.log = logSupport.getLogger("factory")
+ logSupport.log = logSupport.get_logger_with_handlers("factory", logSupport.log_dir, glideinDescript.data)
  logSupport.log.info("Logging initialized")
 
  if glideinDescript.data["Entries"].strip() in ("", ","):

factory/glideFactoryEntry.py

@@ -72,20 +72,7 @@ def __init__(self, name, startup_dir, glidein_descript, frontend_descript):
  self.scheddName = self.jobDescript.data["Schedd"]
 
  # glideFactoryLib.log_files
- process_logs = eval(self.glideinDescript.data["ProcessLogs"])
- for plog in process_logs:
- logSupport.add_processlog_handler(
- self.name,
- self.logDir,
- plog["msg_types"],
- plog["extension"],
- int(float(plog["max_days"])),
- int(float(plog["min_days"])),
- int(float(plog["max_mbytes"])),
- int(float(plog["backup_count"])),
- plog["compression"],
- )
- self.log = logSupport.getLogger(self.name)
+ self.log = logSupport.get_logger_with_handlers(self.name, self.logDir, self.glideinDescript.data)
 
  cleaner = cleanupSupport.DirCleanupWSpace(
  self.logDir,