Created attachment 15252 [details] log.c For the context, OVS has its logging framework (which writes to file, console, syslog etc...). DPDK is a library for networking datapath in userspace, and its components generate log messages through its own framework. DPDK provides a way to redirect those logs by passing a FILE * from fopencookie. OVS does this and disables buffering. After updating from f37 to f38 (glibc-2.36-17.fc37.x86_64 to glibc-2.37-13.fc38.x86_64), I noticed a change in how the logs are written for dpdk messages in OVS. Example of output: 2023-11-17T12:50:38.137Z|00059|dpdk|INFO|VHOST_CONFIG: (/home/dmarchan/git/pub/ovs/master/build/tests/system-dpdk-testsuite.dir/003/dpdkvhostclient0) Linear buffers requ 2023-11-17T12:50:38.137Z|00060|dpdk|INFO|ested without external buffers, The log message has been split in 128 bytes chunks (if I count correctly). I attached a simple reproducer (to mimick what is done in OVS, which takes over DPDK logs with a similar fopencookie + setbuf in non buffering mode). # From a f37 container: [root@cb7d749e838f ~]# gcc -o log -Wall -Werror log.c; ./log no setbuf ========= Calling fprintf idx=0 size=511 Calling vfprintf idx=0 size=511 setbuf _IONBF ============= Calling fprintf idx=0 size=511 Calling vfprintf idx=0 size=511 # From a f38 container: [root@3fbf304e6894 ~]# gcc -o log -Wall -Werror log.c; ./log no setbuf ========= Calling fprintf idx=0 size=511 Calling vfprintf idx=0 size=511 setbuf _IONBF ============= Calling fprintf idx=0 size=511 Calling vfprintf idx=0 size=128 idx=1 size=128 idx=2 size=128 idx=3 size=127
That doesn't look like a bug. You are requesting unbuffered output, so the output appears as soon as possible.
The reproducer is misleading because GCC translates the fprintf call into an fputs call. With -fno-builtin, I get this instead: “ no setbuf ========= Calling fprintf idx=0 size=511 Calling vfprintf idx=0 size=511 setbuf _IONBF ============= Calling fprintf idx=0 size=128 idx=1 size=128 idx=2 size=128 idx=3 size=127 Calling vfprintf idx=0 size=128 idx=1 size=128 idx=2 size=128 idx=3 size=127 ” So at least it's consistent. Echoing what Andreas said, I think you are just observing the effect of a reduced buffer size. It was always there, except that we used to have a large on-stack buffer in vfprintf (8192 bytes, I believe), which probably papered over it. The 128 bytes fallback buffer size is arbitrary. We can probably increase it somewhat if it reduces the compatibility impact of this change. But fopencookie is inherently a byte stream interface, so there is no guarantee that one fprintf call will be translated into one cookie write call.
%s used to write the string directly to the stream.
I'm pretty sure the actual application has a more elaborate format string here. If we don't have a large enough buffer, that will still result in multiple writes even if we can handle arbitrarily large %s strings directly (because we need to flush the previous buffer contents due to lack of vectored writes, and write the subsequent format bits from the buffer).
Given Andreas and Florian's responses I'm marking this closed as not a bug. If you think that we need to increase the fallback buffer size for the purposes of compatibility then please reopen the issue.