[RFC PATCH] libfrog: make cmn_err() emit each message atomically to avoid torn output

[RFC PATCH] libfrog: make cmn_err() emit each message atomically to avoid torn output

[Avinesh Kumar]

From: Avinesh Kumar <avinesh.kumar@suse.com>

fstests xfs/033 fails sporadically with a spurious blank line in the
xfs_repair output:

- output mismatch (see /opt/xfstests/results//xfs/033.out.bad)
    --- tests/xfs/033.out	2026-06-24 15:52:51.000000000 -0400
    +++ /opt/xfstests/results//xfs/033.out.bad	2026-07-14 18:54:46.582495041 -0400
    @@ -103,6 +103,7 @@
     Phase 3 - for each AG...
             - scan and clear agi unlinked lists...
             - process known inodes and perform inode discovery...
    +
     bad magic number 0xffff on inode INO
     bad version number 0xffffffff on inode INO
     inode identifier 18446744073709551615 mismatch on inode INO

Root cause is in cmn_err() (libfrog/util.c), which emits a message
and its newline as two separate writes to unbuffered stderr.
xfs_repair's threads all share stderr. If one is preempted between the
two writes, another thread's line lands in between:

(snips from `cat -A 033.raw`) -
Phase 3 - for each AG...$
        - scan and clear agi unlinked lists...$
        - process known inodes and perform inode discovery...$
Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000        - agno = 0$
$
bad CRC for inode 128$
bad magic number 0x0 on inode 128$

which should be like -

Phase 3 - for each AG...$
        - scan and clear agi unlinked lists...$
        - process known inodes and perform inode discovery...$
Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000$
        - agno = 0$
bad CRC for inode 130$
bad magic number 0x0 on inode 130$

_filter_repair() strips the noise line it glued onto but not the lone
newline, which then fails the golden diff.

Make the two writes atomic.

Signed-off-by: Avinesh Kumar <avinesh.kumar@suse.com>
---

Hi, please give feedback if this should be fixed in a different way.
Thanks!

 libfrog/util.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/libfrog/util.c b/libfrog/util.c
index 5bae5bab..3b6df917 100644
--- a/libfrog/util.c
+++ b/libfrog/util.c
@@ -116,8 +116,10 @@ cmn_err(int level, char *fmt, ...)
 	va_list	ap;
 
 	va_start(ap, fmt);
+	flockfile(stderr);
 	vfprintf(stderr, fmt, ap);
 	fputs("\n", stderr);
+	funlockfile(stderr);
 	va_end(ap);
 }
 
-- 
2.55.0

Re: [RFC PATCH] libfrog: make cmn_err() emit each message atomically to avoid torn output

[Darrick J. Wong]

On Wed, Jul 15, 2026 at 07:28:21PM +0200, Avinesh Kumar wrote:
> From: Avinesh Kumar <avinesh.kumar@suse.com>
> 
> fstests xfs/033 fails sporadically with a spurious blank line in the
> xfs_repair output:
> 
> - output mismatch (see /opt/xfstests/results//xfs/033.out.bad)
>     --- tests/xfs/033.out	2026-06-24 15:52:51.000000000 -0400
>     +++ /opt/xfstests/results//xfs/033.out.bad	2026-07-14 18:54:46.582495041 -0400
>     @@ -103,6 +103,7 @@
>      Phase 3 - for each AG...
>              - scan and clear agi unlinked lists...
>              - process known inodes and perform inode discovery...
>     +
>      bad magic number 0xffff on inode INO
>      bad version number 0xffffffff on inode INO
>      inode identifier 18446744073709551615 mismatch on inode INO
> 
> Root cause is in cmn_err() (libfrog/util.c), which emits a message
> and its newline as two separate writes to unbuffered stderr.
> xfs_repair's threads all share stderr. If one is preempted between the
> two writes, another thread's line lands in between:
> 
> (snips from `cat -A 033.raw`) -
> Phase 3 - for each AG...$
>         - scan and clear agi unlinked lists...$
>         - process known inodes and perform inode discovery...$
> Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000        - agno = 0$
> $
> bad CRC for inode 128$
> bad magic number 0x0 on inode 128$
> 
> which should be like -
> 
> Phase 3 - for each AG...$
>         - scan and clear agi unlinked lists...$
>         - process known inodes and perform inode discovery...$
> Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000$
>         - agno = 0$
> bad CRC for inode 130$
> bad magic number 0x0 on inode 130$
> 
> _filter_repair() strips the noise line it glued onto but not the lone
> newline, which then fails the golden diff.
> 
> Make the two writes atomic.
> 
> Signed-off-by: Avinesh Kumar <avinesh.kumar@suse.com>
> ---
> 
> Hi, please give feedback if this should be fixed in a different way.
> Thanks!
> 
>  libfrog/util.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/libfrog/util.c b/libfrog/util.c
> index 5bae5bab..3b6df917 100644
> --- a/libfrog/util.c
> +++ b/libfrog/util.c
> @@ -116,8 +116,10 @@ cmn_err(int level, char *fmt, ...)
>  	va_list	ap;
>  
>  	va_start(ap, fmt);
> +	flockfile(stderr);
>  	vfprintf(stderr, fmt, ap);
>  	fputs("\n", stderr);
> +	funlockfile(stderr);

I think do_error() in xfs_repair.c is going to need the same treatment
but otherwise this chunk looks ok to me.

--D

>  	va_end(ap);
>  }
>  
> -- 
> 2.55.0
> 
> 

Re: [RFC PATCH] libfrog: make cmn_err() emit each message atomically to avoid torn output

[Avinesh Kumar]

Hello Darrick,


On 7/15/26 9:09 PM, Darrick J. Wong wrote:
> On Wed, Jul 15, 2026 at 07:28:21PM +0200, Avinesh Kumar wrote:
>> From: Avinesh Kumar <avinesh.kumar@suse.com>
>>
>> fstests xfs/033 fails sporadically with a spurious blank line in the
>> xfs_repair output:
>>
>> - output mismatch (see /opt/xfstests/results//xfs/033.out.bad)
>>      --- tests/xfs/033.out	2026-06-24 15:52:51.000000000 -0400
>>      +++ /opt/xfstests/results//xfs/033.out.bad	2026-07-14 18:54:46.582495041 -0400
>>      @@ -103,6 +103,7 @@
>>       Phase 3 - for each AG...
>>               - scan and clear agi unlinked lists...
>>               - process known inodes and perform inode discovery...
>>      +
>>       bad magic number 0xffff on inode INO
>>       bad version number 0xffffffff on inode INO
>>       inode identifier 18446744073709551615 mismatch on inode INO
>>
>> Root cause is in cmn_err() (libfrog/util.c), which emits a message
>> and its newline as two separate writes to unbuffered stderr.
>> xfs_repair's threads all share stderr. If one is preempted between the
>> two writes, another thread's line lands in between:
>>
>> (snips from `cat -A 033.raw`) -
>> Phase 3 - for each AG...$
>>          - scan and clear agi unlinked lists...$
>>          - process known inodes and perform inode discovery...$
>> Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000        - agno = 0$
>> $
>> bad CRC for inode 128$
>> bad magic number 0x0 on inode 128$
>>
>> which should be like -
>>
>> Phase 3 - for each AG...$
>>          - scan and clear agi unlinked lists...$
>>          - process known inodes and perform inode discovery...$
>> Metadata corruption detected at 0x445dd3, xfs_inode block 0x80/0x4000$
>>          - agno = 0$
>> bad CRC for inode 130$
>> bad magic number 0x0 on inode 130$
>>
>> _filter_repair() strips the noise line it glued onto but not the lone
>> newline, which then fails the golden diff.
>>
>> Make the two writes atomic.
>>
>> Signed-off-by: Avinesh Kumar <avinesh.kumar@suse.com>
>> ---
>>
>> Hi, please give feedback if this should be fixed in a different way.
>> Thanks!
>>
>>   libfrog/util.c | 2 ++
>>   1 file changed, 2 insertions(+)
>>
>> diff --git a/libfrog/util.c b/libfrog/util.c
>> index 5bae5bab..3b6df917 100644
>> --- a/libfrog/util.c
>> +++ b/libfrog/util.c
>> @@ -116,8 +116,10 @@ cmn_err(int level, char *fmt, ...)
>>   	va_list	ap;
>>   
>>   	va_start(ap, fmt);
>> +	flockfile(stderr);
>>   	vfprintf(stderr, fmt, ap);
>>   	fputs("\n", stderr);
>> +	funlockfile(stderr);
> 
> I think do_error() in xfs_repair.c is going to need the same treatment
> but otherwise this chunk looks ok to me.
> 
Thanks for the review. I can send a follow up patch for do_error(),
or do you want these to go in the same patch?

Regards,
Avinesh

> --D
> 
>>   	va_end(ap);
>>   }
>>   
>> -- 
>> 2.55.0
>>
>>