Re: kernel BUG at fs/jbd2/journal.c:1951!
On Sun 25-05-14 22:50:53, Meelis Roos wrote: > Tried yesterdays git v3.15-rc6-190-g1ee1cea on Sun Fire T2000 (32-thread > sparc64) and got reproducibly stuck on boot with ext journal replay like > below. Booting Debian 3.14.2-1 replayed the log and mounted FS fine. > After that, my test kernel works fine too. SO I can not reproduce it any > more but it seems like I hit a bug. > > [ 62.064329] EXT4-fs (sda1): INFO: recovery required on readonly filesystem > [ 62.064395] EXT4-fs (sda1): write access will be enabled during recovery > [ 62.077043] EXT4-fs (sda1): orphan cleanup on readonly fs > [ 62.156585] EXT4-fs (sda1): 14 orphan inodes deleted > [ 62.156645] EXT4-fs (sda1): recovery complete > [ 62.156702] kernel BUG at fs/jbd2/journal.c:1951! So if I'm right this is assertion: J_ASSERT(!journal->j_running_transaction); But I don't really see how that could happen especially during mount when there are really just two processes operating in the filesystem - mount and jbd2 process. Hum, after some more thought, maybe this is some strange interaction between writeback completion starting a reserved handle and journal_flush()... There is some potential for problems. Let me think about it for some time. Honza > [ 62.156752] \|/ \|/ > [ 62.156752] "@'/ .. \`@" > [ 62.156752] /_| \__/ |_\ > [ 62.156752] \__U_/ > [ 62.156893] swapper/0(1): Kernel bad sw trap 5 [#1] > [ 62.156943] CPU: 8 PID: 1 Comm: swapper/0 Not tainted 3.15.0-rc6+ #6 > [ 62.157004] task: ff8008677640 ti: ff800870c000 task.ti: > ff800870c000 > [ 62.157079] TSTATE: 004480001605 TPC: 005f3c00 TNPC: > 005f3c04 Y: Not tainted > [ 62.157180] TPC: > [ 62.157225] g0: 009528c8 g1: g2: 00a17f88 > g3: 00a17f80 > [ 62.157301] g4: ff8008677640 g5: ff83f6a4a000 g6: ff800870c000 > g7: ff8008633fa0 > [ 62.157375] o0: 0025 o1: 00961ed8 o2: 079f > o3: ff83f3aab888 > [ 62.157451] o4: ff83ffb72000 o5: 00961ed8 sp: ff800870ed11 > ret_pc: 005f3bf8 > [ 62.157530] RPC: > [ 62.157575] l0: l1: 000e l2: 10018001 > l3: 0088e438 > [ 62.157650] l4: 009528c8 l5: ff00 l6: 00ff > l7: 0095ee30 > [ 62.157726] i0: ff83f3aab800 i1: ff83f3aab824 i2: ff83f3aabb98 > i3: ff83f3aab8e8 > [ 62.157801] i4: ff83f3aab824 i5: ff83f3aab8e8 i6: ff800870edc1 > i7: 005bd640 > [ 62.157887] I7: > [ 62.157942] Call Trace: > [ 62.157990] [005bd640] > ext4_mark_recovery_complete.isra.232+0x4c/0xb0 > [ 62.158068] [005c3860] ext4_fill_super+0x303c/0x33e8 > [ 62.158132] [00538fc4] mount_bdev+0x124/0x18c > [ 62.158192] [00539a4c] mount_fs+0x60/0x17c > [ 62.158246] [0055087c] vfs_kern_mount+0x48/0xe4 > [ 62.158309] [00552e24] do_mount+0x808/0x974 > [ 62.158370] [005531b0] SyS_mount+0x6c/0xa4 > [ 62.158427] [00a74cb8] mount_block_root+0x108/0x2ac > [ 62.158490] [00a75180] prepare_namespace+0x180/0x1bc > [ 62.158552] [00a74a80] kernel_init_freeable+0x208/0x218 > [ 62.158619] [00864724] kernel_init+0x4/0xf4 > [ 62.158684] [00406084] ret_from_fork+0x1c/0x2c > [ 62.158738] [] (null) > [ 62.158780] Disabling lock debugging due to kernel taint > [ 62.158847] Caller[005bd640]: > ext4_mark_recovery_complete.isra.232+0x4c/0xb0 > [ 62.158926] Caller[005c3860]: ext4_fill_super+0x303c/0x33e8 > [ 62.158990] Caller[00538fc4]: mount_bdev+0x124/0x18c > [ 62.159051] Caller[00539a4c]: mount_fs+0x60/0x17c > [ 62.159143] Caller[0055087c]: vfs_kern_mount+0x48/0xe4 > [ 62.159215] Caller[00552e24]: do_mount+0x808/0x974 > [ 62.159279] Caller[005531b0]: SyS_mount+0x6c/0xa4 > [ 62.159345] Caller[00a74cb8]: mount_block_root+0x108/0x2ac > [ 62.159411] Caller[00a75180]: prepare_namespace+0x180/0x1bc > [ 62.159475] Caller[00a74a80]: kernel_init_freeable+0x208/0x218 > [ 62.159540] Caller[00864724]: kernel_init+0x4/0xf4 > [ 62.159604] Caller[00406084]: ret_from_fork+0x1c/0x2c > [ 62.159660] Caller[]: (null) > [ 62.166652] Instruction DUMP: 901222d8 7ff8d20a 0100 <91d02005> > 11002587 921027a1 0af07ffb 901222d8 c45e2310 > [ 62.207443] Kernel panic - not syncing: Attempted to
Re: kernel BUG at fs/jbd2/journal.c:1951!
On Sun 25-05-14 22:50:53, Meelis Roos wrote: Tried yesterdays git v3.15-rc6-190-g1ee1cea on Sun Fire T2000 (32-thread sparc64) and got reproducibly stuck on boot with ext journal replay like below. Booting Debian 3.14.2-1 replayed the log and mounted FS fine. After that, my test kernel works fine too. SO I can not reproduce it any more but it seems like I hit a bug. [ 62.064329] EXT4-fs (sda1): INFO: recovery required on readonly filesystem [ 62.064395] EXT4-fs (sda1): write access will be enabled during recovery [ 62.077043] EXT4-fs (sda1): orphan cleanup on readonly fs [ 62.156585] EXT4-fs (sda1): 14 orphan inodes deleted [ 62.156645] EXT4-fs (sda1): recovery complete [ 62.156702] kernel BUG at fs/jbd2/journal.c:1951! So if I'm right this is assertion: J_ASSERT(!journal-j_running_transaction); But I don't really see how that could happen especially during mount when there are really just two processes operating in the filesystem - mount and jbd2 process. Hum, after some more thought, maybe this is some strange interaction between writeback completion starting a reserved handle and journal_flush()... There is some potential for problems. Let me think about it for some time. Honza [ 62.156752] \|/ \|/ [ 62.156752] @'/ .. \`@ [ 62.156752] /_| \__/ |_\ [ 62.156752] \__U_/ [ 62.156893] swapper/0(1): Kernel bad sw trap 5 [#1] [ 62.156943] CPU: 8 PID: 1 Comm: swapper/0 Not tainted 3.15.0-rc6+ #6 [ 62.157004] task: ff8008677640 ti: ff800870c000 task.ti: ff800870c000 [ 62.157079] TSTATE: 004480001605 TPC: 005f3c00 TNPC: 005f3c04 Y: Not tainted [ 62.157180] TPC: jbd2_journal_flush+0x11c/0x190 [ 62.157225] g0: 009528c8 g1: g2: 00a17f88 g3: 00a17f80 [ 62.157301] g4: ff8008677640 g5: ff83f6a4a000 g6: ff800870c000 g7: ff8008633fa0 [ 62.157375] o0: 0025 o1: 00961ed8 o2: 079f o3: ff83f3aab888 [ 62.157451] o4: ff83ffb72000 o5: 00961ed8 sp: ff800870ed11 ret_pc: 005f3bf8 [ 62.157530] RPC: jbd2_journal_flush+0x114/0x190 [ 62.157575] l0: l1: 000e l2: 10018001 l3: 0088e438 [ 62.157650] l4: 009528c8 l5: ff00 l6: 00ff l7: 0095ee30 [ 62.157726] i0: ff83f3aab800 i1: ff83f3aab824 i2: ff83f3aabb98 i3: ff83f3aab8e8 [ 62.157801] i4: ff83f3aab824 i5: ff83f3aab8e8 i6: ff800870edc1 i7: 005bd640 [ 62.157887] I7: ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.157942] Call Trace: [ 62.157990] [005bd640] ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158068] [005c3860] ext4_fill_super+0x303c/0x33e8 [ 62.158132] [00538fc4] mount_bdev+0x124/0x18c [ 62.158192] [00539a4c] mount_fs+0x60/0x17c [ 62.158246] [0055087c] vfs_kern_mount+0x48/0xe4 [ 62.158309] [00552e24] do_mount+0x808/0x974 [ 62.158370] [005531b0] SyS_mount+0x6c/0xa4 [ 62.158427] [00a74cb8] mount_block_root+0x108/0x2ac [ 62.158490] [00a75180] prepare_namespace+0x180/0x1bc [ 62.158552] [00a74a80] kernel_init_freeable+0x208/0x218 [ 62.158619] [00864724] kernel_init+0x4/0xf4 [ 62.158684] [00406084] ret_from_fork+0x1c/0x2c [ 62.158738] [] (null) [ 62.158780] Disabling lock debugging due to kernel taint [ 62.158847] Caller[005bd640]: ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158926] Caller[005c3860]: ext4_fill_super+0x303c/0x33e8 [ 62.158990] Caller[00538fc4]: mount_bdev+0x124/0x18c [ 62.159051] Caller[00539a4c]: mount_fs+0x60/0x17c [ 62.159143] Caller[0055087c]: vfs_kern_mount+0x48/0xe4 [ 62.159215] Caller[00552e24]: do_mount+0x808/0x974 [ 62.159279] Caller[005531b0]: SyS_mount+0x6c/0xa4 [ 62.159345] Caller[00a74cb8]: mount_block_root+0x108/0x2ac [ 62.159411] Caller[00a75180]: prepare_namespace+0x180/0x1bc [ 62.159475] Caller[00a74a80]: kernel_init_freeable+0x208/0x218 [ 62.159540] Caller[00864724]: kernel_init+0x4/0xf4 [ 62.159604] Caller[00406084]: ret_from_fork+0x1c/0x2c [ 62.159660] Caller[]: (null) [ 62.166652] Instruction DUMP: 901222d8 7ff8d20a 0100 91d02005 11002587 921027a1 0af07ffb 901222d8 c45e2310 [ 62.207443] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0009 -- Meelis Roos (mr...@linux.ee) -- To unsubscribe from this list: send the line unsubscribe linux-ext4 in the body of a message to majord...@vger.kernel.org More majordomo info
kernel BUG at fs/jbd2/journal.c:1951!
Tried yesterdays git v3.15-rc6-190-g1ee1cea on Sun Fire T2000 (32-thread sparc64) and got reproducibly stuck on boot with ext journal replay like below. Booting Debian 3.14.2-1 replayed the log and mounted FS fine. After that, my test kernel works fine too. SO I can not reproduce it any more but it seems like I hit a bug. [ 62.064329] EXT4-fs (sda1): INFO: recovery required on readonly filesystem [ 62.064395] EXT4-fs (sda1): write access will be enabled during recovery [ 62.077043] EXT4-fs (sda1): orphan cleanup on readonly fs [ 62.156585] EXT4-fs (sda1): 14 orphan inodes deleted [ 62.156645] EXT4-fs (sda1): recovery complete [ 62.156702] kernel BUG at fs/jbd2/journal.c:1951! [ 62.156752] \|/ \|/ [ 62.156752] "@'/ .. \`@" [ 62.156752] /_| \__/ |_\ [ 62.156752] \__U_/ [ 62.156893] swapper/0(1): Kernel bad sw trap 5 [#1] [ 62.156943] CPU: 8 PID: 1 Comm: swapper/0 Not tainted 3.15.0-rc6+ #6 [ 62.157004] task: ff8008677640 ti: ff800870c000 task.ti: ff800870c000 [ 62.157079] TSTATE: 004480001605 TPC: 005f3c00 TNPC: 005f3c04 Y: Not tainted [ 62.157180] TPC: [ 62.157225] g0: 009528c8 g1: g2: 00a17f88 g3: 00a17f80 [ 62.157301] g4: ff8008677640 g5: ff83f6a4a000 g6: ff800870c000 g7: ff8008633fa0 [ 62.157375] o0: 0025 o1: 00961ed8 o2: 079f o3: ff83f3aab888 [ 62.157451] o4: ff83ffb72000 o5: 00961ed8 sp: ff800870ed11 ret_pc: 005f3bf8 [ 62.157530] RPC: [ 62.157575] l0: l1: 000e l2: 10018001 l3: 0088e438 [ 62.157650] l4: 009528c8 l5: ff00 l6: 00ff l7: 0095ee30 [ 62.157726] i0: ff83f3aab800 i1: ff83f3aab824 i2: ff83f3aabb98 i3: ff83f3aab8e8 [ 62.157801] i4: ff83f3aab824 i5: ff83f3aab8e8 i6: ff800870edc1 i7: 005bd640 [ 62.157887] I7: [ 62.157942] Call Trace: [ 62.157990] [005bd640] ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158068] [005c3860] ext4_fill_super+0x303c/0x33e8 [ 62.158132] [00538fc4] mount_bdev+0x124/0x18c [ 62.158192] [00539a4c] mount_fs+0x60/0x17c [ 62.158246] [0055087c] vfs_kern_mount+0x48/0xe4 [ 62.158309] [00552e24] do_mount+0x808/0x974 [ 62.158370] [005531b0] SyS_mount+0x6c/0xa4 [ 62.158427] [00a74cb8] mount_block_root+0x108/0x2ac [ 62.158490] [00a75180] prepare_namespace+0x180/0x1bc [ 62.158552] [00a74a80] kernel_init_freeable+0x208/0x218 [ 62.158619] [00864724] kernel_init+0x4/0xf4 [ 62.158684] [00406084] ret_from_fork+0x1c/0x2c [ 62.158738] [] (null) [ 62.158780] Disabling lock debugging due to kernel taint [ 62.158847] Caller[005bd640]: ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158926] Caller[005c3860]: ext4_fill_super+0x303c/0x33e8 [ 62.158990] Caller[00538fc4]: mount_bdev+0x124/0x18c [ 62.159051] Caller[00539a4c]: mount_fs+0x60/0x17c [ 62.159143] Caller[0055087c]: vfs_kern_mount+0x48/0xe4 [ 62.159215] Caller[00552e24]: do_mount+0x808/0x974 [ 62.159279] Caller[005531b0]: SyS_mount+0x6c/0xa4 [ 62.159345] Caller[00a74cb8]: mount_block_root+0x108/0x2ac [ 62.159411] Caller[00a75180]: prepare_namespace+0x180/0x1bc [ 62.159475] Caller[00a74a80]: kernel_init_freeable+0x208/0x218 [ 62.159540] Caller[00864724]: kernel_init+0x4/0xf4 [ 62.159604] Caller[00406084]: ret_from_fork+0x1c/0x2c [ 62.159660] Caller[]: (null) [ 62.166652] Instruction DUMP: 901222d8 7ff8d20a 0100 <91d02005> 11002587 921027a1 0af07ffb 901222d8 c45e2310 [ 62.207443] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0009 -- Meelis Roos (mr...@linux.ee) -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
kernel BUG at fs/jbd2/journal.c:1951!
Tried yesterdays git v3.15-rc6-190-g1ee1cea on Sun Fire T2000 (32-thread sparc64) and got reproducibly stuck on boot with ext journal replay like below. Booting Debian 3.14.2-1 replayed the log and mounted FS fine. After that, my test kernel works fine too. SO I can not reproduce it any more but it seems like I hit a bug. [ 62.064329] EXT4-fs (sda1): INFO: recovery required on readonly filesystem [ 62.064395] EXT4-fs (sda1): write access will be enabled during recovery [ 62.077043] EXT4-fs (sda1): orphan cleanup on readonly fs [ 62.156585] EXT4-fs (sda1): 14 orphan inodes deleted [ 62.156645] EXT4-fs (sda1): recovery complete [ 62.156702] kernel BUG at fs/jbd2/journal.c:1951! [ 62.156752] \|/ \|/ [ 62.156752] @'/ .. \`@ [ 62.156752] /_| \__/ |_\ [ 62.156752] \__U_/ [ 62.156893] swapper/0(1): Kernel bad sw trap 5 [#1] [ 62.156943] CPU: 8 PID: 1 Comm: swapper/0 Not tainted 3.15.0-rc6+ #6 [ 62.157004] task: ff8008677640 ti: ff800870c000 task.ti: ff800870c000 [ 62.157079] TSTATE: 004480001605 TPC: 005f3c00 TNPC: 005f3c04 Y: Not tainted [ 62.157180] TPC: jbd2_journal_flush+0x11c/0x190 [ 62.157225] g0: 009528c8 g1: g2: 00a17f88 g3: 00a17f80 [ 62.157301] g4: ff8008677640 g5: ff83f6a4a000 g6: ff800870c000 g7: ff8008633fa0 [ 62.157375] o0: 0025 o1: 00961ed8 o2: 079f o3: ff83f3aab888 [ 62.157451] o4: ff83ffb72000 o5: 00961ed8 sp: ff800870ed11 ret_pc: 005f3bf8 [ 62.157530] RPC: jbd2_journal_flush+0x114/0x190 [ 62.157575] l0: l1: 000e l2: 10018001 l3: 0088e438 [ 62.157650] l4: 009528c8 l5: ff00 l6: 00ff l7: 0095ee30 [ 62.157726] i0: ff83f3aab800 i1: ff83f3aab824 i2: ff83f3aabb98 i3: ff83f3aab8e8 [ 62.157801] i4: ff83f3aab824 i5: ff83f3aab8e8 i6: ff800870edc1 i7: 005bd640 [ 62.157887] I7: ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.157942] Call Trace: [ 62.157990] [005bd640] ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158068] [005c3860] ext4_fill_super+0x303c/0x33e8 [ 62.158132] [00538fc4] mount_bdev+0x124/0x18c [ 62.158192] [00539a4c] mount_fs+0x60/0x17c [ 62.158246] [0055087c] vfs_kern_mount+0x48/0xe4 [ 62.158309] [00552e24] do_mount+0x808/0x974 [ 62.158370] [005531b0] SyS_mount+0x6c/0xa4 [ 62.158427] [00a74cb8] mount_block_root+0x108/0x2ac [ 62.158490] [00a75180] prepare_namespace+0x180/0x1bc [ 62.158552] [00a74a80] kernel_init_freeable+0x208/0x218 [ 62.158619] [00864724] kernel_init+0x4/0xf4 [ 62.158684] [00406084] ret_from_fork+0x1c/0x2c [ 62.158738] [] (null) [ 62.158780] Disabling lock debugging due to kernel taint [ 62.158847] Caller[005bd640]: ext4_mark_recovery_complete.isra.232+0x4c/0xb0 [ 62.158926] Caller[005c3860]: ext4_fill_super+0x303c/0x33e8 [ 62.158990] Caller[00538fc4]: mount_bdev+0x124/0x18c [ 62.159051] Caller[00539a4c]: mount_fs+0x60/0x17c [ 62.159143] Caller[0055087c]: vfs_kern_mount+0x48/0xe4 [ 62.159215] Caller[00552e24]: do_mount+0x808/0x974 [ 62.159279] Caller[005531b0]: SyS_mount+0x6c/0xa4 [ 62.159345] Caller[00a74cb8]: mount_block_root+0x108/0x2ac [ 62.159411] Caller[00a75180]: prepare_namespace+0x180/0x1bc [ 62.159475] Caller[00a74a80]: kernel_init_freeable+0x208/0x218 [ 62.159540] Caller[00864724]: kernel_init+0x4/0xf4 [ 62.159604] Caller[00406084]: ret_from_fork+0x1c/0x2c [ 62.159660] Caller[]: (null) [ 62.166652] Instruction DUMP: 901222d8 7ff8d20a 0100 91d02005 11002587 921027a1 0af07ffb 901222d8 c45e2310 [ 62.207443] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0009 -- Meelis Roos (mr...@linux.ee) -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
