examples/cron/cron.py

   1 #!/usr/bin/env python3
   2
   3 """Wrapper that adds exclusive locks, timeouts, timestamp accounting,
   4 max frequency, logging, etc... to running cron jobs.
   5 """
   6
   7 import datetime
   8 import logging
   9 import os
  10 import sys
  11 from typing import Optional
  12
  13 from pyutils import bootstrap, config, exec_utils, stopwatch
  14 from pyutils.datetimez import datetime_utils
  15 from pyutils.files import file_utils, lockfile
  16
  17 logger = logging.getLogger(__name__)
  18
  19 cfg = config.add_commandline_args(
  20     f'Python Cron Runner ({__file__})',
  21     'Wrapper for cron commands with locking, timeouts, and accounting.',
  22 )
  23 cfg.add_argument(
  24     '--lockfile',
  25     default=None,
  26     metavar='LOCKFILE_PATH',
  27     help='Path to the lockfile to use to ensure that two instances of a command do not execute contemporaneously.',
  28 )
  29 cfg.add_argument(
  30     '--lockfile_audit_record',
  31     default=None,
  32     metavar='LOCKFILE_AUDIT_RECORD_FILENAME',
  33     help='Path to a record of when the logfile was held/released and for what reason',
  34 )
  35 cfg.add_argument(
  36     '--timeout',
  37     type=str,
  38     metavar='TIMEOUT',
  39     default=None,
  40     help='Maximum time for lock acquisition + command execution.  Undecorated for seconds but "3m" or "1h 15m" work too.',
  41 )
  42 cfg.add_argument(
  43     '--timestamp',
  44     type=str,
  45     metavar='TIMESTAMP_FILE',
  46     default=None,
  47     help='The /timestamp/TIMESTAMP_FILE file tracking the work being done; files\' mtimes will be set to the last successful run of a command for accounting purposes.',
  48 )
  49 cfg.add_argument(
  50     '--max_frequency',
  51     type=str,
  52     metavar='FREQUENCY',
  53     default=None,
  54     help='The maximum frequency with which to do this work; even if the wrapper is invoked more often than this it will not run the command.  Requires --timestamp.  Undecorated for seconds but "3h" or "1h 15m" work too.',
  55 )
  56 cfg.add_argument(
  57     '--command',
  58     nargs='*',
  59     required=True,
  60     type=str,
  61     metavar='COMMANDLINE',
  62     help='The commandline to run under a lock.',
  63 )
  64 config.overwrite_argparse_epilog(
  65     """
  66 cron.py's exit value:
  67
  68    -1000 = some internal error occurred (see exception log).
  69        0 = we exited early due to not enough time passage since the last
  70            invocation of --command.
  71     1000 = we could not obtain the lockfile; someone else owns it.
  72  else = if the --command was run successfully, cron.py will exit with
  73         the same code that the subcommand exited with.
  74 """
  75 )
  76
  77
  78 def run_command(timeout: Optional[int], timestamp_file: Optional[str]) -> int:
  79     """Run cron command"""
  80     cmd = ' '.join(config.config['command'])
  81     logger.info('cron cmd = "%s"', cmd)
  82     logger.debug('shell environment:')
  83     for var in os.environ:
  84         val = os.environ[var]
  85         logger.debug('%s = %s', var, val)
  86     logger.debug('____ (↓↓↓ output from the subprocess appears below here ↓↓↓) ____')
  87     try:
  88         with stopwatch.Timer() as t:
  89             ret = exec_utils.cmd_exitcode(cmd, timeout)
  90         logger.debug(
  91             f'____ (↑↑↑ subprocess finished in {t():.2f}s, exit value was {ret} ↑↑↑) ____'
  92         )
  93         if timestamp_file is not None and os.path.exists(timestamp_file):
  94             logger.debug('Touching %s', timestamp_file)
  95             file_utils.touch_file(timestamp_file)
  96         return ret
  97     except Exception as e:
  98         logger.exception(e)
  99         print('Cron subprocess failed, giving up.', file=sys.stderr)
 100         logger.warning('Cron subprocess failed, giving up')
 101         return -1000
 102
 103
 104 @bootstrap.initialize
 105 def main() -> int:
 106     """Entry point"""
 107     if config.config['timestamp']:
 108         timestamp_file = f"/timestamps/{config.config['timestamp']}"
 109         if not file_utils.does_file_exist(timestamp_file):
 110             logger.error(
 111                 '--timestamp argument\'s target file (%s) must already exist.',
 112                 timestamp_file,
 113             )
 114             sys.exit(-1)
 115     else:
 116         timestamp_file = None
 117         if config.config['max_frequency']:
 118             config.error(
 119                 'The --max_frequency argument requires the --timestamp argument.'
 120             )
 121
 122     now = datetime.datetime.now()
 123     if timestamp_file is not None and os.path.exists(timestamp_file):
 124         max_frequency = config.config['max_frequency']
 125         if max_frequency is not None:
 126             max_delta = datetime_utils.parse_duration(max_frequency)
 127             if max_delta > 0:
 128                 mtime = file_utils.get_file_mtime_as_datetime(timestamp_file)
 129                 delta = now - mtime
 130                 if delta.total_seconds() < max_delta:
 131                     logger.info(
 132                         "It's only been %s since we last ran successfully; bailing out.",
 133                         datetime_utils.describe_duration_briefly(delta.total_seconds()),
 134                     )
 135                     sys.exit(0)
 136
 137     timeout = config.config['timeout']
 138     if timeout is not None:
 139         timeout = datetime_utils.parse_duration(timeout)
 140         assert timeout > 0
 141         logger.debug('Timeout is %ss', timeout)
 142         lockfile_expiration = datetime.datetime.now().timestamp() + timeout
 143     else:
 144         logger.debug('Timeout not specified; no lockfile expiration.')
 145         lockfile_expiration = None
 146
 147     lockfile_path = config.config['lockfile']
 148     if lockfile_path is not None:
 149         logger.debug('Attempting to acquire lockfile %s...', lockfile_path)
 150         try:
 151             with lockfile.LockFile(
 152                 lockfile_path,
 153                 do_signal_cleanup=True,
 154                 override_command=' '.join(config.config['command']),
 155                 expiration_timestamp=lockfile_expiration,
 156             ) as lf:
 157                 record = config.config['lockfile_audit_record']
 158                 cmd = ' '.join(config.config['command'])
 159                 if record:
 160                     start = lf.locktime
 161                     with open(record, 'a') as wf:
 162                         print(f'{lockfile_path}, ACQUIRE, {start}, {cmd}', file=wf)
 163                 retval = run_command(timeout, timestamp_file)
 164                 if record:
 165                     end = datetime.datetime.now().timestamp()
 166                     duration = datetime_utils.describe_duration_briefly(end - start)
 167                     with open(record, 'a') as wf:
 168                         print(
 169                             f'{lockfile_path}, RELEASE({duration}), {end}, {cmd}',
 170                             file=wf,
 171                         )
 172                 return retval
 173         except lockfile.LockFileException as e:
 174             logger.exception(e)
 175             msg = f'Failed to acquire {lockfile_path}, giving up.'
 176             logger.error(msg)
 177             print(msg, file=sys.stderr)
 178             return 1000
 179     else:
 180         logger.debug('No lockfile indicated; not locking anything.')
 181         return run_command(timeout, timestamp_file)
 182
 183
 184 if __name__ == '__main__':
 185     # Insist that our logger.whatever('messages') make their way into
 186     # syslog with a facility=LOG_CRON, please.  Yes, this is hacky.
 187     sys.argv.append('--logging_syslog')
 188     sys.argv.append('--logging_syslog_facility=CRON')
 189     main()