[SeaBIOS] [RFC] Document and rework debug levels

[Kevin O'Connor]

On Wed, Apr 06, 2016 at 07:58:28PM +0200, Laszlo Ersek wrote:
> On 04/06/16 19:52, Kevin O'Connor wrote:
> > On Wed, Apr 06, 2016 at 07:38:49PM +0200, Laszlo Ersek wrote:
> >> On 04/06/16 19:07, Kevin O'Connor wrote:
> >>> There are a number of debug levels in the SeaBIOS code today.
> >>> Unfortunately, much of the code does not follow any particular
> >>> standard for which debug level to use.
> >>>
> >>> This is becoming cumbersome for a few reasons:
> >>>
> >>> - some people want fewer debug messages to reduce boot time, but still
> >>>   want critical messages (eg, error messages).  Debug level 1 can be
> >>>   too verbose while debug level 0 disables all messages.
> >>>
> >>> - some drivers become very verbose before other drivers, and thus
> >>>   depending on a user's hardware, the user might get flooded with
> >>>   messages they don't want before seeing the important messages from
> >>>   the driver they were looking for
> >>>
> >>> - when writing a new driver, it's not easy for a developer to know
> >>>   what debug level to choose
> >>>
> >>> I'm proposing that the debug levels be documented and that all of the
> >>> debug messages in SeaBIOS be reworked to follow that documentation.
> >>> Here are the debug levels I propose using:
> >>>
> >>> Level 1:
> >>>   - SeaBIOS version banner
> >>>   - Major error messages and major warning messages that are likely
> >>>     indicative of an error
> >>>   - Screen output (ie, printf) would also be available at this level
> >>>     when screen-and-debug is true
> >>> Level 2:
> >>>   - Critical memory layout information.  This would include the e820
> >>>     map prior to booting and similar information about UMB memory,
> >>>     EBDA memory, BIOS table locations, etc.
> >>> Level 3:
> >>>   - Found hardware for which there is a SeaBIOS driver and critical
> >>>     information about that hardware (such as its address, hardware
> >>>     version, hardware capabilities, etc.)
> >>> Level 4:
> >>>   - Major code flow events between SeaBIOS phases (eg, post, boot,
> >>>     resume phases)
> >>> Level 5:
> >>>   - Code flow notifications at driver and subsystem startup (eg, "init
> >>>     usb\n" type messages)
> >>>   - Thread startup and shutdown messages
> >>> Level 6:
> >>>   - Basic driver and subsystem debugging.  This would be driver
> >>>     specific messages that are not expected to be called with high
> >>>     frequency (ie, not called on every disk access nor on every
> >>>     keyboard access, etc.)
> >>>
> >>> Finally, for debug messages that could be called with high frequency
> >>> (eg, on each disk read), I propose defining a DEBUG_xyz at the top of
> >>> the particular driver source code file which would default to 9 and a
> >>> developer could change to a lower number when working on that code.
> >>> So, for example, DEBUG_xhci could be introduced and be used on
> >>> dprintf() messages that are invoked on each xhci transfer.
> >>>
> >>> As part of this proposal, the default debug level would change from
> >>> level 1 to level 4.  Most dprintf level 1 calls in the code would
> >>> change to a level between 1 and 4.  Most driver dprintf calls between
> >>> levels 3-8 would end up changing to level 6.  Most dprintf calls with
> >>> 9 (or higher) would instead get a DEBUG_xyz definition.
> >>>
> >>> Thoughts?
> >>
> >> Seems well-thought-out to me. Any chance you could introduce symbolic
> >> constants too for the debug levels?
> > 
> > It would be nice to do that.  However, I'm not sure if:
> > 
> >         dprintf(DEBUG_memory, "my message\n");
> > 
> > would become too cumbersome due to the length of the symbol names.
> 
> For one data point, it wouldn't bother me. (I'm used to this pattern --
> in edk2 the debug log level is a log mask actually. Occasionally a
> bitmask (of two bits) is constructed on the spot.)
> 
> On the other hand:
> 
> > Maybe adding wrappers (eg, debug_mem("my message") ) for the common
> > cases would avoid that problem.
> 
> would nicely imitate pr_*() from Linux's "include/linux/printk.h".

The printk.h code is interesting.  I'm now thinking it might be better
to introduce pr_err (for level 1 above), pr_notice (for levels 2-4
above), pr_info (for level 5), and pr_debug (for level 6).  The "debug
level" would then just be an internal detail.

It still has the issue of making sure debug levels are used
consistently across the code, but we could just use documentation for
that.

For the infrequent debug messages (existing levels 9+) we could
introduce macros like:

#define pr_debug_xhci(...) // pr_debug(__VA_ARGS__)

and a developer could alter the macro to uncomment the call to
pr_debug() when the additional info is desired.

Thanks,
-Kevin