BootMessageLogging

Differences between revisions 3 and 4
Revision 3 as of 2006-06-20 15:46:54
Size: 5582
Editor: ALagny-109-1-9-37
Comment: spam spec
Revision 4 as of 2006-06-21 13:58:31
Size: 7498
Editor: ALagny-109-1-10-249
Comment: expand to non-informational
Deletions are marked like this. Additions are marked like this.
Line 6: Line 6:
 * '''Packages affected''':  * '''Packages affected''': `sysvinit`, `usplash`, `lsb-base`
Line 10: Line 10:
This specification defines what messages will be available during boot, which will be logged and which will be shown by default. This specification discusses what messages will be output on boot, which are available to other processes such as `usplash` and what is logged to `/var/log/boot`; including the mode of dispatch and translation of those messages.
Line 14: Line 14:
Currently much of the information about what goes on during the boot process is lost because there is no writable filesystem to dump it to, and too much information is normally displayed to the screen preventing problems from being found. The messages output during the boot process often carry useful information, yet scroll past too quickly to be read by all but the fastest eyes. Additionally much could be output that is not, such as status messages or detailed error messages, because there is no writable filesystem at that point in the boot process.
Line 16: Line 16:
The log of what happens during boot is useful to both developers and systems administrators debugging problems with the system. Such messages are useful to developers and system administrators for debugging problems but are not so useful, and indeed can often scare off, novice users.
Line 30: Line 30:
 * Jorge is a Spanish user who does not speak English, he is unable to read the messages that scroll past as they are not translated.
Line 31: Line 33:

This specification describes the different levels and methods of boot message logging that should be made available, however it does not specify the implementation as that will likely be handled by the ReplacementInit specification.
Line 36: Line 36:
The following levels of message output are defined, each includes all of the previous things if appropriate. To allow for differing requirements of the number and style of messages displayed and logged during the boot process, the following levels of output are defined. Each includes all of the messages from the previous log levels, unless otherwise stated.
Line 99: Line 99:
 * Service starting and service failed messages on their own lines.
Line 101: Line 103:
 * Early capture of `syslog()` calls by reading from `/dev/log` until `syslogd` is able to take over.  * Early capture of `syslog` calls by reading from `/dev/log` until `syslogd` is able to take over.
Line 105: Line 107:
While the actual implementation is largely dependant on the init system selected for `edgy`, it is possible to define the following: The precise implementation of how messages are obtained from the init scripts is largely dependant on the outcome of the ReplacementInit discussion, however it is likely that at least the following will be true:
Line 107: Line 109:
 * Scripts should output liberally to standard output and standard error without concerning themselves with policy such as the current `"$VERBOSE"` variable.  * Standard output and standard error will be redirected to the logging process.
Line 109: Line 111:
 * Messages of particular importance would be logged using functions either similar to, or just using the LSB init functions.  * An additional channel, or known file descriptor, will be available for logging failure messages and critical errors.
Line 111: Line 113:
 * Standard output and error of init scripts would be redirected and not sent to `/dev/console`.  * These messages will be sent from the init scripts using functions either similar to, or just using the LSB init functions.

 * Service descriptions (and thus the start/stop messages) will be handled from the init system, not the init scripts themselves. This allows for much easier translations, directly obtained from description of the script rather than having to parse the script manually.

 * The output messages will be translated using `gettext`.
Line 115: Line 121:
 * A process (see Code, below) would need to read the kernel messages, syslog messages and messages from the init scripts.  * Existing scripts would always be run with `VERBOSE=yes` to get the full messages.

=== Script changes ===

The initial necessary script changes are minimal, if not zero, as any messages the scripts print today would be shown only in the verbose mode. The only additions would be to ensure scripts exit with a failure code to indicate failure (largely handled by LSB init functions) and supply a useful reason for the failure where appropriate; these things can be added on an individual basis as time permits.

The only scripts that will need to be changed are those that can cause a critical failure of, or delay to, the boot process such as filesystem checking and mounting. The following is noted:
Line 119: Line 131:
 * The init system would output messages for services being started and stopped.  * failure of `fsck` should log a critical message to ensure that it is displayed.

 * failure of `mount` should do likewise.
Line 123: Line 137:
Line-terminated messages from various sources will need to be read and stored in memory until a writable filesystem is available, at which point they will be written to `/var/log/boot` and subsequently appeneded to that file. A tiny logging daemon needs to be implemented to co-ordinate the messages being logged and displayed.
Line 125: Line 139:
Messages should be timestamped and the origin noted.  * It receives line-terminated messages on a number of file descriptors, the source and timestamp for these is noted and the message translated.

 * If `/var/log/boot` is open for writing, the message is appended to the file. If the file cannot be opened, the message is appended to an in-memory buffer. If the file was successfully opened, the in-memory buffer is flushed to the file, and the message appended.

 * A list of named executables are run and passed the message formatted as required, provided the message is appropriate for the level of logging desired.

 * The message is printed to `/dev/console` if appropriate.

The named executables would include `usplash_write` and for the SpokenBoot specification, `spd-say`.

Summary

This specification discusses what messages will be output on boot, which are available to other processes such as usplash and what is logged to /var/log/boot; including the mode of dispatch and translation of those messages.

Rationale

The messages output during the boot process often carry useful information, yet scroll past too quickly to be read by all but the fastest eyes. Additionally much could be output that is not, such as status messages or detailed error messages, because there is no writable filesystem at that point in the boot process.

Such messages are useful to developers and system administrators for debugging problems but are not so useful, and indeed can often scare off, novice users.

Use cases

  • Benson is user who is not tech-savvy and is currently confused by the large number of messages during the boot sequence. He would be comforted by no messages and a simple indication that the machine has not hung.
  • Karl is a systems administrator who would like to be able to watch servers boot and see which services are starting and which have failed to start.
  • Duncan is a consultant who has been called in to determine why a client's server is not running correctly, the problem happens at boot and there are no useful log files for him to read.
  • Dale is an Ubuntu developer and bug contact for a package that is failing at boot-time, he would like be able to ask for a verbose log file of the boot to quickly pin-point the problem.
  • Greg is a member of the Ubuntu QA team who triages incoming bug reports before giving them to developers, a single verbose log file of the boot would be a great aid towards determining the cause of the problem.
  • Jorge is a Spanish user who does not speak English, he is unable to read the messages that scroll past as they are not translated.

Scope

Design

To allow for differing requirements of the number and style of messages displayed and logged during the boot process, the following levels of output are defined. Each includes all of the messages from the previous log levels, unless otherwise stated.

Quiet

This is the level of information that will be passed to usplash by default, and sent to /dev/console when usplash is normally running.

  • Critical messages only. Any message printed explains why the boot process is being delayed or stopped immediately after the message.
  • Progress of fsck is displayed.
  • Boot activity is shown, either as a progress bar or throbber if appropriate. Whichever is displayed will be driven by activity from the init system, rather than idle time, so inactivity can be spotted.
    Loading kernel.....
    
    
    Ubuntu edgy (development branch) ubuntu tty1
    
    ubuntu login:

Failures

This is the level of information that will be sent to /dev/console on servers where usplash is not normally running.

  • The names of services or scripts that failed during boot are printed, with a short error message if a useful one can be obtained.
    Loading kernel...
    
    apache2 failed: unable to bind to 192.168.1.1
    
    
    Ubuntu edgy (development branch) ubuntu tty
    
    ubuntu login:

Services

  • "Service starting" messages will be shown on a single line, overwriting any previous starting message on that line.
  • "Service failed" messages will be shown and the cursor moved down to the next line for future messages.

(example during boot, once boot has complete it looks the same as the Failures mode)

  • Loading kernel...
    
    apache2 failed: unable to bind to 192.168.1.1
    Starting postgresql...

Verbose

This is the level of information that will be placed in /var/log/boot.

  • Kernel messages.
  • Names and arguments of scripts being run.
  • Commands run within each script (sh -x), perhaps optional.

  • Service starting and service failed messages on their own lines.
  • Output of every service and script run.
  • Early capture of syslog calls by reading from /dev/log until syslogd is able to take over.

Implementation

The precise implementation of how messages are obtained from the init scripts is largely dependant on the outcome of the ReplacementInit discussion, however it is likely that at least the following will be true:

  • Standard output and standard error will be redirected to the logging process.
  • An additional channel, or known file descriptor, will be available for logging failure messages and critical errors.
  • These messages will be sent from the init scripts using functions either similar to, or just using the LSB init functions.
  • Service descriptions (and thus the start/stop messages) will be handled from the init system, not the init scripts themselves. This allows for much easier translations, directly obtained from description of the script rather than having to parse the script manually.
  • The output messages will be translated using gettext.

  • Kernel messages would not be sent to /dev/console.

  • Existing scripts would always be run with VERBOSE=yes to get the full messages.

Script changes

The initial necessary script changes are minimal, if not zero, as any messages the scripts print today would be shown only in the verbose mode. The only additions would be to ensure scripts exit with a failure code to indicate failure (largely handled by LSB init functions) and supply a useful reason for the failure where appropriate; these things can be added on an individual basis as time permits.

The only scripts that will need to be changed are those that can cause a critical failure of, or delay to, the boot process such as filesystem checking and mounting. The following is noted:

  • fsck should be run such that it's progress output is captured and sent to usplash

  • failure of fsck should log a critical message to ensure that it is displayed.

  • failure of mount should do likewise.

Code

A tiny logging daemon needs to be implemented to co-ordinate the messages being logged and displayed.

  • It receives line-terminated messages on a number of file descriptors, the source and timestamp for these is noted and the message translated.
  • If /var/log/boot is open for writing, the message is appended to the file. If the file cannot be opened, the message is appended to an in-memory buffer. If the file was successfully opened, the in-memory buffer is flushed to the file, and the message appended.

  • A list of named executables are run and passed the message formatted as required, provided the message is appropriate for the level of logging desired.
  • The message is printed to /dev/console if appropriate.

The named executables would include usplash_write and for the SpokenBoot specification, spd-say.

For future expansion, this program could also write the messages to a designated network socket (on the kernel command-line, causing the network card to be configured in initramfs) providing piece-of-mind during remote reboots.


CategorySpec

BootMessageLogging (last edited 2008-08-06 16:30:31 by localhost)