SysLog

Standard SysLog Interfaces

The NuttX SYSLOG is an architecture for getting debug and status information from the system. The syslogging interfaces are defined in the header file include/syslog.h.

The primary interface to SYSLOG sub-system is the function syslog() and, to a lesser extent, its companion vsyslog():

/****************************************************************************
 * Name: syslog and vsyslog
 *
 * Description:
 *   syslog() generates a log message. The priority argument is formed by
 *   ORing the facility and the level values (see include/syslog.h). The
 *   remaining arguments are a format, as in printf and any arguments to the
 *   format.
 *
 *   The NuttX implementation does not support any special formatting
 *   characters beyond those supported by printf.
 *
 *   The function vsyslog() performs the same task as syslog() with the
 *   difference that it takes a set of arguments which have been obtained
 *   using the stdarg variable argument list macros.
 *
 ****************************************************************************/

int syslog(int priority, FAR const IPTR char *format, ...);
int vsyslog(int priority, FAR const IPTR char *src, va_list ap);

The additional setlogmask() interface can use use to filter SYSLOG output:

/****************************************************************************
 * Name: setlogmask
 *
 * Description:
 *   The setlogmask() function sets the logmask and returns the previous
 *   mask. If the mask argument is 0, the current logmask is not modified.
 *
 *   The SYSLOG priorities are: LOG_EMERG, LOG_ALERT, LOG_CRIT, LOG_ERR,
 *   LOG_WARNING, LOG_NOTICE, LOG_INFO, and LOG_DEBUG.  The bit corresponding
 *   to a priority p is LOG_MASK(p); LOG_UPTO(p) provides the mask of all
 *   priorities in the above list up to and including p.
 *
 *   Per OpenGroup.org "If the maskpri argument is 0, the current log mask
 *   is not modified."  In this implementation, the value zero is permitted
 *   in order to disable all syslog levels.
 *
 *   REVISIT: Per POSIX the syslog mask should be a per-process value but in
 *   NuttX, the scope of the mask is dependent on the nature of the build:
 *
 *   Flat Build:  There is one, global SYSLOG mask that controls all output.
 *   Protected Build:  There are two SYSLOG masks.  One within the kernel
 *     that controls only kernel output.  And one in user-space that controls
 *     only user SYSLOG output.
 *   Kernel Build:  The kernel build is compliant with the POSIX requirement:
 *     There will be one mask for for each user process, controlling the
 *     SYSLOG output only form that process.  There will be a separate mask
 *     accessable only in the kernel code to control kernel SYSLOG output.
 *
 ****************************************************************************/

int setlogmask(int mask);

These are all standard interfaces as defined at https://www.OpenGroup.org.

Debug Interfaces

In NuttX syslog output is really synonymous to debug output and, therefore, the debugging interface macros defined in the header file include/debug.h are also syslogging interfaces. Those macros are simply wrappers around syslog().

Note

Debug here means “system log” rather than on-chip-debug.

The debugging interfaces differ from the syslog interfaces in that:

They do not take a priority parameter; the priority is inherent in the debug macro name.
They decorate the output stream with information such as the file name.
They can each be disabled via configuration options.

Each debug macro has a base name that represents the priority and a prefix that represents the sub-system. Each macro is individually initialized by both priority and sub-system. For example, uerr() is the macro used for error level messages from the USB subsystem and is enabled with CONFIG_DEBUG_USB_ERROR.

The base debug macro names, their priority, and configuration variable are summarized below:

info(): The info() macro is the lowest priority (LOG_INFO) and is intended to provide general information about the flow of program execution so that you can get an overview of the behavior of the program. info() is often very chatty and voluminous and usually more information than you may want to see. The info() macro is controlled via CONFIG_DEBUG+subsystem+INFO.
warn(): The warn() macro has medium priority (LOG_WARN) and is controlled by CONFIG_DEBUG+subsystem+WARN. The warn() is intended to note exceptional or unexpected conditions that might be potential errors or, perhaps, minor errors that easily recovered.
err(): This is a high priority debug macro (LOG_ERROR) and controlled by CONFIG_DEBUG+subsystem+ERROR. The err() is reserved to indicate important error conditions.
alert(): The highest priority debug macro (LOG_EMERG) and is controlled by CONFIG_DEBUG_ALERT. The alert() macro is reserved for use solely by assertion and crash handling logic. It also differs from the other macros in that it is global and cannot be enabled or disabled per subsystem.

SYSLOG Channels

SYSLOG Channel Interfaces

In the NuttX SYSLOG implementation, the underlying device logic the supports the SYSLOG output is referred to as a SYSLOG channel. Each SYSLOG channel is represented by an interface defined in include/nuttx/syslog/syslog.h:

/* This structure provides the interface to a SYSLOG device */

typedef CODE int (*syslog_putc_t)(int ch);
typedef CODE int (*syslog_flush_t)(void);

struct syslog_channel_s
{
  /* I/O redirection methods */

  syslog_putc_t sc_putc;    /* Normal buffered output */
  syslog_putc_t sc_force;   /* Low-level output for interrupt handlers */
  syslog_flush_t sc_flush;  /* Flush buffered output (on crash) */

  /* Implementation specific logic may follow */
};

The channel interface is instantiated by calling syslog_channel():

/****************************************************************************
* Name: syslog_channel
*
* Description:
* Configure the SYSLOGging function to use the provided channel to
* generate SYSLOG output.
*
* Input Parameters:
* channel - Provides the interface to the channel to be used.
*
* Returned Value:
* Zero (OK)is returned on success. A negated errno value is returned
* on any failure.
*
****************************************************************************/

int syslog_channel(FAR const struct syslog_channel_s *channel);

syslog_channel() is a non-standard, internal OS interface and is not available to applications. It may be called numerous times as necessary to change channel interfaces. By default, all system log output goes to console (/dev/console).

SYSLOG Channel Initialization

The initial, default SYSLOG channel is established with statically initialized global variables so that some level of SYSLOG output may be available immediately upon reset. This initialized data is in the file drivers/syslog/syslog_channel.c.

The initial SYSLOG capability is determined by the selected SYSLOG channel:

In-Memory Buffer (RAMLOG). Full SYSLOG capability as available at reset.
Serial Console: If the serial implementation provides the low-level character output function up_putc(), then that low level serial output is available as soon as the serial device has been configured.
For all other SYSLOG channels, all SYSLOG output goes to the bit-bucket (discarded) until the SYSLOG channel device has been initialized.

The syslog channel device is initialized when the bring-up logic calls syslog_intialize():

/****************************************************************************
 * Name: syslog_initialize
 *
 * Description:
 *   One power up, the SYSLOG facility is non-existent or limited to very
 *   low-level output.  This function is called later in the initialization
 *   sequence after full driver support has been initialized.  It installs
 *   the configured SYSLOG drivers and enables full SYSLOGing capability.
 *
 *   This function performs these basic operations:
 *
 *   - Initialize the SYSLOG device
 *   - Call syslog_channel() to begin using that device.
 *
 *   If CONFIG_ARCH_SYSLOG is selected, then the architecture-specific
 *   logic will provide its own SYSLOG device initialize which must include
 *   as a minimum a call to syslog_channel() to use the device.
 *
 * Input Parameters:
 *   phase - One of {SYSLOG_INIT_EARLY, SYSLOG_INIT_LATE}
 *
 * Returned Value:
 *   Zero (OK) is returned on success; a negated errno value is returned on
 *   any failure.
 *
 ****************************************************************************/

#ifndef CONFIG_ARCH_SYSLOG
int syslog_initialize(enum syslog_init_e phase);
#else
#  define syslog_initialize(phase)
#endif

Different types of SYSLOG devices have different OS initialization requirements. Some are available immediately at reset, some are available after some basic OS initialization, and some only after OS is fully initialized. In order to satisfy these different initialization requirements, syslog_initialize() is called twice from the boot-up logic:

syslog_initialize() is called from the architecture-specific up_initialize() function as some as basic hardware resources have been initialized: Timers, interrupts, etc. In this case, syslog_initialize() is called with the argument SYSLOG_INIT_EARLY.
syslog_initialize() is called again from nx_start() when the full OS initialization has completed, just before the application main entry point is spawned. In this case, syslog_initialize() is called with the argument SYSLOG_INIT_LATE.

There are other types of SYSLOG channel devices that may require even further initialization. For example, the file SYSLOG channel (described below) cannot be initialized until the necessary file systems have been mounted.

Interrupt Level SYSLOG Output

As a general statement, SYSLOG output only supports normal output from NuttX tasks. However, for debugging purposes, it is also useful to get SYSLOG output from interrupt level logic. In an embedded system, that is often where the most critical operations are performed.

There are three conditions under which SYSLOG output generated from interrupt level processing can a included the SYSLOG output stream:

Low-Level Serial Output.
In-Memory Buffering.
Serialization Buffer.

The SYSLOG interrupt buffer is enabled with CONFIG_SYSLOG_INTBUFFER. When the interrupt buffer is enabled, you must also provide the size of the interrupt buffer with CONFIG_SYSLOG_INTBUFSIZE.

Low-Level Serial Output

If you are using a SYSLOG console channel (CONFIG_SYSLOG_CONSOLE) with a serial console (CONFIG_SYSLOG_SERIAL_CONSOLE) and if the underlying architecture supports the low-level up_putc() interface (CONFIG_ARCH_LOWPUTC), then the SYLOG logic will direct the output to up_putc() which is capable of generating the serial output within the context of an interrupt handler.

There are a few issues in doing this however:

up_putc() is able to generate debug output in any context because it disables serial interrupts and polls the hardware directly. These polls may take many milliseconds and during that time, all interrupts are disable within the interrupt handler. This, of course, interferes with the real-time behavior of the RTOS.
The output generated by up_putc() is immediate and in real-time. The normal SYSLOG output, on the other hand, is buffered in the serial driver and may be delayed with respect to the immediate output by many lines. Therefore, the interrupt level SYSLOG ouput provided throug up_putc() is grossly out of synchronization with other debug output.

In-Memory Buffering

If the RAMLOG SYSLOG channel is supported, then all SYSLOG output is buffered in memory. Interrupt level SYSLOG output is no different than normal SYSLOG output in this case.

Serialization Buffering

A final option is the use the an interrupt buffer to buffer the interrupt level SYSLOG output. In this case:

SYSLOG output generated from interrupt level process in not sent to the SYSLOG channel immediately. Rather, it is buffered in the interrupt serialization buffer.
Later, when the next normal syslog output is generated, it will first empty the content of the interrupt buffer to the SYSLOG device in the proper context. It will then be followed by the normal syslog output. In this case, the interrupt level SYSLOG output will interrupt the normal output stream and the interrupt level SYSLOG output will be inserted into the correct position in the SYSLOG output when the next normal SYLOG output is generated.

SYSLOG Channel Options

SYSLOG Console Device

The typical SYSLOG device is the system console. If you are using a serial console, for example, then the SYSLOG output will appear on that serial port.

This SYSLOG channel is automatically selected by syslog_initialize() in the LATE initialization phase based on configuration options. The configuration options that affect this channel selection include:

CONFIG_DEV_CONSOLE: This setting indicates that the system supports a console device, i.e., that the character device /dev/console exists.
CONFIG_SERIAL_CONSOLE: This configuration option is automatically selected when a UART or USART is configured as the system console. There is no user selection.
CONFIG_SYSLOG_CONSOLE: This configuration option is manually selected from the SYSLOG menu. This is the option that acutally enables the SYSLOG console device. It depends on CONFIG_DEV_CONSOLE and it will automatically select CONFIG_SYSLOG_SERIAL_CONSOLE if CONFIG_SERIAL_CONSOLE is selected.
CONFIG_ARCH_LOWPUTC: This is an indication from the architecture configuration that the platform supports the up_putc() interface. up_putc() is a very low level UART interface that can even be used from interrupt handling.
CONFIG_SYSLOG_SERIAL_CONSOLE: This enables certain features of the SYSLOG operation that depend on a serial console. If CONFIG_ARCH_LOWPUTC is also selected, for example, then up_putc() will be used for the forced SYSLOG output.

Interrupt level SYSLOG output will be lost unless:

The interrupt buffer is enabled to support serialization, or
A serial console is used and up_putc() is supported.

Note

The console channel uses the fixed character device at /dev/console. The console channel is not synonymous with stdout (or file descriptor 1). stdout is the current output from a task when, say, printf() if used. Initially, stdout does, indeed, use the /dev/console device. However, stdout may subsequently be redirected to some other device or file. This is always the case, for example, when a transient device is used for a console – such as a USB console or a Telnet console. The SYSLOG channel is not redirected as stdout is; the SYSLOG channel will stayed fixed (unless it is explicitly changed via syslog_channel()).

References: drivers/syslog/syslog_consolechannel.c and drivers/syslog/syslog_device.c.

SYSLOG Character Device

The system console device, /dev/console, is a character driver with some special properties. However, any character driver may be used as the SYSLOG output channel. For example, suppose you have a serial console on /dev/ttyS0 and you want SYSLOG output on /dev/ttyS1. Or suppose you support only a Telnet console but want to capture debug output /dev/ttyS0.

This SYSLOG device channel is selected with CONFIG_SYSLOG_CHAR and has no other dependencies. Differences fromthe SYSLOG console channel include:

CONFIG_SYSLOG_DEVPATH: This configuration option string must be set provide the full path to the character device to be used.
The forced SYSLOG output always goes to the bit-bucket. This means that interrupt level SYSLOG output will be lost unless the interrupt buffer is enabled to support serialization.
CONFIG_SYSLOG_CHAR_CRLF: If CONFIG_SYSLOG_CHAR_CRLF is selected, then inefeeds in the SYSLOG output will be expanded to Carriage Return + Linefeed. Since the character device is not a console device, the addition of carriage returns to line feeds would not be performed otherwise. You would probably want this expansion if you use a serial terminal program with the character device output.

References: drivers/syslog/syslog_devchannel.c and drivers/syslog/syslog_device.c.

SYSLOG File Device

Files can also be used as the sink for SYSLOG output. There is, however, a very fundamental difference in using a file as opposed the system console, a RAM buffer, or character device: You must first mount the file system that supports the SYSLOG file. That difference means that the file SYSLOG channel cannot be supported during the boot-up phase but can be instantiated later when board level logic configures the application environment, including mounting of the file systems.

The interface syslog_file_channel() is used to configure the SYSLOG file channel:

/****************************************************************************
 * Name: syslog_file_channel
 *
 * Description:
 *   Configure to use a file in a mounted file system at 'devpath' as the
 *   SYSLOG channel.
 *
 *   This tiny function is simply a wrapper around syslog_dev_initialize()
 *   and syslog_channel().  It calls syslog_dev_initialize() to configure
 *   the character file at 'devpath then calls syslog_channel() to use that
 *   device as the SYSLOG output channel.
 *
 *   File SYSLOG channels differ from other SYSLOG channels in that they
 *   cannot be established until after fully booting and mounting the target
 *   file system.  This function would need to be called from board-specific
 *   bring-up logic AFTER mounting the file system containing 'devpath'.
 *
 *   SYSLOG data generated prior to calling syslog_file_channel will, of
 *   course, not be included in the file.
 *
 *   NOTE interrupt level SYSLOG output will be lost in this case unless
 *   the interrupt buffer is used.
 *
 * Input Parameters:
 *   devpath - The full path to the file to be used for SYSLOG output.
 *     This may be an existing file or not.  If the file exists,
 *     syslog_file_channel() will append new SYSLOG data to the end of the
 *     file.  If it does not, then syslog_file_channel() will create the
 *     file.
 *
 * Returned Value:
 *   Zero (OK) is returned on success; a negated errno value is returned on
 *   any failure.
 *
 ****************************************************************************/

#ifdef CONFIG_SYSLOG_FILE
int syslog_file_channel(FAR const char *devpath);
#endif

References: drivers/syslog/syslog_filechannel.c, drivers/syslog/syslog_device.c, and include/nuttx/syslog/syslog.h.

SYSLOG RAMLOG Device

The RAMLOG is a standalone feature that can be used to buffer any character data in memory. There are, however, special configurations that can be used to configure the RAMLOG as a SYSLOG channel. The RAMLOG functionality is described in a more general way in the following paragraphs.

RAM Logging Device

The RAM logging driver is a driver that was intended to support debugging output (SYSLOG) when the normal serial output is not available. For example, if you are using a Telnet or USB serial console, the debug output will get lost – or worse. For example, what if you want to debug the network over Telnet?

The RAM logging driver can also accept debug output data from interrupt handler with no special serialization buffering. As an added benefit, the RAM logging driver is much less invasive. Since no actual I/O is performed with the debug output is generated, the RAM logger tends to be much faster and will interfere much less when used with time critical drivers.

The RAM logging driver is similar to a pipe in that it saves the debugging output in a circular buffer in RAM. It differs from a pipe in numerous details as needed to support logging.

This driver is built when CONFIG_RAMLOG is defined in the Nuttx configuration.

dmesg

When the RAMLOG (with SYSLOG) is enabled, a new NuttShell (NSH) command will appear: dmesg. The dmsg command will dump the contents of the circular buffer to the console (and also clear the circular buffer).

RAMLOG Configuration options

CONFIG_RAMLOG - Enables the RAM logging feature.
CONFIG_RAMLOG_CONSOLE - Use the RAM logging device as a system console. If this feature is enabled (along with CONFIG_DEV_CONSOLE), then all console output will be re-directed to a circular buffer in RAM. This might be useful, for example, if the only console is a Telnet console. Then in that case, console output from non-Telnet threads will go to the circular buffer and can be viewed using the NSH dmesg command. This optional is not useful in other scenarios.
CONFIG_RAMLOG_SYSLOG - Use the RAM logging device for the syslogging interface. If this feature is enabled, then all debug output will be re-directed to the circular buffer in RAM. This RAM log can be viewed from NSH using the dmesg command. NOTE: Unlike the limited, generic character driver SYSLOG device, the RAMLOG can be used to capture debug output from interrupt level handlers.
CONFIG_RAMLOG_NPOLLWAITERS - The number of threads than can be waiting for this driver on poll(). Default: 4.

If CONFIG_RAMLOG_CONSOLE or CONFIG_RAMLOG_SYSLOG is selected, then the following must also be provided:

CONFIG_RAMLOG_BUFSIZE - The size of the circular buffer to use. Default: 1024 bytes.

Other miscellaneous settings:

CONFIG_RAMLOG_CRLF - Pre-pend a carriage return before every linefeed that goes into the RAM log.
CONFIG_RAMLOG_NONBLOCKING - Reading from the RAMLOG will never block if the RAMLOG is empty. If the RAMLOG is empty, then zero is returned (usually interpreted as end-of-file). If you do not define this, the NSH dmsg command will lock up when called! So you probably do want this!
CONFIG_RAMLOG_NPOLLWAITERS - The maximum number of threads that may be waiting on the poll method.

SYSLOG (Input) Character Device

If the option CONFIG_SYSLOG_CHARDEV is selected then support for a special character device at /dev/syslog is supported. The function syslog_register() can be used to register that character device:

/****************************************************************************
 * Name: syslog_register
 *
 * Description:
 *   Register a simple character driver at /dev/syslog whose write() method
 *   will transfer data to the SYSLOG device.  This can be useful if, for
 *   example, you want to redirect the output of a program to the SYSLOG.
 *
 *   NOTE that unlike other syslog output, this data is unformatted raw
 *   byte output with no time-stamping or any other SYSLOG features
 *   supported.
 *
 ****************************************************************************/

void syslog_register(void);

Note

Careful… there is overloaded naming here!

A character device can serve as the SYSLOG output channel as described above. There we were referring to a data path like:

syslog() -> SYSLOG channel layer -> Character driver output channel.

Here we are talking about a different SYSLOG character devices that provides input data to the SYSLOG channel. That is a data path like:

SYSLOG Character driver -> SYSLOG channel layer -> Output channel.

Very confusing and begs for some re-naming.

Using SYSLOG for Debug

Lately, I have starting thinking a little more about the SYSLOG functions in general (as well as all of those debug macros). I think I am coming to the conclusion that there needs to be some things done.

The original design of syslog() was just some hooks for simple serial debug output. These simple debug hooks were standardized and renamed syslog() so that they provide a portable debug interface. As NuttX has increased in complexity and sophistication over the years, the implementation of syslog() “under the hood” is still that mindlessly simple serial debug logic from the original NuttX release. Perhaps the time as come to assess what is wrong with the solution and to implement some improvements in the syslog() design?

Here are some of the issues of the current implementation that bother me:

Use of File Descriptors

In the default case, the debug output goes out on file descriptor 1 (stdout). But if you think about that, it is a little crazy.

Each task can have I/O redirected in various ways. In most simple systems, a serial console is used for stdout in all tasks and the debug output goes to the serial console so everything is seamless. But if you are using a mixture of serial consoles, USB serial consoles, telnet sessions, etc. then who know were where the output is going to go in the most general case. Bits and pieces could go to different devices.

If you are redirecting stdout to a file, for example, then the debug information could go into your file, corrupting the output that you wanted. As another perverse example, try enabling network debug output using a Telnet session. That is an interesting exercise for anyone who like to see infinite loops: Telnet I/O generates debug output, the debug output goes to the Telnet network connection, which generates more network debug output, and on and one.

Interrupt Handlers

Output from interrupt handlers, of course, cannot use the console device at all. File descriptor I/O is not permitted from interrupt handlers. Attempts to do “normal” SYSLOG output from interrupt handlers will just result in the output going to the bit bucket.

Low-Level Serial Driver

The usual workaround to get debug output from interrupt handlers is to use the low-level serial I/O from interrupt handlers. But there are issues with this as well:

First, the console may not be the same serial device. It might be something else althogether. That means that non-interrupt SYSLOG output goes output one way and interrupt level SYSLOG output always goes out the serial port. Potentially very strange behavior could result.
Second, the low-level serial output does a busy wait poll! That interferes badly with the behavior of the interrupt handler – it has to wait within the interrupt handler while the serial output is performed. That wait would will be many milliseconds with interrupts disabled!
The low level serial output also interacts the serial driver itself making other use of the console impossible. Even, in some cases on some platforms, locking up the serial driver.

Interrupt Buffer

Another way to handle interrupt level output is supported. This is the only other option available if a Serial Console is not being used. This second option is enabled with CONFIG_SYSLOG_INTBUFFER.

In this case, syslog output generated from interrupt level logic will simply be buffered in memory. Then, later, when the next non-interrupt level syslog output is generated, the buffer interrupt level output will performed. This works because it essentially defers the syslog output generated from interrupt handlers until the next opportunity to perform normal output.

Asynchronous Output

Another syslog related issue is the asynchronous behavior with debug output from interrupt handlers. The normal debug output goes to the serial driver and is buffered for sending there. The size of the serial RX buffer is configurable. At any given point in time, the current output is behind realtme depending on that buffer size and the serial BAUD.

The interrupt debug output does not use the serial driver but immdiately commandeers the serial port and outputs dara in real time. The result is it appears to happen earlier in the output.

This is also why you lose the last debug output on a crash… the last debug data is stranded in the serial drivers RX buffer.

Interleaved Output

Because the output is done character at a time, the debug output from different tasks may get multiplexed and unreadable in the most critical of cases. The interleaved output can become totally useless, usually in the most complex situations where you need the debug output the most. Many times my plans to debug a problem with SYSLOG output has been thwarted because the output is just uninterpretable in a highly multitasking context.

Buffer Overrun

The root cause of this problem is the RX buffering in the serial driver: Character output is done one character at a time. That is not usually an issue. But when the system is very busy and he serial RX buffer becomes full, then each character output causes the caller to suspending, waiting for space in the RX buffer. It suspends and is moved to the last of the FIFO for that priority.

When this happens, many tasks may be suspended waiting space to put the next byte in the serial RX buffer. If the tasks are the same priority, then the output will be interleaved as described since each task gets essentially round-robin access to the serial driver. If one of the tasks is lower priority, then its its output may be deferred for some time until all of the higher priority tasks complete their output. Again, leaving a big time skew in the output data.

When there is is a big time skew in the debug output – whether from asynchronous output from interrupt handlers or from blocked, lower priority tasks – This can lead to misinterpretation of the debug output since our instinct is to treat the output as if it were in sequential order in time.

Note

Although a simple working around for a partical debug scenario is simply to increase the size of the RX buffer in the serial driver. Assuming that the RX buffer overrun is only the result of short-term, bursty behavior, then the large buffer migh prevent tasks blocking waiting for space to write the next byte.

Of course, there is no work around for the perverse case where the debug output is generated at a higher rate than can be transferred on the serial port. You are just basically out-of-luck in that case.

Solutions

Serialization Buffer

Some of these asynchrony problems could also be reduced or eliminated if all debug output were buffered in an in-memory FIFO. That buffer would serialize output from diffrent sources: Various tasks and interrupt level logic.

There is already a outgoing, RX buffer in the serial driver. Why would an additional layer of buffering help? Only because then the interrupt handler debug output could also be serialized. The input to the FIFO is debug output from all concurrent tasks and interrupt handlers; the single output of the FIFO would be the serial driver.

Serialization via syslog buffer has been recently implemented in NuttX, this option is enabled with CONFIG_SYSLOG_BUFFER.

Crash Dump

It might even be possible to flush that serialization buffer at the time of the crash. This has ability has not yet been implemented as of the time of this writing.

CONFIG_SYSLOG and the RAMLOG

There is a partial solution for all of these issues when CONFIG_SYSLOG=y. In that case, stdout is not used but instead some custom logic is used that is established by the configuration. Currently that option is only used with the RAMLOG. The RAMLOG actually works very nicely and eliminates most of the above issue (except for the interleaving issue). But the RAMLOG also requires some additional logic to get the debug information out of the RAMLOG. In NSH, you can use the dmesg command to dump the content of the RAMLOG to the NSH console.

But I am thinking that some in-memory buffering and serialization is the solution to most of the issues mentioned about: That would end the reliance on stdout. It would be compatible with debug output from interrupt handlers; interrupt handler output would be serialized in the in-memory buffer in the correct position.

The same interleaving problem could still occur. Adding more buffering can always eliminate the interleaving problem, provided that the problem is due to bursty, high-volume output. But you can just increase the size of the serial RX buffer to accomplish that; any special serialization is of no help (other than it effectively increases the size of the RX buffer).

The existing RAMLOG code could be extended so that the buffered data is agressively dumped to the SYSLOG device and I think all problems would be eliminated. The buffer could be dumped that the end of each non-interrupt level execution of syslog() (and also on a crash). Interrupt level output would have to pend in the buffer until the next, non-interrupt level debug output pushes it out to the serial driver.