Heming Zhao
2023-May-01 03:09 UTC
[Ocfs2-devel] [PATCH 1/2] ocfs2: fix missing reset j_num_trans for sync
On Mon, May 01, 2023 at 10:52:13AM +0800, Joseph Qi wrote:> > > On 5/1/23 10:26 AM, Heming Zhao wrote: > > On Mon, May 01, 2023 at 10:07:34AM +0800, Joseph Qi wrote: > >> Hi, > >> > >> What's the journal status in this case? > > jbd2 is marked with JBD2_ABORT > > > >> I wonder why commit thread is not working, which should flush journal > >> and reset j_num_trans during commit cache. > > The reason is in my above answer. > > > > below is the dmesg log for No. 266. > > > > ``` > > [ 595.071807] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... > > [ 595.080950] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > [ 595.081091] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 > > [ 595.081580] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 > > [ 595.081886] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes > > [ 595.082173] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 > > [ 595.082420] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory > > [ 595.082696] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new > > [ 595.082932] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages > > [ 595.083188] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms > > [ 595.084721] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete > > [ 595.095436] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. > > [ 595.787078] systemd[1]: Started /usr/bin/bash -c exit 77. > > [ 595.802650] systemd[1]: fstests-check.scope: Deactivated successfully. > > [ 596.195734] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: joining the lockspace group... > > [ 596.206310] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 > > [ 596.206350] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 > > [ 596.209667] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: add member 1 > > [ 596.211433] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_members 1 nodes > > [ 596.213942] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: generation 1 slots 1 1:1 > > [ 596.215668] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory > > [ 596.217171] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 in 0 new > > [ 596.218253] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 out 0 messages > > [ 596.219401] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 generation 1 done: 0 ms > > [ 596.220628] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: join complete > > [ 596.224616] kernel: JBD2: Ignoring recovery information on journal > > [ 596.229686] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. > > [ 596.870008] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > [ 596.236135] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: leaving the lockspace group... > > [ 596.237431] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 > > [ 596.239442] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: release_lockspace final free > > [ 596.877286] ocfs2_hb_ctl[5436]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 78CE18109AE44E6AA896722A5E25CFC0 > > [ 596.248299] kernel: ocfs2: Unmounting device (253,32) on (node 1) > > [ 596.255888] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: leaving the lockspace group... > > [ 596.905718] systemd[1]: fstest-test.mount: Deactivated successfully. > > [ 596.280602] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > [ 596.281762] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: release_lockspace final free > > [ 596.921672] ocfs2_hb_ctl[5448]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 838DD74847E34AA1839D6C4AA31132F1 > > [ 596.299507] kernel: ocfs2: Unmounting device (253,16) on (node 1) > > [ 596.481755] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... > > [ 596.484722] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 > > [ 596.484729] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > [ 596.485361] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 > > [ 596.485622] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes > > [ 596.485861] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 > > [ 596.486063] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory > > [ 596.486293] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new > > [ 596.486498] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages > > [ 596.486768] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms > > [ 596.487037] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete > > [ 596.491655] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. > > [ 597.139758] root[5475]: run xfstest generic/266 > > [ 596.505896] unknown: run fstests generic/266 at 2023-05-01 10:19:02 > > [ 597.186885] systemd[1]: Started /usr/bin/bash -c test -w /proc/self/oom_score_adj && echo 250 > /proc/self/oom_score_adj; exec ./tests/generic/266. > > [ 597.566466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... > > [ 597.579759] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > [ 597.579766] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 > > [ 597.581004] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 > > [ 597.581820] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes > > [ 597.582292] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 > > [ 597.582894] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory > > [ 597.583423] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new > > [ 597.583991] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages > > [ 597.584547] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 4 ms > > [ 597.585079] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete > > [ 597.590136] kernel: JBD2: Ignoring recovery information on journal > > [ 597.594258] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. > > [ 598.239046] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > [ 597.606575] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: leaving the lockspace group... > > [ 597.607446] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > [ 598.244507] ocfs2_hb_ctl[5680]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u AB0245F740984C25A9D0907D61DFCF8A > > [ 597.607843] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: release_lockspace final free > > [ 597.615474] kernel: ocfs2: Unmounting device (253,32) on (node 1) > > [ 597.641624] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... > > [ 597.659435] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 > > [ 597.659479] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > [ 597.661482] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 > > [ 597.662340] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes > > [ 597.663211] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 > > [ 597.664150] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory > > [ 597.665466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new > > [ 597.666370] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages > > [ 597.667235] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 0 ms > > [ 597.668428] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete > > [ 600.194974] systemd[1]: Started Daily Cleanup of Snapper Snapshots. > > [ 600.207227] dbus-daemon[672]: [system] Activating via systemd: service name='org.opensuse.Snapper' unit='snapperd.service' requested by ':1.10' (uid=0 pid=5728 comm="/usr/lib/snapper/systemd-helper --cleanup") > > [ 600.209151] systemd[1]: Starting DBus interface for snapper... > > [ 600.217270] dbus-daemon[672]: [system] Successfully activated service 'org.opensuse.Snapper' > > [ 600.217370] systemd[1]: Started DBus interface for snapper. > > [ 600.218969] systemd[1]: snapper-cleanup.service: Deactivated successfully. > > [ 599.608010] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... > > [ 599.611041] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 > > [ 599.611127] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > [ 599.611813] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 > > [ 599.612019] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes > > [ 599.612227] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 > > [ 599.612397] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory > > [ 599.612559] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new > > [ 599.612712] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages > > [ 599.612880] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 0 ms > > [ 599.613078] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete > > [ 599.615320] kernel: JBD2: Ignoring recovery information on journal > > [ 599.619221] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. > > [ 600.392044] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > [ 599.780111] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: leaving the lockspace group... > > [ 599.781949] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > [ 599.784235] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: release_lockspace final free > > [ 600.426136] ocfs2_hb_ctl[5762]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u F06626AE7D754F11A0211679C145C8BF > > [ 599.808566] kernel: ocfs2: Unmounting device (254,0) on (node 1) > > [ 599.827803] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... > > [ 599.832848] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 > > [ 599.832984] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > [ 599.833810] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 > > [ 599.834272] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes > > [ 599.834663] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 > > [ 599.835030] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory > > [ 599.835474] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new > > [ 599.835868] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages > > [ 599.836365] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 4 ms > > [ 599.836829] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete > > [ 599.845790] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. > > [ 600.079285] kernel: Buffer I/O error on dev dm-0, logical block 2621424, async page read > > [ 600.090845] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > [ 600.091387] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > [ 600.091924] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > [ 600.092422] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > [ 600.094252] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > [ 600.095029] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > [ 600.095891] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > [ 600.096698] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > [ 600.099071] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > [ 600.099957] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > [ 600.100798] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > [ 600.101623] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > [ 600.107094] kernel: (xfs_io,5785,1):ocfs2_get_refcount_tree:358 ERROR: status = -5 > > [ 600.107659] kernel: (xfs_io,5785,1):ocfs2_lock_refcount_tree:456 ERROR: status = -5 > > [ 600.108175] kernel: (xfs_io,5785,1):ocfs2_refcount_cow_hunk:3417 ERROR: status = -5 > > [ 600.108654] kernel: (xfs_io,5785,1):ocfs2_refcount_cow:3478 ERROR: status = -5 > > [ 600.109128] kernel: (xfs_io,5785,1):ocfs2_prepare_inode_for_write:2326 ERROR: status = -5 > > [ 600.109613] kernel: (xfs_io,5785,1):ocfs2_file_write_iter:2433 ERROR: status = -5 > > [ 600.118113] kernel: (umount,5789,3):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > [ 600.118481] kernel: (umount,5789,3):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > [ 600.118898] kernel: (umount,5789,3):ocfs2_statfs:1654 ERROR: status = -5 > > [ 600.119364] kernel: (umount,5789,3):ocfs2_statfs:1686 ERROR: status = -5 > > [ 600.759255] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > [ 600.127135] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write > > [ 600.127373] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. > > [ 600.127615] kernel: Aborting journal on device dm-0-24. > > [ 600.127893] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write > > [ 600.128137] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. > > [ 600.128362] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 600.128591] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. > > [ 601.147704] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 602.171745] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 603.195707] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 604.219709] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 605.243712] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 606.267748] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 607.291715] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 608.315742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 609.339724] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 610.363774] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 611.387693] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 612.411727] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 613.435719] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 614.459743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 615.483742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 615.484503] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. > > [ 616.507742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 617.531751] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 618.555743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 619.579702] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > [ 620.603758] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > ^C > > tb-fstest1:/usr/src/linux/fs/ocfs2 # > > ``` > > So the case is, flush journal in commit thread will never end if journal > is abort, and then lead to umount hang since commit thread won't stop, > right?Yes.> > If so, I don't think your changes in sync fs is a right solution. It > seems it just for bypassing the testcase.No. In my view, No. 266 shouldn't trigger jbd2 ABORT status. The 'sync' should tidy up all already issued write IOs. After sync & load dm-error, new write IOs fails on rw IOs, which shouldn't generate any journal IOs and shouldn't trigger jbd2 to enter ABORT status.> > If the expected behavior is to let umount ends even journal is abort, > it seems we have to make journal shutdown happy in this case.This is my [patch 2/2] job, which resolves fstest generaic NO. 347 361 628 629. - Heming
Heming Zhao
2023-May-01 03:17 UTC
[Ocfs2-devel] [PATCH 1/2] ocfs2: fix missing reset j_num_trans for sync
On Mon, May 01, 2023 at 11:10:06AM +0800, Heming Zhao wrote:> On Mon, May 01, 2023 at 10:52:13AM +0800, Joseph Qi wrote: > > > > > > On 5/1/23 10:26 AM, Heming Zhao wrote: > > > On Mon, May 01, 2023 at 10:07:34AM +0800, Joseph Qi wrote: > > >> Hi, > > >> > > >> What's the journal status in this case? > > > jbd2 is marked with JBD2_ABORT > > > > > >> I wonder why commit thread is not working, which should flush journal > > >> and reset j_num_trans during commit cache. > > > The reason is in my above answer. > > > > > > below is the dmesg log for No. 266. > > > > > > ``` > > > [ 595.071807] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... > > > [ 595.080950] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > > [ 595.081091] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 > > > [ 595.081580] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 > > > [ 595.081886] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes > > > [ 595.082173] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 > > > [ 595.082420] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory > > > [ 595.082696] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new > > > [ 595.082932] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages > > > [ 595.083188] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms > > > [ 595.084721] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete > > > [ 595.095436] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. > > > [ 595.787078] systemd[1]: Started /usr/bin/bash -c exit 77. > > > [ 595.802650] systemd[1]: fstests-check.scope: Deactivated successfully. > > > [ 596.195734] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: joining the lockspace group... > > > [ 596.206310] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 > > > [ 596.206350] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 > > > [ 596.209667] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: add member 1 > > > [ 596.211433] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_members 1 nodes > > > [ 596.213942] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: generation 1 slots 1 1:1 > > > [ 596.215668] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory > > > [ 596.217171] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 in 0 new > > > [ 596.218253] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 out 0 messages > > > [ 596.219401] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 generation 1 done: 0 ms > > > [ 596.220628] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: join complete > > > [ 596.224616] kernel: JBD2: Ignoring recovery information on journal > > > [ 596.229686] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. > > > [ 596.870008] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > > [ 596.236135] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: leaving the lockspace group... > > > [ 596.237431] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 > > > [ 596.239442] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: release_lockspace final free > > > [ 596.877286] ocfs2_hb_ctl[5436]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 78CE18109AE44E6AA896722A5E25CFC0 > > > [ 596.248299] kernel: ocfs2: Unmounting device (253,32) on (node 1) > > > [ 596.255888] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: leaving the lockspace group... > > > [ 596.905718] systemd[1]: fstest-test.mount: Deactivated successfully. > > > [ 596.280602] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > > [ 596.281762] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: release_lockspace final free > > > [ 596.921672] ocfs2_hb_ctl[5448]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 838DD74847E34AA1839D6C4AA31132F1 > > > [ 596.299507] kernel: ocfs2: Unmounting device (253,16) on (node 1) > > > [ 596.481755] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... > > > [ 596.484722] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 > > > [ 596.484729] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 > > > [ 596.485361] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 > > > [ 596.485622] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes > > > [ 596.485861] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 > > > [ 596.486063] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory > > > [ 596.486293] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new > > > [ 596.486498] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages > > > [ 596.486768] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms > > > [ 596.487037] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete > > > [ 596.491655] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. > > > [ 597.139758] root[5475]: run xfstest generic/266 > > > [ 596.505896] unknown: run fstests generic/266 at 2023-05-01 10:19:02 > > > [ 597.186885] systemd[1]: Started /usr/bin/bash -c test -w /proc/self/oom_score_adj && echo 250 > /proc/self/oom_score_adj; exec ./tests/generic/266. > > > [ 597.566466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... > > > [ 597.579759] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > > [ 597.579766] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 > > > [ 597.581004] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 > > > [ 597.581820] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes > > > [ 597.582292] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 > > > [ 597.582894] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory > > > [ 597.583423] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new > > > [ 597.583991] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages > > > [ 597.584547] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 4 ms > > > [ 597.585079] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete > > > [ 597.590136] kernel: JBD2: Ignoring recovery information on journal > > > [ 597.594258] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. > > > [ 598.239046] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > > [ 597.606575] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: leaving the lockspace group... > > > [ 597.607446] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > > [ 598.244507] ocfs2_hb_ctl[5680]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u AB0245F740984C25A9D0907D61DFCF8A > > > [ 597.607843] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: release_lockspace final free > > > [ 597.615474] kernel: ocfs2: Unmounting device (253,32) on (node 1) > > > [ 597.641624] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... > > > [ 597.659435] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 > > > [ 597.659479] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 > > > [ 597.661482] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 > > > [ 597.662340] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes > > > [ 597.663211] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 > > > [ 597.664150] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory > > > [ 597.665466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new > > > [ 597.666370] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages > > > [ 597.667235] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 0 ms > > > [ 597.668428] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete > > > [ 600.194974] systemd[1]: Started Daily Cleanup of Snapper Snapshots. > > > [ 600.207227] dbus-daemon[672]: [system] Activating via systemd: service name='org.opensuse.Snapper' unit='snapperd.service' requested by ':1.10' (uid=0 pid=5728 comm="/usr/lib/snapper/systemd-helper --cleanup") > > > [ 600.209151] systemd[1]: Starting DBus interface for snapper... > > > [ 600.217270] dbus-daemon[672]: [system] Successfully activated service 'org.opensuse.Snapper' > > > [ 600.217370] systemd[1]: Started DBus interface for snapper. > > > [ 600.218969] systemd[1]: snapper-cleanup.service: Deactivated successfully. > > > [ 599.608010] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... > > > [ 599.611041] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 > > > [ 599.611127] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > > [ 599.611813] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 > > > [ 599.612019] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes > > > [ 599.612227] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 > > > [ 599.612397] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory > > > [ 599.612559] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new > > > [ 599.612712] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages > > > [ 599.612880] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 0 ms > > > [ 599.613078] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete > > > [ 599.615320] kernel: JBD2: Ignoring recovery information on journal > > > [ 599.619221] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. > > > [ 600.392044] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > > [ 599.780111] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: leaving the lockspace group... > > > [ 599.781949] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > > [ 599.784235] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: release_lockspace final free > > > [ 600.426136] ocfs2_hb_ctl[5762]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u F06626AE7D754F11A0211679C145C8BF > > > [ 599.808566] kernel: ocfs2: Unmounting device (254,0) on (node 1) > > > [ 599.827803] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... > > > [ 599.832848] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 > > > [ 599.832984] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 > > > [ 599.833810] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 > > > [ 599.834272] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes > > > [ 599.834663] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 > > > [ 599.835030] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory > > > [ 599.835474] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new > > > [ 599.835868] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages > > > [ 599.836365] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 4 ms > > > [ 599.836829] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete > > > [ 599.845790] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. > > > [ 600.079285] kernel: Buffer I/O error on dev dm-0, logical block 2621424, async page read > > > [ 600.090845] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > > [ 600.091387] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > > [ 600.091924] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > > [ 600.092422] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > > [ 600.094252] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > > [ 600.095029] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > > [ 600.095891] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > > [ 600.096698] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > > [ 600.099071] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > > [ 600.099957] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > > [ 600.100798] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 > > > [ 600.101623] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 > > > [ 600.107094] kernel: (xfs_io,5785,1):ocfs2_get_refcount_tree:358 ERROR: status = -5 > > > [ 600.107659] kernel: (xfs_io,5785,1):ocfs2_lock_refcount_tree:456 ERROR: status = -5 > > > [ 600.108175] kernel: (xfs_io,5785,1):ocfs2_refcount_cow_hunk:3417 ERROR: status = -5 > > > [ 600.108654] kernel: (xfs_io,5785,1):ocfs2_refcount_cow:3478 ERROR: status = -5 > > > [ 600.109128] kernel: (xfs_io,5785,1):ocfs2_prepare_inode_for_write:2326 ERROR: status = -5 > > > [ 600.109613] kernel: (xfs_io,5785,1):ocfs2_file_write_iter:2433 ERROR: status = -5 > > > [ 600.118113] kernel: (umount,5789,3):ocfs2_inode_lock_update:2354 ERROR: status = -5 > > > [ 600.118481] kernel: (umount,5789,3):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 > > > [ 600.118898] kernel: (umount,5789,3):ocfs2_statfs:1654 ERROR: status = -5 > > > [ 600.119364] kernel: (umount,5789,3):ocfs2_statfs:1686 ERROR: status = -5 > > > [ 600.759255] systemd[1]: fstest-scratch.mount: Deactivated successfully. > > > [ 600.127135] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write > > > [ 600.127373] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. > > > [ 600.127615] kernel: Aborting journal on device dm-0-24. > > > [ 600.127893] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write > > > [ 600.128137] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. > > > [ 600.128362] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 600.128591] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. > > > [ 601.147704] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 602.171745] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 603.195707] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 604.219709] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 605.243712] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 606.267748] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 607.291715] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 608.315742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 609.339724] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 610.363774] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 611.387693] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 612.411727] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 613.435719] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 614.459743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 615.483742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 615.484503] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. > > > [ 616.507742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 617.531751] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 618.555743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 619.579702] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > [ 620.603758] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 > > > ^C > > > tb-fstest1:/usr/src/linux/fs/ocfs2 # > > > ``` > > > > So the case is, flush journal in commit thread will never end if journal > > is abort, and then lead to umount hang since commit thread won't stop, > > right? > Yes. > > > > > If so, I don't think your changes in sync fs is a right solution. It > > seems it just for bypassing the testcase. > No. > In my view, No. 266 shouldn't trigger jbd2 ABORT status. The 'sync' should > tidy up all already issued write IOs. After sync & load dm-error, new write IOs > fails on rw IOs, which shouldn't generate any journal IOs and shouldn't trigger > jbd2 to enter ABORT status. > > > > > If the expected behavior is to let umount ends even journal is abort, > > it seems we have to make journal shutdown happy in this case. > This is my [patch 2/2] job, which resolves fstest generaic NO. 347 361 628 629. > > - HemingThe log after patching [1/2] (without patch [2/2]) ``` [ 2252.964874] root[2991]: run xfstest generic/266 [ 2252.566084] unknown: run fstests generic/266 at 2023-05-01 10:58:37 [ 2253.006923] systemd[1]: Started /usr/bin/bash -c test -w /proc/self/oom_score_adj && echo 250 > /proc/self/oom_score_adj; exec ./tests/generic/266. [ 2253.595670] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: joining the lockspace group... [ 2253.598924] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover 1 [ 2253.598954] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: group event done 0 [ 2253.601184] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: add member 1 [ 2253.602340] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_members 1 nodes [ 2253.602624] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: generation 1 slots 1 1:1 [ 2253.602842] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory [ 2253.603010] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory 0 in 0 new [ 2253.603171] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory 0 out 0 messages [ 2253.603340] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover 1 generation 1 done: 0 ms [ 2253.603619] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: join complete [ 2253.606374] kernel: JBD2: Ignoring recovery information on journal [ 2253.611239] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. [ 2254.020143] systemd[1]: fstest-scratch.mount: Deactivated successfully. [ 2253.623800] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: leaving the lockspace group... [ 2253.624720] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: group event done 0 [ 2253.626368] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: release_lockspace final free [ 2254.027879] ocfs2_hb_ctl[3197]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u D9AC6C30527E4F8799E9BCDAC64F2F47 [ 2253.634342] kernel: ocfs2: Unmounting device (253,32) on (node 1) [ 2253.659701] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: joining the lockspace group... [ 2253.668134] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: group event done 0 [ 2253.668158] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover 1 [ 2253.668583] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: add member 1 [ 2253.668792] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_members 1 nodes [ 2253.669003] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: generation 1 slots 1 1:1 [ 2253.669211] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory [ 2253.669670] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory 0 in 0 new [ 2253.670034] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover_directory 0 out 0 messages [ 2253.670610] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: dlm_recover 1 generation 1 done: 4 ms [ 2253.671041] kernel: dlm: D9AC6C30527E4F8799E9BCDAC64F2F47: join complete [ 2255.687006] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: joining the lockspace group... [ 2255.689981] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: group event done 0 [ 2255.689993] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 [ 2255.690435] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: add member 1 [ 2255.690688] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_members 1 nodes [ 2255.690897] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: generation 1 slots 1 1:1 [ 2255.691128] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory [ 2255.691354] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 in 0 new [ 2255.691561] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 out 0 messages [ 2255.691847] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 generation 1 done: 0 ms [ 2255.692446] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: join complete [ 2255.695546] kernel: JBD2: Ignoring recovery information on journal [ 2255.700152] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. [ 2256.230778] systemd[1]: fstest-scratch.mount: Deactivated successfully. [ 2255.851082] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: leaving the lockspace group... [ 2255.853187] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: group event done 0 [ 2255.855128] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: release_lockspace final free [ 2256.260312] ocfs2_hb_ctl[3265]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 0DCC4C24451D49CF918C2994FD09B36B [ 2255.871911] kernel: ocfs2: Unmounting device (254,0) on (node 1) [ 2255.885376] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: joining the lockspace group... [ 2255.898789] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 [ 2255.898801] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: group event done 0 [ 2255.899523] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: add member 1 [ 2255.899899] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_members 1 nodes [ 2255.900227] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: generation 1 slots 1 1:1 [ 2255.900544] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory [ 2255.900875] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 in 0 new [ 2255.901153] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 out 0 messages [ 2255.901516] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 generation 1 done: 0 ms [ 2255.901944] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: join complete [ 2255.908503] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. [ 2256.139340] kernel: Buffer I/O error on dev dm-0, logical block 2621424, async page read [ 2256.151624] kernel: (xfs_io,3288,1):ocfs2_inode_lock_update:2354 ERROR: status = -5 [ 2256.152027] kernel: (xfs_io,3288,1):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 [ 2256.152422] kernel: (xfs_io,3288,1):ocfs2_statfs:1652 ERROR: status = -5 [ 2256.152778] kernel: (xfs_io,3288,1):ocfs2_statfs:1684 ERROR: status = -5 [ 2256.154220] kernel: (xfs_io,3288,1):ocfs2_inode_lock_update:2354 ERROR: status = -5 [ 2256.154673] kernel: (xfs_io,3288,1):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 [ 2256.154995] kernel: (xfs_io,3288,1):ocfs2_statfs:1652 ERROR: status = -5 [ 2256.155272] kernel: (xfs_io,3288,1):ocfs2_statfs:1684 ERROR: status = -5 [ 2256.157120] kernel: (xfs_io,3288,1):ocfs2_inode_lock_update:2354 ERROR: status = -5 [ 2256.157425] kernel: (xfs_io,3288,1):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 [ 2256.157713] kernel: (xfs_io,3288,1):ocfs2_statfs:1652 ERROR: status = -5 [ 2256.157994] kernel: (xfs_io,3288,1):ocfs2_statfs:1684 ERROR: status = -5 [ 2256.160671] kernel: (xfs_io,3288,3):ocfs2_get_refcount_tree:358 ERROR: status = -5 [ 2256.160956] kernel: (xfs_io,3288,3):ocfs2_lock_refcount_tree:456 ERROR: status = -5 [ 2256.161205] kernel: (xfs_io,3288,3):ocfs2_refcount_cow_hunk:3417 ERROR: status = -5 [ 2256.161445] kernel: (xfs_io,3288,3):ocfs2_refcount_cow:3478 ERROR: status = -5 [ 2256.161680] kernel: (xfs_io,3288,3):ocfs2_prepare_inode_for_write:2326 ERROR: status = -5 [ 2256.161918] kernel: (xfs_io,3288,3):ocfs2_file_write_iter:2433 ERROR: status = -5 [ 2256.570033] systemd[1]: fstest-scratch.mount: Deactivated successfully. [ 2256.166077] kernel: (umount,3292,3):ocfs2_inode_lock_update:2354 ERROR: status = -5 [ 2256.166494] kernel: (umount,3292,3):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 [ 2256.166745] kernel: (umount,3292,3):ocfs2_statfs:1652 ERROR: status = -5 [ 2256.166965] kernel: (umount,3292,3):ocfs2_statfs:1684 ERROR: status = -5 [ 2256.174011] kernel: (umount,3292,3):ocfs2_inode_lock_update:2354 ERROR: status = -5 [ 2256.174249] kernel: (umount,3292,3):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 [ 2256.174511] kernel: (umount,3292,3):ocfs2_shutdown_local_alloc:416 ERROR: status = -5 [ 2256.175558] kernel: Buffer I/O error on dev dm-0, logical block 70163, lost sync page write [ 2256.176960] kernel: (umount,3292,3):ocfs2_write_block:78 ERROR: status = -5 [ 2256.177256] kernel: (umount,3292,3):ocfs2_update_disk_slot:199 ERROR: status = -5 [ 2256.177498] kernel: (umount,3292,3):ocfs2_put_slot:517 ERROR: status = -5 [ 2256.178604] kernel: Buffer I/O error on dev dm-0, logical block 24, lost sync page write [ 2256.178933] kernel: (umount,3292,2):ocfs2_write_block:78 ERROR: status = -5 [ 2256.179215] kernel: (umount,3292,2):ocfs2_journal_toggle_dirty:984 ERROR: status = -5 [ 2256.179449] kernel: (umount,3292,2):ocfs2_journal_shutdown:1052 ERROR: status = -5 [ 2256.179881] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: leaving the lockspace group... [ 2256.181581] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: group event done 0 [ 2256.182134] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: release_lockspace final free [ 2256.583796] ocfs2_hb_ctl[3293]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 0DCC4C24451D49CF918C2994FD09B36B [ 2256.194870] kernel: ocfs2: Unmounting device (254,0) on (node 1) [ 2256.202861] kernel: dm-0: detected capacity change from 20971520 to 0 [ 2256.241314] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: joining the lockspace group... [ 2256.244424] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 [ 2256.244431] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: group event done 0 [ 2256.245010] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: add member 1 [ 2256.245186] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_members 1 nodes [ 2256.245360] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: generation 1 slots 1 1:1 [ 2256.245527] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory [ 2256.245690] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 in 0 new [ 2256.245848] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover_directory 0 out 0 messages [ 2256.246015] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: dlm_recover 1 generation 1 done: 0 ms [ 2256.246295] kernel: dlm: 0DCC4C24451D49CF918C2994FD09B36B: join complete [ 2257.367729] kernel: ocfs2: Unable to create the lockspace 0DCC4C24451D49CF918C2994FD09B36B (-17), because a ocfs2-tools program is running on this file system with the same name lockspace [ 2257.368058] kernel: (mount.ocfs2,3306,0):ocfs2_dlm_init:3355 ERROR: status = -17 [ 2257.368264] kernel: (mount.ocfs2,3306,2):ocfs2_mount_volume:1808 ERROR: status = -17 [ 2257.368596] kernel: (mount.ocfs2,3306,2):ocfs2_fill_super:1192 ERROR: status = -17 [ 2257.800975] systemd[1]: fstests-generic-266.scope: Deactivated successfully. [ 2257.823311] systemd[1]: fstest-test.mount: Deactivated successfully. [ 2257.424691] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: leaving the lockspace group... [ 2257.426048] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 [ 2257.829022] ocfs2_hb_ctl[3323]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 838DD74847E34AA1839D6C4AA31132F1 [ 2257.427000] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: release_lockspace final free [ 2257.434399] kernel: ocfs2: Unmounting device (253,16) on (node 1) [ 2337.361206] CRON[3392]: (root) CMD (run-parts /etc/cron.hourly) [ 2337.367344] CRON[3391]: (root) CMDEND (run-parts /etc/cron.hourly) [ 2365.960233] systemd[1]: Started Timeline of Snapper Snapshots. [ 2365.967411] dbus-daemon[672]: [system] Activating via systemd: service name='org.opensuse.Snapper' unit='snapperd.service' requested by ':1.12' (uid=0 pid=3407 comm="/usr/lib/snapper/systemd-helper --timeline") [ 2365.969446] systemd[1]: Starting DBus interface for snapper... [ 2365.973698] dbus-daemon[672]: [system] Successfully activated service 'org.opensuse.Snapper' [ 2365.973755] systemd[1]: Started DBus interface for snapper. [ 2365.974893] systemd[1]: snapper-timeline.service: Deactivated successfully. [ 2426.037566] systemd[1]: snapperd.service: Deactivated successfully. ^C tb-fstest1:/usr/src/linux/fs/ocfs2 # ``` - Heming
Joseph Qi
2023-May-01 03:21 UTC
[Ocfs2-devel] [PATCH 1/2] ocfs2: fix missing reset j_num_trans for sync
On 5/1/23 11:09 AM, Heming Zhao wrote:> On Mon, May 01, 2023 at 10:52:13AM +0800, Joseph Qi wrote: >> >> >> On 5/1/23 10:26 AM, Heming Zhao wrote: >>> On Mon, May 01, 2023 at 10:07:34AM +0800, Joseph Qi wrote: >>>> Hi, >>>> >>>> What's the journal status in this case? >>> jbd2 is marked with JBD2_ABORT >>> >>>> I wonder why commit thread is not working, which should flush journal >>>> and reset j_num_trans during commit cache. >>> The reason is in my above answer. >>> >>> below is the dmesg log for No. 266. >>> >>> ``` >>> [ 595.071807] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... >>> [ 595.080950] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 >>> [ 595.081091] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 >>> [ 595.081580] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 >>> [ 595.081886] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes >>> [ 595.082173] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 >>> [ 595.082420] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory >>> [ 595.082696] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new >>> [ 595.082932] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages >>> [ 595.083188] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms >>> [ 595.084721] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete >>> [ 595.095436] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. >>> [ 595.787078] systemd[1]: Started /usr/bin/bash -c exit 77. >>> [ 595.802650] systemd[1]: fstests-check.scope: Deactivated successfully. >>> [ 596.195734] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: joining the lockspace group... >>> [ 596.206310] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 >>> [ 596.206350] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 >>> [ 596.209667] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: add member 1 >>> [ 596.211433] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_members 1 nodes >>> [ 596.213942] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: generation 1 slots 1 1:1 >>> [ 596.215668] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory >>> [ 596.217171] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 in 0 new >>> [ 596.218253] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover_directory 0 out 0 messages >>> [ 596.219401] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: dlm_recover 1 generation 1 done: 0 ms >>> [ 596.220628] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: join complete >>> [ 596.224616] kernel: JBD2: Ignoring recovery information on journal >>> [ 596.229686] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. >>> [ 596.870008] systemd[1]: fstest-scratch.mount: Deactivated successfully. >>> [ 596.236135] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: leaving the lockspace group... >>> [ 596.237431] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: group event done 0 >>> [ 596.239442] kernel: dlm: 78CE18109AE44E6AA896722A5E25CFC0: release_lockspace final free >>> [ 596.877286] ocfs2_hb_ctl[5436]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 78CE18109AE44E6AA896722A5E25CFC0 >>> [ 596.248299] kernel: ocfs2: Unmounting device (253,32) on (node 1) >>> [ 596.255888] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: leaving the lockspace group... >>> [ 596.905718] systemd[1]: fstest-test.mount: Deactivated successfully. >>> [ 596.280602] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 >>> [ 596.281762] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: release_lockspace final free >>> [ 596.921672] ocfs2_hb_ctl[5448]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u 838DD74847E34AA1839D6C4AA31132F1 >>> [ 596.299507] kernel: ocfs2: Unmounting device (253,16) on (node 1) >>> [ 596.481755] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: joining the lockspace group... >>> [ 596.484722] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 >>> [ 596.484729] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: group event done 0 >>> [ 596.485361] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: add member 1 >>> [ 596.485622] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_members 1 nodes >>> [ 596.485861] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: generation 1 slots 1 1:1 >>> [ 596.486063] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory >>> [ 596.486293] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 in 0 new >>> [ 596.486498] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover_directory 0 out 0 messages >>> [ 596.486768] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: dlm_recover 1 generation 1 done: 0 ms >>> [ 596.487037] kernel: dlm: 838DD74847E34AA1839D6C4AA31132F1: join complete >>> [ 596.491655] kernel: ocfs2: Mounting device (253,16) on (node 1, slot 0) with ordered data mode. >>> [ 597.139758] root[5475]: run xfstest generic/266 >>> [ 596.505896] unknown: run fstests generic/266 at 2023-05-01 10:19:02 >>> [ 597.186885] systemd[1]: Started /usr/bin/bash -c test -w /proc/self/oom_score_adj && echo 250 > /proc/self/oom_score_adj; exec ./tests/generic/266. >>> [ 597.566466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... >>> [ 597.579759] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 >>> [ 597.579766] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 >>> [ 597.581004] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 >>> [ 597.581820] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes >>> [ 597.582292] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 >>> [ 597.582894] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory >>> [ 597.583423] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new >>> [ 597.583991] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages >>> [ 597.584547] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 4 ms >>> [ 597.585079] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete >>> [ 597.590136] kernel: JBD2: Ignoring recovery information on journal >>> [ 597.594258] kernel: ocfs2: Mounting device (253,32) on (node 1, slot 0) with ordered data mode. >>> [ 598.239046] systemd[1]: fstest-scratch.mount: Deactivated successfully. >>> [ 597.606575] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: leaving the lockspace group... >>> [ 597.607446] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 >>> [ 598.244507] ocfs2_hb_ctl[5680]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u AB0245F740984C25A9D0907D61DFCF8A >>> [ 597.607843] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: release_lockspace final free >>> [ 597.615474] kernel: ocfs2: Unmounting device (253,32) on (node 1) >>> [ 597.641624] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: joining the lockspace group... >>> [ 597.659435] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 >>> [ 597.659479] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: group event done 0 >>> [ 597.661482] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: add member 1 >>> [ 597.662340] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_members 1 nodes >>> [ 597.663211] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: generation 1 slots 1 1:1 >>> [ 597.664150] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory >>> [ 597.665466] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 in 0 new >>> [ 597.666370] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover_directory 0 out 0 messages >>> [ 597.667235] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: dlm_recover 1 generation 1 done: 0 ms >>> [ 597.668428] kernel: dlm: AB0245F740984C25A9D0907D61DFCF8A: join complete >>> [ 600.194974] systemd[1]: Started Daily Cleanup of Snapper Snapshots. >>> [ 600.207227] dbus-daemon[672]: [system] Activating via systemd: service name='org.opensuse.Snapper' unit='snapperd.service' requested by ':1.10' (uid=0 pid=5728 comm="/usr/lib/snapper/systemd-helper --cleanup") >>> [ 600.209151] systemd[1]: Starting DBus interface for snapper... >>> [ 600.217270] dbus-daemon[672]: [system] Successfully activated service 'org.opensuse.Snapper' >>> [ 600.217370] systemd[1]: Started DBus interface for snapper. >>> [ 600.218969] systemd[1]: snapper-cleanup.service: Deactivated successfully. >>> [ 599.608010] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... >>> [ 599.611041] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 >>> [ 599.611127] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 >>> [ 599.611813] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 >>> [ 599.612019] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes >>> [ 599.612227] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 >>> [ 599.612397] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory >>> [ 599.612559] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new >>> [ 599.612712] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages >>> [ 599.612880] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 0 ms >>> [ 599.613078] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete >>> [ 599.615320] kernel: JBD2: Ignoring recovery information on journal >>> [ 599.619221] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. >>> [ 600.392044] systemd[1]: fstest-scratch.mount: Deactivated successfully. >>> [ 599.780111] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: leaving the lockspace group... >>> [ 599.781949] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 >>> [ 599.784235] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: release_lockspace final free >>> [ 600.426136] ocfs2_hb_ctl[5762]: ocfs2_hb_ctl /sbin/ocfs2_hb_ctl -K -u F06626AE7D754F11A0211679C145C8BF >>> [ 599.808566] kernel: ocfs2: Unmounting device (254,0) on (node 1) >>> [ 599.827803] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: joining the lockspace group... >>> [ 599.832848] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 >>> [ 599.832984] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: group event done 0 >>> [ 599.833810] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: add member 1 >>> [ 599.834272] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_members 1 nodes >>> [ 599.834663] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: generation 1 slots 1 1:1 >>> [ 599.835030] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory >>> [ 599.835474] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 in 0 new >>> [ 599.835868] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover_directory 0 out 0 messages >>> [ 599.836365] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: dlm_recover 1 generation 1 done: 4 ms >>> [ 599.836829] kernel: dlm: F06626AE7D754F11A0211679C145C8BF: join complete >>> [ 599.845790] kernel: ocfs2: Mounting device (254,0) on (node 1, slot 0) with ordered data mode. >>> [ 600.079285] kernel: Buffer I/O error on dev dm-0, logical block 2621424, async page read >>> [ 600.090845] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 >>> [ 600.091387] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 >>> [ 600.091924] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 >>> [ 600.092422] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 >>> [ 600.094252] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 >>> [ 600.095029] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 >>> [ 600.095891] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 >>> [ 600.096698] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 >>> [ 600.099071] kernel: (xfs_io,5785,0):ocfs2_inode_lock_update:2354 ERROR: status = -5 >>> [ 600.099957] kernel: (xfs_io,5785,0):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 >>> [ 600.100798] kernel: (xfs_io,5785,0):ocfs2_statfs:1654 ERROR: status = -5 >>> [ 600.101623] kernel: (xfs_io,5785,0):ocfs2_statfs:1686 ERROR: status = -5 >>> [ 600.107094] kernel: (xfs_io,5785,1):ocfs2_get_refcount_tree:358 ERROR: status = -5 >>> [ 600.107659] kernel: (xfs_io,5785,1):ocfs2_lock_refcount_tree:456 ERROR: status = -5 >>> [ 600.108175] kernel: (xfs_io,5785,1):ocfs2_refcount_cow_hunk:3417 ERROR: status = -5 >>> [ 600.108654] kernel: (xfs_io,5785,1):ocfs2_refcount_cow:3478 ERROR: status = -5 >>> [ 600.109128] kernel: (xfs_io,5785,1):ocfs2_prepare_inode_for_write:2326 ERROR: status = -5 >>> [ 600.109613] kernel: (xfs_io,5785,1):ocfs2_file_write_iter:2433 ERROR: status = -5 >>> [ 600.118113] kernel: (umount,5789,3):ocfs2_inode_lock_update:2354 ERROR: status = -5 >>> [ 600.118481] kernel: (umount,5789,3):ocfs2_inode_lock_full_nested:2502 ERROR: status = -5 >>> [ 600.118898] kernel: (umount,5789,3):ocfs2_statfs:1654 ERROR: status = -5 >>> [ 600.119364] kernel: (umount,5789,3):ocfs2_statfs:1686 ERROR: status = -5 >>> [ 600.759255] systemd[1]: fstest-scratch.mount: Deactivated successfully. >>> [ 600.127135] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write >>> [ 600.127373] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. >>> [ 600.127615] kernel: Aborting journal on device dm-0-24. >>> [ 600.127893] kernel: Buffer I/O error on dev dm-0, logical block 529, lost sync page write >>> [ 600.128137] kernel: JBD2: I/O error when updating journal superblock for dm-0-24. >>> [ 600.128362] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 600.128591] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. >>> [ 601.147704] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 602.171745] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 603.195707] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 604.219709] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 605.243712] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 606.267748] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 607.291715] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 608.315742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 609.339724] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 610.363774] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 611.387693] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 612.411727] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 613.435719] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 614.459743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 615.483742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 615.484503] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_thread:2346 ERROR: status = -5, journal is already aborted. >>> [ 616.507742] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 617.531751] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 618.555743] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 619.579702] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> [ 620.603758] kernel: (ocfs2cmt-F06626,5771,2):ocfs2_commit_cache:321 ERROR: status = -5 >>> ^C >>> tb-fstest1:/usr/src/linux/fs/ocfs2 # >>> ``` >> >> So the case is, flush journal in commit thread will never end if journal >> is abort, and then lead to umount hang since commit thread won't stop, >> right? > Yes. > >> >> If so, I don't think your changes in sync fs is a right solution. It >> seems it just for bypassing the testcase. > No. > In my view, No. 266 shouldn't trigger jbd2 ABORT status. The 'sync' should > tidy up all already issued write IOs. After sync & load dm-error, new write IOs > fails on rw IOs, which shouldn't generate any journal IOs and shouldn't trigger > jbd2 to enter ABORT status. >What if there is no 'sync' in this case?>> >> If the expected behavior is to let umount ends even journal is abort, >> it seems we have to make journal shutdown happy in this case. > This is my [patch 2/2] job, which resolves fstest generaic NO. 347 361 628 629. > > - Heming