make jbd2 debug switch per device
Subsystems (2)
v2 cover make jbd2 debug switch per device
On a multi-disk machine, because jbd2 debugging switch is global, this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
We can enable jbd2 debugging of a device in the following ways:
echo X > /proc/fs/jbd2/sdX/jbd2_debug
But there is a small disadvantage here. Because the debugging switch is placed in the journal_t object, the log before the object is initialized will be lost. However, usually this will not have much impact on debugging.
Chunguang Xu (4):
jbd2: make jdb2_debug module parameter per device
jbd2: introduce some new log interfaces
jbd2: replace jbd_debug with the new log interface
ext4: replace jbd_debug with the new log interface
fs/ext4/balloc.c | 2 +- fs/ext4/ext4_jbd2.c | 3 +- fs/ext4/fast_commit.c | 64 +++++++++++++----------- fs/ext4/indirect.c | 4 +- fs/ext4/inode.c | 3 +- fs/ext4/namei.c | 10 ++-- fs/ext4/super.c | 16 +++--- fs/jbd2/checkpoint.c | 6 +-- fs/jbd2/commit.c | 36 ++++++------- fs/jbd2/journal.c | 114 +++++++++++++++++++++++++++++------------- fs/jbd2/recovery.c | 59 +++++++++++----------- fs/jbd2/revoke.c | 8 +-- fs/jbd2/transaction.c | 35 ++++++------- include/linux/jbd2.h | 66 +++++++++++++++++------- 14 files changed, 258 insertions(+), 168 deletions(-)
Signature · 1 line
2.30.0
RFC PATCH v2 1/4 jbd2: make jdb2_debug module parameter per device
From: Chunguang Xu <[email protected]>
On a multi-disk machine, because jbd2's debugging switch is global,this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
--- fs/jbd2/journal.c | 55 ++++++++++++++++++++++++++++++++++++++++--- fs/jbd2/transaction.c | 2 +- include/linux/jbd2.h | 7 ++++++ 3 files changed, 60 insertions(+), 4 deletions(-)
fs/jbd2/journal.c +52 -3
@@ -101,13 +101,13 @@ EXPORT_SYMBOL(jbd2_inode_cache);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, +void jbd2_log (int level,journal_t *j,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) +if (!j || (level > jbd2_journal_enable_debug && level > j->j_debug_level))return ;va_start (args, fmt); vaf.fmt = fmt;
@@ -115,7 +115,7 @@ void __jbd2_debug(int level, const char *file, const char *func,printk (KERN_DEBUG "%s: (%s, %u): %pV" , file, func, line, &vaf); va_end(args); } -EXPORT_SYMBOL (__jbd2_debug); +EXPORT_SYMBOL (jbd2_log);#endif /* Checksumming functions */
@@ -1257,6 +1257,48 @@ static int jbd2_seq_info_release(struct inode *inode, struct file *file)return seq_release (inode, file); } +#ifdef CONFIG_JBD2_DEBUG +static int jbd2_proc_debug_show (struct seq_file *m,void *v) +{ +journal_t *j = m->private; + +seq_printf (m,"%d\n" , j->j_debug_level); +return 0 ; +} + +static int jbd2_proc_debug_open (struct inode *inode,struct file *file) +{ +journal_t *journal =PDE_DATA (inode); + +return single_open (file, jbd2_proc_debug_show, journal); +} + +static ssize_t jbd2_proc_debug_write (struct file *file, +const char __user *buffer,size_t count,loff_t *ppos) +{ +struct seq_file *seq = file->private_data; +journal_t *j = seq->private; +char c; + +if (get_user (c, buffer)) +return -EFAULT ; + +if (c <'0' || c >'5' ) +return -EINVAL ; + + j->j_debug_level = c -'0' ; +return count; +} + +static const struct proc_ops jbd2_debug_proc_ops = { + .proc_open = jbd2_proc_debug_open, + .proc_read = seq_read, + .proc_write = jbd2_proc_debug_write, + .proc_release = single_release, + .proc_lseek = seq_lseek, +}; +#endif +static const struct proc_ops jbd2_info_proc_ops = { .proc_open = jbd2_seq_info_open, .proc_read = seq_read,
@@ -1272,12 +1314,19 @@ static void jbd2_stats_proc_init(journal_t *journal)if (journal->j_proc_entry) {proc_create_data ("info" ,S_IRUGO , journal->j_proc_entry, &jbd2_info_proc_ops, journal); +#ifdef CONFIG_JBD2_DEBUG +proc_create_data ("jbd2_debug" ,S_IRUGO , journal->j_proc_entry, + &jbd2_debug_proc_ops, journal); +#endif } }static void jbd2_stats_proc_exit (journal_t *journal) {remove_proc_entry ("info" , journal->j_proc_entry); +#ifdef CONFIG_JBD2_DEBUG +remove_proc_entry ("jbd2_debug" , journal->j_proc_entry); +#endif remove_proc_entry (journal->j_devname, proc_jbd2_stats); }
fs/jbd2/transaction.c +1 -1
@@ -150,7 +150,7 @@ static inline void update_t_max_wait(transaction_t *transaction, unsigned long ts) {#ifdef CONFIG_JBD2_DEBUG -if (jbd2_journal_enable_debug && +if ((jbd2_journal_enable_debug || transaction->t_journal->j_debug_level) &&time_after (transaction->t_start, ts)) { ts =jbd2_time_diff (ts, transaction->t_start);spin_lock (&transaction->t_handle_lock);
include/linux/jbd2.h +7 -0
@@ -1211,6 +1211,13 @@ struct journal_s*/ struct transaction_stats_s j_stats; +#ifdef CONFIG_JBD2_DEBUG +/** +* @j_debug_level: debugging level for jbd2. +*/ +unsigned int j_debug_level; +#endif +/** * @j_failed_commit: Failed journal commit ID. */
Signature · 1 line
2.30.0
Re: [RFC PATCH v2 1/4] jbd2: make jdb2_debug module parameter per device
Hey hi! I don't see my previous comments being handled here or am I missing something? It'd be really handy to have the device name printed in jbd2 logs.
Quoted 149 lines · Chunguang Xu
From: Chunguang Xu <[email protected]>
On a multi-disk machine, because jbd2's debugging switch is global,this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
Signed-off-by Chunguang Xu <[email protected]>Reviewed-by Harshad Shirwadkar <[email protected]>--- fs/jbd2/journal.c | 55 ++++++++++++++++++++++++++++++++++++++++--- fs/jbd2/transaction.c | 2 +- include/linux/jbd2.h | 7 ++++++ 3 files changed, 60 insertions(+), 4 deletions(-)fs/jbd2/journal.c +52
-3@@ -101,13 +101,13 @@ EXPORT_SYMBOL(jbd2_inode_cache);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, +void jbd2_log (int level,journal_t *j,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) +if (!j || (level > jbd2_journal_enable_debug && level > j->j_debug_level))return ;va_start (args, fmt); vaf.fmt = fmt;@@ -115,7 +115,7 @@ void __jbd2_debug(int level, const char *file, const char *func,printk (KERN_DEBUG "%s: (%s, %u): %pV" , file, func, line, &vaf); va_end(args); } -EXPORT_SYMBOL (__jbd2_debug); +EXPORT_SYMBOL (jbd2_log);#endif /* Checksumming functions */ @@ -1257,6 +1257,48 @@ static int jbd2_seq_info_release(struct inode *inode, struct file *file)return seq_release (inode, file); } +#ifdef CONFIG_JBD2_DEBUG +static int jbd2_proc_debug_show (struct seq_file *m,void *v) +{ +journal_t *j = m->private; + +seq_printf (m,"%d\n" , j->j_debug_level); +return 0 ; +} + +static int jbd2_proc_debug_open (struct inode *inode,struct file *file) +{ +journal_t *journal =PDE_DATA (inode); + +return single_open (file, jbd2_proc_debug_show, journal); +} + +static ssize_t jbd2_proc_debug_write (struct file *file, +const char __user *buffer,size_t count,loff_t *ppos) +{ +struct seq_file *seq = file->private_data; +journal_t *j = seq->private; +char c; + +if (get_user (c, buffer)) +return -EFAULT ; + +if (c <'0' || c >'5' ) +return -EINVAL ; + + j->j_debug_level = c -'0' ; +return count; +} + +static const struct proc_ops jbd2_debug_proc_ops = { + .proc_open = jbd2_proc_debug_open, + .proc_read = seq_read, + .proc_write = jbd2_proc_debug_write, + .proc_release = single_release, + .proc_lseek = seq_lseek, +}; +#endif +static const struct proc_ops jbd2_info_proc_ops = { .proc_open = jbd2_seq_info_open, .proc_read = seq_read,@@ -1272,12 +1314,19 @@ static void jbd2_stats_proc_init(journal_t *journal)if (journal->j_proc_entry) {proc_create_data ("info" ,S_IRUGO , journal->j_proc_entry, &jbd2_info_proc_ops, journal); +#ifdef CONFIG_JBD2_DEBUG +proc_create_data ("jbd2_debug" ,S_IRUGO , journal->j_proc_entry, + &jbd2_debug_proc_ops, journal); +#endif } }static void jbd2_stats_proc_exit (journal_t *journal) {remove_proc_entry ("info" , journal->j_proc_entry); +#ifdef CONFIG_JBD2_DEBUG +remove_proc_entry ("jbd2_debug" , journal->j_proc_entry); +#endif remove_proc_entry (journal->j_devname, proc_jbd2_stats); }fs/jbd2/transaction.c +1
-1@@ -150,7 +150,7 @@ static inline void update_t_max_wait(transaction_t *transaction, unsigned long ts) {#ifdef CONFIG_JBD2_DEBUG -if (jbd2_journal_enable_debug && +if ((jbd2_journal_enable_debug || transaction->t_journal->j_debug_level) &&time_after (transaction->t_start, ts)) { ts =jbd2_time_diff (ts, transaction->t_start);spin_lock (&transaction->t_handle_lock);include/linux/jbd2.h +7
-1@@ -1211,6 +1211,13 @@ struct journal_s*/ struct transaction_stats_s j_stats; +#ifdef CONFIG_JBD2_DEBUG +/** +* @j_debug_level: debugging level for jbd2. +*/ +unsigned int j_debug_level; +#endif +/** * @j_failed_commit: Failed journal commit ID. */ --2.30.0
Re: [RFC PATCH v2 1/4] jbd2: make jdb2_debug module parameter per device
harshad shirwadkar wrote on 2021/1/26 1:15:
Quoted 3 lines
Hey hi! I don't see my previous comments being handled here or am I missing something? It'd be really handy to have the device name printed in jbd2 logs.
Maybe I miss something..,the origin switch has been reserved, the new added switch and the origin switch together determine whether the log of a certain device is finally output. . Also, I will add device information to the next version.thanks.
Quoted 150 lines · Chunguang Xu
Quoted 149 lines
From: Chunguang Xu <[email protected]>
On a multi-disk machine, because jbd2's debugging switch is global,this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
Signed-off-by Chunguang Xu <[email protected]>Reviewed-by Harshad Shirwadkar <[email protected]>--- fs/jbd2/journal.c | 55 ++++++++++++++++++++++++++++++++++++++++--- fs/jbd2/transaction.c | 2 +- include/linux/jbd2.h | 7 ++++++ 3 files changed, 60 insertions(+), 4 deletions(-)fs/jbd2/journal.c +52
-3@@ -101,13 +101,13 @@ EXPORT_SYMBOL(jbd2_inode_cache);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, +void jbd2_log (int level,journal_t *j,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) +if (!j || (level > jbd2_journal_enable_debug && level > j->j_debug_level))return ;va_start (args, fmt); vaf.fmt = fmt;@@ -115,7 +115,7 @@ void __jbd2_debug(int level, const char *file, const char *func,printk (KERN_DEBUG "%s: (%s, %u): %pV" , file, func, line, &vaf); va_end(args); } -EXPORT_SYMBOL (__jbd2_debug); +EXPORT_SYMBOL (jbd2_log);#endif /* Checksumming functions */ @@ -1257,6 +1257,48 @@ static int jbd2_seq_info_release(struct inode *inode, struct file *file)return seq_release (inode, file); } +#ifdef CONFIG_JBD2_DEBUG +static int jbd2_proc_debug_show (struct seq_file *m,void *v) +{ +journal_t *j = m->private; + +seq_printf (m,"%d\n" , j->j_debug_level); +return 0 ; +} + +static int jbd2_proc_debug_open (struct inode *inode,struct file *file) +{ +journal_t *journal =PDE_DATA (inode); + +return single_open (file, jbd2_proc_debug_show, journal); +} + +static ssize_t jbd2_proc_debug_write (struct file *file, +const char __user *buffer,size_t count,loff_t *ppos) +{ +struct seq_file *seq = file->private_data; +journal_t *j = seq->private; +char c; + +if (get_user (c, buffer)) +return -EFAULT ; + +if (c <'0' || c >'5' ) +return -EINVAL ; + + j->j_debug_level = c -'0' ; +return count; +} + +static const struct proc_ops jbd2_debug_proc_ops = { + .proc_open = jbd2_proc_debug_open, + .proc_read = seq_read, + .proc_write = jbd2_proc_debug_write, + .proc_release = single_release, + .proc_lseek = seq_lseek, +}; +#endif +static const struct proc_ops jbd2_info_proc_ops = { .proc_open = jbd2_seq_info_open, .proc_read = seq_read,@@ -1272,12 +1314,19 @@ static void jbd2_stats_proc_init(journal_t *journal)if (journal->j_proc_entry) {proc_create_data ("info" ,S_IRUGO , journal->j_proc_entry, &jbd2_info_proc_ops, journal); +#ifdef CONFIG_JBD2_DEBUG +proc_create_data ("jbd2_debug" ,S_IRUGO , journal->j_proc_entry, + &jbd2_debug_proc_ops, journal); +#endif } }static void jbd2_stats_proc_exit (journal_t *journal) {remove_proc_entry ("info" , journal->j_proc_entry); +#ifdef CONFIG_JBD2_DEBUG +remove_proc_entry ("jbd2_debug" , journal->j_proc_entry); +#endif remove_proc_entry (journal->j_devname, proc_jbd2_stats); }fs/jbd2/transaction.c +1
-1@@ -150,7 +150,7 @@ static inline void update_t_max_wait(transaction_t *transaction, unsigned long ts) {#ifdef CONFIG_JBD2_DEBUG -if (jbd2_journal_enable_debug && +if ((jbd2_journal_enable_debug || transaction->t_journal->j_debug_level) &&time_after (transaction->t_start, ts)) { ts =jbd2_time_diff (ts, transaction->t_start);spin_lock (&transaction->t_handle_lock);include/linux/jbd2.h +7
-1@@ -1211,6 +1211,13 @@ struct journal_s*/ struct transaction_stats_s j_stats; +#ifdef CONFIG_JBD2_DEBUG +/** +* @j_debug_level: debugging level for jbd2. +*/ +unsigned int j_debug_level; +#endif +/** * @j_failed_commit: Failed journal commit ID. */ --2.30.0
RFC PATCH v2 2/4 jbd2: introduce some new log interfaces
In reply to Chunguang XuFrom: Chunguang Xu <[email protected]>
Compared to directly using numbers to indicate levels, using abstract error, warn, notice, info, debug to indicate levels may be more convenient for code reading and writing. Similar to other kernel modules, some basic log interfaces are introduced.
--- include/linux/jbd2.h | 59 +++++++++++++++++++++++++++++++------------- 1 file changed, 42 insertions(+), 17 deletions(-)
include/linux/jbd2.h +42 -17
@@ -47,23 +47,6 @@*/ #define JBD2_DEFAULT_MAX_COMMIT_AGE 5 -#ifdef CONFIG_JBD2_DEBUG -/* -* Define JBD2_EXPENSIVE_CHECKING to enable more expensive internal -* consistency checks. By default we don't do this unless -* CONFIG_JBD2_DEBUG is on. -*/ -#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, fmt, a...) \ - __jbd2_debug((n), __FILE__, __func__, __LINE__, (fmt), ##a) -#else -#define jbd_debug(n, fmt, a...) /**/ -#endif -extern void *jbd2_alloc (size_t size,gfp_t flags);extern void jbd2_free (void *ptr,size_t size);
@@ -104,6 +87,48 @@ typedef struct jbd2_journal_handle handle_t; /* Atomic operation type */* This is an opaque datatype. **/ typedef struct journal_s journal_t ;/* Journal control structure */ + +#ifdef CONFIG_JBD2_DEBUG +/* +* Define JBD2_EXPENSIVE_CHECKING to enable more expensive internal +* consistency checks. By default we don't do this unless +* CONFIG_JBD2_DEBUG is on. +*/ +#define JBD2_EXPENSIVE_CHECKING +extern ushort jbd2_journal_enable_debug; +void jbd2_log (int level,journal_t *j,const char *file,const char *func, +unsigned int line,const char *fmt, ...); + +#define JBD2_ERR 1/* error conditions */ +#define JBD2_WARN 2/* warning conditions */ +#define JBD2_NOTICE 3/* normal but significant condition */ +#define JBD2_INFO 4/* informational */ +#define JBD2_DEBUG 5/* debug-level messages */ + +#define jbd2_err(j, fmt, a...) \ + jbd2_log(JBD2_ERR, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_warn(j, fmt, a...) \ + jbd2_log(JBD2_WARN, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_notice(j, fmt, a...) \ + jbd2_log(JBD2_NOTICE, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_info(j, fmt, a...) \ + jbd2_log(JBD2_INFO, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_debug(j, fmt, a...) \ + jbd2_log(JBD2_DEBUG, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#else + +#define jbd2_err(j, fmt, a...) +#define jbd2_warn(j, fmt, a...) +#define jbd2_notice(j, fmt, a...) +#define jbd2_info(j, fmt, a...) +#define jbd2_debug(j, fmt, a...) + +#endif #endif /*
Signature · 1 line
2.30.0
Jan Kara
reviewerRe: [RFC PATCH v2 2/4] jbd2: introduce some new log interfaces
Quoted 8 lines · Chunguang Xu
From: Chunguang Xu <[email protected]>
Compared to directly using numbers to indicate levels, using abstract error, warn, notice, info, debug to indicate levels may be more convenient for code reading and writing. Similar to other kernel modules, some basic log interfaces are introduced.
Signed-off-by Chunguang Xu <[email protected]>
One more thing I've noticed when reading this patch:
Quoted 7 lines
include/linux/jbd2.h +7
-0+ +#ifdef CONFIG_JBD2_DEBUG +/* +* Define JBD2_EXPENSIVE_CHECKING to enable more expensive internal +* consistency checks. By default we don't do this unless +* CONFIG_JBD2_DEBUG is on. +*/
include/linux/jbd2.h typedef struct jbd2_journal_handle handle_t; /* Atomic operation type */ · line 106
Quoted 10 lines
include/linux/jbd2.h +10
-0+#define JBD2_EXPENSIVE_CHECKING +extern ushort jbd2_journal_enable_debug; +void jbd2_log (int level,journal_t *j,const char *file,const char *func, +unsigned int line,const char *fmt, ...); + +#define JBD2_ERR 1/* error conditions */ +#define JBD2_WARN 2/* warning conditions */ +#define JBD2_NOTICE 3/* normal but significant condition */ +#define JBD2_INFO 4/* informational */ +#define JBD2_DEBUG 5/* debug-level messages */
This is actually not true. All the jbd_debug() messages are really debug messages, not errors, not warnings. It is just a different level of detail. Honestly, these days, I'd rather discard all the levels, use pr_debug() function to print these messages inside jdb2_debug() and defer to CONFIG_DYNAMIC_DEBUG framework for configuration of which messages are interesting for a particular debug session.
Honza
Quoted 31 lines
include/linux/jbd2.h +25
-0+ +#define jbd2_err(j, fmt, a...) \ + jbd2_log(JBD2_ERR, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_warn(j, fmt, a...) \ + jbd2_log(JBD2_WARN, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_notice(j, fmt, a...) \ + jbd2_log(JBD2_NOTICE, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_info(j, fmt, a...) \ + jbd2_log(JBD2_INFO, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_debug(j, fmt, a...) \ + jbd2_log(JBD2_DEBUG, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#else + +#define jbd2_err(j, fmt, a...) +#define jbd2_warn(j, fmt, a...) +#define jbd2_notice(j, fmt, a...) +#define jbd2_info(j, fmt, a...) +#define jbd2_debug(j, fmt, a...) + +#endif #endif /* Signature · 1 line
2.30.0
Signature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Re: [RFC PATCH v2 2/4] jbd2: introduce some new log interfaces
Jan Kara wrote on 2021/1/25 22:54:
Quoted 28 lines · Chunguang Xu
Quoted 8 lines
From: Chunguang Xu <[email protected]>
Compared to directly using numbers to indicate levels, using abstract error, warn, notice, info, debug to indicate levels may be more convenient for code reading and writing. Similar to other kernel modules, some basic log interfaces are introduced.
Signed-off-by Chunguang Xu <[email protected]>One more thing I've noticed when reading this patch:
Quoted 16 lines
include/linux/jbd2.h +16
-0+ +#ifdef CONFIG_JBD2_DEBUG +/* +* Define JBD2_EXPENSIVE_CHECKING to enable more expensive internal +* consistency checks. By default we don't do this unless +* CONFIG_JBD2_DEBUG is on. +*/ +#define JBD2_EXPENSIVE_CHECKING +extern ushort jbd2_journal_enable_debug; +void jbd2_log (int level,journal_t *j,const char *file,const char *func, +unsigned int line,const char *fmt, ...); + +#define JBD2_ERR 1/* error conditions */ +#define JBD2_WARN 2/* warning conditions */ +#define JBD2_NOTICE 3/* normal but significant condition */ +#define JBD2_INFO 4/* informational */
Quoted 8 lines
Quoted 1 line
+#define
JBD2_DEBUG5 /* debug-level messages */This is actually not true. All the
jbd_debug()messages are really debug messages, not errors, not warnings. It is just a different level of detail. Honestly, these days, I'd rather discard all the levels, usepr_debug()function to print these messages insidejdb2_debug()and defer toCONFIG_DYNAMIC_DEBUGframework for configuration of which messages are interesting for a particular debug session.
From a certain point, this is indeed, maybe the changes here are not necessary. Thanks.
Quoted 33 lines
Honza
Quoted 31 lines
include/linux/jbd2.h +25
-0+ +#define jbd2_err(j, fmt, a...) \ + jbd2_log(JBD2_ERR, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_warn(j, fmt, a...) \ + jbd2_log(JBD2_WARN, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_notice(j, fmt, a...) \ + jbd2_log(JBD2_NOTICE, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_info(j, fmt, a...) \ + jbd2_log(JBD2_INFO, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#define jbd2_debug(j, fmt, a...) \ + jbd2_log(JBD2_DEBUG, j, __FILE__, __func__, __LINE__, (fmt), ##a) + +#else + +#define jbd2_err(j, fmt, a...) +#define jbd2_warn(j, fmt, a...) +#define jbd2_notice(j, fmt, a...) +#define jbd2_info(j, fmt, a...) +#define jbd2_debug(j, fmt, a...) + +#endif #endif /* Signature · 1 line
2.30.0
RFC PATCH v2 3/4 jbd2: replace jbd_debug with the new log interface
In reply to Chunguang XuFrom: Chunguang Xu <[email protected]>
In order to support jbd2 per device debugging switch, here we need to replace jbd_debug with a new log interface. But there is a small disadvantage here. Because the debugging switch is placed in the journal_t object, the log before the object is initialized will be lost. However, usually this will not have much impact on debugging.
--- fs/jbd2/checkpoint.c | 6 ++--- fs/jbd2/commit.c | 36 +++++++++++++------------- fs/jbd2/journal.c | 59 ++++++++++++++++++++----------------------- fs/jbd2/recovery.c | 59 +++++++++++++++++++++++-------------------- fs/jbd2/revoke.c | 8 +++--- fs/jbd2/transaction.c | 33 ++++++++++++------------ 6 files changed, 100 insertions(+), 101 deletions(-)
fs/jbd2/checkpoint.c +3 -3
@@ -211,7 +211,7 @@ int jbd2_log_do_checkpoint(journal_t *journal)tid_t this_tid;int result, batch_count =0 ; -jbd_debug (1 ,"Start checkpoint\n" ); +jbd2_err (journal,"Start checkpoint\n" );/* * First thing: if there are any transactions in the log which
@@ -220,7 +220,7 @@ int jbd2_log_do_checkpoint(journal_t *journal)*/ result =jbd2_cleanup_journal_tail (journal);trace_jbd2_checkpoint (journal, result); -jbd_debug (1 ,"cleanup_journal_tail returned %d\n" , result); +jbd2_err (journal,"cleanup_journal_tail returned %d\n" , result);if (result <=0 )return result;
@@ -676,5 +676,5 @@ void __jbd2_journal_drop_transaction(journal_t *journal, transaction_t *transacttrace_jbd2_drop_transaction (journal, transaction); -jbd_debug (1 ,"Dropping transaction %d, all done\n" , transaction->t_tid); +jbd2_err (journal,"Dropping transaction %d, all done\n" , transaction->t_tid); }
fs/jbd2/commit.c +18 -18
@@ -419,7 +419,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)/* Do we need to erase the effects of a prior jbd2_journal_flush? */ if (journal->j_flags &JBD2_FLUSHED ) { -jbd_debug (3 ,"super block updated\n" ); +jbd2_notice (journal,"super block updated\n" );mutex_lock_io (&journal->j_checkpoint_mutex);/* * We hold j_checkpoint_mutex so tail cannot change under us.
@@ -433,7 +433,7 @@ void jbd2_journal_commit_transaction(journal_t *journal) REQ_SYNC);mutex_unlock (&journal->j_checkpoint_mutex); }else { -jbd_debug (3 ,"superblock not updated\n" ); +jbd2_notice (journal,"superblock not updated\n" ); }J_ASSERT (journal->j_running_transaction !=NULL );
@@ -465,7 +465,7 @@ void jbd2_journal_commit_transaction(journal_t *journal) commit_transaction = journal->j_running_transaction;trace_jbd2_start_commit (journal, commit_transaction); -jbd_debug (1 ,"JBD2: starting commit of transaction %d\n" , +jbd2_err (journal,"JBD2: starting commit of transaction %d\n" , commit_transaction->t_tid);write_lock (&journal->j_state_lock);
@@ -549,7 +549,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)__jbd2_journal_clean_checkpoint_list (journal, false);spin_unlock (&journal->j_list_lock); -jbd_debug (3 ,"JBD2: commit phase 1\n" ); +jbd2_notice (journal,"JBD2: commit phase 1\n" );/* * Clear revoked flag to reflect there is no revoked buffers
@@ -582,7 +582,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)wake_up (&journal->j_wait_transaction_locked);write_unlock (&journal->j_state_lock); -jbd_debug (3 ,"JBD2: commit phase 2a\n" ); +jbd2_notice (journal,"JBD2: commit phase 2a\n" );/* * Now start flushing things to disk, in the order they appear
@@ -595,7 +595,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)blk_start_plug (&plug);jbd2_journal_write_revoke_records (commit_transaction, &log_bufs); -jbd_debug (3 ,"JBD2: commit phase 2b\n" ); +jbd2_notice (journal,"JBD2: commit phase 2b\n" );/* * Way to go: we have now written out all of the data for a
@@ -651,7 +651,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)if (!descriptor) {J_ASSERT (bufs ==0 ); -jbd_debug (4 ,"JBD2: get descriptor\n" ); +jbd2_info (journal,"JBD2: get descriptor\n" ); descriptor = jbd2_journal_get_descriptor_buffer( commit_transaction,
@@ -661,9 +661,9 @@ void jbd2_journal_commit_transaction(journal_t *journal)continue ; } -jbd_debug (4 ,"JBD2: got buffer %llu (%p)\n" , - (unsigned long long )descriptor->b_blocknr, - descriptor->b_data); +jbd2_info (journal,"JBD2: got buffer %llu (%p)\n" , + (unsigned long long )descriptor->b_blocknr, + descriptor->b_data); tagp = &descriptor->b_data[sizeof (journal_header_t)]; space_left = descriptor->b_size -sizeof (journal_header_t);
@@ -746,7 +746,7 @@ void jbd2_journal_commit_transaction(journal_t *journal) commit_transaction->t_buffers == NULL || space_left < tag_bytes + 16 + csum_size) { -jbd_debug (4 ,"JBD2: Submit %d IOs\n" , bufs); +jbd2_info (journal,"JBD2: Submit %d IOs\n" , bufs);/* Write an end-of-descriptor marker before submitting the IOs. "tag" still points to
@@ -848,7 +848,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)so we incur less scheduling load. */ -jbd_debug (3 ,"JBD2: commit phase 3\n" ); +jbd2_notice (journal,"JBD2: commit phase 3\n" );while (!list_empty (&io_bufs)) { struct buffer_head *bh = list_entry(io_bufs.prev,
@@ -891,7 +891,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)J_ASSERT (commit_transaction->t_shadow_list ==NULL ); -jbd_debug (3 ,"JBD2: commit phase 4\n" ); +jbd2_notice (journal,"JBD2: commit phase 4\n" );/* Here we wait for the revoke record and descriptor record buffers */ while (!list_empty (&log_bufs)) {
@@ -915,7 +915,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)if (err)jbd2_journal_abort (journal, err); -jbd_debug (3 ,"JBD2: commit phase 5\n" ); +jbd2_notice (journal,"JBD2: commit phase 5\n" );write_lock (&journal->j_state_lock);J_ASSERT (commit_transaction->t_state ==T_COMMIT_DFLUSH ); commit_transaction->t_state =T_COMMIT_JFLUSH ;
@@ -954,7 +954,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)transaction can be removed from any checkpoint list it was on before. */ -jbd_debug (3 ,"JBD2: commit phase 6\n" ); +jbd2_notice (journal,"JBD2: commit phase 6\n" );J_ASSERT (list_empty (&commit_transaction->t_inode_list));J_ASSERT (commit_transaction->t_buffers ==NULL );
@@ -1131,7 +1131,7 @@ void jbd2_journal_commit_transaction(journal_t *journal)/* Done with this transaction! */ -jbd_debug (3 ,"JBD2: commit phase 7\n" ); +jbd2_notice (journal,"JBD2: commit phase 7\n" );J_ASSERT (commit_transaction->t_state ==T_COMMIT_JFLUSH );
@@ -1173,8 +1173,8 @@ void jbd2_journal_commit_transaction(journal_t *journal) journal->j_fc_cleanup_callback (journal,1 );trace_jbd2_end_commit (journal, commit_transaction); -jbd_debug (1 ,"JBD2: commit %d complete, head %d\n" , - journal->j_commit_sequence, journal->j_tail_sequence); +jbd2_err (journal,"JBD2: commit %d complete, head %d\n" , + journal->j_commit_sequence, journal->j_tail_sequence);write_lock (&journal->j_state_lock); journal->j_flags &= ~JBD2_FULL_COMMIT_ONGOING ;
fs/jbd2/journal.c +27 -32
157 lines not on this page · raw message
fs/jbd2/recovery.c +31 -28
143 lines not on this page · raw message
fs/jbd2/revoke.c +4 -4
@@ -398,7 +398,7 @@ int jbd2_journal_revoke(handle_t *handle, unsigned long long blocknr, } handle->h_revoke_credits--; -jbd_debug (2 ,"insert revoke for block %llu, bh_in=%p\n" ,blocknr, bh_in); +jbd2_warn (journal,"insert revoke for block %llu, bh_in=%p\n" , blocknr, bh_in); err =insert_revoke_hash (journal, blocknr, handle->h_transaction->t_tid);BUFFER_TRACE (bh_in,"exit" );
@@ -428,7 +428,7 @@ int jbd2_journal_cancel_revoke(handle_t *handle, struct journal_head *jh)int did_revoke =0 ;/* akpm: debug */ struct buffer_head *bh =jh2bh (jh); -jbd_debug (4 ,"journal_head %p, cancelling revoke\n" , jh); +jbd2_info (journal,"journal_head %p, cancelling revoke\n" , jh);/* Is the existing Revoke bit valid? If so, we trust it, and * only perform the full cancel if the revoke bit is set. If
@@ -444,7 +444,7 @@ int jbd2_journal_cancel_revoke(handle_t *handle, struct journal_head *jh)if (need_cancel) { record =find_revoke_record (journal, bh->b_blocknr);if (record) { -jbd_debug (4 ,"cancelled existing revoke on " +jbd2_info (journal,"cancelled existing revoke on " "blocknr %llu\n" , (unsigned long long )bh->b_blocknr);spin_lock (&journal->j_revoke_lock);list_del (&record->hash);
@@ -560,7 +560,7 @@ void jbd2_journal_write_revoke_records(transaction_t *transaction, }if (descriptor)flush_descriptor (journal, descriptor, offset); -jbd_debug (1 ,"Wrote %d revoke records\n" , count); +jbd2_err (journal,"Wrote %d revoke records\n" , count); }/*
fs/jbd2/transaction.c +17 -16
@@ -362,7 +362,7 @@ static int start_this_handle(journal_t *journal, handle_t *handle,return -ENOMEM ; } -jbd_debug (3 ,"New handle %p going live.\n" , handle); +jbd2_notice (journal,"New handle %p going live.\n" , handle);/* * We need to hold j_state_lock until t_updates has been incremented,
@@ -436,7 +436,7 @@ static int start_this_handle(journal_t *journal, handle_t *handle, handle->h_start_jiffies = jiffies;atomic_inc (&transaction->t_updates);atomic_inc (&transaction->t_handle_count); -jbd_debug (4 ,"Handle %p given %d credits (total %d, free %lu)\n" , +jbd2_info (journal,"Handle %p given %d credits (total %d, free %lu)\n" , handle, blocks,atomic_read (&transaction->t_outstanding_credits),jbd2_log_space_left (journal));
@@ -657,8 +657,8 @@ int jbd2_journal_extend(handle_t *handle, int nblocks, int revoke_records)/* Don't extend a locked-down transaction! */ if (transaction->t_state !=T_RUNNING ) { -jbd_debug (3 ,"denied handle %p %d blocks: " -"transaction not running\n" , handle, nblocks); +jbd2_notice (journal,"denied handle %p %d blocks: " +"transaction not running\n" , handle, nblocks); goto error_out; }
@@ -673,8 +673,8 @@ int jbd2_journal_extend(handle_t *handle, int nblocks, int revoke_records) &transaction->t_outstanding_credits);if (wanted > journal->j_max_transaction_buffers) { -jbd_debug (3 ,"denied handle %p %d blocks: " -"transaction too large\n" , handle, nblocks); +jbd2_notice (journal,"denied handle %p %d blocks: " +"transaction too large\n" , handle, nblocks);atomic_sub (nblocks, &transaction->t_outstanding_credits); goto unlock; }
@@ -691,7 +691,7 @@ int jbd2_journal_extend(handle_t *handle, int nblocks, int revoke_records) handle->h_revoke_credits_requested += revoke_records; result =0 ; -jbd_debug (3 ,"extended handle %p by %d\n" , handle, nblocks); +jbd2_notice (journal,"extended handle %p by %d\n" , handle, nblocks); unlock:spin_unlock (&transaction->t_handle_lock); error_out:
@@ -781,7 +781,7 @@ int jbd2__journal_restart(handle_t *handle, int nblocks, int revoke_records,* First unlink the handle from its current transaction, and start the * commit on that. */ -jbd_debug (2 ,"restarting handle %p\n" , handle); +jbd2_warn (journal,"restarting handle %p\n" , handle);stop_this_handle (handle); handle->h_transaction =NULL ;
@@ -948,7 +948,7 @@ do_get_write_access(handle_t *handle, struct journal_head *jh, journal = transaction->t_journal; -jbd_debug (5 ,"journal_head %p, force_copy %d\n" , jh, force_copy); +jbd2_debug (journal,"journal_head %p, force_copy %d\n" , jh, force_copy);JBUFFER_TRACE (jh,"entry" ); repeat:
@@ -1240,13 +1240,13 @@ int jbd2_journal_get_create_access(handle_t *handle, struct buffer_head *bh)struct journal_head *jh =jbd2_journal_add_journal_head (bh);int err; -jbd_debug (5 ,"journal_head %p\n" , jh); err = -EROFS ;if (is_handle_aborted (handle)) goto out; journal = transaction->t_journal; err =0 ; +jbd2_debug (journal,"journal_head %p\n" , jh);JBUFFER_TRACE (jh,"entry" );/* * The buffer may already belong to this transaction due to pre-zeroing
@@ -1465,7 +1465,7 @@ int jbd2_journal_dirty_metadata(handle_t *handle, struct buffer_head *bh)* of the running transaction. */ jh =bh2jh (bh); -jbd_debug (5 ,"journal_head %p\n" , jh); +jbd2_debug (transaction->t_journal,"journal_head %p\n" , jh);JBUFFER_TRACE (jh,"entry" );/*
@@ -1787,8 +1787,9 @@ int jbd2_journal_stop(handle_t *handle)pid_t pid;if (--handle->h_ref >0 ) { -jbd_debug (4 ,"h_ref %d -> %d\n" , handle->h_ref +1 , - handle->h_ref); +jbd2_info (transaction->t_journal, +"h_ref %d -> %d\n" , handle->h_ref +1 , + handle->h_ref);if (is_handle_aborted (handle))return -EIO ;return 0 ;
@@ -1807,7 +1808,7 @@ int jbd2_journal_stop(handle_t *handle)if (is_handle_aborted (handle)) err = -EIO ; -jbd_debug (4 ,"Handle %p going down\n" , handle); +jbd2_info (journal,"Handle %p going down\n" , handle); trace_jbd2_handle_stats(journal->j_fs_dev->bd_dev, tid, handle->h_type, handle->h_line_no, jiffies - handle->h_start_jiffies,
@@ -1885,7 +1886,7 @@ int jbd2_journal_stop(handle_t *handle)* completes the commit thread, it just doesn't write * anything to disk. */ -jbd_debug (2 ,"transaction too old, requesting commit for " +jbd2_warn (journal,"transaction too old, requesting commit for " "handle %p\n" , handle);/* This is non-blocking */ jbd2_log_start_commit (journal, tid);
@@ -2649,7 +2650,7 @@ static int jbd2_journal_file_inode(handle_t *handle, struct jbd2_inode *jinode,return -EROFS ; journal = transaction->t_journal; -jbd_debug (4 ,"Adding inode %lu, tid:%d\n" , jinode->i_vfs_inode->i_ino, +jbd2_info (journal,"Adding inode %lu, tid:%d\n" , jinode->i_vfs_inode->i_ino, transaction->t_tid);spin_lock (&journal->j_list_lock);
Signature · 1 line
2.30.0
RFC PATCH v2 4/4 ext4: replace jbd_debug with the new log interface
In reply to Chunguang XuFrom: Chunguang Xu <[email protected]>
In order to support jbd2 per device debugging switch, here we need to replace jbd_debug with a new log interface. But there is a small disadvantage here. Because the debugging switch is placed in the journal_t object, the log before the object is initialized will be lost. However, usually this will not have much impact on debugging.
--- fs/ext4/balloc.c | 2 +- fs/ext4/ext4_jbd2.c | 3 +- fs/ext4/fast_commit.c | 64 +++++++++++++++++++++++-------------------- fs/ext4/indirect.c | 4 +-- fs/ext4/inode.c | 3 +- fs/ext4/namei.c | 10 +++---- fs/ext4/super.c | 16 ++++++----- 7 files changed, 56 insertions(+), 46 deletions(-)
fs/ext4/balloc.c +1 -1
@@ -645,7 +645,7 @@ int ext4_should_retry_alloc(struct super_block *sb, int *retries)if (EXT4_SB (sb)->s_mb_free_pending ==0 )return 0 ; -jbd_debug (1 ,"%s: retrying operation after ENOSPC\n" , sb->s_id); +jbd2_err (EXT4_SB (sb)->s_journal,"%s: retrying operation after ENOSPC\n" , sb->s_id);jbd2_journal_force_commit_nested (EXT4_SB (sb)->s_journal);return 1 ; }
fs/ext4/ext4_jbd2.c +2 -1
@@ -259,7 +259,8 @@ int __ext4_forget(const char *where, unsigned int line, handle_t *handle,trace_ext4_forget (inode, is_metadata, blocknr);BUFFER_TRACE (bh,"enter" ); -jbd_debug (4 ,"forgetting bh %p: is_metadata = %d, mode %o, " +jbd2_info (EXT4_SB (inode->i_sb)->s_journal, +"forgetting bh %p: is_metadata = %d, mode %o, " "data mode %x\n" , bh, is_metadata, inode->i_mode,test_opt (inode->i_sb,DATA_FLAGS ));
fs/ext4/fast_commit.c +35 -29
195 lines not on this page · raw message
fs/ext4/indirect.c +2 -2
@@ -458,7 +458,7 @@ static int ext4_splice_branch(handle_t *handle,* the new i_size. But that is not done here - it is done in * generic_commit_write->__mark_inode_dirty->ext4_dirty_inode. */ -jbd_debug (5 ,"splicing indirect only\n" ); +jbd2_debug (EXT4_SB (ar->inode->i_sb)->s_journal,"splicing indirect only\n" );BUFFER_TRACE (where->bh,"call ext4_handle_dirty_metadata" ); err =ext4_handle_dirty_metadata (handle, ar->inode, where->bh);if (err)
@@ -470,7 +470,7 @@ static int ext4_splice_branch(handle_t *handle, err =ext4_mark_inode_dirty (handle, ar->inode);if (unlikely (err)) goto err_out; -jbd_debug (5 ,"splicing direct\n" ); +jbd2_debug (EXT4_SB (ar->inode->i_sb)->s_journal,"splicing direct\n" ); }return err;
fs/ext4/inode.c +2 -1
@@ -5212,7 +5212,8 @@ int ext4_write_inode(struct inode *inode, struct writeback_control *wbc)if (EXT4_SB (inode->i_sb)->s_journal) {if (ext4_journal_current_handle ()) { -jbd_debug (1 ,"called recursively, non-PF_MEMALLOC!\n" ); +jbd2_err (EXT4_SB (inode->i_sb)->s_journal, +"called recursively, non-PF_MEMALLOC!\n" );dump_stack ();return -EIO ; }
fs/ext4/namei.c +5 -5
@@ -3003,8 +3003,8 @@ int ext4_orphan_add(handle_t *handle, struct inode *inode) }else brelse (iloc.bh); -jbd_debug (4 ,"superblock will point to %lu\n" , inode->i_ino); -jbd_debug (4 ,"orphan inode %lu will point to %d\n" , +jbd2_info (sbi->s_journal,"superblock will point to %lu\n" , inode->i_ino); +jbd2_info (sbi->s_journal,"orphan inode %lu will point to %d\n" , inode->i_ino,NEXT_ORPHAN (inode)); out:ext4_std_error (sb, err);
@@ -3039,7 +3039,7 @@ int ext4_orphan_del(handle_t *handle, struct inode *inode) }mutex_lock (&sbi->s_orphan_lock); -jbd_debug (4 ,"remove inode %lu from orphan list\n" , inode->i_ino); +jbd2_info (sbi->s_journal,"remove inode %lu from orphan list\n" , inode->i_ino); prev = ei->i_orphan.prev;list_del_init (&ei->i_orphan);
@@ -3055,7 +3055,7 @@ int ext4_orphan_del(handle_t *handle, struct inode *inode) ino_next =NEXT_ORPHAN (inode);if (prev == &sbi->s_orphan) { -jbd_debug (4 ,"superblock will point to %u\n" , ino_next); +jbd2_info (sbi->s_journal,"superblock will point to %u\n" , ino_next);BUFFER_TRACE (sbi->s_sbh,"get_write_access" ); err =ext4_journal_get_write_access (handle, sbi->s_sbh);if (err) {
@@ -3073,7 +3073,7 @@ int ext4_orphan_del(handle_t *handle, struct inode *inode)struct inode *i_prev = &list_entry(prev, struct ext4_inode_info, i_orphan)->vfs_inode; -jbd_debug (4 ,"orphan inode %lu will point to %u\n" , +jbd2_info (sbi->s_journal,"orphan inode %lu will point to %u\n" , i_prev->i_ino, ino_next); err =ext4_reserve_inode_write (handle, i_prev, &iloc2);if (err) {
fs/ext4/super.c +9 -7
@@ -2989,7 +2989,7 @@ static void ext4_orphan_cleanup(struct super_block *sb,int i;#endif if (!es->s_last_orphan) { -jbd_debug (4 ,"no orphan inodes to clean up\n" ); +jbd2_info (EXT4_SB (sb)->s_journal,"no orphan inodes to clean up\n" );return ; }
@@ -3013,7 +3013,8 @@ static void ext4_orphan_cleanup(struct super_block *sb, "clearing orphan list.\n"); es->s_last_orphan =0 ; } -jbd_debug (1 ,"Skipping orphan recovery on fs with errors.\n" ); +jbd2_err (EXT4_SB (sb)->s_journal, +"Skipping orphan recovery on fs with errors.\n" );return ; }
@@ -3062,7 +3063,8 @@ static void ext4_orphan_cleanup(struct super_block *sb,* so, skip the rest. */ if (EXT4_SB (sb)->s_mount_state &EXT4_ERROR_FS ) { -jbd_debug (1 ,"Skipping orphan recovery on fs with errors.\n" ); +jbd2_err (EXT4_SB (sb)->s_journal, +"Skipping orphan recovery on fs with errors.\n" ); es->s_last_orphan =0 ;break ; }
@@ -3080,7 +3082,8 @@ static void ext4_orphan_cleanup(struct super_block *sb,ext4_msg (sb,KERN_DEBUG ,"%s: truncating inode %lu to %lld bytes" , __func__, inode->i_ino, inode->i_size); -jbd_debug (2 ,"truncating inode %lu to %lld bytes\n" , +jbd2_warn (EXT4_SB (sb)->s_journal, +"truncating inode %lu to %lld bytes\n" , inode->i_ino, inode->i_size);inode_lock (inode);truncate_inode_pages (inode->i_mapping, inode->i_size);
@@ -3094,7 +3097,8 @@ static void ext4_orphan_cleanup(struct super_block *sb,ext4_msg (sb,KERN_DEBUG ,"%s: deleting unreferenced inode %lu" , __func__, inode->i_ino); -jbd_debug (2 ,"deleting unreferenced inode %lu\n" , +jbd2_warn (EXT4_SB (sb)->s_journal, +"deleting unreferenced inode %lu\n" , inode->i_ino); nr_orphans++; }
@@ -5226,8 +5230,6 @@ static struct inode *ext4_get_journal_inode(struct super_block *sb,return NULL ; } -jbd_debug (2 ,"Journal inode found at %p: %lld bytes\n" , - journal_inode, journal_inode->i_size);if (!S_ISREG (journal_inode->i_mode)) {ext4_msg (sb,KERN_ERR ,"invalid journal inode" );iput (journal_inode);
Signature · 1 line
2.30.0
Theodore Ts'o
maintainerQuoted 6 lines · Chunguang Xu
On a multi-disk machine, because jbd2 debugging switch is global, this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
Quoted 7 lines
We can enable jbd2 debugging of a device in the following ways:
echo X >/proc/fs/jbd2/sdX/jbd2_debugBut there is a small disadvantage here. Because the debugging switch is placed in the
journal_tobject, the log before the object is initialized will be lost. However, usually this will not have much impact on debugging.
The jbd debugging infrastructure dates back to the very beginnings of ext3, when Stephen Tweedie added them while he was first implementing the jbd layer. So this dates back to a time before we had other schemes like dynamic debug or tracepoints or eBPF.
I wonder if instead of trying to enhance our own bespoke debugging system, instead we set up something like tracepoints where they would be useful. I'm not proposing that we try to replace all jbd_debug() statements with tracepoints but I think it would be useful to look at what sort of information would actually be *useful* on a production server, and add those tracepoints to the jbd2 layer. What I like about tracepoints is you can enable them on a much more fine-grained fashion; information is sent to userspace in a much more efficient manner than printk; you can filter tracepoint events in the kernel, before sending them to userspace; and if you want more sophisticated filtering or aggregation, you can use eBPF.
What was the original use case which inspired this? Were you indeed trying to debug some kind of problem on a production system? (Why did you have multiple disks active at the same time?) Was there a specific problem you were trying to debug? What debug level were you using? Which jbd_debug statements were most useful to you? Which just got in the way (but which had to be enabled given the log level you needed to get the debug messages that you needed)?
- Ted
Theodore Ts'o wrote on 2021/1/26 5:50:
Quoted 15 lines · Chunguang Xu
Quoted 6 lines
On a multi-disk machine, because jbd2 debugging switch is global, this confuses the logs of multiple disks. It is not easy to distinguish the logs of each disk and the amount of generated logs is very large. Maybe a separate debugging switch for each disk would be better, so that we can easily distinguish the logs of a certain disk.
Quoted 7 lines
We can enable jbd2 debugging of a device in the following ways:
echo X >/proc/fs/jbd2/sdX/jbd2_debugBut there is a small disadvantage here. Because the debugging switch is placed in the
journal_tobject, the log before the object is initialized will be lost. However, usually this will not have much impact on debugging.
Quoted 15 lines
The jbd debugging infrastructure dates back to the very beginnings of ext3, when Stephen Tweedie added them while he was first implementing the jbd layer. So this dates back to a time before we had other schemes like dynamic debug or tracepoints or eBPF.
I wonder if instead of trying to enhance our own bespoke debugging system, instead we set up something like tracepoints where they would be useful. I'm not proposing that we try to replace alljbd_debug()statements with tracepoints but I think it would be useful to look at what sort of information would actually be *useful* on a production server, and add those tracepoints to the jbd2 layer. What I like about tracepoints is you can enable them on a much more fine-grained fashion; information is sent to userspace in a much more efficient manner than printk; you can filter tracepoint events in the kernel, before sending them to userspace; and if you want more sophisticated filtering or aggregation, you can use eBPF.
trace point, eBPF and other hook technologies are better for production environments. But for pure debugging work, adding hook points feels a bit heavy. However, your suggestion is very valuable, thank you very much.
Quoted 7 lines
What was the original use case which inspired this? Were you indeed trying to debug some kind of problem on a production system? (Why did you have multiple disks active at the same time?) Was there a specific problem you were trying to debug? What debug level were you using? Which
jbd_debugstatements were most useful to you? Which just got in the way (but which had to be enabled given the log level you needed to get the debug messages that you needed)?
We only do this in the test environment, mainly to facilitate debugging. We will dynamically adjust the log level, sometimes it is 1, sometimes higher. There are two main reasons for multiple disks working at the same time. The first is that the system management tool will update the system disk, and the second is that the collaborative task will update other disks. During the actual debugging, we added more additional logs. The original logs of the system are useful, but some logs don't feel very meaningful. Thanks.
Quoted 2 lines
- Ted
Theodore Ts'o
maintainerQuoted 4 lines · brookxu
trace point, eBPF and other hook technologies are better for production environments. But for pure debugging work, adding hook points feels a bit heavy. However, your suggestion is very valuable, thank you very much.
What feels heavy? The act of adding a new jbd_debug() statement to the sources, versus adding a new tracepoint? Or how to enable a set of tracepoints versus setting a jbd_debug level (either globally, or per mount point)? Or something else?
If it's the latter (which is what I think it is), how often are you needing to add a new jbd_debug() statement *and* needing to run in a test environment where you have multiple disks? How often is it useful to have multiple disks when doing your debugging?
I'm trying to understand why this has been useful to you, since that generally doesn't match with my development, testing, or debugging experience. In general I try to test with one file system at a time, since I'm trying to find something reproducible. Do you have cases where you need multiple file systems in your test environment in order to do your testing? Why is that? Is it because you're trying to use your production server code as your test reproducers? And if so, I would have thought adding the jbd_debug() statements and sending lots of console print messages would distort the timing enough to make it hard to reproduce a problem in found in your production environment.
It sounds like you have a very different set of test practices than what I'm used to, and I'm trying to understand it better.
Cheers,
- Ted
Theodore Ts'o wrote on 2021/1/28 0:21:
Quoted 10 lines · brookxu
Quoted 4 lines
trace point, eBPF and other hook technologies are better for production environments. But for pure debugging work, adding hook points feels a bit heavy. However, your suggestion is very valuable, thank you very much.
What feels heavy? The act of adding a new
jbd_debug()statement to the sources, versus adding a new tracepoint? Or how to enable a set of tracepoints versus setting ajbd_debuglevel (either globally, or per mount point)? Or something else?
Sorry, I didn't make it clear here. I mean the amount of code modification and data analysis. Since we mainly do some process confirmation, if it is to add trace points, the amount of code is relatively large, if it is to add log, it is relatively simple. Secondly, the modification of the kernel and analysis scripts is relatively simple.
Quoted 4 lines
If it's the latter (which is what I think it is), how often are you needing to add a new
jbd_debug()statement *and* needing to run in a test environment where you have multiple disks? How often is it useful to have multiple disks when doing your debugging?
We don't use JBD2_DEBUG much in our work. In most cases, we tend to add hook points and analyze data from hook points. But here because it is a process confirmation, if the hook point method is adopted, there are more hook points and the workload is relatively large. Secondly, these hook points are not needed in the production environment, maybe it is a waste of time.
Quoted 10 lines
I'm trying to understand why this has been useful to you, since that generally doesn't match with my development, testing, or debugging experience. In general I try to test with one file system at a time, since I'm trying to find something reproducible. Do you have cases where you need multiple file systems in your test environment in order to do your testing? Why is that? Is it because you're trying to use your production server code as your test reproducers? And if so, I would have thought adding the
jbd_debug()statements and sending lots of console print messages would distort the timing enough to make it hard to reproduce a problem in found in your production environment.
In our mixed deployment production environment, we occasionally find that containers will have priority inversion problems, that is, low-priority containers will affect the Qos of high-priority containers. We try to do something to make ext4 work better in the container scene. After a basic test, we will use the business program to test, because the IO behavior of the business program is relatively more complicated. It is worth noting that here we are mainly concerned with the correctness of the process, not particularly concerned with performance.
Quoted 2 lines
It sounds like you have a very different set of test practices than what I'm used to, and I'm trying to understand it better.
:), Perhaps my verification method is not optimal, but I found that jbd2 has a similar framework, and tried to use it, and then found that some things can be optimized.
Quoted 4 lines
Cheers,
- Ted