user/atlas/proxy.py

0001 #!/usr/bin/env python
0002 # Licensed under the Apache License, Version 2.0 (the "License");
0003 # you may not use this file except in compliance with the License.
0004 # You may obtain a copy of the License at
0005 # http://www.apache.org/licenses/LICENSE-2.0
0006 #
0007 # Authors:
0008 # - Paul Nilsson, paul.nilsson@cern.ch, 2018
0009 # - Alexander Bogdanchikov, Alexander.Bogdanchikov@cern.ch, 2020
0010
0011 # from pilot.util.container import execute
0012
0013 import os
0014 import logging
0015
0016 from pilot.user.atlas.setup import get_file_system_root_path
0017 from pilot.util.container import execute
0018 from pilot.common.errorcodes import ErrorCodes
0019 from time import time
0020
0021 logger = logging.getLogger(__name__)
0022 errors = ErrorCodes()
0023
0024
0025 def verify_proxy(limit=None, x509=None, proxy_id="pilot", test=False):
0026     """
0027     Check for a valid voms/grid proxy longer than N hours.
0028     Use `limit` to set required time limit.
0029
0030     :param limit: time limit in hours (int).
0031     :param x509: points to the proxy file. If not set (=None) - get proxy file from X509_USER_PROXY environment
0032     :return: exit code (NOPROXY or NOVOMSPROXY), diagnostics (error diagnostics string).
0033     """
0034
0035     if limit is None:
0036         limit = 48
0037
0038     # add setup for arcproxy if it exists
0039     #arcproxy_setup = "%s/atlas.cern.ch/repo/sw/arc/client/latest/slc6/x86_64/setup.sh" % get_file_system_root_path()
0040     if x509 is None:
0041         x509 = os.environ.get('X509_USER_PROXY', '')
0042     if x509 != '':
0043         envsetup = 'export X509_USER_PROXY=%s;' % x509
0044     else:
0045         envsetup = ''
0046
0047     envsetup += ". %s/atlas.cern.ch/repo/ATLASLocalRootBase/user/atlasLocalSetup.sh --quiet;" % get_file_system_root_path()
0048     if os.environ.get('ALRB_noGridMW', '').lower() != "yes":
0049         envsetup += "lsetup emi;"
0050     else:
0051         logger.warning('Skipping "lsetup emi" as ALRB_noGridMW=YES')
0052
0053     # first try to use arcproxy since voms-proxy-info is not working properly on SL6
0054     #  (memory issues on queues with limited memory)
0055
0056     exit_code, diagnostics = verify_arcproxy(envsetup, limit, proxy_id, test=test)
0057     if exit_code != 0 and exit_code != -1:
0058         return exit_code, diagnostics
0059     elif exit_code == -1:
0060         pass  # go to next test
0061     else:
0062         return 0, diagnostics
0063
0064     exit_code, diagnostics = verify_vomsproxy(envsetup, limit)
0065     if exit_code != 0:
0066         return exit_code, diagnostics
0067     else:
0068         return 0, diagnostics
0069
0070     return 0, diagnostics
0071
0072
0073 def verify_arcproxy(envsetup, limit, proxy_id="pilot", test=False):
0074     """
0075     Verify the proxy using arcproxy.
0076
0077     :param envsetup: general setup string for proxy commands (string).
0078     :param limit: time limit in hours (int).
0079     :param  proxy_id: proxy unique id name. The verification result will be cached for this id. If None the result will not be cached (string)
0080     :return: exit code (int), error diagnostics (string).
0081     """
0082     exit_code = 0
0083     diagnostics = ""
0084
0085     if test:
0086         return errors.NOVOMSPROXY, 'dummy test'
0087
0088     if proxy_id is not None:
0089         if not hasattr(verify_arcproxy, "cache"):
0090             verify_arcproxy.cache = {}
0091
0092         if proxy_id in verify_arcproxy.cache:  # if exist, then calculate result from current cache
0093             validity_end = verify_arcproxy.cache[proxy_id]
0094             if validity_end < 0:  # previous validity check failed, do not try to re-check
0095                 exit_code = -1
0096                 diagnostics = "arcproxy verification failed (cached result)"
0097             else:
0098                 tnow = int(time() + 0.5)  # round to seconds
0099                 seconds_left = validity_end - tnow
0100                 logger.info("cache: check %s proxy validity: wanted=%dh left=%.2fh (now=%d validity_end=%d left=%d)",
0101                             proxy_id, limit, float(seconds_left) / 3600, tnow, validity_end, seconds_left)
0102                 if seconds_left < limit * 3600:
0103                     diagnostics = "%s proxy validity time is too short: %.2fh" % (proxy_id, float(seconds_left) / 3600)
0104                     logger.warning(diagnostics)
0105                     exit_code = errors.NOVOMSPROXY
0106                 else:
0107                     logger.info("%s proxy validity time is verified", proxy_id)
0108             return exit_code, diagnostics
0109
0110     # options and options' sequence are important for parsing, do not change it
0111     cmd = "%sarcproxy -i vomsACvalidityEnd -i vomsACvalidityLeft" % envsetup
0112
0113     _exit_code, stdout, stderr = execute(cmd, shell=True)  # , usecontainer=True, copytool=True)
0114     if stdout is not None:
0115         if 'command not found' in stdout:
0116             logger.warning("arcproxy is not available on this queue,"
0117                            "this can lead to memory issues with voms-proxy-info on SL6: %s", stdout)
0118             exit_code = -1
0119         else:
0120             exit_code, diagnostics, validity_end = interpret_proxy_info(_exit_code, stdout, stderr, limit)
0121             if proxy_id and validity_end:  # setup cache if requested
0122                 if exit_code == 0:
0123                     logger.info("cache the validity_end: cache['%s'] = %d", proxy_id, validity_end)
0124                     verify_arcproxy.cache[proxy_id] = validity_end
0125                 else:
0126                     verify_arcproxy.cache[proxy_id] = -1  # -1 in cache means any error in prev validation
0127             if exit_code == 0:
0128                 logger.info("voms proxy verified using arcproxy")
0129                 return 0, diagnostics
0130             elif exit_code == -1:  # skip to next proxy test
0131                 return exit_code, diagnostics
0132             elif exit_code == errors.NOVOMSPROXY:
0133                 return exit_code, diagnostics
0134             else:
0135                 logger.info("will try voms-proxy-info instead")
0136                 exit_code = -1
0137     else:
0138         logger.warning('command execution failed')
0139
0140     return exit_code, diagnostics
0141
0142
0143 def verify_vomsproxy(envsetup, limit):
0144     """
0145     Verify proxy using voms-proxy-info command.
0146
0147     :param envsetup: general setup string for proxy commands (string).
0148     :param limit: time limit in hours (int).
0149     :return: exit code (int), error diagnostics (string).
0150     """
0151
0152     exit_code = 0
0153     diagnostics = ""
0154
0155     if os.environ.get('X509_USER_PROXY', '') != '':
0156         cmd = "%svoms-proxy-info -actimeleft --file $X509_USER_PROXY" % envsetup
0157         logger.info('executing command: %s', cmd)
0158         _exit_code, stdout, stderr = execute(cmd, shell=True)
0159         if stdout is not None:
0160             if "command not found" in stdout:
0161                 logger.info("skipping voms proxy check since command is not available")
0162             else:
0163                 exit_code, diagnostics, validity_end = interpret_proxy_info(_exit_code, stdout, stderr, limit)
0164                 if exit_code == 0:
0165                     logger.info("voms proxy verified using voms-proxy-info")
0166                     return 0, diagnostics
0167         else:
0168             logger.warning('command execution failed')
0169     else:
0170         logger.warning('X509_USER_PROXY is not set')
0171
0172     return exit_code, diagnostics
0173
0174
0175 def verify_gridproxy(envsetup, limit):
0176     """
0177     Verify proxy using grid-proxy-info command.
0178
0179     :param envsetup: general setup string for proxy commands (string).
0180     :param limit: time limit in hours (int).
0181     :return: exit code (int), error diagnostics (string).
0182     """
0183
0184     ec = 0
0185     diagnostics = ""
0186
0187     if limit:
0188         # next clause had problems: grid-proxy-info -exists -valid 0.166666666667:00
0189         #cmd = "%sgrid-proxy-info -exists -valid %s:00" % (envsetup, str(limit))
0190         # more accurate calculation of HH:MM
0191         limit_hours = int(limit * 60) / 60
0192         limit_minutes = int(limit * 60 + .999) - limit_hours * 60
0193         cmd = "%sgrid-proxy-info -exists -valid %d:%02d" % (envsetup, limit_hours, limit_minutes)
0194     else:
0195         cmd = "%sgrid-proxy-info -exists -valid 24:00" % (envsetup)
0196
0197     logger.info('executing command: %s', cmd)
0198     exit_code, stdout, stderr = execute(cmd, shell=True)
0199     if stdout is not None:
0200         if exit_code != 0:
0201             if stdout.find("command not found") > 0:
0202                 logger.info("skipping grid proxy check since command is not available")
0203             else:
0204                 # Analyze exit code / stdout
0205                 diagnostics = "grid proxy certificate does not exist or is too short: %d, %s" % (exit_code, stdout)
0206                 logger.warning(diagnostics)
0207                 return errors.NOPROXY, diagnostics
0208         else:
0209             logger.info("grid proxy verified")
0210     else:
0211         logger.warning('command execution failed')
0212
0213     return ec, diagnostics
0214
0215
0216 def interpret_proxy_info(ec, stdout, stderr, limit):
0217     """
0218     Interpret the output from arcproxy or voms-proxy-info.
0219
0220     :param ec: exit code from proxy command (int).
0221     :param stdout: stdout from proxy command (string).
0222     :param stderr: stderr from proxy command (string).
0223     :param limit: time limit in hours (int).
0224     :return: exit code (int), diagnostics (string). validity end in seconds if detected, None if not detected(int)
0225     """
0226
0227     exitcode = 0
0228     diagnostics = ""
0229     validity_end = None  # not detected
0230
0231     logger.debug('stdout = %s', stdout)
0232     logger.debug('stderr = %s', stderr)
0233
0234     if ec != 0:
0235         if "Unable to verify signature! Server certificate possibly not installed" in stdout:
0236             logger.warning("skipping voms proxy check: %s", stdout)
0237         # test for command errors
0238         elif "arcproxy: error while loading shared libraries" in stderr:
0239             exitcode = -1
0240             logger.warning('skipping arcproxy test')
0241         elif "arcproxy:" in stdout:
0242             diagnostics = "arcproxy failed: %s" % (stdout)
0243             logger.warning(diagnostics)
0244             exitcode = errors.GENERALERROR
0245         else:
0246             # Analyze exit code / output
0247             diagnostics = "voms proxy certificate check failure: %d, %s" % (ec, stdout)
0248             logger.warning(diagnostics)
0249             exitcode = errors.NOVOMSPROXY
0250     else:
0251         if "\n" in stdout:
0252             # try to extract the time left from the command output
0253             validity_end, stdout = extract_time_left(stdout)
0254             if validity_end:
0255                 return exitcode, diagnostics, validity_end
0256
0257         # test for command errors
0258         if "arcproxy:" in stdout:
0259             diagnostics = "arcproxy failed: %s" % stdout
0260             logger.warning(diagnostics)
0261             exitcode = errors.GENERALERROR
0262         else:
0263             # on EMI-3 the time output is different (HH:MM:SS as compared to SS on EMI-2)
0264             if ":" in stdout:
0265                 ftr = [3600, 60, 1]
0266                 stdout = sum([a * b for a, b in zip(ftr, list(map(int, stdout.split(':'))))])  # Python 2/3
0267             try:
0268                 validity = int(stdout)
0269                 if validity >= limit * 3600:
0270                     logger.info("voms proxy verified (%d s)", validity)
0271                 else:
0272                     diagnostics = "voms proxy certificate does not exist or is too short (lifetime %d s)" % validity
0273                     logger.warning(diagnostics)
0274                     exitcode = errors.NOVOMSPROXY
0275             except ValueError as exc:
0276                 diagnostics = "failed to evaluate command stdout: %s, stderr: %s, exc=%s" % (stdout, stderr, exc)
0277                 logger.warning(diagnostics)
0278                 exitcode = errors.GENERALERROR
0279
0280     return exitcode, diagnostics, validity_end
0281
0282
0283 def extract_time_left(stdout):
0284     """
0285     Extract the time left from the proxy command.
0286     Some processing on the stdout is done.
0287
0288     :param stdout: stdout (string).
0289     :return: validity_end, stdout (int, string))
0290     """
0291
0292     # remove the last \n in case there is one
0293     if stdout[-1] == '\n':
0294         stdout = stdout[:-1]
0295     stdout_split = stdout.split('\n')
0296     logger.debug("splitted stdout = %s", stdout_split)
0297
0298     try:
0299         validity_end = int(stdout_split[-2])
0300     except (ValueError, TypeError):
0301         # try to get validity_end in penultimate line
0302         try:
0303             validity_end_str = stdout_split[-1]  # may raise exception IndexError if stdout is too short
0304             logger.debug("try to get validity_end from the line: \"%s\"", validity_end_str)
0305             validity_end = int(validity_end_str)  # may raise ValueError if not string
0306         except (IndexError, ValueError) as exc:
0307             logger.info("validity_end not found in stdout (%s)", exc)
0308         #validity_end = None
0309
0310     if validity_end:
0311         logger.info("validity_end = %d", validity_end)
0312
0313     return validity_end, stdout