[BUG] `nsh_catfile` is writing too fast to the nsh console (garbled output, rp2040)

Open
#3,063 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Assessment

Difficulty
4/5
Estimated time
3-5 days
Newbie friendliness
38/100
Issue type
Bug
Clarity
Mostly clear
Activity status
Stale
Tech stack
c
Domain
cli, embedded-iot

Research direction

Start in nshlib/nsh_fsutils.c at nsh_catfile and review nshlib/nsh_console.h for the nsh_write macro. Reproduce dmesg output on the RP2040 USB serial console with CONFIG_RAMLOG_SYSLOG enabled, then investigate how writes are handled. Done means dmesg output is complete and ungarbled without relying on an artificially small read size.

Written by the indexing model from the issue text.

Description

Type: Bug
Description / Steps to reproduce the issue

I am using the CONFIG_RAMLOG_SYSLOG feature (log messages being sent to /dev/kmsg and retrieved via dmesg). This works in general.
But sadly the output of dmesg is usually heavily garbled: lots of characters (single or in big chunks) are missing. Repeated calls of dmesg emit different output (i.e. the missing characters are randomly spread).

Potential cause

The output of dmesg is created by nsh_catfile.
nsh_catfile uses the nsh_write macro:

#define nsh_write(v,b,n)        (v)->write(v,b,n)

I tried to slow down the read operation in nsh_catfile:

diff --git a/nshlib/nsh_fsutils.c b/nshlib/nsh_fsutils.c
index 878c1d18e..f3d91d2bc 100644
--- a/nshlib/nsh_fsutils.c
+++ b/nshlib/nsh_fsutils.c
@@ -178,7 +178,7 @@ int nsh_catfile(FAR struct nsh_vtbl_s *vtbl, FAR const char *cmd,

   for (; ; )
     {
-      int nbytesread = read(fd, buffer, IOBUFFERSIZE);
+      int nbytesread = read(fd, buffer, 8);

       /* Check for read errors */

The above change fixes the issue for me. No more characters get lost in the void.

The above change is obviously not acceptable.
Instead, the output should probably block in some way in order to prevent itself from being overwhelmed?

Setup

I am using an w5500-evb-pico board (rp2040). The nsh console is writing to the serial USB device.

My configuration:

# CONFIG_ARCH_LEDS is not set
# CONFIG_DEV_CONSOLE is not set
# CONFIG_DISABLE_OS_API is not set
# CONFIG_EXAMPLES_UDPBLASTER_INIT is not set
# CONFIG_LIBC_LONG_LONG is not set
# CONFIG_NET_RECV_PACK is not set
# CONFIG_NSH_ARGCAT is not set
# CONFIG_NSH_CMDOPT_HEXDUMP is not set
# CONFIG_NSH_DISABLE_DATE is not set
# CONFIG_NSH_DISABLE_LOSMART is not set
# CONFIG_NSH_NETINIT is not set
# CONFIG_RP2040_UART0 is not set
CONFIG_ARCH="arm"
CONFIG_ARCH_BOARD="w5500-evb-pico"
CONFIG_ARCH_BOARD_W5500_EVB_PICO=y
CONFIG_ARCH_CHIP="rp2040"
CONFIG_ARCH_CHIP_RP2040=y
CONFIG_ARCH_INTERRUPTSTACK=2048
CONFIG_ARCH_RAMVECTORS=y
CONFIG_ARCH_STACKDUMP=y
CONFIG_AT24XX_MULTI=y
CONFIG_AT24XX_SIZE=256
CONFIG_BOARDCTL_RESET=y
CONFIG_BOARD_LOOPSPERMSEC=10450
CONFIG_BUILTIN=y
CONFIG_CDCACM=y
CONFIG_CDCACM_CONSOLE=y
CONFIG_DEBUG_FEATURES=y
CONFIG_DEBUG_FULLOPT=y
CONFIG_DEBUG_HARDFAULT_ALERT=y
CONFIG_DEBUG_HARDFAULT_INFO=y
CONFIG_DEBUG_SYMBOLS=y
CONFIG_DEV_GPIO=y
CONFIG_DEV_GPIO_NPOLLWAITERS=4
CONFIG_DEV_GPIO_NSIGNALS=4
CONFIG_EEPROM=y
CONFIG_EXAMPLES_UDPBLASTER=y
CONFIG_EXAMPLES_UDPBLASTER_HOSTIP=0xac108c99
CONFIG_EXAMPLES_UDPBLASTER_HOSTRATE=8000000
CONFIG_EXAMPLES_UDPBLASTER_TARGETIP=0xac108c15
CONFIG_FS_LITTLEFS=y
CONFIG_FS_PROCFS=y
CONFIG_FS_PROCFS_REGISTER=y
CONFIG_I2C_EE_24XX=y
CONFIG_IOB_NBUFFERS=24
CONFIG_IOB_THROTTLE=0
CONFIG_MTD=y
CONFIG_MTD_AT24XX=y
CONFIG_MTD_PARTITION=y
CONFIG_MTD_PARTITION_NAMES=y
CONFIG_NET=y
CONFIG_NETDB_DNSCLIENT=y
CONFIG_NETDEV_HPWORK_THREAD=y
CONFIG_NETDEV_MAX_IPv6_ADDR=4
CONFIG_NETDEV_MULTIPLE_IPv6=y
CONFIG_NETINIT_DHCPC=y
CONFIG_NETINIT_NOMAC=y
CONFIG_NETUTILS_CJSON=y
CONFIG_NETUTILS_CJSON_VERSION="1.7.18"
CONFIG_NETUTILS_IPERF=y
CONFIG_NETUTILS_NETCAT=y
CONFIG_NETUTILS_NETINIT=y
CONFIG_NET_ETH_PKTSIZE=1516
CONFIG_NET_ICMPv6=y
CONFIG_NET_ICMPv6_AUTOCONF=y
CONFIG_NET_ICMPv6_NEIGHBOR=y
CONFIG_NET_ICMPv6_SOCKET=y
CONFIG_NET_IPv6=y
CONFIG_NET_IPv6_NCONF_ENTRIES=256
CONFIG_NET_MLD=y
CONFIG_NET_TCP=y
CONFIG_NET_TCP_PREALLOC_CONNS=16
CONFIG_NET_TCP_WRITE_BUFFERS=y
CONFIG_NET_UDP=y
CONFIG_NET_UDP_WRITE_BUFFERS=y
CONFIG_NET_W5500=y
CONFIG_NFILE_DESCRIPTORS_PER_BLOCK=6
CONFIG_NSH_BUILTIN_APPS=y
CONFIG_NSH_READLINE=y
CONFIG_RAMLOG=y
CONFIG_RAMLOG_BUFSIZE=131072
CONFIG_RAMLOG_SYSLOG=y
CONFIG_RAM_SIZE=270336
CONFIG_RAM_START=0x20000000
CONFIG_READLINE_CMD_HISTORY=y
CONFIG_RP2040_I2C1=y
CONFIG_RP2040_I2C1_SCL_GPIO=27
CONFIG_RP2040_I2C1_SDA_GPIO=26
CONFIG_RP2040_I2C=y
CONFIG_RP2040_I2C_DRIVER=y
CONFIG_RP2040_SPI0=y
CONFIG_RP2040_SPI=y
CONFIG_RR_INTERVAL=200
CONFIG_SCHED_BACKTRACE=y
CONFIG_SCHED_CPULOAD_SYSCLK=y
CONFIG_SCHED_CPULOAD_TIMECONSTANT=60
CONFIG_SCHED_HPWORK=y
CONFIG_SCHED_LPWORK=y
CONFIG_SCHED_STACK_RECORD=10
CONFIG_SCHED_WAITPID=y
CONFIG_SCPI_PARSER=y
CONFIG_SMP=y
CONFIG_SMP_NCPUS=2
CONFIG_SPECIFIC_DRIVERS=y
CONFIG_START_YEAR=2025
CONFIG_SYSLOG_CHAR=y
CONFIG_SYSLOG_PRIORITY=y
CONFIG_SYSLOG_TIMESTAMP=y
CONFIG_SYSTEM_DHCPC_RENEW6=y
CONFIG_SYSTEM_DHCPC_RENEW=y
CONFIG_SYSTEM_I2CTOOL=y
CONFIG_SYSTEM_NSH=y
CONFIG_SYSTEM_PING6=y
CONFIG_SYSTEM_PING=y
CONFIG_SYSTEM_SETLOGMASK=y
CONFIG_SYSTEM_TIME64=y
CONFIG_USBDEV=y
CONFIG_USBDEV_BUSPOWERED=y
On which OS does this issue occur?

[OS: Linux]

What is the version of your OS?

Debian Trixie

NuttX Version

master

Issue Architecture

[Arch: arm]

Issue Area

[Area: NSH]

Verification
  • I have verified before submitting the report.
Dominant language
C
Stars
465
Forks
782
Avg merge
3d 11h
Merged PRs (30d)
44

Contributor guide

No contributing guide indexed for this repository

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from apache/nuttx-apps

All issues in apache/nuttx-apps

Similar issues

More C issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.