Bug 524980 - audit and standardize anaconda logging
Summary: audit and standardize anaconda logging
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 14
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: Ales Kozumplik
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 518283 (view as bug list)
Depends On: 576439
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-09-22 21:10 UTC by Chris Lumens
Modified: 2014-09-30 23:38 UTC (History)
6 users (show)

Fixed In Version: anaconda-14.12
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-03-07 16:52:47 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Chris Lumens 2009-09-22 21:10:17 UTC
Right now, anaconda logging is a bit of a mess.  It's grown to include a lot of unnecessary debugging spew by default, is difficult to dig through programatically, and still doesn't really tell us all we need to know.  Tasks that fall under this bug include:

(1) Audit all existing log messages.  Does this message even need to exist?  Does it provide any value?  Is it printing at the proper logging level?  Change and remove things as appropriate.

(2) Log when we enter steps and when we leave steps.  Make sure we log all critical places in anaconda so this can be used as a checkpointing system.  So if there's no step for something important (like CD switching, or starting dependency checking for instance) make sure there's a log message at the same level as the step changing.

(3) Treat certain parts of the logging system as an API.  Standardize what the messages look like so programs can interpret the output.  Provide a promise that we won't change the format just like we do with kickstart.  Document this API on the wiki.

(4) Think about providing the logging output in some other form besides plain text, if that is at all useful.

It may be helpful to talk to QA and customers here to see what formats and information will be useful to them.  I know there are a lot of automated tools interpreting the anaconda logs right now in QA.

Comment 1 Chris Lumens 2009-09-23 14:44:11 UTC
*** Bug 518283 has been marked as a duplicate of this bug. ***

Comment 2 Bug Zapper 2009-11-16 12:46:36 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 12 development cycle.
Changing version to '12'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 3 Ales Kozumplik 2009-11-23 16:04:31 UTC
Some requirements came up when talking to Bill Peck over IRC:

1) have well defined stages that won't change from release to release
2) so we can know how far we have gotten..
3) maybe have a method to return a list of important log files. I would query this method at every stage change (since some log files are not present until a certain stage happens). 
4) allowing QE's custom modules to be registered as log listeners. currently script is run in background from %pre. it watches log files and uploads them via xmlrpc.

Comment 4 Ales Kozumplik 2009-11-23 16:14:23 UTC
Suggestions from clumens and jlaska over IRC:

1) the first thing we need to do in anaconda.log is get storage stuff out of there.
2) Make sure no "entering/exiting step" messages are missing from the log
3) Optionally suggest changing wording of messages so they are more easily parsable.
4) DEBUG logs around calls to external utilities (whenever execWith* is called) in anaconda.log (optionally)

Comment 5 Chris Lumens 2009-11-23 21:05:34 UTC
> 1) have well defined stages that won't change from release to release

We try to not introduce new stages (steps, in dispatch.py-speak) but we cannot offer a guarantee that they will not change over time.  The closest we can come is that we will try very hard to not change the number of steps in the lifetime of a major RHEL release.

> 2) so we can know how far we have gotten..

We don't know this, unfortunately.  The number of steps can and does change during install.  For instance, if you check the "review partitioning" checkbox, we add steps to show the partitioning UI and the bootloader UI.  These were originally in skipSteps, but get unskipped later.

> 3) maybe have a method to return a list of important log files. I would query
> this method at every stage change (since some log files are not present until a
> certain stage happens).

This information can be extracted from the python-meh Config object.  It's Config.fileList, and we set it way down at the bottom of exception.py.  You can't really get this information easily right now, but we can change that.

> 4) allowing QE's custom modules to be registered as log listeners. currently
> script is run in background from %pre. it watches log files and uploads them
> via xmlrpc.  

Ah, very interesting.  I wonder if we can hook this into the python logging framework somehow.  We already have a kickstart command for controlling logging.  Perhaps we can extend that to cover this requirement.

Comment 6 Martin Sivák 2009-12-04 12:16:51 UTC
We also discussed remote logging with Ales.

Standardizing the logging mechanism to something which is able to log to remote location (either all logs though python logger of all logs through syslog) would allow us to debug fixes easier.

Copying the log files from install environment is easy but mundane task. It will also solve the problems QA has with collecting relevant log files.

Comment 7 Ales Kozumplik 2009-12-18 15:52:55 UTC
clumens asked whether we can possibly get rid of LoggerClass so files like command-stubs/raidstart-stub don't have to import anaconda_log (the class exists for autoSetLevel which we may not even need).

Comment 8 Ales Kozumplik 2009-12-21 15:47:22 UTC
Also: remove LoggerClass and implement whatever is necessary to control loglevel= behavior (it controls the level of what gets displayed on tty{1,3})

Comment 9 Ales Kozumplik 2010-01-20 15:28:50 UTC
Also:

make rsyslog talk to virtioserial so we can get remote logging from a virtual machine BEFORE the network is up:
https://fedoraproject.org/wiki/Features/VirtioSerial

Contact: amit

Comment 10 Fedora Update System 2010-02-24 18:57:33 UTC
anaconda-13.31-1.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/anaconda-13.31-1.fc13

Comment 11 Fedora Update System 2010-02-25 12:45:34 UTC
anaconda-13.31-1.fc13 has been pushed to the Fedora 13 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update anaconda'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/F13/FEDORA-2010-2843

Comment 12 Ales Kozumplik 2010-02-26 07:00:20 UTC
I am still working on this. There's been many changes and standardization in the logging subsystem, but it's not finished yet.

Also see http://fedoraproject.org/wiki/Anaconda/Logging.

Comment 13 Radek Vykydal 2010-03-09 09:25:41 UTC
(In reply to comment #0)

 
> (1) Audit all existing log messages.  Does this message even need to exist? 
> Does it provide any value?  Is it printing at the proper logging level?  Change
> and remove things as appropriate.

Suggestion for another audit of existing code: ensure that all silently caught exceptions are logged.

Comment 14 Bug Zapper 2010-03-15 12:51:49 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 13 development cycle.
Changing version to '13'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 15 Ales Kozumplik 2010-03-17 09:23:37 UTC
Changing version to rawhide. Many patches including remote rsyslogd remote logging  and the same patch look across different files has been submitted for f13 already, but the projects is still going on.

Please also see:
http://fedoraproject.org/wiki/Anaconda/Logging

Comment 16 Ales Kozumplik 2010-07-14 13:39:08 UTC
After bug 576439 is fixed (patch currently under review on the devel list), I am going to consider the work on this BZ finished unless some objections come up.

Comment 17 Ales Kozumplik 2010-07-20 07:37:45 UTC
virtio logging functionality for bug 576439 has been submitted. closing as promised. 

For the current specification and the state of the logging subsystem, along with logging tips and guides see the wiki page:
http://fedoraproject.org/wiki/Anaconda/Logging

Comment 18 Bug Zapper 2010-07-30 10:44:24 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 14 development cycle.
Changing version to '14'.

More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping


Note You need to log in before you can comment on or make changes to this bug.