From 77130a185ee2f2268056c093db66a12f92f543b2 Mon Sep 17 00:00:00 2001 From: Andrzej Kotulski Date: Tue, 23 Jun 2015 11:02:00 -0100 Subject: [PATCH] Add basic logging to infer -- script Summary: @public Add some logging to the script and capture modules so it is easier to troubleshoot. What will be logged: versions of infer, platform, versions of java, build systems etc. In the future we will add more info that we might find useful while troubleshooting Test Plan: run infer with gradle, ant, buck, xcode, mvn and see the logging output Run symbolic link pointing to infer: [INFO] Path to infer script /Users/akotulski/tmp/infer_link (/Users/akotulski/infer/infer/bin/infer) --- infer/bin/infer | 39 ++++++++++++++++++++++++++----- infer/bin/inferlib.py | 41 +++++++++++++++++++++++++-------- infer/lib/capture/ant.py | 3 +++ infer/lib/capture/buck.py | 4 ++++ infer/lib/capture/gradle.py | 7 +++++- infer/lib/capture/make.py | 13 ----------- infer/lib/capture/mvn.py | 2 ++ infer/lib/capture/util.py | 17 ++++++++++++++ infer/lib/capture/xcodebuild.py | 16 +++++++++---- 9 files changed, 109 insertions(+), 33 deletions(-) diff --git a/infer/bin/infer b/infer/bin/infer index 1265c8e07..fada0c91e 100755 --- a/infer/bin/infer +++ b/infer/bin/infer @@ -2,9 +2,12 @@ import argparse import imp +import utils import inferlib +import logging import os import sys +import platform CAPTURE_PACKAGE = 'capture' LIB_FOLDER = os.path.join( @@ -28,6 +31,8 @@ MODULE_TO_COMMAND = { 'mvn': ['mvn'] } +FORMAT = '[%(levelname)s] %(message)s' +LOG_FILE = 'toplevel.log' def get_commands(): """Return all commands that are supported.""" @@ -88,11 +93,17 @@ def create_argparser(parents=[]): return parser -def main(): - if sys.version_info < (2, 7, 0): - print("You need python 2.7 or later to run this script") - exit(1) +def configure_logging(infer_dir, log_to_stderr): + if log_to_stderr: + logging.basicConfig(level=logging.INFO, format=FORMAT) + else: + logging.basicConfig(level=logging.INFO, + format=FORMAT, + filename=os.path.join(infer_dir, LOG_FILE), + filemode='w') + +def main(): to_parse, cmd = split_args_to_parse() # get the module name (if any), then load it capture_module_name = os.path.basename(cmd[0]) if len(cmd) > 0 else None @@ -112,12 +123,28 @@ def main(): args = global_argparser.parse_args(to_parse) + if (imported_module and not args.incremental and + capture_module_name != 'analyze'): + inferlib.remove_infer_out(args.infer_out) + + inferlib.create_results_dir(args.infer_out) + + configure_logging(args.infer_out, args.log_to_stderr) + logging.info('Running command %s', ' '.join(sys.argv)) + logging.info('Path to infer script %s (%s)', __file__, + os.path.realpath(__file__)) + logging.info(inferlib.get_infer_version()) + logging.info('Platform: %s', platform.platform()) + logging.info('PATH=%s', os.getenv('PATH')) + logging.info('SHELL=%s', os.getenv('SHELL')) + logging.info('PWD=%s', os.getenv('PWD')) + if imported_module: - if capture_module_name != 'analyze' and not args.incremental: - inferlib.remove_infer_out(args.infer_out) capture_exitcode = imported_module.gen_instance(args, cmd).capture() if capture_exitcode != os.EX_OK: + logging.error('Error during capture phase, exiting') exit(capture_exitcode) + logging.info('Capture phase was successful') elif capture_module_name is not None: # There was a command, but it's not supported print('Command "{cmd}" not recognised'.format( diff --git a/infer/bin/inferlib.py b/infer/bin/inferlib.py index b7756d3fa..0c6464a68 100644 --- a/infer/bin/inferlib.py +++ b/infer/bin/inferlib.py @@ -45,24 +45,27 @@ WARNING = 'WARNING' INFO = 'INFO' +def get_infer_version(): + try: + return subprocess.check_output([ + utils.get_cmd_in_bin_dir(INFER_ANALYZE_BINARY), '-version']) + except: + print("Failed to run {0} binary, exiting". + format(INFER_ANALYZE_BINARY)) + sys.exit(os.EX_UNAVAILABLE) + + # https://github.com/python/cpython/blob/aa8ea3a6be22c92e774df90c6a6ee697915ca8ec/Lib/argparse.py class VersionAction(argparse._VersionAction): def __call__(self, parser, namespace, values, option_string=None): # set self.version so that argparse version action knows it - self.version = self.get_infer_version() + self.version = get_infer_version() super(VersionAction, self).__call__(parser, namespace, values, option_string) - def get_infer_version(self): - try: - return subprocess.check_output([ - utils.get_cmd_in_bin_dir(INFER_ANALYZE_BINARY), '-version']) - except: - print("Failed to run {0} binary, exiting". - format(INFER_ANALYZE_BINARY)) - exit(2) + base_parser = argparse.ArgumentParser(add_help=False) @@ -84,6 +87,10 @@ base_group.add_argument('-nf', '--no-filtering', action='store_true', help='''Also show the results from the experimental checks. Warning: some checks may contain many false alarms''') + +base_group.add_argument('--log_to_stderr', action='store_true', + help='''When set, all logging will go to stderr instead + of log file''') base_parser.add_argument('-v', '--version', help='Get version of the analyzer', action=VersionAction) @@ -153,6 +160,18 @@ def remove_infer_out(infer_out): shutil.rmtree(infer_out, True) +def mkdir_if_not_exists(path): + if not os.path.exists(path): + os.mkdir(path) + + +def create_results_dir(results_dir): + mkdir_if_not_exists(results_dir) + mkdir_if_not_exists(os.path.join(results_dir, 'specs')) + mkdir_if_not_exists(os.path.join(results_dir, 'captured')) + mkdir_if_not_exists(os.path.join(results_dir, 'sources')) + + def clean_infer_out(infer_out): directories = ['multicore', 'classnames', 'sources'] @@ -399,6 +418,7 @@ class Infer: return javac_status def analyze(self): + logging.info('Starting analysis') infer_analyze = [ utils.get_cmd_in_bin_dir(INFER_ANALYZE_BINARY), '-results_dir', @@ -504,6 +524,9 @@ class Infer: captured_plural = '' if captured_total <= 1 else 's' print('\n%d file%s analyzed' % (captured_total, captured_plural)) + logging.info('Analyzed file count: %d', captured_total) + logging.info('Analysis status: %d', exit_status) + return exit_status def file_stats(self, file, stats): diff --git a/infer/lib/capture/ant.py b/infer/lib/capture/ant.py index 543e71cfb..1077bddea 100644 --- a/infer/lib/capture/ant.py +++ b/infer/lib/capture/ant.py @@ -1,4 +1,5 @@ import os +import logging import util MODULE_NAME = __name__ @@ -20,6 +21,8 @@ class AntCapture: def __init__(self, args, cmd): self.args = args + util.log_java_version() + logging.info(util.run_cmd_ignore_fail(['ant', '-version'])) # TODO: make the extraction of targets smarter self.build_cmd = ['ant', '-verbose'] + cmd[1:] diff --git a/infer/lib/capture/buck.py b/infer/lib/capture/buck.py index 482ba49dd..339109f2a 100644 --- a/infer/lib/capture/buck.py +++ b/infer/lib/capture/buck.py @@ -3,6 +3,7 @@ import os import subprocess import traceback import util +import logging import utils # this is module located in ../utils.py @@ -43,6 +44,9 @@ def create_argparser(group_name=MODULE_NAME): class BuckAnalyzer: def __init__(self, args, cmd): self.args = args + util.log_java_version() + logging.info(util.run_cmd_ignore_fail(['buck', '--version'])) + self.cmd = cmd[2:] # TODO: make the extraction of targets smarter def capture(self): diff --git a/infer/lib/capture/gradle.py b/infer/lib/capture/gradle.py index 941562f69..9fef2d136 100644 --- a/infer/lib/capture/gradle.py +++ b/infer/lib/capture/gradle.py @@ -1,5 +1,7 @@ import os import util +import logging +import subprocess MODULE_NAME = __name__ MODULE_DESCRIPTION = '''Run analysis of code built with a command like: @@ -22,8 +24,11 @@ class GradleCapture: def __init__(self, args, cmd): self.args = args - # TODO: make the extraction of targets smarter + # TODO: make the extraction of targets smarter self.build_cmd = [cmd[0], '--debug'] + cmd[1:] + # That contains javac version as well + version_str = util.run_cmd_ignore_fail([cmd[0], '--version']) + logging.info("Running with:\n" + version_str) def get_inferJ_commands(self, verbose_output): argument_start_pattern = ' Compiler arguments: ' diff --git a/infer/lib/capture/make.py b/infer/lib/capture/make.py index 0564caf15..5f9813444 100644 --- a/infer/lib/capture/make.py +++ b/infer/lib/capture/make.py @@ -21,10 +21,6 @@ def gen_instance(*args): return MakeCapture(*args) -def mkdir_if_not_exists(path): - if not os.path.exists(path): - os.mkdir(path) - create_argparser = \ util.clang_frontend_argparser(MODULE_DESCRIPTION, MODULE_NAME) @@ -34,13 +30,6 @@ class MakeCapture: self.args = args self.cmd = [os.path.basename(cmd[0])] + cmd[1:] - def create_results_dir(self): - results_dir = self.args.infer_out - mkdir_if_not_exists(results_dir) - mkdir_if_not_exists(os.path.join(results_dir, 'specs')) - mkdir_if_not_exists(os.path.join(results_dir, 'captured')) - mkdir_if_not_exists(os.path.join(results_dir, 'sources')) - def get_envvars(self): env_vars = dict(os.environ) wrappers_path = os.path.join( @@ -58,8 +47,6 @@ class MakeCapture: return env_vars def capture(self): - self.create_results_dir() - try: subprocess.check_call(self.cmd, env=self.get_envvars()) return os.EX_OK diff --git a/infer/lib/capture/mvn.py b/infer/lib/capture/mvn.py index 04c154e63..211bee3dc 100644 --- a/infer/lib/capture/mvn.py +++ b/infer/lib/capture/mvn.py @@ -3,6 +3,7 @@ # import os +import logging import re import util @@ -24,6 +25,7 @@ create_argparser = util.base_argparser(MODULE_DESCRIPTION, MODULE_NAME) class MavenCapture: def __init__(self, args, cmd): self.args = args + logging.info(util.run_cmd_ignore_fail(['mvn', '-version'])) # TODO: make the extraction of targets smarter self.build_cmd = ['mvn', '-X'] + cmd[1:] diff --git a/infer/lib/capture/util.py b/infer/lib/capture/util.py index b9b4520e8..44c3c6a18 100644 --- a/infer/lib/capture/util.py +++ b/infer/lib/capture/util.py @@ -5,8 +5,10 @@ import argparse import os +import logging import subprocess import inferlib +import traceback def create_inferJ_command(args, javac_arguments): @@ -36,6 +38,21 @@ def run_commands(cmds): return os.EX_OK +def run_cmd_ignore_fail(cmd): + try: + return subprocess.check_output(cmd, stderr=subprocess.STDOUT) + except: + return 'calling {cmd} failed\n{trace}'.format( + cmd=' '.join(cmd), + trace=traceback.format_exc()) + + +def log_java_version(): + java_version = run_cmd_ignore_fail(['java', '-version']) + javac_version = run_cmd_ignore_fail(['javac', '-version']) + logging.info("java versions:\n%s%s", java_version, javac_version) + + def base_argparser(description, module_name): def _func(group_name=module_name): """This creates an empty argparser for the module, which provides only diff --git a/infer/lib/capture/xcodebuild.py b/infer/lib/capture/xcodebuild.py index 9dfdd7b63..02cd33699 100644 --- a/infer/lib/capture/xcodebuild.py +++ b/infer/lib/capture/xcodebuild.py @@ -1,6 +1,7 @@ import os import subprocess import traceback +import logging import util MODULE_NAME = __name__ @@ -32,15 +33,22 @@ create_argparser = \ class XcodebuildCapture: def __init__(self, args, cmd): self.args = args + self.apple_clang_path = \ + subprocess.check_output(['xcrun', '--find', 'clang']).strip() + + xcode_version = util.run_cmd_ignore_fail(['xcodebuild', '-version']) + apple_clang_version = util.run_cmd_ignore_fail([self.apple_clang_path, + '--version']) + logging.info('Xcode version:\n%s', xcode_version) + + logging.info('clang version:\n%s', apple_clang_version) + self.cmd = cmd def get_envvars(self): env_vars = dict(os.environ) - apple_clang_path = \ - subprocess.check_output(['xcrun', '--find', 'clang']).strip() - - env_vars['FCP_APPLE_CLANG'] = apple_clang_path + env_vars['FCP_APPLE_CLANG'] = self.apple_clang_path frontend_env_vars = \ util.get_clang_frontend_envvars(self.args)