pkg/mplaland-printf: Use buffered output

[maribu]

Contribution description

With this patch a small (64 byte) on-stack is buffer is used. On stdio transports with extremely high overhead per call of stdio_write() (like e.g. telnet or semihosting), this will make the stdio usable again.

Compared to e.g. the stdio from newlib, the increased stack requirements are still modest.

Testing procedure

Run e.g. an app with lots of stdio output with an stdio transport that has a lot of overhead per stdio_write() call. E.g.

USEMODULE=stdio_semihosting make BOAD=<board_with_many_timers> -C tests/periph/timer RIOT_TERMINAL=semihosting flash term

In master, this will be unusable. (About two chars per second on for semihosting on master). With this PR, this should be faster.

Issues/PRs references

Fixes a regression from #21438

[maribu]

Ah, I also sneaked in a fix where stdio_write() would return a number smaller than the requested output. mpaland-printf should now loop until the transport actually managed to write all output.

[riot-ci]

Murdock results

✔️ PASSED

30a4647 pkg/mplaland-printf: Use buffered output

Success	Failures	Total	Runtime
10552	0	10552	09m:41s

Artifacts

• Documentation preview

[Teufelchen1]

Great thanks. I will need two or three days to find time to test this on hardware.

[benpicco]

I suggest we s/picolibc_stdout_buffered/libc_stdout_buffered/g so you can only enable the feature when needed.

[maribu]

True.

With the number of patches stacking up and upstream being dead, I wonder if we should also just reduce our pain with the integration by just vendoring in the code.

[crasbe]

With the number of patches stacking up and upstream being dead, I wonder if we should also just reduce our pain with the integration by just vendoring in the code.

Apparently there is an actively maintained fork:
mpaland/printf#128
https://github.com/eyalroz/printf

[maribu]

OK, but that fork is almost twice as large. And the addition of cmakes increases integration complexity and build time for little to no benefit in our use case...

[Teufelchen1]

Works great!

[mguetschow]

Thanks! I think it wouldn't harm to add some documentation to the file about why we use the buffering?

[crasbe]

I think you have to force-push again, Github seems to be confused because it was already on the queue 🤔

[benpicco]

Something is not quite right. When I run tests/sys/usbus_cdc_acm_stdio on nrf52840dk, I get

> help
2025-10-29 16:55:45,877 # ain():Tisis Rmhelp
2025-10-29 16:55:45,877 # shell: command not found: main():Tisis
> text 128
2025-10-29 16:55:49,680 # text 128
2025-10-29 16:55:49,680 # 
2025-10-29 16:55:49,680 # 
> help
2025-10-29 16:55:53,501 # 01234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567help

On 2025.01-branch this would produce

2025-10-29 16:57:31,235 # > text 128
2025-10-29 16:57:31,235 # 01234567890123456789012345678901234567890123456789012345678901234567890123456789
2025-10-29 16:57:31,236 # 012345678901234567890123456789012345678901234567

[maribu]

Is that issue only happening on USB, or also on UART? If it depends on the transport, it is more likely triggering an issue in the transport rather than actually causing it.

There always has been something fishy with the USB CDC ACM, as the first command entered into the shell always contained part of the boot message printed.

[maribu]

Does it work up to 128 B?

/**
 * @brief Buffer size for STDIN and STDOUT data to and from USB when using
 *        the USBUS_CDC_ACM_STDIO module
 */
#ifdef CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE_EXP
#define CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE (1<<CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE_EXP)
#endif
#ifndef CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE
#define CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE (128)
#endif

That seems to then trigger the "drop" flow control path in

    /* stuff as much data as possible into tsrb, discarding the oldest */
    old = irq_disable();
    n = tsrb_free(&cdcacm->tsrb);
    if (len > n) {
        n += tsrb_drop(&cdcacm->tsrb, len - n);
        buf += len - n;
    } else {
        n = len;
    }

If usbus_cdc_acm_submit() instead would just write what is possible (not discarding old data), mpaland_printf() would call stdio_write() in a loop for the remaining data until everything is written. Probably that is what needs to change.

[maribu]

Specifically, does this fix the issue?

diff --git a/sys/usb/usbus/cdc/acm/cdc_acm.c b/sys/usb/usbus/cdc/acm/cdc_acm.c
index 77c93bcb5a..5528d1f28b 100644
--- a/sys/usb/usbus/cdc/acm/cdc_acm.c
+++ b/sys/usb/usbus/cdc/acm/cdc_acm.c
@@ -158,19 +158,8 @@ size_t usbus_cdc_acm_submit(usbus_cdcacm_device_t *cdcacm, const uint8_t *buf, s
         irq_restore(old);
         return n;
     }
-    /* stuff as much data as possible into tsrb, discarding the oldest */
-    old = irq_disable();
-    n = tsrb_free(&cdcacm->tsrb);
-    if (len > n) {
-        n += tsrb_drop(&cdcacm->tsrb, len - n);
-        buf += len - n;
-    } else {
-        n = len;
-    }
-    tsrb_add(&cdcacm->tsrb, buf, n);
-    /* behave as if everything has been written correctly */
-    irq_restore(old);
-    return len;
+
+    return tsrb_add(&cdcacm->tsrb, buf, len);
 }
 
 void usbus_cdc_acm_set_coding_cb(usbus_cdcacm_device_t *cdcacm,
diff --git a/sys/usb/usbus/cdc/acm/cdc_acm_stdio.c b/sys/usb/usbus/cdc/acm/cdc_acm_stdio.c
index fe171e7420..aca489a16e 100644
--- a/sys/usb/usbus/cdc/acm/cdc_acm_stdio.c
+++ b/sys/usb/usbus/cdc/acm/cdc_acm_stdio.c
@@ -36,15 +36,9 @@ static uint8_t _cdc_tx_buf_mem[CONFIG_USBUS_CDC_ACM_STDIO_BUF_SIZE];
 
 static ssize_t _write(const void* buffer, size_t len)
 {
-    const char *start = buffer;
-    while (len) {
-        size_t n = usbus_cdc_acm_submit(&cdcacm, buffer, len);
-        usbus_cdc_acm_flush(&cdcacm);
-        /* Use tsrb and flush */
-        buffer = (char *)buffer + n;
-        len -= n;
-    }
-    return (char *)buffer - start;
+    size_t res = usbus_cdc_acm_submit(&cdcacm, buffer, len);
+    usbus_cdc_acm_flush(&cdcacm);
+    return (ssize_t)res;
 }
 
 static void _cdc_acm_rx_pipe(usbus_cdcacm_device_t *cdcacm,

[benpicco]

Hm not really - what's pointing towards mpland is that the issue also occurs when I add USEMODULE += stdio_uart