VirtualBox + kgdb: How to analyze ext4 filesystem processing in Linux kernel?

After the “gdb ./vmlinux” at the root of linux kernel source code directory, do a “rbreak ext4_*”:

(gdb) rbreak ext4_*
Breakpoint 1 at 0xffffffff8120ceb9: file fs/ext4/balloc.c, line 640.
int ext4_bg_has_super(struct super_block *, ext4_group_t);
Breakpoint 2 at 0xffffffff8120cf79: file fs/ext4/balloc.c, line 688.
long unsigned int ext4_bg_num_gdb(struct super_block *, ext4_group_t);
Breakpoint 3 at 0xffffffff8120cc65: file fs/ext4/balloc.c, line 478.
int ext4_claim_free_clusters(struct ext4_sb_info *, s64, unsigned int);
Breakpoint 4 at 0xffffffff8120ce50: file fs/ext4/balloc.c, line 565.
ext4_fsblk_t ext4_count_free_clusters(struct super_block *);
Breakpoint 5 at 0xffffffff8120d90e: file fs/ext4/balloc.c, line 222.
unsigned int ext4_free_clusters_after_init(struct super_block *, ext4_group_t,
struct ext4_group_desc *);
Breakpoint 6 at 0xffffffff8120c9fd: file fs/ext4/balloc.c, line 250.
struct ext4_group_desc *ext4_get_group_desc(struct super_block *,
ext4_group_t, struct buffer_head **);
Breakpoint 7 at 0xffffffff8120c9a9: file fs/ext4/balloc.c, line 765.
void ext4_get_group_no_and_offset(struct super_block *, ext4_fsblk_t,
ext4_group_t *, ext4_grpblk_t *);
Breakpoint 8 at 0xffffffff8120d0c6: file fs/ext4/balloc.c, line 167.
void ext4_init_block_bitmap(struct super_block *, struct buffer_head *,
ext4_group_t, struct ext4_group_desc *);
Breakpoint 9 at 0xffffffff8120d969: file fs/ext4/balloc.c, line 765. (2 locations)
ext4_fsblk_t ext4_inode_to_goal_block(struct inode *);
---Type <return> to continue, or q <return> to quit---

And so keep entering “enter” to set the breakpoints automatically. Not all the breakpoints can be set successfully. At about page 7 of the above some error occurred.

/build/buildd/gdb-7.1/gdb/breakpoint.c:6481: internal-error: expand_line_sal_maybe: Assertion `found' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
Quit this debugging session? (y or n)
Please answer y or n.
/build/buildd/gdb-7.1/gdb/breakpoint.c:6481: internal-error: expand_line_sal_maybe: Assertion `found' failed.

So I stopped at about page 6 of setting breakpoints, good enough numbers of breakpoints.

(gdb) cont
Continuing.
[New Thread 180]
[Switching to Thread 180]

Breakpoint 6, ext4_get_group_desc (sb=0xffff880030c4f800, block_group=0,
bh=0x0) at fs/ext4/balloc.c:250
250 if (EXT4_HAS_INCOMPAT_FEATURE(sb, EXT4_FEATURE_INCOMPAT_FLEX_BG)) {
(gdb) bt
#0 ext4_get_group_desc (sb=0xffff880030c4f800, block_group=0, bh=0x0)
at fs/ext4/balloc.c:250
#1 0xffffffff812351e5 in ext4_check_descriptors (sb=0xffff880030c4f800,
data=<value optimized out>, silent=6) at fs/ext4/super.c:1965
#2 ext4_fill_super (sb=0xffff880030c4f800, data=<value optimized out>,
silent=6) at fs/ext4/super.c:3401
#3 0xffffffff8117cdd6 in mount_bdev (fs_type=<value optimized out>,
flags=<value optimized out>, dev_name=<value optimized out>, data=0x0,
fill_super=0xffffffff81234100 <ext4_fill_super>) at fs/super.c:1024
#4 0xffffffff812236e5 in ext4_mount (fs_type=<value optimized out>,
flags=<value optimized out>, dev_name=<value optimized out>,
data=<value optimized out>) at fs/ext4/super.c:4779
#5 0xffffffff8117dc13 in mount_fs (type=0xffffffff81c5c8c0, flags=32769,
name=<value optimized out>, data=<value optimized out>) at fs/super.c:1130
#6 0xffffffff81197972 in vfs_kern_mount (type=0xffffffff81c5c8c0,
flags=32769,
name=0xffff88001c6fee00 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=0x0) at fs/namespace.c:707
#7 0xffffffff811981b4 in do_kern_mount (fstype=0xffff88001c69ebf0 "ext4",
flags=32769,
name=0xffff88001c6fee00 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=<value optimized out>) at fs/namespace.c:1804
#8 0xffffffff811999a4 in do_new_mount (
---Type <return> to continue, or q <return> to quit---
dev_name=0xffff88001c6fee00 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c69ebf0 "ext4",
flags=<value optimized out>, data_page=0x0) at fs/namespace.c:1864
#9 do_mount (
dev_name=0xffff88001c6fee00 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c69ebf0 "ext4",
flags=<value optimized out>, data_page=0x0) at fs/namespace.c:2188
#10 0xffffffff8119a190 in sys_mount (
dev_name=0x7fff22af4e30 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type=<value optimized out>, flags=32769,
data=0x0) at fs/namespace.c:2387
#11 <signal handler called>
#12 0x00007f5a220d9cea in __brk_reservation_fn_dmi_alloc__ ()
#13 0xffff880030ceadc0 in __brk_reservation_fn_dmi_alloc__ ()
#14 0xffffffff81c1ece0 in ?? ()
#15 0x0000000000000000 in ?? ()

Analysing the stacktrace, we should know something:

  • These stacktrace are kernel stacks, and so since transitioning from userspace to kernel is always starting with syscall, the lowest part of the stacktrace is always the syscall function.
  • Reading upwards, it shows the calling sequence from syscall functions to other functions.
  • So in the stack trace above, we know the calling sequence start with syscall sys_mount(), and subsequently other functions – reading upwards.

    Some error occurred, so in the starting up of second attempt, the following (different) stacktrace were recorded:

    (gdb) bt
    #0 ext4_get_group_desc (sb=0xffff880030cdc800, block_group=0, bh=0x0)
    at fs/ext4/balloc.c:250
    #1 0xffffffff812351e5 in ext4_check_descriptors (sb=0xffff880030cdc800,
    data=<value optimized out>, silent=6) at fs/ext4/super.c:1965
    #2 ext4_fill_super (sb=0xffff880030cdc800, data=<value optimized out>,
    silent=6) at fs/ext4/super.c:3401
    #3 0xffffffff8117cdd6 in mount_bdev (fs_type=<value optimized out>,
    flags=<value optimized out>, dev_name=<value optimized out>, data=0x0,
    fill_super=0xffffffff81234100 <ext4_fill_super>) at fs/super.c:1024
    #4 0xffffffff812236e5 in ext4_mount (fs_type=<value optimized out>,
    flags=<value optimized out>, dev_name=<value optimized out>,
    data=<value optimized out>) at fs/ext4/super.c:4779
    #5 0xffffffff8117dc13 in mount_fs (type=0xffffffff81c5c8c0, flags=32769,
    name=<value optimized out>, data=<value optimized out>) at fs/super.c:1130
    #6 0xffffffff81197972 in vfs_kern_mount (type=0xffffffff81c5c8c0,
    flags=32769,
    name=0xffff88001c754140 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=0x0) at fs/namespace.c:707
    #7 0xffffffff811981b4 in do_kern_mount (fstype=0xffff88001c683570 "ext4",
    flags=32769,
    name=0xffff88001c754140 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=<value optimized out>) at fs/namespace.c:1804
    #8 0xffffffff811999a4 in do_new_mount (
    ---Type <return> to continue, or q <return> to quit---
    dev_name=0xffff88001c754140 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c683570 "ext4",
    flags=<value optimized out>, data_page=0x0) at fs/namespace.c:1864
    #9 do_mount (
    dev_name=0xffff88001c754140 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c683570 "ext4",
    flags=<value optimized out>, data_page=0x0) at fs/namespace.c:2188
    #10 0xffffffff8119a190 in sys_mount (
    dev_name=0x7fffa93e9e30 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type=<value optimized out>, flags=32769,
    data=0x0) at fs/namespace.c:2387
    #11 <signal handler called>
    #12 0x00007fa7b17decea in __brk_reservation_fn_dmi_alloc__ ()
    #13 0x0000000000000000 in ?? ()
    (gdb) cont
    Continuing.

    And it continue, never seemingly terminate or return back, neither any displayed in VirtualBox.

    And so I restart the whole thing again, now setting only one breakpoint – ext4_get_group_desc:

    Breakpoint 1, ext4_get_group_desc (sb=0xffff880030e8f000, block_group=0,
    bh=0x0) at fs/ext4/balloc.c:250
    250 if (EXT4_HAS_INCOMPAT_FEATURE(sb, EXT4_FEATURE_INCOMPAT_FLEX_BG)) {
    (gdb) bt
    #0 ext4_get_group_desc (sb=0xffff880030e8f000, block_group=0, bh=0x0)
    at fs/ext4/balloc.c:250
    #1 0xffffffff812351e5 in ext4_check_descriptors (sb=0xffff880030e8f000,
    data=<value optimized out>, silent=6) at fs/ext4/super.c:1965
    #2 ext4_fill_super (sb=0xffff880030e8f000, data=<value optimized out>,
    silent=6) at fs/ext4/super.c:3401
    #3 0xffffffff8117cdd6 in mount_bdev (fs_type=<value optimized out>,
    flags=<value optimized out>, dev_name=<value optimized out>, data=0x0,
    fill_super=0xffffffff81234100 <ext4_fill_super>) at fs/super.c:1024
    #4 0xffffffff812236e5 in ext4_mount (fs_type=<value optimized out>,
    flags=<value optimized out>, dev_name=<value optimized out>,
    data=<value optimized out>) at fs/ext4/super.c:4779
    #5 0xffffffff8117dc13 in mount_fs (type=0xffffffff81c5c8c0, flags=32769,
    name=<value optimized out>, data=<value optimized out>) at fs/super.c:1130
    #6 0xffffffff81197972 in vfs_kern_mount (type=0xffffffff81c5c8c0,
    flags=32769,
    name=0xffff88001c679f40 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=0x0) at fs/namespace.c:707
    #7 0xffffffff811981b4 in do_kern_mount (fstype=0xffff88001c6816a8 "ext4",
    flags=32769,
    name=0xffff88001c679f40 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", data=<value optimized out>) at fs/namespace.c:1804
    #8 0xffffffff811999a4 in do_new_mount (
    ---Type <return> to continue, or q <return> to quit---
    dev_name=0xffff88001c679f40 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c6816a8 "ext4",
    flags=<value optimized out>, data_page=0x0) at fs/namespace.c:1864
    #9 do_mount (
    dev_name=0xffff88001c679f40 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type_page=0xffff88001c6816a8 "ext4",
    flags=<value optimized out>, data_page=0x0) at fs/namespace.c:2188
    #10 0xffffffff8119a190 in sys_mount (
    dev_name=0x7fff299bfe30 "/dev/disk/by-uuid/30532f8e-6a1e-4cc1-96d9-e0b01a27e68e", dir_name=<value optimized out>, type=<value optimized out>, flags=32769,
    data=0x0) at fs/namespace.c:2387
    #11 <signal handler called>
    #12 0x00007fa6fa9b4cea in __brk_reservation_fn_dmi_alloc__ ()
    #13 0x000000000000ff4f in __brk_reservation_fn_dmi_alloc__ ()
    #14 0x000000000001eaaf in __brk_reservation_fn_dmi_alloc__ ()
    xxx
    xxx (near 500 lines of __brk_reservation_fn_dmi_alloc__())
    xxx
    #521 0x000000000001fc19 in __brk_reservation_fn_dmi_alloc__ ()
    #522 0x0000001b0000000a in __brk_reservation_fn_dmi_alloc__ ()
    #523 0x000000000000e4a6 in __brk_reservation_fn_dmi_alloc__ ()
    #524 0x000000000001fc1f in __brk_reservation_fn_dmi_alloc__ ()

    #525 0x0000000000000000 in ?? ()
    (gdb) cont
    Continuing.

    What is happening, and why is the __brk_reservation_fn_dmi_alloc__() called recursively so many times?

    Advertisements

    Leave a Reply

    Please log in using one of these methods to post your comment:

    WordPress.com Logo

    You are commenting using your WordPress.com account. Log Out / Change )

    Twitter picture

    You are commenting using your Twitter account. Log Out / Change )

    Facebook photo

    You are commenting using your Facebook account. Log Out / Change )

    Google+ photo

    You are commenting using your Google+ account. Log Out / Change )

    Connecting to %s

    %d bloggers like this: