Skip to content

drivers/syslog: fix syslog_write() returning -EIO on every write - #19568

Merged
jerpelea merged 1 commit into
apache:masterfrom
casaroli:fix-syslog-write-eio
Jul 29, 2026
Merged

drivers/syslog: fix syslog_write() returning -EIO on every write#19568
jerpelea merged 1 commit into
apache:masterfrom
casaroli:fix-syslog-write-eio

Conversation

@casaroli

Copy link
Copy Markdown
Contributor

Summary

syslog_write_foreach() compares an unsigned count against a signed accumulator, so it
returns -EIO after a fully successful write:

size_t  nwritten     = 0;
ssize_t nwritten_max = -EIO;
...
      if (nwritten > nwritten_max)
        {
          nwritten_max = nwritten;
        }
    }

  return nwritten_max;

The usual arithmetic conversions promote nwritten_max to size_t, so -5 becomes
4294967291 on a 32-bit target. The comparison is never true, the assignment never runs,
and the initial -EIO is returned no matter how many bytes actually went out.

Captured under gdb on a running qemu-i486:ostest guest, stopped at the return:

$1 = 64          type = size_t     <- all 64 bytes written
$2 = -5          type = ssize_t
$3 = 0           <- nwritten > nwritten_max
$4 = 4294967291  <- (size_t)nwritten_max
$5 = 1           <- (ssize_t)nwritten > nwritten_max

Introduced by 1685e8f ("syslog: avoid an infinite loop if one channel fails"), which
changed nwritten_max from size_t to ssize_t = -EIO so that an all-channels-failed
case could be reported. Casting at the comparison preserves that intent: nwritten_max
stays -EIO only when no channel wrote anything.

Impact

Most callers discard the return value — syslog() itself returns void — so this is
normally invisible.

It becomes fatal when /dev/console is backed by syslog_console_write(), because then
stdio acts on it. lib_fflush_unlocked() sees a negative return, sets __FS_FLAG_ERROR
and returns early, before resetting fs_bufpos. The bytes have already been emitted,
but the buffer is never cleared, so every subsequent stdio call re-flushes the same
CONFIG_STDIO_BUFFER_SIZE bytes. The console fills with one repeated fragment and the
system makes no further progress.

Reaching that state needs CONFIG_CONSOLE_SYSLOG=y and no driver claiming
/dev/console ahead of syslog_console_init(). Three in-tree defconfigs qualify:

  • boards/x86/qemu/qemu-i486/configs/ostest
  • boards/renesas/m16c/skp16c26/configs/ostest
  • boards/x86_64/qemu/qemu-intel64/configs/earlyfb

The other 56 CONFIG_CONSOLE_SYSLOG=y configurations have a serial console that registers
/dev/console first, so syslog's register_driver() fails and the bad return never
reaches stdio. That is why this has gone unnoticed.

No API, ABI or configuration change. One line; the fix can only turn a spurious -EIO
into the correct positive count.

Testing

Host: macOS 26.5.1 on Apple Silicon (arm64), QEMU 11.0.3, arm-none-eabi-gcc 16.1.0,
Homebrew i686-elf-gcc.

tools/checkpatch.sh -c -u -m -g origin/master..HEADAll checks pass.

A/B on mps2-an521 (armv8-m, Cortex-M33)

No in-tree armv8-m defconfig reaches the failing path, so the arrangement is built from
stock mps2-an521:nsh with four config changes — no code changes, no stubs:

# CONFIG_CMSDK_UART0_SERIAL_CONSOLE is not set   # stop the UART claiming /dev/console
CONFIG_CONSOLE_SYSLOG=y                          # so syslog_console_init() gets it
CONFIG_ARM_SEMIHOSTING_SYSLOG=y                  # a syslog channel needing no serial driver
CONFIG_INIT_ENTRYPOINT="ostest_main"             # emit more than STDIO_BUFFER_SIZE (64)
CONFIG_TESTING_OSTEST_LOOPS=3
qemu-system-arm -M mps2-an521 -nographic -kernel ./nuttx -semihosting

Before — 25 s, 5681 lines, no forward progress. The console repeats one fragment,
cut at the 64-byte stdio buffer boundary, with lines fused together:

   1627  user_main: Started with argc=5
   1626  user_main: argv[0]="ostest"
   1617  user
    468  restart_main: argv[0]="ostest"restart_main: Started with argc=4

After — same 25 s, 175 lines, and left running it walked all three ostest loops
(2483 lines, user_main: setvbuf test x3), zero ERROR lines, and no repeated fragment:

    162  wqueue_test: call = 100, expect = 100     <- ordinary test output
     19  VARIABLE  BEFORE   AFTER

qemu-i486:ostest (the in-tree config that hits this)

Before: 5+ MB of console in 60 s, user_main: Started with argc=5 x77094, and
ostest_main: putenv(Varia x356 which never once completes.

After, same tree and same QEMU line:

stdio_test: write fd=1
stdio_test: Standard I/O Check: printf
stdio_test: write fd=2
ostest_main: putenv(Variable1=BadValue3)          <- complete line
ostest_main: setenv(Variable1, GoodValue1, TRUE)
...
ostest_main: Exiting with status 0

27 KB in 60 s instead of ~5 MB, user_main: Started once instead of 77094 times,
mxordblk flat at c9c88 across 52 samples.

No regression on unaffected configurations

mps2-an521:nsh stock and unmodified — serial console owns /dev/console, so the syslog
return value is never consulted — runs ostest to completion with the patch applied:

ostest_main: Exiting with status 0

964 lines, 227 s, no errors.

Comment thread drivers/syslog/syslog_write.c Outdated
syslog_write_foreach() compares an unsigned count against a signed
accumulator:

  size_t  nwritten     = 0;
  ssize_t nwritten_max = -EIO;
  ...
  if (nwritten > nwritten_max)
    {
      nwritten_max = nwritten;
    }
  return nwritten_max;

The usual arithmetic conversions promote nwritten_max to size_t, so -EIO
becomes 4294967291 on a 32-bit target, and the comparison is never true.
nwritten_max keeps its initial value and the function returns -EIO no
matter how many bytes actually went out.  Observed under gdb on a running
target: nwritten == 64, nwritten_max == -5, (nwritten > nwritten_max) == 0.

Most callers discard the result -- syslog() itself returns void -- so this
is normally invisible.  It becomes fatal when /dev/console is backed by
syslog_console_write(), because then stdio acts on it.
lib_fflush_unlocked() sees a negative return, sets __FS_FLAG_ERROR and
returns early, before resetting fs_bufpos.  The bytes have already been
emitted, but the buffer is never cleared, so every subsequent stdio call
re-flushes the same CONFIG_STDIO_BUFFER_SIZE bytes.  The console fills
with one repeated fragment and the system makes no further progress.

Reaching that state needs CONFIG_CONSOLE_SYSLOG=y together with no driver
claiming /dev/console ahead of syslog_console_init().  Three in-tree
defconfigs qualify: x86/qemu-i486:ostest, renesas/skp16c26:ostest and
x86_64/qemu-intel64:earlyfb.  The other 56 CONSOLE_SYSLOG configurations
have a serial console that registers /dev/console first, which is why this
has gone unnoticed.

Introduced by 1685e8f ("syslog: avoid an infinite loop if one channel
fails"), which changed nwritten_max from size_t to ssize_t = -EIO so that
an all-channels-failed case could be reported.  Give nwritten the same type
so the comparison is signed, which preserves that intent: nwritten_max
stays -EIO only when no channel wrote anything.  nwritten is never negative,
so the remaining comparisons against buflen are unaffected.

Signed-off-by: Marco Casaroli <marco.casaroli@gmail.com>

Assisted-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
@casaroli
casaroli force-pushed the fix-syslog-write-eio branch from 8146222 to c24694a Compare July 28, 2026 13:01
@casaroli
casaroli requested a review from xiaoxiang781216 July 28, 2026 13:09
@github-actions github-actions Bot added Area: Drivers Drivers issues Size: XS The size of the change in this PR is very small labels Jul 28, 2026
@github-actions

Copy link
Copy Markdown

MemBrowse Memory Report

arduino-mega2560

  • flash: .text +18 B (+0.0%, 67,418 B / 262,144 B, total: 26% used)

esp32-devkitc

  • ROM: .flash.text -28 B (-0.0%, 124,372 B / 4,194,272 B, total: 3% used)
  • irom0_0_seg: .flash.text -28 B (-0.0%, 88,580 B / 3,342,304 B, total: 3% used)

hifive1-revb

  • flash: .text -4 B (-0.0%, 83,344 B / 4,194,304 B, total: 2% used)

mirtoo

  • kseg0_progmem: .text +120 B (+0.2%, 67,412 B / 131,072 B, total: 51% used)

qemu-armv8a

  • Code: .text.syslog_write_foreach -4 B (-0.0%, 318,074 B)

qemu-intel64

  • Code: .text -16 B (-0.0%, 8,657,976 B)

rx65n-rsk2mb

@jerpelea
jerpelea merged commit 5a7f1b5 into apache:master Jul 29, 2026
53 checks passed
@michallenc

Copy link
Copy Markdown
Contributor

Thanks for the fix!

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

Labels

Area: Drivers Drivers issues Size: XS The size of the change in this PR is very small

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants