Uploaded image for project: 'Lustre'
  1. Lustre
  2. LU-16863

sanity-pfl test_0b, replay-dual: open/close 8739 timeout

Details

    • Bug
    • Resolution: Unresolved
    • Minor
    • None
    • None
    • None
    • 3
    • 9223372036854775807

    Description

      This issue was created by maloo for Arshad <arshad.hussain@aeoncomputing.com>

      This issue relates to the following test suite run: https://testing.whamcloud.com/test_sets/b5101811-eec7-4faf-a93e-e77b6d6e319d

      test_0b failed with the following error:

      Timeout occurred after 478 minutes, last suite running was sanity-pfl

      Test session details:
      clients: https://build.whamcloud.com/job/lustre-reviews/95276 - 4.18.0-425.10.1.el8_7.x86_64
      servers: https://build.whamcloud.com/job/lustre-reviews/95276 - 4.18.0-425.10.1.el8_lustre.x86_64

      <<Please provide additional information about the failure here>>

      VVVVVVV DO NOT REMOVE LINES BELOW, Added by Maloo for auto-association VVVVVVV
      sanity-pfl test_0b - Timeout occurred after 478 minutes, last suite running was sanity-pfl

      Attachments

        Issue Links

          is related to

          Improvement - An improvement or enhancement to an existing feature or task. LU-11912 reduce number of OST objects created per MDS Sequence

          • Major - Major loss of function.
          • Resolved
          is related to

          Improvement - An improvement or enhancement to an existing feature or task. LU-11912 reduce number of OST objects created per MDS Sequence

          • Major - Major loss of function.
          • Resolved

          Activity

            [LU-16863] sanity-pfl test_0b, replay-dual: open/close 8739 timeout
            adilger Andreas Dilger added a comment -

            This timeout should hopefully be resolved by the landing of patch https://review.whamcloud.com/51292 "LU-11912 tests: consume precreated objects in parallel" on 2023-06-28.

            adilger Andreas Dilger added a comment - This timeout should hopefully be resolved by the landing of patch https://review.whamcloud.com/51292 " LU-11912 tests: consume precreated objects in parallel " on 2023-06-28.
            arshad512 Arshad Hussain added a comment -

            +1 on master https://testing.whamcloud.com/test_sets/051b15ef-ab78-46c8-9088-a82ecda12d2a (This has a fix ready)

            arshad512 Arshad Hussain added a comment - +1 on master https://testing.whamcloud.com/test_sets/051b15ef-ab78-46c8-9088-a82ecda12d2a (This has a fix ready)
            adilger Andreas Dilger added a comment -

            The force_new_seq_all call in some tests can take a surprisingly long time (I've seen up to 2000 seconds in some cases) because it is creating sometimes 4000-5000 objects on each OST, with 4 MDTs and 8 OSTs to work through, so it is causing the tests to time out.

            I'm not sure if there is a way to avoid this, so for now I've pushed the above patch to do the precreates in parallel across the MDTs, but that is only going to reduce the precreate times by 1/4, still hundreds of seconds in some cases. Ideally there should be a better way to force the sequence to roll over that doesn't require consuming all of the precreated objects (e.g. lctl set_param mdt.*.precreate_flush or ... fail_loc=N).

            adilger Andreas Dilger added a comment - The force_new_seq_all call in some tests can take a surprisingly long time (I've seen up to 2000 seconds in some cases) because it is creating sometimes 4000-5000 objects on each OST, with 4 MDTs and 8 OSTs to work through, so it is causing the tests to time out. I'm not sure if there is a way to avoid this, so for now I've pushed the above patch to do the precreates in parallel across the MDTs, but that is only going to reduce the precreate times by 1/4, still hundreds of seconds in some cases. Ideally there should be a better way to force the sequence to roll over that doesn't require consuming all of the precreated objects (e.g. lctl set_param mdt.*.precreate_flush or ... fail_loc=N ).
            adilger Andreas Dilger added a comment -

            "Andreas Dilger <adilger@whamcloud.com>" uploaded a new patch: https://review.whamcloud.com/c/fs/lustre-release/+/51292
            Subject: LU-16863 tests: consume precreated objects in parallel
            Project: fs/lustre-release
            Branch: master
            Current Patch Set: 1
            Commit: fff18a8adbd47d6e9e798ebbb68b93ce531b08dc

            adilger Andreas Dilger added a comment - "Andreas Dilger <adilger@whamcloud.com>" uploaded a new patch: https://review.whamcloud.com/c/fs/lustre-release/+/51292 Subject: LU-16863 tests: consume precreated objects in parallel Project: fs/lustre-release Branch: master Current Patch Set: 1 Commit: fff18a8adbd47d6e9e798ebbb68b93ce531b08dc
            adilger Andreas Dilger added a comment - - edited

            It looks like this timeout was first hit on 2023-04-24 on a patch that has not landed yet, so must be another patch. Patches that landed then are:

            $ git log --oneline --after 2023-04-22 --before 2023-04-25 lustre
cd1e7bdd90 LU-14139 statahead: add test for batch statahead processing
2fdb1f8d01 LU-11912 tests: SEQ rollover fixes
73a7b1c2a3 LU-11170 tests: don't fail sanity/415 in VM
3201bd4ac4 LU-15690 tests: skip replay-ost-single/12a on old server
5a2dfd36f9 LU-14139 ptlrpc: grow PtlRPC properly when prepare sub request
3ba223327f LU-16465 tests: update sanity test 806 to use save/restore_opencache
013a671150 LU-16734 gss: fix lookup_user_key() bug
f3ba286b05 LU-16573 lnet: Check empty list in cfs_match_nid_net
add0aa8a89 LU-16721 lfs: Fix path2fid segfault
d2a5f10463 LU-16714 utils: Clarify fd/fdv naming
9c316c69b9 LU-16706 kernel: update RHEL 9.1 [5.14.0-162.22.2.el9_1]
f8cc7db39d LU-16694 tests: replace resolveip script
d96b98ee6b LU-16693 lod: ENODEV on setstripe with wrong OST#
87f2733d53 LU-16684 utils: reset buf_len in print_out_devices()
d5036b55b8 LU-16672 tests: auster node.yml labels Alma and Rocky as CentOS
6c3b50434b LU-13340 mgs: convert class_parse_nid4 to class_parse_nid
8851266823 LU-13340 mgs: change record_add_uuid() to take large nids
25fb82eb41 LU-15374 tests: check FULL and IDLE for client import state
5edb883b44 LU-14139 ptlrpc: grow reply buffer properly for batch request
a20f25d24b LU-14139 statahead: add stats for batch RPC requests
3b43457cf1 LU-12885 mdd: only bottom of clf_flags in changelog
e2602bd49c LU-10391 ptlrpc: change tc_nid in nrs to be struct lnet_nid
3d0b1b0200 LU-10391 lustre: change cfs_match_nid to take large nid.
89aac3d3b3 LU-10391 obdclass: remove class_parse_nid4()
c098c09564 LU-14976 nrs: change nrs policies at run time
13557aa869 LU-15300 mdt: refresh LOVEA with LL granted
e69eea5f60 LU-8367 osp: remove unused fail_locs from sanity/27S,822
b7f07db28f LU-15072 lod: extra status for spilling

            It looks like the culprit is patch https://review.whamcloud.com/50478 "LU-11912 tests: SEQ rollover fixes" which added a bunch of file creates at the start of this test.

            I've pushed patch https://review.whamcloud.com/51292 "LU-11912 tests: consume precreated objects in parallel" to speed this up.

            adilger Andreas Dilger added a comment - - edited It looks like this timeout was first hit on 2023-04-24 on a patch that has not landed yet, so must be another patch. Patches that landed then are: $ git log --oneline --after 2023-04-22 --before 2023-04-25 lustre cd1e7bdd90 LU-14139 statahead: add test for batch statahead processing 2fdb1f8d01 LU-11912 tests: SEQ rollover fixes 73a7b1c2a3 LU-11170 tests: don't fail sanity/415 in VM 3201bd4ac4 LU-15690 tests: skip replay-ost-single/12a on old server 5a2dfd36f9 LU-14139 ptlrpc: grow PtlRPC properly when prepare sub request 3ba223327f LU-16465 tests: update sanity test 806 to use save/restore_opencache 013a671150 LU-16734 gss: fix lookup_user_key() bug f3ba286b05 LU-16573 lnet: Check empty list in cfs_match_nid_net add0aa8a89 LU-16721 lfs: Fix path2fid segfault d2a5f10463 LU-16714 utils: Clarify fd/fdv naming 9c316c69b9 LU-16706 kernel: update RHEL 9.1 [5.14.0-162.22.2.el9_1] f8cc7db39d LU-16694 tests: replace resolveip script d96b98ee6b LU-16693 lod: ENODEV on setstripe with wrong OST# 87f2733d53 LU-16684 utils: reset buf_len in print_out_devices() d5036b55b8 LU-16672 tests: auster node.yml labels Alma and Rocky as CentOS 6c3b50434b LU-13340 mgs: convert class_parse_nid4 to class_parse_nid 8851266823 LU-13340 mgs: change record_add_uuid() to take large nids 25fb82eb41 LU-15374 tests: check FULL and IDLE for client import state 5edb883b44 LU-14139 ptlrpc: grow reply buffer properly for batch request a20f25d24b LU-14139 statahead: add stats for batch RPC requests 3b43457cf1 LU-12885 mdd: only bottom of clf_flags in changelog e2602bd49c LU-10391 ptlrpc: change tc_nid in nrs to be struct lnet_nid 3d0b1b0200 LU-10391 lustre: change cfs_match_nid to take large nid. 89aac3d3b3 LU-10391 obdclass: remove class_parse_nid4() c098c09564 LU-14976 nrs: change nrs policies at run time 13557aa869 LU-15300 mdt: refresh LOVEA with LL granted e69eea5f60 LU-8367 osp: remove unused fail_locs from sanity/27S,822 b7f07db28f LU-15072 lod: extra status for spilling It looks like the culprit is patch https://review.whamcloud.com/50478 " LU-11912 tests: SEQ rollover fixes " which added a bunch of file creates at the start of this test. I've pushed patch https://review.whamcloud.com/51292 " LU-11912 tests: consume precreated objects in parallel " to speed this up.
            arshad512 Arshad Hussain added a comment -

            +1 on master (https://testing.whamcloud.com/test_sets/8ec2f249-163c-4a49-90c3-0add997318eb)

            arshad512 Arshad Hussain added a comment - +1 on master ( https://testing.whamcloud.com/test_sets/8ec2f249-163c-4a49-90c3-0add997318eb )
            arshad512 Arshad Hussain added a comment - - edited 
            == sanity-pfl test 0b: Verify comp stripe count limits === 17:24:58 (1685640298)
CMD: trevis-26vm8 dumpe2fs -h /dev/mapper/mds1_flakey 2>&1 |
		grep -E -q '(ea_inode|large_xattr)'
CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0x210a
fail_loc=0x210a
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0000...
 - open/close 17 (time 1685640312.98 total 10.49 last 1.62)
 - open/close 32 (time 1685640323.06 total 20.57 last 1.49)
 - open/close 48 (time 1685640333.55 total 31.06 last 1.53)
 - open/close 63 (time 1685640344.73 total 42.24 last 1.34)
total: 64 open/close in 42.24 seconds: 1.52 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0001...
 - open/close 19 (time 1685640356.43 total 10.31 last 1.84)
 - open/close 34 (time 1685640366.73 total 20.61 last 1.46)
 - open/close 51 (time 1685640377.69 total 31.57 last 1.55)
 - open/close 57 (time 1685640387.79 total 41.66 last 0.59)
total: 64 open/close in 49.03 seconds: 1.31 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0002...
 - open/close 0 (time 1685640400.16 total 3.56 last 0.00)
 - open/close 9 (time 1685640410.37 total 13.77 last 0.88)
 - open/close 25 (time 1685640420.51 total 23.91 last 1.58)
 - open/close 42 (time 1685640430.93 total 34.32 last 1.63)
 - open/close 54 (time 1685640441.76 total 45.16 last 1.11)
total: 64 open/close in 54.40 seconds: 1.18 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0003...
 - open/close 23 (time 1685640462.72 total 10.23 last 2.25)
total: 64 open/close in 18.68 seconds: 3.43 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0004...
 - open/close 27 (time 1685640483.00 total 10.29 last 2.62)
 - open/close 48 (time 1685640494.36 total 21.65 last 1.85)
total: 64 open/close in 27.68 seconds: 2.31 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0005...
 - open/close 13 (time 1685640511.83 total 10.01 last 1.30)
 - open/close 30 (time 1685640522.57 total 20.74 last 1.58)
 - open/close 42 (time 1685640532.88 total 31.06 last 1.16)
 - open/close 60 (time 1685640543.20 total 41.37 last 1.74)
total: 64 open/close in 43.23 seconds: 1.48 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0006...
 - open/close 15 (time 1685640557.24 total 10.65 last 1.41)
 - open/close 31 (time 1685640567.70 total 21.11 last 1.53)
 - open/close 48 (time 1685640578.04 total 31.44 last 1.64)
 - open/close 63 (time 1685640588.09 total 41.49 last 1.49)
total: 64 open/close in 41.49 seconds: 1.54 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0000.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0000.prealloc_next_id
Creating to objid 65 on ost lustre-OST0007...
 - open/close 20 (time 1685640600.33 total 10.69 last 1.87)
 - open/close 38 (time 1685640610.38 total 20.74 last 1.79)
 - open/close 62 (time 1685640621.04 total 31.40 last 2.25)
total: 64 open/close in 32.56 seconds: 1.97 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0
fail_loc=0
CMD: trevis-26vm9 /usr/sbin/lctl set_param fail_loc=0x210a
fail_loc=0x210a
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0001.prealloc_next_id
Creating to objid 7201 on ost lustre-OST0000...
 - open/close 23 (time 1685640637.28 total 10.64 last 2.16)
total: 32 open/close in 14.73 seconds: 2.17 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0001...
 - open/close 17 (time 1685640652.92 total 10.13 last 1.68)
total: 32 open/close in 17.24 seconds: 1.86 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0001.prealloc_next_id
Creating to objid 7105 on ost lustre-OST0002...
 - open/close 18 (time 1685640671.58 total 10.20 last 1.76)
total: 33 open/close in 19.43 seconds: 1.70 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0003...
 - open/close 19 (time 1685640692.40 total 10.20 last 1.86)
total: 33 open/close in 18.15 seconds: 1.82 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0004...
 - open/close 27 (time 1685640712.49 total 10.75 last 2.51)
total: 33 open/close in 11.96 seconds: 2.76 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0005...
 - open/close 22 (time 1685640725.37 total 10.18 last 2.16)
total: 33 open/close in 16.82 seconds: 1.96 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0006...
 - open/close 18 (time 1685640743.49 total 10.05 last 1.79)
total: 33 open/close in 19.79 seconds: 1.67 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0001.prealloc_last_id
CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0001.prealloc_next_id
Creating to objid 7073 on ost lustre-OST0007...
 - open/close 14 (time 1685640764.86 total 10.23 last 1.37)
 - open/close 30 (time 1685640775.19 total 20.56 last 1.55)
total: 32 open/close in 22.13 seconds: 1.45 ops/second
CMD: trevis-26vm9 /usr/sbin/lctl set_param fail_loc=0
fail_loc=0
CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0x210a
fail_loc=0x210a
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0002.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0002.prealloc_next_id
Creating to objid 33 on ost lustre-OST0000...
 - open/close 13 (time 1685640791.72 total 10.11 last 1.29)
 - open/close 28 (time 1685640802.26 total 20.66 last 1.42)
total: 33 open/close in 24.04 seconds: 1.37 ops/second
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0002.prealloc_last_id
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0002.prealloc_next_id
Creating to objid 16416 on ost lustre-OST0001...
CMD: trevis-26vm8 /usr/sbin/lctl get_param -n debug
CMD: trevis-128vm2,trevis-26vm8,trevis-26vm9,trevis-74vm1.trevis.whamcloud.com,trevis-74vm2 /usr/sbin/lctl set_param -n debug=0
 - open/close 14 (time 1685640818.86 total 10.34 last 1.35)
 ...
 - open/close 8578 (time 1685643404.77 total 2596.25 last 2.06)
 - open/close 8606 (time 1685643415.08 total 2606.57 last 2.71)
 - open/close 8645 (time 1685643425.20 total 2616.68 last 3.86)
 - open/close 8684 (time 1685643435.32 total 2626.80 last 3.85)
...
            arshad512 Arshad Hussain added a comment - - edited == sanity-pfl test 0b: Verify comp stripe count limits === 17:24:58 (1685640298) CMD: trevis-26vm8 dumpe2fs -h /dev/mapper/mds1_flakey 2>&1 | grep -E -q '(ea_inode|large_xattr)' CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0x210a fail_loc=0x210a CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0000... - open/close 17 (time 1685640312.98 total 10.49 last 1.62) - open/close 32 (time 1685640323.06 total 20.57 last 1.49) - open/close 48 (time 1685640333.55 total 31.06 last 1.53) - open/close 63 (time 1685640344.73 total 42.24 last 1.34) total: 64 open/close in 42.24 seconds: 1.52 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0001... - open/close 19 (time 1685640356.43 total 10.31 last 1.84) - open/close 34 (time 1685640366.73 total 20.61 last 1.46) - open/close 51 (time 1685640377.69 total 31.57 last 1.55) - open/close 57 (time 1685640387.79 total 41.66 last 0.59) total: 64 open/close in 49.03 seconds: 1.31 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0002... - open/close 0 (time 1685640400.16 total 3.56 last 0.00) - open/close 9 (time 1685640410.37 total 13.77 last 0.88) - open/close 25 (time 1685640420.51 total 23.91 last 1.58) - open/close 42 (time 1685640430.93 total 34.32 last 1.63) - open/close 54 (time 1685640441.76 total 45.16 last 1.11) total: 64 open/close in 54.40 seconds: 1.18 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0003... - open/close 23 (time 1685640462.72 total 10.23 last 2.25) total: 64 open/close in 18.68 seconds: 3.43 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0004... - open/close 27 (time 1685640483.00 total 10.29 last 2.62) - open/close 48 (time 1685640494.36 total 21.65 last 1.85) total: 64 open/close in 27.68 seconds: 2.31 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0005... - open/close 13 (time 1685640511.83 total 10.01 last 1.30) - open/close 30 (time 1685640522.57 total 20.74 last 1.58) - open/close 42 (time 1685640532.88 total 31.06 last 1.16) - open/close 60 (time 1685640543.20 total 41.37 last 1.74) total: 64 open/close in 43.23 seconds: 1.48 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0006... - open/close 15 (time 1685640557.24 total 10.65 last 1.41) - open/close 31 (time 1685640567.70 total 21.11 last 1.53) - open/close 48 (time 1685640578.04 total 31.44 last 1.64) - open/close 63 (time 1685640588.09 total 41.49 last 1.49) total: 64 open/close in 41.49 seconds: 1.54 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0000.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0000.prealloc_next_id Creating to objid 65 on ost lustre-OST0007... - open/close 20 (time 1685640600.33 total 10.69 last 1.87) - open/close 38 (time 1685640610.38 total 20.74 last 1.79) - open/close 62 (time 1685640621.04 total 31.40 last 2.25) total: 64 open/close in 32.56 seconds: 1.97 ops/second CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0 fail_loc=0 CMD: trevis-26vm9 /usr/sbin/lctl set_param fail_loc=0x210a fail_loc=0x210a CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0001.prealloc_next_id Creating to objid 7201 on ost lustre-OST0000... - open/close 23 (time 1685640637.28 total 10.64 last 2.16) total: 32 open/close in 14.73 seconds: 2.17 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0001... - open/close 17 (time 1685640652.92 total 10.13 last 1.68) total: 32 open/close in 17.24 seconds: 1.86 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0002-osc-MDT0001.prealloc_next_id Creating to objid 7105 on ost lustre-OST0002... - open/close 18 (time 1685640671.58 total 10.20 last 1.76) total: 33 open/close in 19.43 seconds: 1.70 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0003-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0003... - open/close 19 (time 1685640692.40 total 10.20 last 1.86) total: 33 open/close in 18.15 seconds: 1.82 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0004-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0004... - open/close 27 (time 1685640712.49 total 10.75 last 2.51) total: 33 open/close in 11.96 seconds: 2.76 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0005-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0005... - open/close 22 (time 1685640725.37 total 10.18 last 2.16) total: 33 open/close in 16.82 seconds: 1.96 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0006-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0006... - open/close 18 (time 1685640743.49 total 10.05 last 1.79) total: 33 open/close in 19.79 seconds: 1.67 ops/second CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0001.prealloc_last_id CMD: trevis-26vm9 /usr/sbin/lctl get_param -n osp.lustre-OST0007-osc-MDT0001.prealloc_next_id Creating to objid 7073 on ost lustre-OST0007... - open/close 14 (time 1685640764.86 total 10.23 last 1.37) - open/close 30 (time 1685640775.19 total 20.56 last 1.55) total: 32 open/close in 22.13 seconds: 1.45 ops/second CMD: trevis-26vm9 /usr/sbin/lctl set_param fail_loc=0 fail_loc=0 CMD: trevis-26vm8 /usr/sbin/lctl set_param fail_loc=0x210a fail_loc=0x210a CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0002.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0000-osc-MDT0002.prealloc_next_id Creating to objid 33 on ost lustre-OST0000... - open/close 13 (time 1685640791.72 total 10.11 last 1.29) - open/close 28 (time 1685640802.26 total 20.66 last 1.42) total: 33 open/close in 24.04 seconds: 1.37 ops/second CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0002.prealloc_last_id CMD: trevis-26vm8 /usr/sbin/lctl get_param -n osp.lustre-OST0001-osc-MDT0002.prealloc_next_id Creating to objid 16416 on ost lustre-OST0001... CMD: trevis-26vm8 /usr/sbin/lctl get_param -n debug CMD: trevis-128vm2,trevis-26vm8,trevis-26vm9,trevis-74vm1.trevis.whamcloud.com,trevis-74vm2 /usr/sbin/lctl set_param -n debug=0 - open/close 14 (time 1685640818.86 total 10.34 last 1.35) ... - open/close 8578 (time 1685643404.77 total 2596.25 last 2.06) - open/close 8606 (time 1685643415.08 total 2606.57 last 2.71) - open/close 8645 (time 1685643425.20 total 2616.68 last 3.86) - open/close 8684 (time 1685643435.32 total 2626.80 last 3.85) ...

            People

              wc-triage WC Triage
              maloo Maloo
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated: