[LNT] r255958 - Fix LNT's logging, add /log endpoint to view logs from web

Chris Matthews via llvm-commits llvm-commits at lists.llvm.org
Thu Dec 17 17:37:53 PST 2015


Author: cmatthews
Date: Thu Dec 17 19:37:53 2015
New Revision: 255958

URL: http://llvm.org/viewvc/llvm-project?rev=255958&view=rev
Log:
Fix LNT's logging, add /log endpoint to view logs from web

LNT's logging support has always been horrible.  This makes debugging server problems hard.  This patch tries to get all the parts of logging in LNT working together better. First replace the stderr loggers in commands with python logging package.  Replace all uses of the python logging package with a single logger, so all messages from LNT will be in one log.  Add a in memory logging buffer, and allow the user to see that through the /log page. Make sure the rotating file logging is used as well.

Later patches will add support for subprocesses.

Added:
    lnt/trunk/lnt/server/ui/templates/log.html
Modified:
    lnt/trunk/lnt/lnttool/main.py
    lnt/trunk/lnt/server/db/rules/rule_update_fixed_regressions.py
    lnt/trunk/lnt/server/ui/app.py
    lnt/trunk/lnt/server/ui/views.py
    lnt/trunk/lnt/testing/util/commands.py

Modified: lnt/trunk/lnt/lnttool/main.py
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/lnttool/main.py?rev=255958&r1=255957&r2=255958&view=diff
==============================================================================
--- lnt/trunk/lnt/lnttool/main.py (original)
+++ lnt/trunk/lnt/lnttool/main.py Thu Dec 17 19:37:53 2015
@@ -65,10 +65,12 @@ view the results.\
     input_path, = args
 
     # Setup the base LNT logger.
-    logger = logging.getLogger("lnt")
+    # Root logger in debug.
+    logger = logging.getLogger("LNT")
     if opts.debugger:
         logger.setLevel(logging.DEBUG)
-    handler = logging.StreamHandler(sys.stderr)
+    handler = logging.StreamHandler()
+    handler.setLevel(logging.DEBUG)
     handler.setFormatter(logging.Formatter(
             '%(asctime)s %(levelname)s: %(message)s',
             datefmt='%Y-%m-%d %H:%M:%S'))
@@ -79,7 +81,7 @@ view the results.\
         sa_logger = logging.getLogger("sqlalchemy")
         if opts.debugger:
             sa_logger.setLevel(logging.DEBUG)
-        sa_logger.setLevel(logging.DEBUG)
+        sa_logger.setLevel(logging.INFO)
         sa_logger.addHandler(handler)
 
     import lnt.server.ui.app
@@ -158,6 +160,14 @@ def action_runtest(name, args):
             warning("--{} should be passed directly to the"
                         " test suite.".format(key))
 
+    logger = logging.getLogger("LNT")
+    logger.setLevel(logging.DEBUG)
+    handler = logging.StreamHandler()
+    handler.setLevel(logging.DEBUG)
+    handler.setFormatter(logging.Formatter(
+            '%(asctime)s %(levelname)s: %(message)s',
+            datefmt='%Y-%m-%d %H:%M:%S'))
+    logger.addHandler(handler)
     import lnt.tests
     try:
         test_instance = lnt.tests.get_test_instance(test_name)

Modified: lnt/trunk/lnt/server/db/rules/rule_update_fixed_regressions.py
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/server/db/rules/rule_update_fixed_regressions.py?rev=255958&r1=255957&r2=255958&view=diff
==============================================================================
--- lnt/trunk/lnt/server/db/rules/rule_update_fixed_regressions.py (original)
+++ lnt/trunk/lnt/server/db/rules/rule_update_fixed_regressions.py Thu Dec 17 19:37:53 2015
@@ -35,6 +35,7 @@ def regression_evolution(ts, regressions
     Look at regressions in detect, do they match our policy? If no, move to NTBF.
 
     """
+    note("Running regression evolution")
     detects = [r for r in regressions if r.state == RegressionState.DETECTED]
     
     for regression in detects:

Modified: lnt/trunk/lnt/server/ui/app.py
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/server/ui/app.py?rev=255958&r1=255957&r2=255958&view=diff
==============================================================================
--- lnt/trunk/lnt/server/ui/app.py (original)
+++ lnt/trunk/lnt/server/ui/app.py Thu Dec 17 19:37:53 2015
@@ -5,6 +5,7 @@ import logging.handlers
 from logging import Formatter
 import os
 import time
+import StringIO
 
 import flask
 from flask import current_app
@@ -64,7 +65,6 @@ class Request(flask.Request):
             #
             # FIXME: Conditionalize on an is_production variable.
             if echo:
-                import logging, StringIO
                 g.db_log = StringIO.StringIO()
                 logger = logging.getLogger("sqlalchemy")
                 logger.addHandler(logging.StreamHandler(g.db_log))
@@ -137,7 +137,10 @@ class App(flask.Flask):
         # Inject a fix for missing slashes on the root URL (see Flask issue
         # #169).
         self.wsgi_app = RootSlashPatchMiddleware(self.wsgi_app)
-
+        
+        self.lnt_logger = logging.getLogger('LNT')
+        self.lnt_logger.setLevel(logging.DEBUG)
+        
     def load_config(self, instance):
         self.instance = instance
         self.old_config = self.instance.config
@@ -154,9 +157,21 @@ class App(flask.Flask):
         to stderr, so just log to a file as well.
 
         """
+        # Print to screen.
+        ch = logging.StreamHandler()
+        ch.setLevel(logging.DEBUG)
+        self.lnt_logger.addHandler(ch)
+        
+        # Log to mem for the /log view.
+        h = logging.handlers.MemoryHandler(1024 * 1024)
+        h.setLevel(logging.DEBUG)
+        self.lnt_logger.addHandler(h)
+        self.logger.addHandler(h)
+        self.old_config.mem_logger = h
+        
         if not self.debug:
             LOG_FILENAME = "lnt.log"
-            try:
+            try:    
                 rotating = logging.handlers.RotatingFileHandler(
                     LOG_FILENAME, maxBytes=1048576, backupCount=5)
                 rotating.setFormatter(Formatter(
@@ -164,7 +179,7 @@ class App(flask.Flask):
                     '[in %(pathname)s:%(lineno)d]'
                 ))
                 rotating.setLevel(logging.DEBUG)
-                self.logger.addHandler(rotating)
+                self.lnt_logger.addHandler(rotating)                
             except (OSError, IOError) as e:
                 print >> sys.stderr, "Error making log file", LOG_FILENAME, str(e)
                 print >> sys.stderr, "Will not log to file."

Added: lnt/trunk/lnt/server/ui/templates/log.html
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/server/ui/templates/log.html?rev=255958&view=auto
==============================================================================
--- lnt/trunk/lnt/server/ui/templates/log.html (added)
+++ lnt/trunk/lnt/server/ui/templates/log.html Thu Dec 17 19:37:53 2015
@@ -0,0 +1,35 @@
+{% import "utils.html" as utils %}
+
+{% extends "layout.html" %}
+{% set components = [] %}
+
+{% block title %}Log{%endblock%}
+
+{% block body %}
+
+<table class="table table-striped table-hover table-condensed">
+  <thead>
+    <tr>
+      <th>Kind</th>
+      <th>Location</th>
+      <th>Time</th>
+      <th>Message<th>
+    </tr>
+  </thead>
+  <tbody class="searchable">
+{% for item in old_config.mem_logger.buffer %}
+    {% if item.levelname|string() == 'WARNING' %}
+    <tr class="warning">
+    {% elif item.levelname|string() == 'ERROR' %}
+    <tr class="error">
+    {% else %}
+    <tr class="info">
+    {% endif %}
+      <td>{{ item.levelname}}</td>
+      <td>{{item.filename}}:{{item.lineno}}</td>
+      <td>{{ item.asctime}}</td>
+      <td>{{ item.msg }}</td>
+    </tr>
+{% endfor %}
+
+{% endblock %}

Modified: lnt/trunk/lnt/server/ui/views.py
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/server/ui/views.py?rev=255958&r1=255957&r2=255958&view=diff
==============================================================================
--- lnt/trunk/lnt/server/ui/views.py (original)
+++ lnt/trunk/lnt/server/ui/views.py Thu Dec 17 19:37:53 2015
@@ -1169,3 +1169,7 @@ def rules():
     lnt.server.db.rules.register_hooks()
     discovered_rules = lnt.server.db.rules.DESCRIPTIONS
     return render_template("rules.html",rules=discovered_rules)
+
+ at frontend.route('/log')
+def log():
+    return render_template("log.html")

Modified: lnt/trunk/lnt/testing/util/commands.py
URL: http://llvm.org/viewvc/llvm-project/lnt/trunk/lnt/testing/util/commands.py?rev=255958&r1=255957&r2=255958&view=diff
==============================================================================
--- lnt/trunk/lnt/testing/util/commands.py (original)
+++ lnt/trunk/lnt/testing/util/commands.py Thu Dec 17 19:37:53 2015
@@ -6,23 +6,18 @@ import errno
 import inspect
 import os
 import sys
-
+import logging
 # FIXME: Find a better place for this code.
 
-def _write_message(kind, message):
-    # Get the file/line where this message was generated.
-    f = inspect.currentframe()
-    # Step out of _write_message, and then out of wrapper.
-    f = f.f_back.f_back
-    file,line,_,_,_ = inspect.getframeinfo(f)
-    location = '%s:%d' % (os.path.basename(file), line)
+note = lambda message: logging.getLogger('LNT').info(message)
+warning = lambda message: logging.getLogger('LNT').warning(message)
+error = lambda message: logging.getLogger('LNT').error(message)
+
 
-    print >>sys.stderr, '%s: %s: %s' % (location, kind, message)
+def fatal(message):
+    logging.getLogger('LNT').critical(message)
+    sys.exit(1)
 
-note = lambda message: _write_message('note', message)
-warning = lambda message: _write_message('warning', message)
-error = lambda message: _write_message('error', message)
-fatal = lambda message: (_write_message('fatal error', message), sys.exit(1))
 
 def rm_f(path):
     try:




More information about the llvm-commits mailing list