[PATCH 0/4] Backports of jbd2 commits to jbd

[PATCH 0/4] Backports of jbd2 commits to jbd

[Paul Gortmaker]

The following commits exist in jbd2, and the backport to jbd is
relatively straightforward.  In doing so we make the debug enable
interface consistent between jbd and jbd2.

For testing, I've booted up a machine with ext3 fs, done some basic
operations (update a git tree, build a kernel) and also ensured that
enabling debug via the new /sys/module/jbd/parameters/ entry works.
Testing was on a baseline of v3.10-rc1-39-g741ddbc.

Paul.
---

Paul Gortmaker (4):
  jbd: use module parameters instead of debugfs for jbd_debug
  jbd: relocate assert after state lock in journal_commit_transaction()
  jbd: drop checkpoint mutex when waiting in __log_wait_for_space()
  jbd: use a single printk for jbd_debug()

 fs/jbd/Kconfig      |  6 ++---
 fs/jbd/checkpoint.c |  8 +++++++
 fs/jbd/commit.c     |  2 +-
 fs/jbd/journal.c    | 67 +++++++++++++++++++++--------------------------------
 include/linux/jbd.h | 20 +++++++---------
 5 files changed, 46 insertions(+), 57 deletions(-)

-- 
1.8.1.2

[PATCH 1/4] jbd: use module parameters instead of debugfs for jbd_debug

[Paul Gortmaker]

This is a direct backport of commit b6e96d0067d81f6a300bedee
("jbd2: use module parameters instead of debugfs for jbd_debug")
from jbd2 into jbd.  The value is in making ext4 and ext3 user
experiences consistent with each other.  Quoting the original:

 --------------
 There are multiple reasons to move away from debugfs.  First of all,
 we are only using it for a single parameter, and it is much more
 complicated to set up (some 30 lines of code compared to 3), and one
 more thing that might fail while loading the jbd2 module.

 Secondly, as a module paramter it can be specified as a boot option if
 jbd2 is built into the kernel, or as a parameter when the module is
 loaded, and it can also be manipulated dynamically under
 /sys/module/jbd2/parameters/jbd2_debug.  So it is more flexible.

 Ultimately we want to move away from using jbd_debug() towards
 tracepoints, but for now this is still a useful simplification of the
 code base.
 --------------

It is worth noting that we use /sys/module/jbd/parameters/jbd1_debug
(i.e. the "1" might appear odd) for the module parameter in order to
avoid namespace collisions with the existing jbd_debug used as a
function call.

In addition, we combine the content of jbd2 commit 75497d0607b56e16e4
("jbd2: remove debug dependency on debug_fs and update Kconfig help text")
since they were only separate commits unintentionally in jbd2.

Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
---
 fs/jbd/Kconfig      |  6 +++---
 fs/jbd/journal.c    | 49 ++++++++-----------------------------------------
 include/linux/jbd.h |  3 +--
 3 files changed, 12 insertions(+), 46 deletions(-)

diff --git a/fs/jbd/Kconfig b/fs/jbd/Kconfig
index 4e28bee..54cbb55 100644
--- a/fs/jbd/Kconfig
+++ b/fs/jbd/Kconfig
@@ -15,7 +15,7 @@ config JBD
 
 config JBD_DEBUG
 	bool "JBD (ext3) debugging support"
-	depends on JBD && DEBUG_FS
+	depends on JBD
 	help
 	  If you are using the ext3 journaled file system (or potentially any
 	  other file system/device using JBD), this option allows you to
@@ -24,7 +24,7 @@ config JBD_DEBUG
 	  debugging output will be turned off.
 
 	  If you select Y here, then you will be able to turn on debugging
-	  with "echo N > /sys/kernel/debug/jbd/jbd-debug", where N is a
+	  with "echo N > /sys/module/jbd/parameters/jbd1_debug", where N is a
 	  number between 1 and 5, the higher the number, the more debugging
 	  output is generated.  To turn debugging off again, do
-	  "echo 0 > /sys/kernel/debug/jbd/jbd-debug".
+	  "echo 0 > /sys/module/jbd/parameters/jbd1_debug".
diff --git a/fs/jbd/journal.c b/fs/jbd/journal.c
index 6510d63..166263d 100644
--- a/fs/jbd/journal.c
+++ b/fs/jbd/journal.c
@@ -35,7 +35,6 @@
 #include <linux/kthread.h>
 #include <linux/poison.h>
 #include <linux/proc_fs.h>
-#include <linux/debugfs.h>
 #include <linux/ratelimit.h>
 
 #define CREATE_TRACE_POINTS
@@ -44,6 +43,14 @@
 #include <asm/uaccess.h>
 #include <asm/page.h>
 
+#ifdef CONFIG_JBD_DEBUG
+ushort jbd_journal_enable_debug __read_mostly;
+EXPORT_SYMBOL(jbd_journal_enable_debug);
+
+module_param_named(jbd1_debug, jbd_journal_enable_debug, ushort, 0644);
+MODULE_PARM_DESC(jbd1_debug, "Debugging level for jbd");
+#endif
+
 EXPORT_SYMBOL(journal_start);
 EXPORT_SYMBOL(journal_restart);
 EXPORT_SYMBOL(journal_extend);
@@ -2017,44 +2024,6 @@ void journal_put_journal_head(struct journal_head *jh)
 		jbd_unlock_bh_journal_head(bh);
 }
 
-/*
- * debugfs tunables
- */
-#ifdef CONFIG_JBD_DEBUG
-
-u8 journal_enable_debug __read_mostly;
-EXPORT_SYMBOL(journal_enable_debug);
-
-static struct dentry *jbd_debugfs_dir;
-static struct dentry *jbd_debug;
-
-static void __init jbd_create_debugfs_entry(void)
-{
-	jbd_debugfs_dir = debugfs_create_dir("jbd", NULL);
-	if (jbd_debugfs_dir)
-		jbd_debug = debugfs_create_u8("jbd-debug", S_IRUGO | S_IWUSR,
-					       jbd_debugfs_dir,
-					       &journal_enable_debug);
-}
-
-static void __exit jbd_remove_debugfs_entry(void)
-{
-	debugfs_remove(jbd_debug);
-	debugfs_remove(jbd_debugfs_dir);
-}
-
-#else
-
-static inline void jbd_create_debugfs_entry(void)
-{
-}
-
-static inline void jbd_remove_debugfs_entry(void)
-{
-}
-
-#endif
-
 struct kmem_cache *jbd_handle_cache;
 
 static int __init journal_init_handle_cache(void)
@@ -2109,7 +2078,6 @@ static int __init journal_init(void)
 	ret = journal_init_caches();
 	if (ret != 0)
 		journal_destroy_caches();
-	jbd_create_debugfs_entry();
 	return ret;
 }
 
@@ -2120,7 +2088,6 @@ static void __exit journal_exit(void)
 	if (n)
 		printk(KERN_EMERG "JBD: leaked %d journal_heads!\n", n);
 #endif
-	jbd_remove_debugfs_entry();
 	journal_destroy_caches();
 }
 
diff --git a/include/linux/jbd.h b/include/linux/jbd.h
index 8685d1b..e45b430 100644
--- a/include/linux/jbd.h
+++ b/include/linux/jbd.h
@@ -20,7 +20,6 @@
 #ifndef __KERNEL__
 #include "jfs_compat.h"
 #define JFS_DEBUG
-#define jfs_debug jbd_debug
 #else
 
 #include <linux/types.h>
@@ -55,7 +54,7 @@
  * CONFIG_JBD_DEBUG is on.
  */
 #define JBD_EXPENSIVE_CHECKING
-extern u8 journal_enable_debug;
+extern ushort journal_enable_debug;
 
 #define jbd_debug(n, f, a...)						\
 	do {								\
-- 
1.8.1.2

[PATCH 2/4] jbd: relocate assert after state lock in journal_commit_transaction()

[Paul Gortmaker]

Backport of jbd2 commit 3ca841c106fd6cd2c942985977a5d126434a8dd6
("jbd2: relocate assert after state lock in journal_commit_transaction()")

Quoting that commit:
 ---------------
 The state lock is taken after we are doing an assert on the state
 value, not before.  So we might in fact be doing an assert on a
 transient value.  Ensure the state check is within the scope of
 the state lock being taken.
 ---------------

Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
---
 fs/jbd/commit.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/jbd/commit.c b/fs/jbd/commit.c
index 11bb11f..bb217dc 100644
--- a/fs/jbd/commit.c
+++ b/fs/jbd/commit.c
@@ -340,13 +340,13 @@ void journal_commit_transaction(journal_t *journal)
 	J_ASSERT(journal->j_committing_transaction == NULL);
 
 	commit_transaction = journal->j_running_transaction;
-	J_ASSERT(commit_transaction->t_state == T_RUNNING);
 
 	trace_jbd_start_commit(journal, commit_transaction);
 	jbd_debug(1, "JBD: starting commit of transaction %d\n",
 			commit_transaction->t_tid);
 
 	spin_lock(&journal->j_state_lock);
+	J_ASSERT(commit_transaction->t_state == T_RUNNING);
 	commit_transaction->t_state = T_LOCKED;
 
 	trace_jbd_commit_locking(journal, commit_transaction);
-- 
1.8.1.2

[PATCH 3/4] jbd: drop checkpoint mutex when waiting in __log_wait_for_space()

[Paul Gortmaker]

Backport of jbd2 commit 0ef54180e0187117062939202b96faf04c8673bc
("jbd2: drop checkpoint mutex when waiting in __jbd2_log_wait_for_space()")

Quoting that commit:
 --------------
 While trying to debug an an issue under extreme I/O loading
 on preempt-rt kernels, the following backtrace was observed
 via SysRQ output:

 rm              D ffff8802203afbc0  4600  4878   4748 0x00000000
  ffff8802217bfb78 0000000000000082 ffff88021fc2bb80 ffff88021fc2bb80
  ffff88021fc2bb80 ffff8802217bffd8 ffff8802217bffd8 ffff8802217bffd8
  ffff88021f1d4c80 ffff88021fc2bb80 ffff8802217bfb88 ffff88022437b000
 Call Trace:
  [<ffffffff8172dc34>] schedule+0x24/0x70
  [<ffffffff81225b5d>] jbd2_log_wait_commit+0xbd/0x140
  [<ffffffff81060390>] ? __init_waitqueue_head+0x50/0x50
  [<ffffffff81223635>] jbd2_log_do_checkpoint+0xf5/0x520
  [<ffffffff81223b09>] __jbd2_log_wait_for_space+0xa9/0x1f0
  [<ffffffff8121dc40>] start_this_handle.isra.10+0x2e0/0x530
  [<ffffffff81060390>] ? __init_waitqueue_head+0x50/0x50
  [<ffffffff8121e0a3>] jbd2__journal_start+0xc3/0x110
  [<ffffffff811de7ce>] ? ext4_rmdir+0x6e/0x230
  [<ffffffff8121e0fe>] jbd2_journal_start+0xe/0x10
  [<ffffffff811f308b>] ext4_journal_start_sb+0x5b/0x160
  [<ffffffff811de7ce>] ext4_rmdir+0x6e/0x230
  [<ffffffff811435c5>] vfs_rmdir+0xd5/0x140
  [<ffffffff8114370f>] do_rmdir+0xdf/0x120
  [<ffffffff8105c6b4>] ? task_work_run+0x44/0x80
  [<ffffffff81002889>] ? do_notify_resume+0x89/0x100
  [<ffffffff817361ae>] ? int_signal+0x12/0x17
  [<ffffffff81145d85>] sys_unlinkat+0x25/0x40
  [<ffffffff81735f22>] system_call_fastpath+0x16/0x1b

 What is interesting here, is that we call log_wait_commit, from
 within wait_for_space, but we are still holding the checkpoint_mutex
 as it surrounds mostly the whole of wait_for_space.  And then, as we
 are waiting, journal_commit_transaction can run, and if the JBD2_FLUSHED
 bit is set, then we will also try to take the same checkpoint_mutex.

 It seems that we need to drop the checkpoint_mutex while sitting in
 jbd2_log_wait_commit, if we want to guarantee that progress can be made
 by jbd2_journal_commit_transaction().  There does not seem to be
 anything preempt-rt specific about this, other then perhaps increasing
 the odds of it happening.
 --------------

Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
---
 fs/jbd/checkpoint.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/fs/jbd/checkpoint.c b/fs/jbd/checkpoint.c
index 08c0304..8e8e0ee 100644
--- a/fs/jbd/checkpoint.c
+++ b/fs/jbd/checkpoint.c
@@ -160,7 +160,15 @@ void __log_wait_for_space(journal_t *journal)
 				/* We were able to recover space; yay! */
 				;
 			} else if (tid) {
+				/*
+				 * jbd_journal_commit_transaction() may want
+				 * to take the checkpoint_mutex if JBD_FLUSHED
+				 * is set.  So we need to temporarily drop it.
+				 */
+				mutex_unlock(&journal->j_checkpoint_mutex);
 				log_wait_commit(journal, tid);
+				spin_lock(&journal->j_state_lock);
+				continue;
 			} else {
 				printk(KERN_ERR "%s: needed %d blocks and "
 				       "only had %d space available\n",
-- 
1.8.1.2

[PATCH 4/4] jbd: use a single printk for jbd_debug()

[Paul Gortmaker]

Backport of jbd2 commit 169f1a2a87aae44034da4b9f81be1683d33de6d0
("jbd2: use a single printk for jbd_debug()")

Quoting the original:
 --------------
 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.
 --------------

Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
---
 fs/jbd/journal.c    | 18 ++++++++++++++++++
 include/linux/jbd.h | 15 ++++++---------
 2 files changed, 24 insertions(+), 9 deletions(-)

diff --git a/fs/jbd/journal.c b/fs/jbd/journal.c
index 166263d..f45f0a3 100644
--- a/fs/jbd/journal.c
+++ b/fs/jbd/journal.c
@@ -97,6 +97,24 @@ static int journal_convert_superblock_v1(journal_t *, journal_superblock_t *);
 static void __journal_abort_soft (journal_t *journal, int errno);
 static const char *journal_dev_name(journal_t *journal, char *buffer);
 
+#ifdef CONFIG_JBD_DEBUG
+void __jbd_debug(int level, const char *file, const char *func,
+		 unsigned int line, const char *fmt, ...)
+{
+	struct va_format vaf;
+	va_list args;
+
+	if (level > jbd_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(__jbd_debug);
+#endif
+
 /*
  * Helper function used to manage commit timeouts
  */
diff --git a/include/linux/jbd.h b/include/linux/jbd.h
index e45b430..d6d3ae0 100644
--- a/include/linux/jbd.h
+++ b/include/linux/jbd.h
@@ -56,16 +56,13 @@
 #define JBD_EXPENSIVE_CHECKING
 extern ushort journal_enable_debug;
 
-#define jbd_debug(n, f, a...)						\
-	do {								\
-		if ((n) <= journal_enable_debug) {			\
-			printk (KERN_DEBUG "(%s, %d): %s: ",		\
-				__FILE__, __LINE__, __func__);	\
-			printk (f, ## a);				\
-		}							\
-	} while (0)
+void __jbd_debug(int level, const char *file, const char *func,
+		 unsigned int line, const char *fmt, ...);
+
+#define jbd_debug(n, fmt, a...) \
+	__jbd_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a)
 #else
-#define jbd_debug(f, a...)	/**/
+#define jbd_debug(n, fmt, a...)    /**/
 #endif
 
 static inline void *jbd_alloc(size_t size, gfp_t flags)
-- 
1.8.1.2

Re: [PATCH 0/4] Backports of jbd2 commits to jbd

[Paul Gortmaker]

On 13-08-01 03:01 PM, Paul Gortmaker wrote:
> The following commits exist in jbd2, and the backport to jbd is
> relatively straightforward.  In doing so we make the debug enable
> interface consistent between jbd and jbd2.
> 
> For testing, I've booted up a machine with ext3 fs, done some basic
> operations (update a git tree, build a kernel) and also ensured that
> enabling debug via the new /sys/module/jbd/parameters/ entry works.
> Testing was on a baseline of v3.10-rc1-39-g741ddbc.

That should have been v3.11-rc3-40-g75eaff0; the above just happens
to be the 1st non-merge commit on mainline today.

Re: [PATCH 4/4] jbd: use a single printk for jbd_debug()

[Joe Perches]

On Thu, 2013-08-01 at 15:01 -0400, Paul Gortmaker wrote:
> Backport of jbd2 commit 169f1a2a87aae44034da4b9f81be1683d33de6d0
> ("jbd2: use a single printk for jbd_debug()")

Hey Paul.

> diff --git a/include/linux/jbd.h b/include/linux/jbd.h
[]
> @@ -56,16 +56,13 @@
>  #define JBD_EXPENSIVE_CHECKING
>  extern ushort journal_enable_debug;
>  
> -#define jbd_debug(n, f, a...)						\
> -	do {								\
> -		if ((n) <= journal_enable_debug) {			\
> -			printk (KERN_DEBUG "(%s, %d): %s: ",		\
> -				__FILE__, __LINE__, __func__);	\
> -			printk (f, ## a);				\
> -		}							\
> -	} while (0)
> +void __jbd_debug(int level, const char *file, const char *func,
> +		 unsigned int line, const char *fmt, ...
> +
> +#define jbd_debug(n, fmt, a...) \
> +	__jbd_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a)
>  #else
> -#define jbd_debug(f, a...)	/**/
> +#define jbd_debug(n, fmt, a...)    /**/
>  #endif

It might have been (and may still be) simpler/better
to use a single macro like:

#define jbd_dbg(n, fmt, ...)			\
do {						\
	if ((n) < journal_enable_debug)		\
		pr_debug(fmt, ##__VA_ARGS__);	\
} while (0)

and then use dynamic_debug to add the __func__,
and __LINE__ when desired.

echo -n 'module jbd +pfl' <dynamic_debug>/control

Re: [PATCH 1/4] jbd: use module parameters instead of debugfs for jbd_debug

[Jan Kara]

On Thu 01-08-13 15:01:05, Paul Gortmaker wrote:
> This is a direct backport of commit b6e96d0067d81f6a300bedee
> ("jbd2: use module parameters instead of debugfs for jbd_debug")
> from jbd2 into jbd.  The value is in making ext4 and ext3 user
> experiences consistent with each other.  Quoting the original:
> 
>  --------------
>  There are multiple reasons to move away from debugfs.  First of all,
>  we are only using it for a single parameter, and it is much more
>  complicated to set up (some 30 lines of code compared to 3), and one
>  more thing that might fail while loading the jbd2 module.
> 
>  Secondly, as a module paramter it can be specified as a boot option if
>  jbd2 is built into the kernel, or as a parameter when the module is
>  loaded, and it can also be manipulated dynamically under
>  /sys/module/jbd2/parameters/jbd2_debug.  So it is more flexible.
> 
>  Ultimately we want to move away from using jbd_debug() towards
>  tracepoints, but for now this is still a useful simplification of the
>  code base.
>  --------------
> 
> It is worth noting that we use /sys/module/jbd/parameters/jbd1_debug
> (i.e. the "1" might appear odd) for the module parameter in order to
> avoid namespace collisions with the existing jbd_debug used as a
> function call.
> 
> In addition, we combine the content of jbd2 commit 75497d0607b56e16e4
> ("jbd2: remove debug dependency on debug_fs and update Kconfig help text")
> since they were only separate commits unintentionally in jbd2.
  Thanks for the patch but is jbd_debug really worth it - especially with
the somewhat ugly jbd1_debug? I don't thing anybody besides kernel
developers really uses it and those can figure how to do what they need...

								Honza
> 
> Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
> ---
>  fs/jbd/Kconfig      |  6 +++---
>  fs/jbd/journal.c    | 49 ++++++++-----------------------------------------
>  include/linux/jbd.h |  3 +--
>  3 files changed, 12 insertions(+), 46 deletions(-)
> 
> diff --git a/fs/jbd/Kconfig b/fs/jbd/Kconfig
> index 4e28bee..54cbb55 100644
> --- a/fs/jbd/Kconfig
> +++ b/fs/jbd/Kconfig
> @@ -15,7 +15,7 @@ config JBD
>  
>  config JBD_DEBUG
>  	bool "JBD (ext3) debugging support"
> -	depends on JBD && DEBUG_FS
> +	depends on JBD
>  	help
>  	  If you are using the ext3 journaled file system (or potentially any
>  	  other file system/device using JBD), this option allows you to
> @@ -24,7 +24,7 @@ config JBD_DEBUG
>  	  debugging output will be turned off.
>  
>  	  If you select Y here, then you will be able to turn on debugging
> -	  with "echo N > /sys/kernel/debug/jbd/jbd-debug", where N is a
> +	  with "echo N > /sys/module/jbd/parameters/jbd1_debug", where N is a
>  	  number between 1 and 5, the higher the number, the more debugging
>  	  output is generated.  To turn debugging off again, do
> -	  "echo 0 > /sys/kernel/debug/jbd/jbd-debug".
> +	  "echo 0 > /sys/module/jbd/parameters/jbd1_debug".
> diff --git a/fs/jbd/journal.c b/fs/jbd/journal.c
> index 6510d63..166263d 100644
> --- a/fs/jbd/journal.c
> +++ b/fs/jbd/journal.c
> @@ -35,7 +35,6 @@
>  #include <linux/kthread.h>
>  #include <linux/poison.h>
>  #include <linux/proc_fs.h>
> -#include <linux/debugfs.h>
>  #include <linux/ratelimit.h>
>  
>  #define CREATE_TRACE_POINTS
> @@ -44,6 +43,14 @@
>  #include <asm/uaccess.h>
>  #include <asm/page.h>
>  
> +#ifdef CONFIG_JBD_DEBUG
> +ushort jbd_journal_enable_debug __read_mostly;
> +EXPORT_SYMBOL(jbd_journal_enable_debug);
> +
> +module_param_named(jbd1_debug, jbd_journal_enable_debug, ushort, 0644);
> +MODULE_PARM_DESC(jbd1_debug, "Debugging level for jbd");
> +#endif
> +
>  EXPORT_SYMBOL(journal_start);
>  EXPORT_SYMBOL(journal_restart);
>  EXPORT_SYMBOL(journal_extend);
> @@ -2017,44 +2024,6 @@ void journal_put_journal_head(struct journal_head *jh)
>  		jbd_unlock_bh_journal_head(bh);
>  }
>  
> -/*
> - * debugfs tunables
> - */
> -#ifdef CONFIG_JBD_DEBUG
> -
> -u8 journal_enable_debug __read_mostly;
> -EXPORT_SYMBOL(journal_enable_debug);
> -
> -static struct dentry *jbd_debugfs_dir;
> -static struct dentry *jbd_debug;
> -
> -static void __init jbd_create_debugfs_entry(void)
> -{
> -	jbd_debugfs_dir = debugfs_create_dir("jbd", NULL);
> -	if (jbd_debugfs_dir)
> -		jbd_debug = debugfs_create_u8("jbd-debug", S_IRUGO | S_IWUSR,
> -					       jbd_debugfs_dir,
> -					       &journal_enable_debug);
> -}
> -
> -static void __exit jbd_remove_debugfs_entry(void)
> -{
> -	debugfs_remove(jbd_debug);
> -	debugfs_remove(jbd_debugfs_dir);
> -}
> -
> -#else
> -
> -static inline void jbd_create_debugfs_entry(void)
> -{
> -}
> -
> -static inline void jbd_remove_debugfs_entry(void)
> -{
> -}
> -
> -#endif
> -
>  struct kmem_cache *jbd_handle_cache;
>  
>  static int __init journal_init_handle_cache(void)
> @@ -2109,7 +2078,6 @@ static int __init journal_init(void)
>  	ret = journal_init_caches();
>  	if (ret != 0)
>  		journal_destroy_caches();
> -	jbd_create_debugfs_entry();
>  	return ret;
>  }
>  
> @@ -2120,7 +2088,6 @@ static void __exit journal_exit(void)
>  	if (n)
>  		printk(KERN_EMERG "JBD: leaked %d journal_heads!\n", n);
>  #endif
> -	jbd_remove_debugfs_entry();
>  	journal_destroy_caches();
>  }
>  
> diff --git a/include/linux/jbd.h b/include/linux/jbd.h
> index 8685d1b..e45b430 100644
> --- a/include/linux/jbd.h
> +++ b/include/linux/jbd.h
> @@ -20,7 +20,6 @@
>  #ifndef __KERNEL__
>  #include "jfs_compat.h"
>  #define JFS_DEBUG
> -#define jfs_debug jbd_debug
>  #else
>  
>  #include <linux/types.h>
> @@ -55,7 +54,7 @@
>   * CONFIG_JBD_DEBUG is on.
>   */
>  #define JBD_EXPENSIVE_CHECKING
> -extern u8 journal_enable_debug;
> +extern ushort journal_enable_debug;
>  
>  #define jbd_debug(n, f, a...)						\
>  	do {								\
> -- 
> 1.8.1.2
> 
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH 2/4] jbd: relocate assert after state lock in journal_commit_transaction()

[Jan Kara]

On Thu 01-08-13 15:01:06, Paul Gortmaker wrote:
> Backport of jbd2 commit 3ca841c106fd6cd2c942985977a5d126434a8dd6
> ("jbd2: relocate assert after state lock in journal_commit_transaction()")
> 
> Quoting that commit:
>  ---------------
>  The state lock is taken after we are doing an assert on the state
>  value, not before.  So we might in fact be doing an assert on a
>  transient value.  Ensure the state check is within the scope of
>  the state lock being taken.
>  ---------------
  Thanks. I've added this patch to my tree.

								Honza
> 
> Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
> ---
>  fs/jbd/commit.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/fs/jbd/commit.c b/fs/jbd/commit.c
> index 11bb11f..bb217dc 100644
> --- a/fs/jbd/commit.c
> +++ b/fs/jbd/commit.c
> @@ -340,13 +340,13 @@ void journal_commit_transaction(journal_t *journal)
>  	J_ASSERT(journal->j_committing_transaction == NULL);
>  
>  	commit_transaction = journal->j_running_transaction;
> -	J_ASSERT(commit_transaction->t_state == T_RUNNING);
>  
>  	trace_jbd_start_commit(journal, commit_transaction);
>  	jbd_debug(1, "JBD: starting commit of transaction %d\n",
>  			commit_transaction->t_tid);
>  
>  	spin_lock(&journal->j_state_lock);
> +	J_ASSERT(commit_transaction->t_state == T_RUNNING);
>  	commit_transaction->t_state = T_LOCKED;
>  
>  	trace_jbd_commit_locking(journal, commit_transaction);
> -- 
> 1.8.1.2
> 
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH 4/4] jbd: use a single printk for jbd_debug()

[Jan Kara]

On Thu 01-08-13 15:01:08, Paul Gortmaker wrote:
> Backport of jbd2 commit 169f1a2a87aae44034da4b9f81be1683d33de6d0
> ("jbd2: use a single printk for jbd_debug()")
> 
> Quoting the original:
>  --------------
>  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.
>  --------------
  Thanks. I've merged the patch to my tree.

								Honza

> 
> Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
> ---
>  fs/jbd/journal.c    | 18 ++++++++++++++++++
>  include/linux/jbd.h | 15 ++++++---------
>  2 files changed, 24 insertions(+), 9 deletions(-)
> 
> diff --git a/fs/jbd/journal.c b/fs/jbd/journal.c
> index 166263d..f45f0a3 100644
> --- a/fs/jbd/journal.c
> +++ b/fs/jbd/journal.c
> @@ -97,6 +97,24 @@ static int journal_convert_superblock_v1(journal_t *, journal_superblock_t *);
>  static void __journal_abort_soft (journal_t *journal, int errno);
>  static const char *journal_dev_name(journal_t *journal, char *buffer);
>  
> +#ifdef CONFIG_JBD_DEBUG
> +void __jbd_debug(int level, const char *file, const char *func,
> +		 unsigned int line, const char *fmt, ...)
> +{
> +	struct va_format vaf;
> +	va_list args;
> +
> +	if (level > jbd_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(__jbd_debug);
> +#endif
> +
>  /*
>   * Helper function used to manage commit timeouts
>   */
> diff --git a/include/linux/jbd.h b/include/linux/jbd.h
> index e45b430..d6d3ae0 100644
> --- a/include/linux/jbd.h
> +++ b/include/linux/jbd.h
> @@ -56,16 +56,13 @@
>  #define JBD_EXPENSIVE_CHECKING
>  extern ushort journal_enable_debug;
>  
> -#define jbd_debug(n, f, a...)						\
> -	do {								\
> -		if ((n) <= journal_enable_debug) {			\
> -			printk (KERN_DEBUG "(%s, %d): %s: ",		\
> -				__FILE__, __LINE__, __func__);	\
> -			printk (f, ## a);				\
> -		}							\
> -	} while (0)
> +void __jbd_debug(int level, const char *file, const char *func,
> +		 unsigned int line, const char *fmt, ...);
> +
> +#define jbd_debug(n, fmt, a...) \
> +	__jbd_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a)
>  #else
> -#define jbd_debug(f, a...)	/**/
> +#define jbd_debug(n, fmt, a...)    /**/
>  #endif
>  
>  static inline void *jbd_alloc(size_t size, gfp_t flags)
> -- 
> 1.8.1.2
> 
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH 4/4] jbd: use a single printk for jbd_debug()

[Jan Kara]

On Thu 01-08-13 12:21:05, Joe Perches wrote:
> On Thu, 2013-08-01 at 15:01 -0400, Paul Gortmaker wrote:
> > Backport of jbd2 commit 169f1a2a87aae44034da4b9f81be1683d33de6d0
> > ("jbd2: use a single printk for jbd_debug()")
> 
> Hey Paul.
> 
> > diff --git a/include/linux/jbd.h b/include/linux/jbd.h
> []
> > @@ -56,16 +56,13 @@
> >  #define JBD_EXPENSIVE_CHECKING
> >  extern ushort journal_enable_debug;
> >  
> > -#define jbd_debug(n, f, a...)						\
> > -	do {								\
> > -		if ((n) <= journal_enable_debug) {			\
> > -			printk (KERN_DEBUG "(%s, %d): %s: ",		\
> > -				__FILE__, __LINE__, __func__);	\
> > -			printk (f, ## a);				\
> > -		}							\
> > -	} while (0)
> > +void __jbd_debug(int level, const char *file, const char *func,
> > +		 unsigned int line, const char *fmt, ...
> > +
> > +#define jbd_debug(n, fmt, a...) \
> > +	__jbd_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a)
> >  #else
> > -#define jbd_debug(f, a...)	/**/
> > +#define jbd_debug(n, fmt, a...)    /**/
> >  #endif
> 
> It might have been (and may still be) simpler/better
> to use a single macro like:
> 
> #define jbd_dbg(n, fmt, ...)			\
> do {						\
> 	if ((n) < journal_enable_debug)		\
> 		pr_debug(fmt, ##__VA_ARGS__);	\
> } while (0)
> 
> and then use dynamic_debug to add the __func__,
> and __LINE__ when desired.
> 
> echo -n 'module jbd +pfl' <dynamic_debug>/control
  Umm, I like the Paul's way better. Sure we have to jump into
__jbd_debug() even if we won't write any message because debug level is low
but OTOH jbd_debug() is non-empty only when JBD_EXPENSIVE_CHECKING is
enabled. So there the extra call is fine.

								Honza
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH 3/4] jbd: drop checkpoint mutex when waiting in __log_wait_for_space()

[Jan Kara]

On Thu 01-08-13 15:01:07, Paul Gortmaker wrote:
> Backport of jbd2 commit 0ef54180e0187117062939202b96faf04c8673bc
> ("jbd2: drop checkpoint mutex when waiting in __jbd2_log_wait_for_space()")
> 
> Quoting that commit:
>  --------------
>  While trying to debug an an issue under extreme I/O loading
>  on preempt-rt kernels, the following backtrace was observed
>  via SysRQ output:
> 
>  rm              D ffff8802203afbc0  4600  4878   4748 0x00000000
>   ffff8802217bfb78 0000000000000082 ffff88021fc2bb80 ffff88021fc2bb80
>   ffff88021fc2bb80 ffff8802217bffd8 ffff8802217bffd8 ffff8802217bffd8
>   ffff88021f1d4c80 ffff88021fc2bb80 ffff8802217bfb88 ffff88022437b000
>  Call Trace:
>   [<ffffffff8172dc34>] schedule+0x24/0x70
>   [<ffffffff81225b5d>] jbd2_log_wait_commit+0xbd/0x140
>   [<ffffffff81060390>] ? __init_waitqueue_head+0x50/0x50
>   [<ffffffff81223635>] jbd2_log_do_checkpoint+0xf5/0x520
>   [<ffffffff81223b09>] __jbd2_log_wait_for_space+0xa9/0x1f0
>   [<ffffffff8121dc40>] start_this_handle.isra.10+0x2e0/0x530
>   [<ffffffff81060390>] ? __init_waitqueue_head+0x50/0x50
>   [<ffffffff8121e0a3>] jbd2__journal_start+0xc3/0x110
>   [<ffffffff811de7ce>] ? ext4_rmdir+0x6e/0x230
>   [<ffffffff8121e0fe>] jbd2_journal_start+0xe/0x10
>   [<ffffffff811f308b>] ext4_journal_start_sb+0x5b/0x160
>   [<ffffffff811de7ce>] ext4_rmdir+0x6e/0x230
>   [<ffffffff811435c5>] vfs_rmdir+0xd5/0x140
>   [<ffffffff8114370f>] do_rmdir+0xdf/0x120
>   [<ffffffff8105c6b4>] ? task_work_run+0x44/0x80
>   [<ffffffff81002889>] ? do_notify_resume+0x89/0x100
>   [<ffffffff817361ae>] ? int_signal+0x12/0x17
>   [<ffffffff81145d85>] sys_unlinkat+0x25/0x40
>   [<ffffffff81735f22>] system_call_fastpath+0x16/0x1b
> 
>  What is interesting here, is that we call log_wait_commit, from
>  within wait_for_space, but we are still holding the checkpoint_mutex
>  as it surrounds mostly the whole of wait_for_space.  And then, as we
>  are waiting, journal_commit_transaction can run, and if the JBD2_FLUSHED
>  bit is set, then we will also try to take the same checkpoint_mutex.
> 
>  It seems that we need to drop the checkpoint_mutex while sitting in
>  jbd2_log_wait_commit, if we want to guarantee that progress can be made
>  by jbd2_journal_commit_transaction().  There does not seem to be
>  anything preempt-rt specific about this, other then perhaps increasing
>  the odds of it happening.
>  --------------
  As much as this is a sensible optimization, I don't agree with the
analysis that the system can deadlock when JBD2_FLUSHED is set. We call
jbd2_log_wait_commit() only if there is already committing transaction and
that gets set *after* JBD2_FLUSHED is handled. So it would be good if you
went back and actually checked where exactly did we hang in
jbd2_journal_commit_transaction()...

								Honza
> 
> Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
> ---
>  fs/jbd/checkpoint.c | 8 ++++++++
>  1 file changed, 8 insertions(+)
> 
> diff --git a/fs/jbd/checkpoint.c b/fs/jbd/checkpoint.c
> index 08c0304..8e8e0ee 100644
> --- a/fs/jbd/checkpoint.c
> +++ b/fs/jbd/checkpoint.c
> @@ -160,7 +160,15 @@ void __log_wait_for_space(journal_t *journal)
>  				/* We were able to recover space; yay! */
>  				;
>  			} else if (tid) {
> +				/*
> +				 * jbd_journal_commit_transaction() may want
> +				 * to take the checkpoint_mutex if JBD_FLUSHED
> +				 * is set.  So we need to temporarily drop it.
> +				 */
> +				mutex_unlock(&journal->j_checkpoint_mutex);
>  				log_wait_commit(journal, tid);
> +				spin_lock(&journal->j_state_lock);
> +				continue;
>  			} else {
>  				printk(KERN_ERR "%s: needed %d blocks and "
>  				       "only had %d space available\n",
> -- 
> 1.8.1.2
> 
-- 
Jan Kara <jack@suse.cz>
SUSE Labs, CR

Re: [PATCH 1/4] jbd: use module parameters instead of debugfs for jbd_debug

[Paul Gortmaker]

[Re: [PATCH 1/4] jbd: use module parameters instead of debugfs for jbd_debug] On 01/08/2013 (Thu 23:24) Jan Kara wrote:

> On Thu 01-08-13 15:01:05, Paul Gortmaker wrote:
> > This is a direct backport of commit b6e96d0067d81f6a300bedee
> > ("jbd2: use module parameters instead of debugfs for jbd_debug")
> > from jbd2 into jbd.  The value is in making ext4 and ext3 user
> > experiences consistent with each other.  Quoting the original:
> > 
> >  --------------
> >  There are multiple reasons to move away from debugfs.  First of all,
> >  we are only using it for a single parameter, and it is much more
> >  complicated to set up (some 30 lines of code compared to 3), and one
> >  more thing that might fail while loading the jbd2 module.
> > 
> >  Secondly, as a module paramter it can be specified as a boot option if
> >  jbd2 is built into the kernel, or as a parameter when the module is
> >  loaded, and it can also be manipulated dynamically under
> >  /sys/module/jbd2/parameters/jbd2_debug.  So it is more flexible.
> > 
> >  Ultimately we want to move away from using jbd_debug() towards
> >  tracepoints, but for now this is still a useful simplification of the
> >  code base.
> >  --------------
> > 
> > It is worth noting that we use /sys/module/jbd/parameters/jbd1_debug
> > (i.e. the "1" might appear odd) for the module parameter in order to
> > avoid namespace collisions with the existing jbd_debug used as a
> > function call.
> > 
> > In addition, we combine the content of jbd2 commit 75497d0607b56e16e4
> > ("jbd2: remove debug dependency on debug_fs and update Kconfig help text")
> > since they were only separate commits unintentionally in jbd2.
>   Thanks for the patch but is jbd_debug really worth it - especially with
> the somewhat ugly jbd1_debug? I don't thing anybody besides kernel
> developers really uses it and those can figure how to do what they need...

It is your call; I agree that people who use jbd_debug are going to be
only people who are motivated to do so, and hence most likely kernel
developers.  So I won't be upset if you want to drop this patch.

Thanks,
Paul.
--
> 
> 								Honza
> > 
> > Signed-off-by: Paul Gortmaker <paul.gortmaker@windriver.com>
> > ---
> >  fs/jbd/Kconfig      |  6 +++---
> >  fs/jbd/journal.c    | 49 ++++++++-----------------------------------------
> >  include/linux/jbd.h |  3 +--
> >  3 files changed, 12 insertions(+), 46 deletions(-)
> > 
> > diff --git a/fs/jbd/Kconfig b/fs/jbd/Kconfig
> > index 4e28bee..54cbb55 100644
> > --- a/fs/jbd/Kconfig
> > +++ b/fs/jbd/Kconfig
> > @@ -15,7 +15,7 @@ config JBD
> >  
> >  config JBD_DEBUG
> >  	bool "JBD (ext3) debugging support"
> > -	depends on JBD && DEBUG_FS
> > +	depends on JBD
> >  	help
> >  	  If you are using the ext3 journaled file system (or potentially any
> >  	  other file system/device using JBD), this option allows you to
> > @@ -24,7 +24,7 @@ config JBD_DEBUG
> >  	  debugging output will be turned off.
> >  
> >  	  If you select Y here, then you will be able to turn on debugging
> > -	  with "echo N > /sys/kernel/debug/jbd/jbd-debug", where N is a
> > +	  with "echo N > /sys/module/jbd/parameters/jbd1_debug", where N is a
> >  	  number between 1 and 5, the higher the number, the more debugging
> >  	  output is generated.  To turn debugging off again, do
> > -	  "echo 0 > /sys/kernel/debug/jbd/jbd-debug".
> > +	  "echo 0 > /sys/module/jbd/parameters/jbd1_debug".
> > diff --git a/fs/jbd/journal.c b/fs/jbd/journal.c
> > index 6510d63..166263d 100644
> > --- a/fs/jbd/journal.c
> > +++ b/fs/jbd/journal.c
> > @@ -35,7 +35,6 @@
> >  #include <linux/kthread.h>
> >  #include <linux/poison.h>
> >  #include <linux/proc_fs.h>
> > -#include <linux/debugfs.h>
> >  #include <linux/ratelimit.h>
> >  
> >  #define CREATE_TRACE_POINTS
> > @@ -44,6 +43,14 @@
> >  #include <asm/uaccess.h>
> >  #include <asm/page.h>
> >  
> > +#ifdef CONFIG_JBD_DEBUG
> > +ushort jbd_journal_enable_debug __read_mostly;
> > +EXPORT_SYMBOL(jbd_journal_enable_debug);
> > +
> > +module_param_named(jbd1_debug, jbd_journal_enable_debug, ushort, 0644);
> > +MODULE_PARM_DESC(jbd1_debug, "Debugging level for jbd");
> > +#endif
> > +
> >  EXPORT_SYMBOL(journal_start);
> >  EXPORT_SYMBOL(journal_restart);
> >  EXPORT_SYMBOL(journal_extend);
> > @@ -2017,44 +2024,6 @@ void journal_put_journal_head(struct journal_head *jh)
> >  		jbd_unlock_bh_journal_head(bh);
> >  }
> >  
> > -/*
> > - * debugfs tunables
> > - */
> > -#ifdef CONFIG_JBD_DEBUG
> > -
> > -u8 journal_enable_debug __read_mostly;
> > -EXPORT_SYMBOL(journal_enable_debug);
> > -
> > -static struct dentry *jbd_debugfs_dir;
> > -static struct dentry *jbd_debug;
> > -
> > -static void __init jbd_create_debugfs_entry(void)
> > -{
> > -	jbd_debugfs_dir = debugfs_create_dir("jbd", NULL);
> > -	if (jbd_debugfs_dir)
> > -		jbd_debug = debugfs_create_u8("jbd-debug", S_IRUGO | S_IWUSR,
> > -					       jbd_debugfs_dir,
> > -					       &journal_enable_debug);
> > -}
> > -
> > -static void __exit jbd_remove_debugfs_entry(void)
> > -{
> > -	debugfs_remove(jbd_debug);
> > -	debugfs_remove(jbd_debugfs_dir);
> > -}
> > -
> > -#else
> > -
> > -static inline void jbd_create_debugfs_entry(void)
> > -{
> > -}
> > -
> > -static inline void jbd_remove_debugfs_entry(void)
> > -{
> > -}
> > -
> > -#endif
> > -
> >  struct kmem_cache *jbd_handle_cache;
> >  
> >  static int __init journal_init_handle_cache(void)
> > @@ -2109,7 +2078,6 @@ static int __init journal_init(void)
> >  	ret = journal_init_caches();
> >  	if (ret != 0)
> >  		journal_destroy_caches();
> > -	jbd_create_debugfs_entry();
> >  	return ret;
> >  }
> >  
> > @@ -2120,7 +2088,6 @@ static void __exit journal_exit(void)
> >  	if (n)
> >  		printk(KERN_EMERG "JBD: leaked %d journal_heads!\n", n);
> >  #endif
> > -	jbd_remove_debugfs_entry();
> >  	journal_destroy_caches();
> >  }
> >  
> > diff --git a/include/linux/jbd.h b/include/linux/jbd.h
> > index 8685d1b..e45b430 100644
> > --- a/include/linux/jbd.h
> > +++ b/include/linux/jbd.h
> > @@ -20,7 +20,6 @@
> >  #ifndef __KERNEL__
> >  #include "jfs_compat.h"
> >  #define JFS_DEBUG
> > -#define jfs_debug jbd_debug
> >  #else
> >  
> >  #include <linux/types.h>
> > @@ -55,7 +54,7 @@
> >   * CONFIG_JBD_DEBUG is on.
> >   */
> >  #define JBD_EXPENSIVE_CHECKING
> > -extern u8 journal_enable_debug;
> > +extern ushort journal_enable_debug;
> >  
> >  #define jbd_debug(n, f, a...)						\
> >  	do {								\
> > -- 
> > 1.8.1.2
> > 
> -- 
> Jan Kara <jack@suse.cz>
> SUSE Labs, CR