[PATCH] Add syslog logging support (#1153768)

Martin Kolman mkolman at redhat.com
Wed Oct 22 16:47:47 UTC 2014


Add an Initial Setup specific log handling module that
forwards nicely formated log messages to the system log
and also correctly maps message log levels to system log
priorities (in journalctl: info & debug - no highlight, warning - bold,
error & critical - red).

This finally makes it possible to report in detail what's going on during the Initial
Setup run, with emphasis on providing enough information on problematic areas,
such as Kickstart parsing.

BTW, to check for all Initial Setup log messages in Journal you can
use the -u flag with the Initial Setup unit name:

journalctl -u initial-setup-graphical

or

journalctl -u initial-setup-text

Resolves: rhbz#1153768
Signed-off-by: Martin Kolman <mkolman at redhat.com>
---
 initial_setup/__main__.py          | 49 ++++++++++++++++++++++++++++++++++---
 initial_setup/gui/spokes/eula.py   |  9 +++++++
 initial_setup/initial_setup_log.py | 50 ++++++++++++++++++++++++++++++++++++++
 initial_setup/product.py           |  5 +++-
 initial_setup/tui/spokes/eula.py   |  8 ++++++
 5 files changed, 116 insertions(+), 5 deletions(-)
 create mode 100644 initial_setup/initial_setup_log.py

diff --git a/initial_setup/__main__.py b/initial_setup/__main__.py
index 4b07386..f76a600 100644
--- a/initial_setup/__main__.py
+++ b/initial_setup/__main__.py
@@ -3,22 +3,37 @@ import os
 import sys
 import signal
 import pykickstart
+import logging
 from pyanaconda.users import Users
 from initial_setup.post_installclass import InstallClass
+from initial_setup import initial_setup_log
+from pyanaconda import iutil
+
+INPUT_KICKSTART_PATH = "/root/anaconda-ks.cfg"
+OUTPUT_KICKSTART_PATH = "/root/initial-setup-ks.cfg"
+
+# set root to "/", we are now in the installed system
+iutil.setSysroot("/")
 
 signal.signal(signal.SIGINT, signal.SIG_IGN)
 
+initial_setup_log.init()
+log = logging.getLogger("initial-setup")
+
 if "DISPLAY" in os.environ and os.environ["DISPLAY"]:
     mode="gui"
 else:
     mode="tui"
 
+log.debug("display mode detected: %s", mode)
+
 if mode == "gui":
     # We need this so we can tell GI to look for overrides objects
     # also in anaconda source directories
     import gi.overrides
     for p in os.environ.get("ANACONDA_WIDGETS_OVERRIDES", "").split(":"):
         gi.overrides.__path__.insert(0, p)
+    log.debug("GI overrides imported")
 
 # set the root path to / so the imported spokes
 # know where to apply their changes
@@ -36,18 +51,24 @@ addon_paths = ["/usr/share/initial-setup/modules", "/usr/share/anaconda/addons"]
 sys.path.extend(addon_paths)
 
 addon_module_paths = collect_addon_paths(addon_paths, mode)
+log.info("found %d addon modules:", len(addon_module_paths))
+for addon_path in addon_module_paths:
+    log.debug(addon_path)
 
 # Too bad anaconda does not have modularized logging
+log.debug("initializing the Anaconda log")
 from pyanaconda import anaconda_log
 anaconda_log.init()
 
 
 # init threading before Gtk can do anything and before we start using threads
 # initThreading initializes the threadMgr instance, import it afterwards
+log.debug("initializing threading")
 from pyanaconda.threads import initThreading
 initThreading()
 
 # initialize network logging (needed by the Network spoke that may be shown)
+log.debug("initializing network logging")
 from pyanaconda.network import setup_ifcfg_log
 setup_ifcfg_log()
 
@@ -71,18 +92,23 @@ commandMap = dict((k, kickstart.commandMap[k]) for k in kickstart_commands)
 # Prepare new data object
 data = kickstart.AnacondaKSHandler(addon_module_paths["ks"], commandUpdates=commandMap)
 
+log.info("parsing input kickstart %s", INPUT_KICKSTART_PATH)
 try:
     # Read the installed kickstart
     parser = kickstart.AnacondaKSParser(data)
-    parser.readKickstart("/root/anaconda-ks.cfg")
+    parser.readKickstart(INPUT_KICKSTART_PATH)
+    log.info("kickstart parsing done")
 except pykickstart.errors.KickstartError as kserr:
+    log.exception("kickstart parsing failed")
     sys.exit(1)
 
 if mode == "gui":
     try:
         # Try to import IS gui specifics
+        log.debug("trying to import GUI")
         import gui
     except ImportError:
+        log.error("GUI import failed, falling back to TUI")
         mode = "tui"
 
 if mode == "gui":
@@ -92,6 +118,7 @@ if mode == "gui":
     gui.InitialSetupGraphicalUserInterface.update_paths(addon_module_paths)
 
     # Initialize the UI
+    log.debug("initializing GUI")
     ui = gui.InitialSetupGraphicalUserInterface(None, None, InstallClass())
 else:
     # Import IS gui specifics
@@ -101,21 +128,26 @@ else:
     tui.InitialSetupTextUserInterface.update_paths(addon_module_paths)
 
     # Initialize the UI
+    log.debug("initializing TUI")
     ui = tui.InitialSetupTextUserInterface(None, None, None)
 
 # Pass the data object to user inteface
+log.debug("setting up the UI")
 ui.setup(data)
 
 # Start the application
+log.info("starting the UI")
 ret = ui.run()
 
 # TUI returns False if the app was ended prematurely
 # all other cases return True or None
 if ret == False:
     if data.eula.agreed:
+	log.info("EULA accepted, shuttong down")
         sys.exit(0)
     else:
         # EULA not agreed, reboot the system and leave Initial Setup enabled
+        log.info("EULA not accepted, leaving Initial Setup enabled and rebooting the system")
         os.system("reboot")
 
 # Do not execute sections that were part of the original
@@ -126,9 +158,13 @@ sections = [data.keyboard, data.lang, data.timezone]
 # data.selinux
 # data.firewall
 
+log.info("executing kickstart")
 for section in sections:
+    section_msg = "%s on line %d" % (repr(section), section.lineno)
     if section.seen:
+        log.debug("skipping %s", section_msg)
         continue
+    log.debug("executing %s", section_msg)
     section.execute(None, data, None)
 
 # Prepare the user database tools
@@ -136,14 +172,19 @@ u = Users()
 
 sections = [data.group, data.user, data.rootpw]
 for section in sections:
+    section_msg = "%s on line %d" % (repr(section), section.lineno)
     if section.seen:
+        log.debug("skipping %s", section_msg)
         continue
+    log.debug("executing %s", section_msg)
     section.execute(None, data, None, u)
 
 # Configure all addons
+log.info("executing addons")
 data.addons.execute(None, data, None, u)
 
-# Print the kickstart data to file
-with open("/root/initial-setup-ks.cfg", "w") as f:
+# Write the kickstart data to file
+log.info("writing the Initial Setup kickstart file %s", OUTPUT_KICKSTART_PATH)
+with open(OUTPUT_KICKSTART_PATH, "w") as f:
     f.write(str(data))
-
+log.info("finished writing the Initial Setup kickstart file")
diff --git a/initial_setup/gui/spokes/eula.py b/initial_setup/gui/spokes/eula.py
index ed3b521..27d348f 100644
--- a/initial_setup/gui/spokes/eula.py
+++ b/initial_setup/gui/spokes/eula.py
@@ -1,6 +1,7 @@
 """EULA spoke for the Initial Setup"""
 
 import gettext
+import logging
 
 from gi.repository import Pango
 from pyanaconda.ui.common import FirstbootOnlySpokeMixIn
@@ -10,6 +11,8 @@ from pyanaconda.constants import FIRSTBOOT_ENVIRON
 
 from initial_setup.product import get_license_file_name
 
+log = logging.getLogger("initial-setup")
+
 _ = lambda x: gettext.ldgettext("initial-setup", x)
 N_ = lambda x: x
 
@@ -29,6 +32,7 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalSpoke):
     translationDomain = "initial-setup"
 
     def initialize(self):
+        log.debug("initializing the EULA spoke")
         NormalSpoke.initialize(self)
 
         self._have_eula = True
@@ -37,8 +41,10 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalSpoke):
         self._agree_label = self._agree_check_button.get_child()
         self._agree_text = self._agree_label.get_text()
 
+        log.debug("looking for the license file")
         license_file = get_license_file_name()
         if not license_file:
+            log.error("no license found")
             self._have_eula = False
             self._eula_buffer.set_text(_("No license found. Please report this "
                                          "at http://bugzilla.redhat.com"))
@@ -46,6 +52,7 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalSpoke):
 
         self._eula_buffer.set_text("")
         itr = self._eula_buffer.get_iter_at_offset(0)
+        log.debug("opening the license file")
         with open(license_file, "r") as fobj:
             fobj_lines = fobj.xreadlines()
 
@@ -86,6 +93,8 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalSpoke):
 
     def on_check_button_toggled(self, checkbutton, *args):
         if self._agree_check_button.get_active():
+            log.debug("license is now accepted")
             self._agree_label.set_markup("<b>%s</b>" % self._agree_text)
         else:
+            log.debug("license no longer accepted")
             self._agree_label.set_markup(self._agree_text)
diff --git a/initial_setup/initial_setup_log.py b/initial_setup/initial_setup_log.py
new file mode 100644
index 0000000..fee1370
--- /dev/null
+++ b/initial_setup/initial_setup_log.py
@@ -0,0 +1,50 @@
+#
+# initial_setup_log.py: Support for logging to syslog during the
+#                       Initial Setup run
+#
+# Copyright (C) 2014  Red Hat, Inc.  All rights reserved.
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+# Author(s): Martin Kolman <mkolman at redhat.com>
+
+import logging
+from logging.handlers import SysLogHandler, SYSLOG_UDP_PORT
+
+class InitialSetupSyslogHandler(SysLogHandler):
+    """A SysLogHandler subclass that makes sure the Initial Setup
+    messages are easy to identify in the syslog/Journal
+    """
+    def __init__(self,
+                 address=('localhost', SYSLOG_UDP_PORT),
+                 facility=SysLogHandler.LOG_USER,
+                 tag=''):
+        self.tag = tag
+        SysLogHandler.__init__(self, address, facility)
+
+    def emit(self, record):
+        original_msg = record.msg
+        # this is needed to properly show the "initial-setup" prefix
+        # for log messages in syslog/Journal
+        record.msg = '%s: %s' % (self.tag, original_msg)
+        SysLogHandler.emit(self, record)
+        record.msg = original_msg
+
+def init():
+    """Initialize the Initial Setup logging system"""
+    log = logging.getLogger("initial-setup")
+    log.setLevel(logging.DEBUG)
+    syslogHandler = InitialSetupSyslogHandler('/dev/log', SysLogHandler.LOG_LOCAL1, "initial-setup")
+    syslogHandler.setLevel(logging.DEBUG)
+    log.addHandler(syslogHandler)
diff --git a/initial_setup/product.py b/initial_setup/product.py
index e1b38db..164d8b4 100644
--- a/initial_setup/product.py
+++ b/initial_setup/product.py
@@ -1,4 +1,5 @@
 """Module providing information about the installed product."""
+import logging
 
 from pyanaconda.localization import find_best_locale_match
 from pyanaconda.constants import DEFAULT_LANG
@@ -8,6 +9,8 @@ import glob
 RELEASE_STRING_FILE = "/etc/os-release"
 LICENSE_FILE_GLOB = "/usr/share/redhat-release*/EULA*"
 
+log = logging.getLogger("initial-setup")
+
 def product_title():
     """
     Get product title.
@@ -26,7 +29,7 @@ def product_title():
                 if key == "PRETTY_NAME":
                     return value.strip('"')
     except IOError:
-        pass
+        log.exception("failed to check the release string file")
 
     return ""
 
diff --git a/initial_setup/tui/spokes/eula.py b/initial_setup/tui/spokes/eula.py
index b819eae..bbc2bc1 100644
--- a/initial_setup/tui/spokes/eula.py
+++ b/initial_setup/tui/spokes/eula.py
@@ -2,6 +2,7 @@
 
 import gettext
 import codecs
+import logging
 
 from pyanaconda.ui.tui.spokes import NormalTUISpoke
 from pyanaconda.ui.tui.simpleline.widgets import TextWidget, CheckboxWidget
@@ -9,6 +10,8 @@ from pyanaconda.ui.tui.simpleline.base import UIScreen
 from pyanaconda.ui.common import FirstbootOnlySpokeMixIn
 from initial_setup.product import get_license_file_name
 
+log = logging.getLogger("initial-setup")
+
 _ = lambda x: gettext.ldgettext("initial-setup", x)
 N_ = lambda x: x
 
@@ -34,12 +37,14 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalTUISpoke):
         NormalTUISpoke.refresh(self, args)
 
         if self._have_eula:
+            log.debug("license found")
             # make the options aligned to the same column (the checkbox has the
             # '[ ]' prepended)
             self._window += [TextWidget("    1) %s" % _("Read the License Agreement")), ""]
             self._window += [CheckboxWidget(title="2) %s" % _("I accept the license agreement."),
                                             completed=self.data.eula.agreed), ""]
         else:
+            log.debug("license not found")
             self._window += [TextWidget(_("No license found. Please report this "
                                           "at http://bugzilla.redhat.com")), ""]
 
@@ -73,11 +78,13 @@ class EULAspoke(FirstbootOnlySpokeMixIn, NormalTUISpoke):
 
         if keyid == 1:
             # show license
+            log.debug("showing the license")
             eula_screen = LicenseScreen(self._app)
             self.app.switch_screen_with_return(eula_screen)
             return None
         elif keyid == 2:
             # toggle EULA agreed checkbox by changing ksdata
+            log.debug("license accepted state changed to: %s", self.data.eula.agreed)
             self.data.eula.agreed = not self.data.eula.agreed
             return None
 
@@ -101,6 +108,7 @@ class LicenseScreen(UIScreen):
         # read the license file and make it one long string so that it can be
         # processed by the TextWidget to fit in the screen in a best possible
         # way
+        log.debug("reading the license file")
         buf = u""
         with codecs.open(self._license_file, "r", "utf-8", "ignore") as fobj:
             for line in fobj:
-- 
1.9.3



More information about the anaconda-patches mailing list