Commit 169f1a2a authored Jun 12, 2013 by Paul Gortmaker Committed by Theodore Ts'o Jun 12, 2013

jbd2: use a single printk for jbd_debug()



Since the jbd_debug() is implemented with two separate printk()
calls, it can lead to corrupted and misleading debug output like
the following (see lines marked with "*"):

[  290.339362] (fs/jbd2/journal.c, 203): kjournald2: kjournald2 wakes
[  290.339365] (fs/jbd2/journal.c, 155): kjournald2: commit_sequence=42103, commit_request=42104
[  290.339369] (fs/jbd2/journal.c, 158): kjournald2: OK, requests differ
[* 290.339376] (fs/jbd2/journal.c, 648): jbd2_log_wait_commit:
[* 290.339379] (fs/jbd2/commit.c, 370): jbd2_journal_commit_transaction: JBD2: want 42104, j_commit_sequence=42103
[* 290.339382] JBD2: starting commit of transaction 42104
[  290.339410] (fs/jbd2/revoke.c, 566): jbd2_journal_write_revoke_records: Wrote 0 revoke records
[  290.376555] (fs/jbd2/commit.c, 1088): jbd2_journal_commit_transaction: JBD2: commit 42104 complete, head 42079

i.e. the debug output from log_wait_commit and journal_commit_transaction
have become interleaved.  The output should have been:

(fs/jbd2/journal.c, 648): jbd2_log_wait_commit: JBD2: want 42104, j_commit_sequence=42103
(fs/jbd2/commit.c, 370): jbd2_journal_commit_transaction: JBD2: starting commit of transaction 42104

It is expected that this is not easy to replicate -- I was only able
to cause it on preempt-rt kernels, and even then only under heavy
I/O load.

Reported-by: Paul Gortmaker <paul.gortmaker@windriver.com>
Suggested-by: "Theodore Ts'o" <tytso@mit.edu>
Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>

parent c9b3a8cc

fs/jbd2/journal.c

+18 −0

Original line number	Diff line number	Diff line
		@@ -103,6 +103,24 @@ EXPORT_SYMBOL(jbd2_inode_cache);
		static void __journal_abort_soft (journal_t *journal, int errno);
		static int jbd2_journal_create_slab(size_t slab_size);

		#ifdef CONFIG_JBD2_DEBUG
		void __jbd2_debug(int level, const char file, const char func,
		unsigned int line, const char *fmt, ...)
		{
		struct va_format vaf;
		va_list args;

		if (level > jbd2_journal_enable_debug)
		return;
		va_start(args, fmt);
		vaf.fmt = fmt;
		vaf.va = &args;
		printk(KERN_DEBUG "%s: (%s, %u): %pV\n", file, func, line, &vaf);
		va_end(args);
		}
		EXPORT_SYMBOL(__jbd2_debug);
		#endif

		/* Checksumming functions */
		int jbd2_verify_csum_type(journal_t j, journal_superblock_t sb)
		{

include/linux/jbd2.h

+5 −9

Original line number	Diff line number	Diff line
		@@ -56,17 +56,13 @@
		*/
		#define JBD2_EXPENSIVE_CHECKING
		extern ushort jbd2_journal_enable_debug;
		void __jbd2_debug(int level, const char file, const char func,
		unsigned int line, const char *fmt, ...);

		#define jbd_debug(n, f, a...) \
		do { \
		if ((n) <= jbd2_journal_enable_debug) { \
		printk (KERN_DEBUG "(%s, %d): %s: ", \
		__FILE__, __LINE__, __func__); \
		printk (f, ## a); \
		} \
		} while (0)
		#define jbd_debug(n, fmt, a...) \
		__jbd2_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a)
		#else
		#define jbd_debug(f, a...) /**/
		#define jbd_debug(n, fmt, a...) /**/
		#endif

		extern void *jbd2_alloc(size_t size, gfp_t flags);

Admin message