Skip to content

buffered_logger: u8 counter overflow stops all log output after 256 messages in debug builds #728

Open

Description

@ytakano

buffered_logger: u8 counter overflow stops all log output after 256 messages in debug builds

Summary

applications/awkernel_services/src/buffered_logger.rs, run():

let mut n: u8 = 0;
while let Ok(msg) = rx.recv().await {
    awkernel_lib::console::print(&msg);
    n += 1;

    if n & 0x0f == 0 {
        awkernel_async_lib::r#yield().await;
    }
}

n += 1 overflows on the 256th message. In a debug build (make x86_64 without
RELEASE=1, dev profile with overflow checks on) this panics inside the logger task,
the task moves to the Panicked scheduler, and nothing is printed through the buffered
logger any more. The kernel keeps running; only the console goes silent. In release
builds the addition wraps and the bug is invisible.

The panic message itself cannot be seen either: it is emitted through log::, which
goes to the now-dead buffered logger.

Reproduction

QEMU x86_64 (q35) with any workload that logs more than ~256 lines, e.g.

make x86_64 OPT="--features debug --features userland/test_prioritized_rr"
make qemu-x86_64-nographic

Observed on main (40300f0), unmodified:

vCPUs total lines before silence lines from Starting [Awkernel] network service.
4 363 270
16 450 270

The cut-off is a fixed message count, not time, CPU count, or workload. The QEMU
monitor (info registers -a) shows the vCPUs still executing after the log stops, so
the system is alive. With RELEASE=1 the same image logs for the whole run.

Impact

  • Every QEMU debug run looks like a hang after the first couple of hundred lines, which
    is easy to misread as a scheduler or lock bug (it was, while testing fix(scheduler): do not preempt a running task of equal priority #725).
  • scripts/ci.sh does not exercise this path (host builds use the std feature and a
    different console), so it has gone unnoticed.

Fix

Any of:

  • n = n.wrapping_add(1);
  • make n a u32/usize (the only use is n & 0x0f == 0),
  • or count down from 16 and reset instead of using a running counter.

Additionally, consider having the panic path of the logger task fall back to the raw
console (awkernel_lib::logger::set_raw_console is already there) so that a panic in
the buffered logger is visible rather than silently stopping output.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions