From aa9f48111fd07669e7f8e6ac77b8f026c8de3818 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pamela=20McA=E2=80=99Nulty?= Date: Mon, 27 Nov 2017 11:58:50 -0500 Subject: [PATCH 1/4] Add logging and new config stuff --- README.rst | 21 +++++ django_coverage_plugin/__init__.py | 2 +- django_coverage_plugin/plugin.py | 120 +++++++++++++++++++++++++---- setup.py | 2 +- 4 files changed, 129 insertions(+), 16 deletions(-) diff --git a/README.rst b/README.rst index 7660613..4f7cc6b 100644 --- a/README.rst +++ b/README.rst @@ -45,6 +45,21 @@ The Django template plugin uses some existing settings from your .coveragerc file. The ``source=``, ``include=``, and ``omit=`` options control what template files are included in the report. +It also has some optional configuration settings to enable certain debugging flags:: + + [django_coverage_plugin] + show_startup = True + show_tracing = True + show_startup = True + log_file_path = dj_coverage.log + +``show_startup`` will log information during the startup sequence. This is +especially useful when debugging settings configurations. +``show_parsing`` will log information about how a template file is parsed. +``show_tracing`` will log information about how template code is traced. +``log_file_path`` is the relative or absolute path to the log file to which log messages +should be written. If not specified, log messages will be written to stdout. + Caveats ~~~~~~~ @@ -56,6 +71,12 @@ plural text, so both are marked as used if the tag is used. Changes ~~~~~~~ +v1.5.3 --- 2017-11-28 +---------------------- + +Exposes debugging configuration settings to .coveragerc. Adds logging to startup. +Adds option to log to a file for easier issue analysis. + v1.5.2 --- 2017-10-18 ---------------------- diff --git a/django_coverage_plugin/__init__.py b/django_coverage_plugin/__init__.py index 5150b20..041bca1 100644 --- a/django_coverage_plugin/__init__.py +++ b/django_coverage_plugin/__init__.py @@ -8,4 +8,4 @@ def coverage_init(reg, options): - reg.add_file_tracer(DjangoTemplatePlugin()) + reg.add_file_tracer(DjangoTemplatePlugin(options)) diff --git a/django_coverage_plugin/plugin.py b/django_coverage_plugin/plugin.py index 661f4ac..ed3b49c 100644 --- a/django_coverage_plugin/plugin.py +++ b/django_coverage_plugin/plugin.py @@ -5,9 +5,12 @@ from __future__ import print_function +import datetime import os.path import re +import sys +import six from six.moves import range import coverage.plugin @@ -34,6 +37,65 @@ class DjangoTemplatePluginException(Exception): # For debugging the plugin itself. SHOW_PARSING = False SHOW_TRACING = False +SHOW_STARTUP = True +LOG_FILE = "testing_log_file.log" + + +def print_log(*args, **kwargs): + """ Print logging message, either appending to the LOG_FILE or to stdout.""" + log_file = None + try: + if LOG_FILE: + log_file = open(LOG_FILE, "a") + kwargs['file'] = log_file if log_file else sys.stdout + print(*args, **kwargs) + finally: + if log_file: + log_file.close() + + +def get_debug_option_value(curr_value, options, option_name): + """Common handling of debug options. + + - If the current value is truthy, then ignore the option value All + current values should default to falsy, so they will only be truthy + when someone is debugging the plugin code + - If the requested option name isn't in the options, then use the default + (aka current) value. + + :param curr_value Initial value of option + :param options Dictionary of options passed in from coverage.py + :param option_name Key name of option in 'options' dict + :returns option value + """ + if curr_value: + if option_name: + print_log("Ignoring options '%s', already set to %s" % (option_name, curr_value)) + return curr_value + + value = options.get(option_name, curr_value) + if isinstance(value, six.string_types): + v = value.lower() + if v in ("f", "false", "no", "n", 0): + value = False + elif v in ("t", "true", "yes", "y", 1): + value = True + return value + + +def handle_debugging_options(options): + """Set global debugging flags based on configuration options""" + global LOG_FILE, SHOW_PARSING, SHOW_TRACING, SHOW_STARTUP + print("handle_debugging_options: %r" % options) + LOG_FILE = get_debug_option_value(LOG_FILE, options, 'log_file_path') + SHOW_PARSING = get_debug_option_value(SHOW_PARSING, options, 'show_parsing') + SHOW_TRACING = get_debug_option_value(SHOW_TRACING, options, 'show_tracing') + SHOW_STARTUP = get_debug_option_value(SHOW_STARTUP, options, 'show_startup') + if SHOW_STARTUP: + print_log("--- django_coverage_plugin started at %s ---" % datetime.datetime.now()) + print_log("Python Version: %s" % (sys.version,)) + print_log("Django Version: %s" % (django.VERSION,)) + print_log("command args : %s" % (sys.argv,)) def check_debug(): @@ -48,29 +110,49 @@ def check_debug(): from django.conf import settings if not settings.configured: + if SHOW_STARTUP: + print_log("check_debug: settings not configured") return False # I _think_ this check is all that's needed and the 3 "hasattr" checks # below can be removed, but it's not clear how to verify that from django.apps import apps if not apps.ready: + if SHOW_STARTUP: + print_log("check_debug: apps not ready") return False # django.template.backends.django gets loaded lazily, so return false # until they've been loaded if not hasattr(django.template, "backends"): + if SHOW_STARTUP: + print_log("check_debug: django.template missing 'backends' attr") return False if not hasattr(django.template.backends, "django"): + if SHOW_STARTUP: + print_log( + "check_debug: django.template.backends missing 'django' attr" + ) return False if not hasattr(django.template.backends.django, "DjangoTemplates"): + if SHOW_STARTUP: + print_log( + "check_debug: django.template.backends missing 'DjangoTemplates' attr" + ) raise DjangoTemplatePluginException("Can't use non-Django templates.") for engine in django.template.engines.all(): if not isinstance(engine, django.template.backends.django.DjangoTemplates): + if SHOW_STARTUP: + print_log("check_debug: Non Django template engine: %s" % engine) raise DjangoTemplatePluginException( "Can't use non-Django templates." ) if not engine.engine.debug: + if SHOW_STARTUP: + print_log( + "check_debug: DjangoTemplates engine not DEBUG enabled" + ) raise DjangoTemplatePluginException( "Template debugging must be enabled in settings." ) @@ -116,6 +198,8 @@ def read_template_source(filename): from django.conf import settings if not settings.configured: + if SHOW_STARTUP: + print_log("read_template_source: settings not configured for filename '%s'" % filename) settings.configure() with open(filename, "rb") as f: @@ -129,7 +213,10 @@ class DjangoTemplatePlugin( coverage.plugin.FileTracer, ): - def __init__(self): + def __init__(self, options): + handle_debugging_options(options) + if SHOW_STARTUP: + print_log("DjangoTemplatePlugin.__init__") self.debug_checked = False self.django_template_dir = os.path.realpath( @@ -151,6 +238,8 @@ def sys_info(self): ] def file_tracer(self, filename): + if SHOW_STARTUP and not filename.endswith(".py"): + print_log("file_tracer: %s" % filename) if filename.startswith(self.django_template_dir): if not self.debug_checked: # Keep calling check_debug until it returns True, which it @@ -206,7 +295,7 @@ def line_number_range(self, frame): return -1, -1 if SHOW_TRACING: - print("{!r}: {}".format(render_self, position)) + print_log("{!r}: {}".format(render_self, position)) s_start, s_end = position if isinstance(render_self, TextNode): first_line = render_self.s.splitlines(True)[0] @@ -231,7 +320,7 @@ def line_number_range(self, frame): if start < 0 or end < 0: start, end = -1, -1 if SHOW_TRACING: - print("line_number_range({}) -> {}".format( + print_log("line_number_range({}) -> {}".format( filename, (start, end) )) return start, end @@ -254,7 +343,7 @@ def get_line_map(self, filename): template_source = read_template_source(filename) if 0: # change to see the template text for i in range(0, len(template_source), 10): - print("%3d: %r" % (i, template_source[i:i+10])) + print_log("%3d: %r" % (i, template_source[i:i+10])) self.source_map[filename] = make_line_map(template_source) return self.source_map[filename] @@ -275,7 +364,7 @@ def lines(self): source_lines = set() if SHOW_PARSING: - print("-------------- {}".format(self.filename)) + print_log("-------------- {}".format(self.filename)) if django.VERSION >= (1, 9): lexer = Lexer(self.source()) @@ -292,7 +381,7 @@ def lines(self): for token in tokens: if SHOW_PARSING: - print( + print_log( "%10s %2d: %r" % ( TOKEN_MAPPING[token.token_type], token.lineno, @@ -353,7 +442,7 @@ def lines(self): source_lines.update(range(lineno, lineno+num_lines)) if SHOW_PARSING: - print("\t\t\tNow source_lines is: {!r}".format(source_lines)) + print_log("\t\t\tNow source_lines is: {!r}".format(source_lines)) return source_lines @@ -380,7 +469,10 @@ def get_line_number(line_map, offset): def dump_frame(frame, label=""): - """Dump interesting information about this frame.""" + """ + Dump interesting information about this frame. + ** ONLY USED WHEN DEBUGGING ** + """ locals = dict(frame.f_locals) self = locals.get('self', None) context = locals.get('context', None) @@ -389,15 +481,15 @@ def dump_frame(frame, label=""): if label: label = " ( %s ) " % label - print("-- frame --%s---------------------" % label) - print("{}:{}:{}".format( + print_log("-- frame --%s---------------------" % label) + print_log("{}:{}:{}".format( os.path.basename(frame.f_code.co_filename), frame.f_lineno, type(self), )) - print(locals) + print_log(locals) if self: - print("self:", self.__dict__) + print_log("self:", self.__dict__) if context: - print("context:", context.__dict__) - print("\\--") + print_log("context:", context.__dict__) + print_log("\\--") diff --git a/setup.py b/setup.py index 983e2e6..63d7b36 100644 --- a/setup.py +++ b/setup.py @@ -22,7 +22,7 @@ setup( name='django_coverage_plugin', - version='1.5.2', + version='1.5.3', description='Django template coverage.py plugin', author='Ned Batchelder', author_email='ned@nedbatchelder.com', From 1b3258be26c856202cf342278a36964cb481c42e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pamela=20McA=E2=80=99Nulty?= Date: Mon, 27 Nov 2017 12:16:35 -0500 Subject: [PATCH 2/4] Pre review cleanups --- README.rst | 3 +++ django_coverage_plugin/plugin.py | 13 +++++++++---- 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/README.rst b/README.rst index 4f7cc6b..f7c6e26 100644 --- a/README.rst +++ b/README.rst @@ -55,8 +55,11 @@ It also has some optional configuration settings to enable certain debugging fla ``show_startup`` will log information during the startup sequence. This is especially useful when debugging settings configurations. + ``show_parsing`` will log information about how a template file is parsed. + ``show_tracing`` will log information about how template code is traced. + ``log_file_path`` is the relative or absolute path to the log file to which log messages should be written. If not specified, log messages will be written to stdout. diff --git a/django_coverage_plugin/plugin.py b/django_coverage_plugin/plugin.py index ed3b49c..ad3bf24 100644 --- a/django_coverage_plugin/plugin.py +++ b/django_coverage_plugin/plugin.py @@ -37,8 +37,8 @@ class DjangoTemplatePluginException(Exception): # For debugging the plugin itself. SHOW_PARSING = False SHOW_TRACING = False -SHOW_STARTUP = True -LOG_FILE = "testing_log_file.log" +SHOW_STARTUP = False +LOG_FILE = None def print_log(*args, **kwargs): @@ -70,10 +70,13 @@ def get_debug_option_value(curr_value, options, option_name): """ if curr_value: if option_name: - print_log("Ignoring options '%s', already set to %s" % (option_name, curr_value)) + print_log( + "Ignoring options '%s', already set to %s" % (option_name, curr_value) + ) return curr_value value = options.get(option_name, curr_value) + # Be permissive wrt boolean configuration values if isinstance(value, six.string_types): v = value.lower() if v in ("f", "false", "no", "n", 0): @@ -199,7 +202,9 @@ def read_template_source(filename): if not settings.configured: if SHOW_STARTUP: - print_log("read_template_source: settings not configured for filename '%s'" % filename) + print_log( + "read_template_source: settings not configured for filename '%s'" % filename + ) settings.configure() with open(filename, "rb") as f: From c85cbb27217b739afa64cf5043529d4f48045dbd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pamela=20McA=E2=80=99Nulty?= Date: Tue, 28 Nov 2017 09:14:36 -0500 Subject: [PATCH 3/4] Add some explanitory doc --- django_coverage_plugin/plugin.py | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/django_coverage_plugin/plugin.py b/django_coverage_plugin/plugin.py index ad3bf24..c17058e 100644 --- a/django_coverage_plugin/plugin.py +++ b/django_coverage_plugin/plugin.py @@ -108,6 +108,10 @@ def check_debug(): to do its work. Check that the setting is correct, and raise an exception if it is not. + It can take a fair amount of time before the Django settings are fully + configured, so check_debug() is called by file_tracer() until it + returns True. + Returns True if the debug check was performed, False otherwise """ from django.conf import settings @@ -137,6 +141,9 @@ def check_debug(): "check_debug: django.template.backends missing 'django' attr" ) return False + + # Now configurations have been loaded enough to check that the settings + # are valid if not hasattr(django.template.backends.django, "DjangoTemplates"): if SHOW_STARTUP: print_log( From e2de74656f88f0a319b77158df1560d89fa15283 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pamela=20McA=E2=80=99Nulty?= Date: Wed, 29 Nov 2017 12:15:30 -0500 Subject: [PATCH 4/4] Rename LOG_FILE -> LOG_FILE_PATH --- django_coverage_plugin/plugin.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/django_coverage_plugin/plugin.py b/django_coverage_plugin/plugin.py index c17058e..b584392 100644 --- a/django_coverage_plugin/plugin.py +++ b/django_coverage_plugin/plugin.py @@ -38,15 +38,15 @@ class DjangoTemplatePluginException(Exception): SHOW_PARSING = False SHOW_TRACING = False SHOW_STARTUP = False -LOG_FILE = None +LOG_FILE_PATH = None def print_log(*args, **kwargs): - """ Print logging message, either appending to the LOG_FILE or to stdout.""" + """ Print logging message, either appending to the LOG_FILE_PATH or to stdout.""" log_file = None try: - if LOG_FILE: - log_file = open(LOG_FILE, "a") + if LOG_FILE_PATH: + log_file = open(LOG_FILE_PATH, "a") kwargs['file'] = log_file if log_file else sys.stdout print(*args, **kwargs) finally: @@ -88,9 +88,9 @@ def get_debug_option_value(curr_value, options, option_name): def handle_debugging_options(options): """Set global debugging flags based on configuration options""" - global LOG_FILE, SHOW_PARSING, SHOW_TRACING, SHOW_STARTUP + global LOG_FILE_PATH, SHOW_PARSING, SHOW_TRACING, SHOW_STARTUP print("handle_debugging_options: %r" % options) - LOG_FILE = get_debug_option_value(LOG_FILE, options, 'log_file_path') + LOG_FILE_PATH = get_debug_option_value(LOG_FILE_PATH, options, 'log_file_path') SHOW_PARSING = get_debug_option_value(SHOW_PARSING, options, 'show_parsing') SHOW_TRACING = get_debug_option_value(SHOW_TRACING, options, 'show_tracing') SHOW_STARTUP = get_debug_option_value(SHOW_STARTUP, options, 'show_startup')