[BUG] trace_printk() broken?

[Brian Foster <bfoster@redhat.com>]

Hi,

While poking around the bcachefs tree I ran into a problem where
trace_printk() seems to be broken. I suspect this has something to do
with the printbuf bits as it works once I back out some of those
changes.

What I observe is that a smaller printk with a fixed string seems to
work as expected, but once I add some variable args the message string
seems to get chewed up. This results in wonky formatting when reading
/sys/kernel/debug/tracing/trace and a read of the corresponding
trace_pipe file seems to spin in a livelock.

A diff is appended below to give a simple example of each case. A read
of the trace file ends up looking like this:

       fsck.ext4-535     [003] .....     6.112680: write_cache_pages:        fsck.ext4-535     [003] .....     6.113224: write_cache_pages: test
       fsck.ext4-535     [003] .....     6.117957: write_cache_pages:        fsck.ext4-535     [003] .....     6.118445: write_cache_pages: test
...

Brian

--- 8< ---

diff --git a/mm/page-writeback.c b/mm/page-writeback.c
index 032a7bf8d259..59ae76cb5756 100644
--- a/mm/page-writeback.c
+++ b/mm/page-writeback.c
@@ -2355,6 +2355,9 @@ int write_cache_pages(struct address_space *mapping,
 			if (!clear_page_dirty_for_io(page))
 				goto continue_unlock;
 
+			trace_printk("%d: ino 0x%lx\n", __LINE__, mapping->host->i_ino);
+			trace_printk("test\n");
+
 			trace_wbc_writepage(wbc, inode_to_bdi(mapping->host));
 			error = (*writepage)(page, wbc, data);
 			if (unlikely(error)) {