Merge pull request hpcugent#77 from wdpypere/lazy

fix lazy logging

lib/vsc/utils/cache.py

@@ -160,7 +160,7 @@ def close(self):
             os.makedirs(dirname)
         f = open(self.filename, 'wb')
         if not f:
-            self.log.error('cannot open the file cache at %s for writing' % (self.filename))
+            self.log.error('cannot open the file cache at %s for writing', self.filename)
         else:
             if self.retain_old:
                 self.shelf.update(self.new_shelf)
@@ -173,4 +173,4 @@ def close(self):
             g.close()
             f.close()
 
-            self.log.info('closing the file cache at %s' % (self.filename))
+            self.log.info('closing the file cache at %s', self.filename)

lib/vsc/utils/fs_store.py

@@ -56,35 +56,35 @@ def store_on_gpfs(user_name, path, key, information, gpfs, login_mount_point, gp
     """
 
     if user_name and user_name.startswith('vsc4'):
-        logger.debug("Storing %s information for user %s" % (key, user_name,))
-        logger.debug("information: %s" % (information,))
-        logger.debug("path for storing information would be %s" % (path,))
+        logger.debug("Storing %s information for user %s", key, user_name)
+        logger.debug("information: %s", information)
+        logger.debug("path for storing information would be %s", path)
 
         # FIXME: We need some better way to address this
         # Right now, we replace the nfs mount prefix which the symlink points to
         # with the gpfs mount point. this is a workaround until we resolve the
         # symlink problem once we take new default scratch into production
         if gpfs.is_symlink(path):
             target = os.path.realpath(path)
-            logger.debug("path is a symlink, target is %s" % (target,))
-            logger.debug("login_mount_point is %s" % (login_mount_point,))
+            logger.debug("path is a symlink, target is %s", target)
+            logger.debug("login_mount_point is %s", login_mount_point)
             if target.startswith(login_mount_point):
                 new_path = target.replace(login_mount_point, gpfs_mount_point, 1)
-                logger.info("Found a symlinked path %s to the nfs mount point %s. Replaced with %s" %
-                            (path, login_mount_point, gpfs_mount_point))
+                logger.info("Found a symlinked path %s to the nfs mount point %s. Replaced with %s",
+                            path, login_mount_point, gpfs_mount_point)
             else:
-                logger.warning("Unable to store quota information for %s on %s; symlink cannot be resolved properly"
-                                % (user_name, path))
+                logger.warning("Unable to store quota information for %s on %s; symlink cannot be resolved properly",
+                               user_name, path)
         else:
             new_path = path
 
         path_stat = os.stat(new_path)
         filename = os.path.join(new_path, filename)
 
         if dry_run:
-            logger.info("Dry run: would update cache for at %s with %s" % (new_path, "%s" % (information,)))
-            logger.info("Dry run: would chmod 640 %s" % (filename,))
-            logger.info("Dry run: would chown %s to %s %s" % (filename, path_stat.st_uid, path_stat.st_gid))
+            logger.info("Dry run: would update cache for at %s with %s", new_path, information)
+            logger.info("Dry run: would chmod 640 %s", filename)
+            logger.info("Dry run: would chown %s to %s %s", filename, path_stat.st_uid, path_stat.st_gid)
         else:
             cache = FileCache(filename, False)  # data need not be retained
             cache.update(key=key, data=information, threshold=0)
@@ -95,7 +95,7 @@ def store_on_gpfs(user_name, path, key, information, gpfs, login_mount_point, gp
             gpfs.chown(path_stat.st_uid, path_stat.st_uid, filename)
             gpfs.ignorerealpathmismatch = False
 
-        logger.info("Stored user %s %s information at %s" % (user_name, key, filename))
+        logger.info("Stored user %s %s information at %s", user_name, key, filename)
 
 
 

lib/vsc/utils/lock.py

@@ -55,11 +55,11 @@ def lock_or_bork(lockfile, simple_nagios):
         lockfile.acquire()
     except LockFailed:
         logger.critical('Unable to obtain lock: lock failed')
-        simple_nagios.critical("failed to take lock on %s" % (lockfile.path,))
+        simple_nagios.critical("failed to take lock on %s" % (lockfile.path))
         sys.exit(NAGIOS_EXIT_CRITICAL)
     except LockError:
-        logger.critical("Unable to obtain lock: could not read previous lock file %s" % (lockfile.path,))
-        simple_nagios.critical("failed to read lockfile %s" % (lockfile.path,))
+        logger.critical("Unable to obtain lock: could not read previous lock file %s", lockfile.path)
+        simple_nagios.critical("failed to read lockfile %s" % (lockfile.path))
         sys.exit(NAGIOS_EXIT_CRITICAL)
 
 

lib/vsc/utils/nagios.py

@@ -1,3 +1,4 @@
+
 # -*- encoding: utf-8 -*-
 #
 # Copyright 2012-2021 Ghent University
@@ -88,7 +89,7 @@ def _real_exit(message, code, metrics=''):
         metrics = '|%s' % message[1]
     if len(msg) > NAGIOS_MAX_MESSAGE_LENGTH:
         # log long message but print truncated message
-        log.info("Nagios report %s: %s%s" % (exit_text, msg, metrics))
+        log.info("Nagios report %s: %s%s", exit_text, msg, metrics)
         msg = msg[:NAGIOS_MAX_MESSAGE_LENGTH-3] + '...'
 
     print("%s %s%s" % (exit_text, msg, metrics))
@@ -156,7 +157,7 @@ def __init__(self, nrange):
 
         if not is_string(nrange):
             newnrange = str(nrange)
-            self.log.debug("nrange %s of type %s, converting to string (%s)" % (str(nrange), type(nrange), newnrange))
+            self.log.debug("nrange %s of type %s, converting to string (%s)", str(nrange), type(nrange), newnrange)
             try:
                 float(newnrange)
             except ValueError:
@@ -174,7 +175,7 @@ def parse(self, nrange):
         r = reg.search(nrange)
         if r:
             res = r.groupdict()
-            self.log.debug("parse: nrange %s gave %s" % (nrange, res))
+            self.log.debug("parse: nrange %s gave %s", nrange, res)
 
             start_txt = res['start']
             if start_txt is None:
@@ -195,7 +196,7 @@ def parse(self, nrange):
                     self.log.raiseException("Invalid end value %s" % end)
 
             neg = res['neg'] is not None
-            self.log.debug("parse: start %s end %s neg %s" % (start, end, neg))
+            self.log.debug("parse: start %s end %s neg %s", start, end, neg)
         else:
             self.log.raiseException('parse: invalid nrange %s.' % nrange)
 
@@ -220,8 +221,8 @@ def range_fn(test):
             if neg:
                 tmp_res = operator.not_(tmp_res)
 
-            self.log.debug("range_fn: test %s start_res %s end_res %s result %s (neg %s)" %
-                           (test, start_res, end_res, tmp_res, neg))
+            self.log.debug("range_fn: test %s start_res %s end_res %s result %s (neg %s)",
+                           test, start_res, end_res, tmp_res, neg)
             return tmp_res
 
         return range_fn
@@ -272,13 +273,13 @@ def report_and_exit(self):
         try:
             nagios_cache = FileCache(self.filename, True)
         except (IOError, OSError):
-            self.log.critical("Error opening file %s for reading" % (self.filename))
+            self.log.critical("Error opening file %s for reading", self.filename)
             unknown_exit("%s nagios gzipped JSON file unavailable (%s)" % (self.header, self.filename))
 
         (timestamp, ((nagios_exit_code, nagios_exit_string), nagios_message)) = nagios_cache.load('nagios')
 
         if self.threshold <= 0 or time.time() - timestamp < self.threshold:
-            self.log.info("Nagios check cache file %s contents delivered: %s" % (self.filename, nagios_message))
+            self.log.info("Nagios check cache file %s contents delivered: %s", self.filename, nagios_message)
             print("%s %s" % (nagios_exit_string, nagios_message))
             sys.exit(nagios_exit_code)
         else:
@@ -297,10 +298,10 @@ def cache(self, nagios_exit, nagios_message):
             nagios_cache = FileCache(self.filename)
             nagios_cache.update('nagios', (nagios_exit, nagios_message), 0)  # always update
             nagios_cache.close()
-            self.log.info("Wrote nagios check cache file %s at about %s" % (self.filename, time.ctime(time.time())))
+            self.log.info("Wrote nagios check cache file %s at about %s", self.filename, time.ctime(time.time()))
         except (IOError, OSError):
             # raising an error is ok, since we usually do this as the very last thing in the script
-            self.log.raiseException("Cannot save to the nagios gzipped JSON file (%s)" % (self.filename))
+            self.log.raiseException("Cannot save to the nagios gzipped JSON file (%s)" % self.filename)
 
         try:
             p = pwd.getpwnam(self.nagios_username)
@@ -313,8 +314,8 @@ def cache(self, nagios_exit, nagios_message):
             if os.geteuid() == 0:
                 os.chown(self.filename, p.pw_uid, p.pw_gid)
             else:
-                self.log.warn("Not running as root: Cannot chown the nagios check file %s to %s" %
-                              (self.filename, self.nagios_username))
+                self.log.warn("Not running as root: Cannot chown the nagios check file %s to %s",
+                              self.filename, self.nagios_username)
         except OSError:
             self.log.raiseException("Cannot chown the nagios check file %s to the nagios user" % (self.filename))
 

lib/vsc/utils/pickle_files.py

@@ -62,7 +62,7 @@ def read(self):
         try:
             timestamp = pickle.load(open(self.filename, "rb"))
         except (IOError, OSError):
-            self.log.exception("Failed to load timestamp pickle from filename %s." % (self.filename))
+            self.log.exception("Failed to load timestamp pickle from filename %s.", self.filename)
             return None
 
         return timestamp
@@ -80,11 +80,11 @@ def write(self, timestamp):
         try:
             pickle.dump(timestamp, open(self.filename, "wb"))
         except Exception:
-            self.log.exception("Failed to dump timestamp %s to pickle in filename %s" % (timestamp, self.filename))
+            self.log.exception("Failed to dump timestamp %s to pickle in filename %s", timestamp, self.filename)
             raise
 
         try:
             os.chmod(self.filename, stat.S_IRWXU)
         except Exception:
-            self.log.exception("Failed to set permissions on filename %s" % (self.filename))
+            self.log.exception("Failed to set permissions on filename %s", self.filename)
             raise

lib/vsc/utils/script_tools.py

@@ -160,7 +160,7 @@ def prologue(self):
 
         # check for HA host
         if self.options.ha and not proceed_on_ha_service(self.options.ha):
-            self.log.warning("Not running on the target host %s in the HA setup. Stopping." % (self.options.ha,))
+            self.log.warning("Not running on the target host %s in the HA setup. Stopping.", self.options.ha)
             self.nagios_reporter.ok("Not running on the HA master.")
             sys.exit(NAGIOS_EXIT_OK)
 
@@ -169,7 +169,7 @@ def prologue(self):
                                                    threshold=self.options.nagios_check_interval_threshold * 2)
             lock_or_bork(self.lockfile, self.nagios_reporter)
 
-        self.log.info("%s has started" % (_script_name(sys.argv[0])))
+        self.log.info("%s has started", _script_name(sys.argv[0]))
 
     def _epilogue(self):
         if not self.options.disable_locking and not self.options.dry_run:
@@ -184,7 +184,7 @@ def epilogue(self, nagios_message, nagios_thresholds=None):
 
         nagios_thresholds['message'] = nagios_message
         self.nagios_reporter._eval_and_exit(**nagios_thresholds)
-        self.log.info("%s has finished" % (_script_name(sys.argv[0])))  # may not be reached
+        self.log.info("%s has finished", _script_name(sys.argv[0]))  # may not be reached
 
     def ok(self, nagios_message):
         """Run at the end of a script and force an OK exit."""

lib/vsc/utils/timestamp_pid_lockfile.py

@@ -84,7 +84,7 @@ def acquire(self, timeout=None):
             timeout = self.threshold
         try:
             _write_pid_timestamp_file(self.path)
-            self.logger.info('Obtained lock on timestamped pid lockfile %s' % (self.path))
+            self.logger.info('Obtained lock on timestamped pid lockfile %s', self.path)
         except OSError as err:
             doraise = True
             if err.errno == errno.EEXIST:
@@ -93,15 +93,15 @@ def acquire(self, timeout=None):
                 if time.time() - timestamp > timeout:
                     _find_and_kill(pid)
                     os.unlink(self.path)
-                    self.logger.warning('Obsolete lockfile detected at %s: pid = %d, timestamp = %s' %
-                                        (self.path, pid, time.ctime(timestamp)))
+                    self.logger.warning('Obsolete lockfile detected at %s: pid = %d, timestamp = %s',
+                                        self.path, pid, time.ctime(timestamp))
                     try:
                         _write_pid_timestamp_file(self.path)
                         doraise = False
                     except Exception:
                         pass
             if doraise:
-                self.logger.error('Unable to obtain lock on %s: %s' % (self.path, err))
+                self.logger.error('Unable to obtain lock on %s: %s', self.path, err)
                 raise LockFailed
 
     def release(self):
@@ -110,10 +110,10 @@ def release(self):
         Remove the lockfile to indicate the lock was released.
         '''
         if not self.is_locked():
-            self.logger.error('Trying to release a lock that does not exist at %s.' % (self.path))
+            self.logger.error('Trying to release a lock that does not exist at %s.', self.path)
             raise NotLocked
         if not self.i_am_locking():
-            self.logger.error('Trying to release a lock the current process is not holding at %s' % (self.path))
+            self.logger.error('Trying to release a lock the current process is not holding at %s', self.path)
             raise NotMyLock
         os.remove(self.path)
 

setup.py

@@ -54,7 +54,7 @@
 
 
 PACKAGE = {
-    'version': '2.1.7',
+    'version': '2.1.8',
     'author': [ag, sdw],
     'maintainer': [ag, sdw],
     'excluded_pkgs_rpm': ['vsc', 'vsc.utils'],  # vsc is default, vsc.utils is provided by vsc-base