wangyan
2020-Feb-20 08:48 UTC
[Ocfs2-devel] [QUESTION] An NULL pointer dereference problem which was caused when dereference journal head
Hi all, I met an null pointer dereference problem, the running environment: kernel version: 4.19 A cluster with two nodes, 5 luns mounted on two nodes, and do some file operations like dd/fallocate/truncate/rm on every lun with storage network disconnection. The fallocate operation on dm-23-45 caused an null pointer dereference. The information of NULL pointer dereference as follows: [577992.878282] JBD2: Error -5 detected when updating journal superblock for dm-23-45. [577992.878290] Aborting journal on device dm-23-45. ... [577992.890778] JBD2: Error -5 detected when updating journal superblock for dm-24-46. [577992.890908] __journal_remove_journal_head: freeing b_committed_data [577992.890916] (fallocate,88392,52):ocfs2_extend_trans:474 ERROR: status = -30 [577992.890918] __journal_remove_journal_head: freeing b_committed_data [577992.890920] (fallocate,88392,52):ocfs2_rotate_tree_right:2500 ERROR: status = -30 [577992.890922] __journal_remove_journal_head: freeing b_committed_data [577992.890924] (fallocate,88392,52):ocfs2_do_insert_extent:4382 ERROR: status = -30 [577992.890928] (fallocate,88392,52):ocfs2_insert_extent:4842 ERROR: status = -30 [577992.890928] __journal_remove_journal_head: freeing b_committed_data [577992.890930] (fallocate,88392,52):ocfs2_add_clusters_in_btree:4947 ERROR: status = -30 [577992.890933] __journal_remove_journal_head: freeing b_committed_data [577992.890939] __journal_remove_journal_head: freeing b_committed_data [577992.890949] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000020 [577992.890950] Mem abort info: [577992.890951] ESR = 0x96000004 [577992.890952] Exception class = DABT (current EL), IL = 32 bits [577992.890952] SET = 0, FnV = 0 [577992.890953] EA = 0, S1PTW = 0 [577992.890954] Data abort info: [577992.890955] ISV = 0, ISS = 0x00000004 [577992.890956] CM = 0, WnR = 0 [577992.890958] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000f8da07a9 [577992.890960] [0000000000000020] pgd=0000000000000000 [577992.890964] Internal error: Oops: 96000004 [#1] SMP [577992.890965] Process fallocate (pid: 88392, stack limit = 0x00000000013db2fd) [577992.890968] CPU: 52 PID: 88392 Comm: fallocate Kdump: loaded Tainted: G W OE 4.19.36 #1 [577992.890969] Hardware name: Huawei TaiShan 2280 V2/BC82AMDD, BIOS 0.98 08/25/2019 [577992.890971] pstate: 60400009 (nZCv daif +PAN -UAO) [577992.891054] pc : _ocfs2_free_suballoc_bits+0x63c/0x968 [ocfs2] [577992.891082] lr : _ocfs2_free_suballoc_bits+0x618/0x968 [ocfs2] [577992.891084] sp : ffff0000c8e2b810 [577992.891085] x29: ffff0000c8e2b820 x28: 0000000000000000 [577992.891087] x27: 00000000000006f3 x26: ffffa07957b02e70 [577992.891089] x25: ffff807c59d50000 x24: 00000000000006f2 [577992.891091] x23: 0000000000000001 x22: ffff807bd39abc30 [577992.891093] x21: ffff0000811d9000 x20: ffffa07535d6a000 [577992.891097] x19: ffff000001681638 x18: ffffffffffffffff [577992.891098] x17: 0000000000000000 x16: ffff000080a03df0 [577992.891100] x15: ffff0000811d9708 x14: 203d207375746174 [577992.891101] x13: 73203a524f525245 x12: 20373439343a6565 [577992.891103] x11: 0000000000000038 x10: 0101010101010101 [577992.891106] x9 : ffffa07c68a85d70 x8 : 7f7f7f7f7f7f7f7f [577992.891109] x7 : 0000000000000000 x6 : 0000000000000080 [577992.891110] x5 : 0000000000000000 x4 : 0000000000000002 [577992.891112] x3 : ffff000001713390 x2 : 2ff90f88b1c22f00 [577992.891114] x1 : ffff807bd39abc30 x0 : 0000000000000000 [577992.891116] Call trace: [577992.891139] _ocfs2_free_suballoc_bits+0x63c/0x968 [ocfs2] [577992.891162] _ocfs2_free_clusters+0x100/0x290 [ocfs2] [577992.891185] ocfs2_free_clusters+0x50/0x68 [ocfs2] [577992.891206] ocfs2_add_clusters_in_btree+0x198/0x5e0 [ocfs2] [577992.891227] ocfs2_add_inode_data+0x94/0xc8 [ocfs2] [577992.891248] ocfs2_extend_allocation+0x1bc/0x7a8 [ocfs2] [577992.891269] ocfs2_allocate_extents+0x14c/0x338 [ocfs2] [577992.891290] __ocfs2_change_file_space+0x3f8/0x610 [ocfs2] [577992.891309] ocfs2_fallocate+0xe4/0x128 [ocfs2] [577992.891316] vfs_fallocate+0x11c/0x250 [577992.891317] ksys_fallocate+0x54/0x88 [577992.891319] __arm64_sys_fallocate+0x28/0x38 [577992.891323] el0_svc_common+0x78/0x130 [577992.891325] el0_svc_handler+0x38/0x78 [577992.891327] el0_svc+0x8/0xc My analysis process as follows: ocfs2_fallocate __ocfs2_change_file_space ocfs2_allocate_extents ocfs2_extend_allocation ocfs2_add_inode_data ocfs2_add_clusters_in_btree ocfs2_insert_extent ocfs2_do_insert_extent ocfs2_rotate_tree_right ocfs2_extend_rotate_transaction ocfs2_extend_trans jbd2_journal_restart jbd2__journal_restart /* handle->h_transaction is NULL, * is_handle_aborted(handle) is true */ handle->h_transaction = NULL; start_this_handle return -EROFS; ocfs2_free_clusters _ocfs2_free_clusters _ocfs2_free_suballoc_bits ocfs2_block_group_clear_bits ocfs2_journal_access_gd __ocfs2_journal_access jbd2_journal_get_undo_access /* I think jbd2_write_access_granted() will * return true, because do_get_write_access() * will return -EROFS. */ if (jbd2_write_access_granted(...)) return 0; do_get_write_access /* handle->h_transaction is NULL, it will * return -EROFS here, so do_get_write_access() * was not called. */ if (is_handle_aborted(handle)) return -EROFS; /* bh2jh(group_bh) is NULL, caused NULL pointer dereference */ undo_bg = (struct ocfs2_group_desc *) bh2jh(group_bh)->b_committed_data; I found the log "__journal_remove_journal_head: freeing b_committed_data" before causing NULL pointer dereference which will be printed when remove journal head. So, I think bh2jh(group_bh) is removed after ocfs2_journal_access_gd() and before call "bh2jh(group_bh)->b_committed_data", I don't know if this condition will happen and if the analysis result is right? Thanks, Yan Wang
Jan Kara
2020-Feb-20 10:06 UTC
[Ocfs2-devel] [QUESTION] An NULL pointer dereference problem which was caused when dereference journal head
On Thu 20-02-20 16:48:56, wangyan wrote:> Hi all, > > I met an null pointer dereference problem, the running environment: > kernel version: 4.19 > A cluster with two nodes, 5 luns mounted on two nodes, and do some > file operations like dd/fallocate/truncate/rm on every lun with storage > network disconnection. > > The fallocate operation on dm-23-45 caused an null pointer dereference. > > The information of NULL pointer dereference as follows: > [577992.878282] JBD2: Error -5 detected when updating journal superblock for dm-23-45. > [577992.878290] Aborting journal on device dm-23-45. > ... > [577992.890778] JBD2: Error -5 detected when updating journal superblock for dm-24-46. > [577992.890908] __journal_remove_journal_head: freeing b_committed_data > [577992.890916] (fallocate,88392,52):ocfs2_extend_trans:474 ERROR: status = -30 > [577992.890918] __journal_remove_journal_head: freeing b_committed_data > [577992.890920] (fallocate,88392,52):ocfs2_rotate_tree_right:2500 ERROR: status = -30 > [577992.890922] __journal_remove_journal_head: freeing b_committed_data > [577992.890924] (fallocate,88392,52):ocfs2_do_insert_extent:4382 ERROR: status = -30 > [577992.890928] (fallocate,88392,52):ocfs2_insert_extent:4842 ERROR: status = -30 > [577992.890928] __journal_remove_journal_head: freeing b_committed_data > [577992.890930] (fallocate,88392,52):ocfs2_add_clusters_in_btree:4947 ERROR: status = -30 > [577992.890933] __journal_remove_journal_head: freeing b_committed_data > [577992.890939] __journal_remove_journal_head: freeing b_committed_data > [577992.890949] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000020 > [577992.890950] Mem abort info: > [577992.890951] ESR = 0x96000004 > [577992.890952] Exception class = DABT (current EL), IL = 32 bits > [577992.890952] SET = 0, FnV = 0 > [577992.890953] EA = 0, S1PTW = 0 > [577992.890954] Data abort info: > [577992.890955] ISV = 0, ISS = 0x00000004 > [577992.890956] CM = 0, WnR = 0 > [577992.890958] user pgtable: 4k pages, 48-bit VAs, pgdp = 00000000f8da07a9 > [577992.890960] [0000000000000020] pgd=0000000000000000 > [577992.890964] Internal error: Oops: 96000004 [#1] SMP > [577992.890965] Process fallocate (pid: 88392, stack limit = 0x00000000013db2fd) > [577992.890968] CPU: 52 PID: 88392 Comm: fallocate Kdump: loaded Tainted: G W OE 4.19.36 #1 > [577992.890969] Hardware name: Huawei TaiShan 2280 V2/BC82AMDD, BIOS 0.98 08/25/2019 > [577992.890971] pstate: 60400009 (nZCv daif +PAN -UAO) > [577992.891054] pc : _ocfs2_free_suballoc_bits+0x63c/0x968 [ocfs2] > [577992.891082] lr : _ocfs2_free_suballoc_bits+0x618/0x968 [ocfs2] > [577992.891084] sp : ffff0000c8e2b810 > [577992.891085] x29: ffff0000c8e2b820 x28: 0000000000000000 > [577992.891087] x27: 00000000000006f3 x26: ffffa07957b02e70 > [577992.891089] x25: ffff807c59d50000 x24: 00000000000006f2 > [577992.891091] x23: 0000000000000001 x22: ffff807bd39abc30 > [577992.891093] x21: ffff0000811d9000 x20: ffffa07535d6a000 > [577992.891097] x19: ffff000001681638 x18: ffffffffffffffff > [577992.891098] x17: 0000000000000000 x16: ffff000080a03df0 > [577992.891100] x15: ffff0000811d9708 x14: 203d207375746174 > [577992.891101] x13: 73203a524f525245 x12: 20373439343a6565 > [577992.891103] x11: 0000000000000038 x10: 0101010101010101 > [577992.891106] x9 : ffffa07c68a85d70 x8 : 7f7f7f7f7f7f7f7f > [577992.891109] x7 : 0000000000000000 x6 : 0000000000000080 > [577992.891110] x5 : 0000000000000000 x4 : 0000000000000002 > [577992.891112] x3 : ffff000001713390 x2 : 2ff90f88b1c22f00 > [577992.891114] x1 : ffff807bd39abc30 x0 : 0000000000000000 > [577992.891116] Call trace: > [577992.891139] _ocfs2_free_suballoc_bits+0x63c/0x968 [ocfs2] > [577992.891162] _ocfs2_free_clusters+0x100/0x290 [ocfs2] > [577992.891185] ocfs2_free_clusters+0x50/0x68 [ocfs2] > [577992.891206] ocfs2_add_clusters_in_btree+0x198/0x5e0 [ocfs2] > [577992.891227] ocfs2_add_inode_data+0x94/0xc8 [ocfs2] > [577992.891248] ocfs2_extend_allocation+0x1bc/0x7a8 [ocfs2] > [577992.891269] ocfs2_allocate_extents+0x14c/0x338 [ocfs2] > [577992.891290] __ocfs2_change_file_space+0x3f8/0x610 [ocfs2] > [577992.891309] ocfs2_fallocate+0xe4/0x128 [ocfs2] > [577992.891316] vfs_fallocate+0x11c/0x250 > [577992.891317] ksys_fallocate+0x54/0x88 > [577992.891319] __arm64_sys_fallocate+0x28/0x38 > [577992.891323] el0_svc_common+0x78/0x130 > [577992.891325] el0_svc_handler+0x38/0x78 > [577992.891327] el0_svc+0x8/0xc > > My analysis process as follows: > ocfs2_fallocate > __ocfs2_change_file_space > ocfs2_allocate_extents > ocfs2_extend_allocation > ocfs2_add_inode_data > ocfs2_add_clusters_in_btree > ocfs2_insert_extent > ocfs2_do_insert_extent > ocfs2_rotate_tree_right > ocfs2_extend_rotate_transaction > ocfs2_extend_trans > jbd2_journal_restart > jbd2__journal_restart > /* handle->h_transaction is NULL, > * is_handle_aborted(handle) is true > */ > handle->h_transaction = NULL; > start_this_handle > return -EROFS; > ocfs2_free_clusters > _ocfs2_free_clusters > _ocfs2_free_suballoc_bits > ocfs2_block_group_clear_bits > ocfs2_journal_access_gd > __ocfs2_journal_access > jbd2_journal_get_undo_access > /* I think jbd2_write_access_granted() will > * return true, because do_get_write_access() > * will return -EROFS. > */ > if (jbd2_write_access_granted(...)) return 0; > do_get_write_access > /* handle->h_transaction is NULL, it will > * return -EROFS here, so do_get_write_access() > * was not called. > */ > if (is_handle_aborted(handle)) return -EROFS; > /* bh2jh(group_bh) is NULL, caused NULL > pointer dereference */ > undo_bg = (struct ocfs2_group_desc *) > bh2jh(group_bh)->b_committed_data; > > I found the log "__journal_remove_journal_head: freeing b_committed_data" > before causing NULL pointer dereference which will be printed when remove > journal head. > > So, I think bh2jh(group_bh) is removed after ocfs2_journal_access_gd() and > before call "bh2jh(group_bh)->b_committed_data", I don't know if this > condition will happen and if the analysis result is right?Thanks for the analysis! Yes, what you write seems to be possible because if handle->h_transaction == NULL, then jbd2_write_access_granted() does not really guarantee that journal_head will stay around, not even speaking of its b_committed_data. I think a proper fix is to move is_handle_aborted() check from do_get_write_access() into jbd2_journal_get_undo_access() and jbd2_journal_get_write_access() before the call to jbd2_write_access_granted(). Will you send a patch to fix this or should I do it? Honza -- Jan Kara <jack at suse.com> SUSE Labs, CR