Skip to content

Output Interleaving due to Unprotected I/O Loops #64

@HeatCrab

Description

@HeatCrab

During the review of PR #62, a race condition was identified in the _tputs system call. The output loop iterates character-by-character using _putchar without protection. If a context switch occurs during this loop, output from different tasks becomes interleaved, resulting in garbled log messages.

While _tputs is being fixed in the current PR, further investigation revealed that this is a system-wide issue affecting other I/O paths in the kernel. The following locations contain similar for/while loops that invoke _putchar directly without critical section protection:

Logger Task Main Loop (kernel/logger.c)

The async logger drains the buffer and prints characters one by one. Being a lower priority task, it is highly susceptible to preemption.

static void logger_task(void)
{
       /* Omitted */

        if (have_message) {
            /* Key design: UART output outside lock prevents blocking enqueuers.
             * shorter UART write does not hold mutex - other tasks enqueue in
             * parallel.
             */
            for (uint16_t i = 0; i < entry.length; i++)
                _putchar(entry.data[i]);
            
            ...
}

Logger Flush (kernel/logger.c)

When flushing the logger, the loop runs in the context of the caller.

void mo_logger_flush(void)
{
        /* Omitted */

        if (!have_message)
            break;

        /* Output outside lock */
        for (uint16_t i = 0; i < entry.length; i++)
            _putchar(entry.data[i]);
    }
}

Direct Printf Mode (lib/stdio.c)
The direct output mode used by printf when the logger is bypassed or not initialized.

int32_t printf(const char *fmt, ...)
{
    /* Omitted */

    /* Direct output: early boot, direct mode (post-flush), queue full, or too
     * long.
     */
    char *p = buf;
    while (*p)
        _putchar(*p++);

    return len;
}

Thus, the lack of atomicity allows debugging messages from concurrently executing threads to interleave, resulting in garbled and unreadable output. This log corruption compromises the reliability of the system's primary diagnostic tool, making it significantly more difficult to trace complex race conditions or system behaviors, particularly under high-load scenarios where accurate logging is most critical.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions