ext4: mballoc: make mb_debug() implementation to use pr_debug()

mb_debug() msg had only 1 control level for all type of msgs.
And if we enable mballoc_debug then all of those msgs would be enabled.
Instead of adding multiple debug levels for mb_debug() msgs, use
pr_debug() with which we could have finer control to print msgs at all
of different levels (i.e. at file, func, line no.).

Also add process name/pid, superblk id, and other info in mb_debug()
msg. This also kills the mballoc_debug module parameter, since it is
not needed any more.

Signed-off-by: Ritesh Harjani <riteshh@linux.ibm.com>
Link: https://lore.kernel.org/r/f0c660cbde9e2edbe95c67942ca9ad80dd2231eb.1589086800.git.riteshh@linux.ibm.com
Signed-off-by: Theodore Ts'o <tytso@mit.edu>
This commit is contained in:
Ritesh Harjani 2020-05-10 11:54:54 +05:30 committed by Theodore Ts'o
parent 8ec2d31b27
commit d3df14535f
3 changed files with 55 additions and 68 deletions

View File

@ -99,8 +99,7 @@ config EXT4_DEBUG
Enables run-time debugging support for the ext4 filesystem. Enables run-time debugging support for the ext4 filesystem.
If you select Y here, then you will be able to turn on debugging If you select Y here, then you will be able to turn on debugging
with a command such as: using dynamic debug control for mb_debug() msgs.
echo 1 > /sys/module/ext4/parameters/mballoc_debug
config EXT4_KUNIT_TESTS config EXT4_KUNIT_TESTS
tristate "KUnit tests for ext4" tristate "KUnit tests for ext4"

View File

@ -18,13 +18,6 @@
#include <linux/backing-dev.h> #include <linux/backing-dev.h>
#include <trace/events/ext4.h> #include <trace/events/ext4.h>
#ifdef CONFIG_EXT4_DEBUG
ushort ext4_mballoc_debug __read_mostly;
module_param_named(mballoc_debug, ext4_mballoc_debug, ushort, 0644);
MODULE_PARM_DESC(mballoc_debug, "Debugging level for ext4's mballoc");
#endif
/* /*
* MUSTDO: * MUSTDO:
* - test ext4_ext_search_left() and ext4_ext_search_right() * - test ext4_ext_search_left() and ext4_ext_search_right()
@ -858,14 +851,14 @@ static int ext4_mb_init_cache(struct page *page, char *incore, gfp_t gfp)
char *bitmap; char *bitmap;
struct ext4_group_info *grinfo; struct ext4_group_info *grinfo;
mb_debug(1, "init page %lu\n", page->index);
inode = page->mapping->host; inode = page->mapping->host;
sb = inode->i_sb; sb = inode->i_sb;
ngroups = ext4_get_groups_count(sb); ngroups = ext4_get_groups_count(sb);
blocksize = i_blocksize(inode); blocksize = i_blocksize(inode);
blocks_per_page = PAGE_SIZE / blocksize; blocks_per_page = PAGE_SIZE / blocksize;
mb_debug(sb, "init page %lu\n", page->index);
groups_per_page = blocks_per_page >> 1; groups_per_page = blocks_per_page >> 1;
if (groups_per_page == 0) if (groups_per_page == 0)
groups_per_page = 1; groups_per_page = 1;
@ -905,7 +898,7 @@ static int ext4_mb_init_cache(struct page *page, char *incore, gfp_t gfp)
bh[i] = NULL; bh[i] = NULL;
goto out; goto out;
} }
mb_debug(1, "read bitmap for group %u\n", group); mb_debug(sb, "read bitmap for group %u\n", group);
} }
/* wait for I/O completion */ /* wait for I/O completion */
@ -950,7 +943,7 @@ static int ext4_mb_init_cache(struct page *page, char *incore, gfp_t gfp)
if ((first_block + i) & 1) { if ((first_block + i) & 1) {
/* this is block of buddy */ /* this is block of buddy */
BUG_ON(incore == NULL); BUG_ON(incore == NULL);
mb_debug(1, "put buddy for group %u in page %lu/%x\n", mb_debug(sb, "put buddy for group %u in page %lu/%x\n",
group, page->index, i * blocksize); group, page->index, i * blocksize);
trace_ext4_mb_buddy_bitmap_load(sb, group); trace_ext4_mb_buddy_bitmap_load(sb, group);
grinfo = ext4_get_group_info(sb, group); grinfo = ext4_get_group_info(sb, group);
@ -970,7 +963,7 @@ static int ext4_mb_init_cache(struct page *page, char *incore, gfp_t gfp)
} else { } else {
/* this is block of bitmap */ /* this is block of bitmap */
BUG_ON(incore != NULL); BUG_ON(incore != NULL);
mb_debug(1, "put bitmap for group %u in page %lu/%x\n", mb_debug(sb, "put bitmap for group %u in page %lu/%x\n",
group, page->index, i * blocksize); group, page->index, i * blocksize);
trace_ext4_mb_bitmap_load(sb, group); trace_ext4_mb_bitmap_load(sb, group);
@ -1076,7 +1069,7 @@ int ext4_mb_init_group(struct super_block *sb, ext4_group_t group, gfp_t gfp)
int ret = 0; int ret = 0;
might_sleep(); might_sleep();
mb_debug(1, "init group %u\n", group); mb_debug(sb, "init group %u\n", group);
this_grp = ext4_get_group_info(sb, group); this_grp = ext4_get_group_info(sb, group);
/* /*
* This ensures that we don't reinit the buddy cache * This ensures that we don't reinit the buddy cache
@ -1148,7 +1141,7 @@ ext4_mb_load_buddy_gfp(struct super_block *sb, ext4_group_t group,
struct inode *inode = sbi->s_buddy_cache; struct inode *inode = sbi->s_buddy_cache;
might_sleep(); might_sleep();
mb_debug(1, "load group %u\n", group); mb_debug(sb, "load group %u\n", group);
blocks_per_page = PAGE_SIZE / sb->s_blocksize; blocks_per_page = PAGE_SIZE / sb->s_blocksize;
grp = ext4_get_group_info(sb, group); grp = ext4_get_group_info(sb, group);
@ -2299,7 +2292,7 @@ out:
if (!err && ac->ac_status != AC_STATUS_FOUND && first_err) if (!err && ac->ac_status != AC_STATUS_FOUND && first_err)
err = first_err; err = first_err;
mb_debug(1, "Best len %d, origin len %d, ac_status %u, ac_flags 0x%x, cr %d ret %d\n", mb_debug(sb, "Best len %d, origin len %d, ac_status %u, ac_flags 0x%x, cr %d ret %d\n",
ac->ac_b_ex.fe_len, ac->ac_o_ex.fe_len, ac->ac_status, ac->ac_b_ex.fe_len, ac->ac_o_ex.fe_len, ac->ac_status,
ac->ac_flags, cr, err); ac->ac_flags, cr, err);
return err; return err;
@ -2731,7 +2724,7 @@ out:
} }
/* need to called with the ext4 group lock held */ /* need to called with the ext4 group lock held */
static void ext4_mb_cleanup_pa(struct ext4_group_info *grp) static int ext4_mb_cleanup_pa(struct ext4_group_info *grp)
{ {
struct ext4_prealloc_space *pa; struct ext4_prealloc_space *pa;
struct list_head *cur, *tmp; struct list_head *cur, *tmp;
@ -2743,9 +2736,7 @@ static void ext4_mb_cleanup_pa(struct ext4_group_info *grp)
count++; count++;
kmem_cache_free(ext4_pspace_cachep, pa); kmem_cache_free(ext4_pspace_cachep, pa);
} }
if (count) return count;
mb_debug(1, "mballoc: %u PAs left\n", count);
} }
int ext4_mb_release(struct super_block *sb) int ext4_mb_release(struct super_block *sb)
@ -2756,6 +2747,7 @@ int ext4_mb_release(struct super_block *sb)
struct ext4_group_info *grinfo, ***group_info; struct ext4_group_info *grinfo, ***group_info;
struct ext4_sb_info *sbi = EXT4_SB(sb); struct ext4_sb_info *sbi = EXT4_SB(sb);
struct kmem_cache *cachep = get_groupinfo_cache(sb->s_blocksize_bits); struct kmem_cache *cachep = get_groupinfo_cache(sb->s_blocksize_bits);
int count;
if (sbi->s_group_info) { if (sbi->s_group_info) {
for (i = 0; i < ngroups; i++) { for (i = 0; i < ngroups; i++) {
@ -2763,7 +2755,10 @@ int ext4_mb_release(struct super_block *sb)
grinfo = ext4_get_group_info(sb, i); grinfo = ext4_get_group_info(sb, i);
mb_group_bb_bitmap_free(grinfo); mb_group_bb_bitmap_free(grinfo);
ext4_lock_group(sb, i); ext4_lock_group(sb, i);
ext4_mb_cleanup_pa(grinfo); count = ext4_mb_cleanup_pa(grinfo);
if (count)
mb_debug(sb, "mballoc: %d PAs left\n",
count);
ext4_unlock_group(sb, i); ext4_unlock_group(sb, i);
kmem_cache_free(cachep, grinfo); kmem_cache_free(cachep, grinfo);
} }
@ -2836,7 +2831,7 @@ static void ext4_free_data_in_buddy(struct super_block *sb,
struct ext4_group_info *db; struct ext4_group_info *db;
int err, count = 0, count2 = 0; int err, count = 0, count2 = 0;
mb_debug(1, "gonna free %u blocks in group %u (0x%p):", mb_debug(sb, "gonna free %u blocks in group %u (0x%p):",
entry->efd_count, entry->efd_group, entry); entry->efd_count, entry->efd_group, entry);
err = ext4_mb_load_buddy(sb, entry->efd_group, &e4b); err = ext4_mb_load_buddy(sb, entry->efd_group, &e4b);
@ -2876,7 +2871,8 @@ static void ext4_free_data_in_buddy(struct super_block *sb,
kmem_cache_free(ext4_free_data_cachep, entry); kmem_cache_free(ext4_free_data_cachep, entry);
ext4_mb_unload_buddy(&e4b); ext4_mb_unload_buddy(&e4b);
mb_debug(1, "freed %u blocks in %u structures\n", count, count2); mb_debug(sb, "freed %d blocks in %d structures\n", count,
count2);
} }
/* /*
@ -3107,8 +3103,7 @@ static void ext4_mb_normalize_group_request(struct ext4_allocation_context *ac)
BUG_ON(lg == NULL); BUG_ON(lg == NULL);
ac->ac_g_ex.fe_len = EXT4_SB(sb)->s_mb_group_prealloc; ac->ac_g_ex.fe_len = EXT4_SB(sb)->s_mb_group_prealloc;
mb_debug(1, "#%u: goal %u blocks for locality group\n", mb_debug(sb, "goal %u blocks for locality group\n", ac->ac_g_ex.fe_len);
current->pid, ac->ac_g_ex.fe_len);
} }
/* /*
@ -3306,8 +3301,8 @@ ext4_mb_normalize_request(struct ext4_allocation_context *ac,
ac->ac_flags |= EXT4_MB_HINT_TRY_GOAL; ac->ac_flags |= EXT4_MB_HINT_TRY_GOAL;
} }
mb_debug(1, "goal: %lld(was %lld) blocks at %u\n", size, orig_size, mb_debug(ac->ac_sb, "goal: %lld(was %lld) blocks at %u\n", size,
start); orig_size, start);
} }
static void ext4_mb_collect_stats(struct ext4_allocation_context *ac) static void ext4_mb_collect_stats(struct ext4_allocation_context *ac)
@ -3396,7 +3391,7 @@ static void ext4_mb_use_inode_pa(struct ext4_allocation_context *ac,
BUG_ON(pa->pa_free < len); BUG_ON(pa->pa_free < len);
pa->pa_free -= len; pa->pa_free -= len;
mb_debug(1, "use %llu/%d from inode pa %p\n", start, len, pa); mb_debug(ac->ac_sb, "use %llu/%d from inode pa %p\n", start, len, pa);
} }
/* /*
@ -3420,7 +3415,8 @@ static void ext4_mb_use_group_pa(struct ext4_allocation_context *ac,
* in on-disk bitmap -- see ext4_mb_release_context() * in on-disk bitmap -- see ext4_mb_release_context()
* Other CPUs are prevented from allocating from this pa by lg_mutex * Other CPUs are prevented from allocating from this pa by lg_mutex
*/ */
mb_debug(1, "use %u/%u from group pa %p\n", pa->pa_lstart-len, len, pa); mb_debug(ac->ac_sb, "use %u/%u from group pa %p\n",
pa->pa_lstart-len, len, pa);
} }
/* /*
@ -3603,7 +3599,7 @@ void ext4_mb_generate_from_pa(struct super_block *sb, void *bitmap,
ext4_set_bits(bitmap, start, len); ext4_set_bits(bitmap, start, len);
preallocated += len; preallocated += len;
} }
mb_debug(1, "preallocated %d for group %u\n", preallocated, group); mb_debug(sb, "preallocated %d for group %u\n", preallocated, group);
} }
static void ext4_mb_pa_callback(struct rcu_head *head) static void ext4_mb_pa_callback(struct rcu_head *head)
@ -3746,8 +3742,8 @@ ext4_mb_new_inode_pa(struct ext4_allocation_context *ac)
pa->pa_deleted = 0; pa->pa_deleted = 0;
pa->pa_type = MB_INODE_PA; pa->pa_type = MB_INODE_PA;
mb_debug(1, "new inode pa %p: %llu/%d for %u\n", pa, mb_debug(sb, "new inode pa %p: %llu/%d for %u\n", pa, pa->pa_pstart,
pa->pa_pstart, pa->pa_len, pa->pa_lstart); pa->pa_len, pa->pa_lstart);
trace_ext4_mb_new_inode_pa(ac, pa); trace_ext4_mb_new_inode_pa(ac, pa);
ext4_mb_use_inode_pa(ac, pa); ext4_mb_use_inode_pa(ac, pa);
@ -3806,8 +3802,8 @@ ext4_mb_new_group_pa(struct ext4_allocation_context *ac)
pa->pa_deleted = 0; pa->pa_deleted = 0;
pa->pa_type = MB_GROUP_PA; pa->pa_type = MB_GROUP_PA;
mb_debug(1, "new group pa %p: %llu/%d for %u\n", pa, mb_debug(sb, "new group pa %p: %llu/%d for %u\n", pa, pa->pa_pstart,
pa->pa_pstart, pa->pa_len, pa->pa_lstart); pa->pa_len, pa->pa_lstart);
trace_ext4_mb_new_group_pa(ac, pa); trace_ext4_mb_new_group_pa(ac, pa);
ext4_mb_use_group_pa(ac, pa); ext4_mb_use_group_pa(ac, pa);
@ -3874,7 +3870,7 @@ ext4_mb_release_inode_pa(struct ext4_buddy *e4b, struct buffer_head *bitmap_bh,
if (bit >= end) if (bit >= end)
break; break;
next = mb_find_next_bit(bitmap_bh->b_data, end, bit); next = mb_find_next_bit(bitmap_bh->b_data, end, bit);
mb_debug(1, " free preallocated %u/%u in group %u\n", mb_debug(sb, "free preallocated %u/%u in group %u\n",
(unsigned) ext4_group_first_block_no(sb, group) + bit, (unsigned) ext4_group_first_block_no(sb, group) + bit,
(unsigned) next - bit, (unsigned) group); (unsigned) next - bit, (unsigned) group);
free += next - bit; free += next - bit;
@ -3945,8 +3941,7 @@ ext4_mb_discard_group_preallocations(struct super_block *sb,
int busy = 0; int busy = 0;
int free = 0; int free = 0;
mb_debug(1, "discard preallocation for group %u\n", group); mb_debug(sb, "discard preallocation for group %u\n", group);
if (list_empty(&grp->bb_prealloc_list)) if (list_empty(&grp->bb_prealloc_list))
goto out_dbg; goto out_dbg;
@ -4009,7 +4004,7 @@ repeat:
/* found anything to free? */ /* found anything to free? */
if (list_empty(&list)) { if (list_empty(&list)) {
BUG_ON(free != 0); BUG_ON(free != 0);
mb_debug(1, "Someone else may have freed PA for this group %u\n", mb_debug(sb, "Someone else may have freed PA for this group %u\n",
group); group);
goto out; goto out;
} }
@ -4036,7 +4031,7 @@ out:
ext4_mb_unload_buddy(&e4b); ext4_mb_unload_buddy(&e4b);
put_bh(bitmap_bh); put_bh(bitmap_bh);
out_dbg: out_dbg:
mb_debug(1, "discarded (%d) blocks preallocated for group %u bb_free (%d)\n", mb_debug(sb, "discarded (%d) blocks preallocated for group %u bb_free (%d)\n",
free, group, grp->bb_free); free, group, grp->bb_free);
return free; return free;
} }
@ -4066,7 +4061,8 @@ void ext4_discard_preallocations(struct inode *inode)
return; return;
} }
mb_debug(1, "discard preallocation for inode %lu\n", inode->i_ino); mb_debug(sb, "discard preallocation for inode %lu\n",
inode->i_ino);
trace_ext4_discard_preallocations(inode); trace_ext4_discard_preallocations(inode);
INIT_LIST_HEAD(&list); INIT_LIST_HEAD(&list);
@ -4159,12 +4155,11 @@ static inline void ext4_mb_show_pa(struct super_block *sb)
{ {
ext4_group_t i, ngroups; ext4_group_t i, ngroups;
if (!ext4_mballoc_debug || if (EXT4_SB(sb)->s_mount_flags & EXT4_MF_FS_ABORTED)
(EXT4_SB(sb)->s_mount_flags & EXT4_MF_FS_ABORTED))
return; return;
ngroups = ext4_get_groups_count(sb); ngroups = ext4_get_groups_count(sb);
ext4_msg(sb, KERN_ERR, "groups: "); mb_debug(sb, "groups: ");
for (i = 0; i < ngroups; i++) { for (i = 0; i < ngroups; i++) {
struct ext4_group_info *grp = ext4_get_group_info(sb, i); struct ext4_group_info *grp = ext4_get_group_info(sb, i);
struct ext4_prealloc_space *pa; struct ext4_prealloc_space *pa;
@ -4178,30 +4173,27 @@ static inline void ext4_mb_show_pa(struct super_block *sb)
ext4_get_group_no_and_offset(sb, pa->pa_pstart, ext4_get_group_no_and_offset(sb, pa->pa_pstart,
NULL, &start); NULL, &start);
spin_unlock(&pa->pa_lock); spin_unlock(&pa->pa_lock);
printk(KERN_ERR "PA:%u:%d:%d \n", i, mb_debug(sb, "PA:%u:%d:%d\n", i, start,
start, pa->pa_len); pa->pa_len);
} }
ext4_unlock_group(sb, i); ext4_unlock_group(sb, i);
mb_debug(sb, "%u: %d/%d\n", i, grp->bb_free,
printk(KERN_ERR "%u: %d/%d \n", grp->bb_fragments);
i, grp->bb_free, grp->bb_fragments);
} }
printk(KERN_ERR "\n");
} }
static void ext4_mb_show_ac(struct ext4_allocation_context *ac) static void ext4_mb_show_ac(struct ext4_allocation_context *ac)
{ {
struct super_block *sb = ac->ac_sb; struct super_block *sb = ac->ac_sb;
if (!ext4_mballoc_debug || if (EXT4_SB(sb)->s_mount_flags & EXT4_MF_FS_ABORTED)
(EXT4_SB(sb)->s_mount_flags & EXT4_MF_FS_ABORTED))
return; return;
ext4_msg(sb, KERN_ERR, "Can't allocate:" mb_debug(sb, "Can't allocate:"
" Allocation context details:"); " Allocation context details:");
ext4_msg(sb, KERN_ERR, "status %u flags 0x%x", mb_debug(sb, "status %u flags 0x%x",
ac->ac_status, ac->ac_flags); ac->ac_status, ac->ac_flags);
ext4_msg(sb, KERN_ERR, "orig %lu/%lu/%lu@%lu, " mb_debug(sb, "orig %lu/%lu/%lu@%lu, "
"goal %lu/%lu/%lu@%lu, " "goal %lu/%lu/%lu@%lu, "
"best %lu/%lu/%lu@%lu cr %d", "best %lu/%lu/%lu@%lu cr %d",
(unsigned long)ac->ac_o_ex.fe_group, (unsigned long)ac->ac_o_ex.fe_group,
@ -4217,7 +4209,7 @@ static void ext4_mb_show_ac(struct ext4_allocation_context *ac)
(unsigned long)ac->ac_b_ex.fe_len, (unsigned long)ac->ac_b_ex.fe_len,
(unsigned long)ac->ac_b_ex.fe_logical, (unsigned long)ac->ac_b_ex.fe_logical,
(int)ac->ac_criteria); (int)ac->ac_criteria);
ext4_msg(sb, KERN_ERR, "%u found", ac->ac_found); mb_debug(sb, "%u found", ac->ac_found);
ext4_mb_show_pa(sb); ext4_mb_show_pa(sb);
} }
#else #else
@ -4330,7 +4322,7 @@ ext4_mb_initialize_context(struct ext4_allocation_context *ac,
* locality group. this is a policy, actually */ * locality group. this is a policy, actually */
ext4_mb_group_or_file(ac); ext4_mb_group_or_file(ac);
mb_debug(1, "init ac: %u blocks @ %u, goal %u, flags %x, 2^%d, " mb_debug(sb, "init ac: %u blocks @ %u, goal %u, flags 0x%x, 2^%d, "
"left: %u/%u, right %u/%u to %swritable\n", "left: %u/%u, right %u/%u to %swritable\n",
(unsigned) ar->len, (unsigned) ar->logical, (unsigned) ar->len, (unsigned) ar->logical,
(unsigned) ar->goal, ac->ac_flags, ac->ac_2order, (unsigned) ar->goal, ac->ac_flags, ac->ac_2order,
@ -4351,7 +4343,7 @@ ext4_mb_discard_lg_preallocations(struct super_block *sb,
struct list_head discard_list; struct list_head discard_list;
struct ext4_prealloc_space *pa, *tmp; struct ext4_prealloc_space *pa, *tmp;
mb_debug(1, "discard locality group preallocation\n"); mb_debug(sb, "discard locality group preallocation\n");
INIT_LIST_HEAD(&discard_list); INIT_LIST_HEAD(&discard_list);

View File

@ -24,19 +24,15 @@
#include "ext4.h" #include "ext4.h"
/* /*
* mb_debug() dynamic printk msgs could be used to debug mballoc code.
*/ */
#ifdef CONFIG_EXT4_DEBUG #ifdef CONFIG_EXT4_DEBUG
extern ushort ext4_mballoc_debug; #define mb_debug(sb, fmt, ...) \
pr_debug("[%s/%d] EXT4-fs (%s): (%s, %d): %s: " fmt, \
#define mb_debug(n, fmt, ...) \ current->comm, task_pid_nr(current), sb->s_id, \
do { \ __FILE__, __LINE__, __func__, ##__VA_ARGS__)
if ((n) <= ext4_mballoc_debug) { \
printk(KERN_DEBUG "(%s, %d): %s: " fmt, \
__FILE__, __LINE__, __func__, ##__VA_ARGS__); \
} \
} while (0)
#else #else
#define mb_debug(n, fmt, ...) no_printk(fmt, ##__VA_ARGS__) #define mb_debug(sb, fmt, ...) no_printk(fmt, ##__VA_ARGS__)
#endif #endif
#define EXT4_MB_HISTORY_ALLOC 1 /* allocation */ #define EXT4_MB_HISTORY_ALLOC 1 /* allocation */