[LU-17506] sanity: test_51b (aarch64) timeout occurred after 231 minutes Created: 06/Feb/24  Updated: 06/Feb/24

Status: Open
Project: Lustre
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Minor
Reporter: Maloo Assignee: WC Triage
Resolution: Unresolved Votes: 0
Labels: None

Attachments: Zip Archive sanity_2024-02-06_0451.zip    
Severity: 3
Rank (Obsolete): 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/21c0ab05-9afa-497f-a6b9-c4b9a6ccad2e

Test session details:
clients: https://build.whamcloud.com/job/lustre-reviews/101871 - 4.18.0-477.27.1.el8_8.aarch64
servers: https://build.whamcloud.com/job/lustre-reviews/101871 - 4.18.0-477.27.1.el8_lustre.x86_64

Node type
Client: aarch64/2.15.60,58/RHEL 8.8/4.18.0-477.27.1.el8_8.aarch64
Server: aarch64/2.15.60,58/RHEL 8.8/4.18.0-477.27.1.el8_8.aarch64

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



 Comments   
Comment by Arshad Hussain [ 06/Feb/24 ]

MDS:

 

[ 8312.886223] Lustre: DEBUG MARKER: == sanity test 51b: exceed 64k subdirectory nlink limit on create, verify unlink ========================================================== 14:58:02 (1707145082)^M
[ 8316.008024] Lustre: DEBUG MARKER: /usr/sbin/lctl get_param -n debug^M
[ 8316.887968] Lustre: DEBUG MARKER: /usr/sbin/lctl set_param -n debug=0^M
[12681.294334] Lustre: DEBUG MARKER: /usr/sbin/lctl set_param debug="trace inode super iotrace malloc cache info ioctl neterror net warning buffs other dentry nettrace page dlmtrace error emerg ha rpctrace vfstrace reada mmap config console quota sec lfsck hsm snapshot layout"^M
[12685.839890] Lustre: DEBUG MARKER: /usr/sbin/lctl get_param -n debug^M
[12686.495082] Lustre: DEBUG MARKER: /usr/sbin/lctl set_param -n debug=0^M
[13781.584601] sysrq: SysRq : Changing Loglevel^M
[13781.589760] sysrq: Loglevel set to 8^M
[13781.591841] sysrq: SysRq : Show State^M
[13781.592532] task:systemd         state:S stack:    0 pid:    1 ppid:     0 flags:0x00000000^M
[13781.593955] Call Trace:^M
[13781.594487]  __schedule+0x2d1/0x870^M
[13781.595285]  schedule+0x55/0xf0^M
[13781.595867]  schedule_hrtimeout_range_clock+0xf9/0x110^M
[13781.596788]  ? ep_scan_ready_list.constprop.23+0x210/0x230^M
[13781.597793]  ? __handle_mm_fault+0x453/0x6c0^M
[13781.598602]  ep_poll+0x3f7/0x450^M
[13781.599226]  ? wake_up_q+0x70/0x70^M
[13781.599900]  do_epoll_wait+0xb8/0xe0^M
[13781.600537]  __x64_sys_epoll_wait+0x1a/0x30^M
[13781.601279]  do_syscall_64+0x5b/0x1b0^M
[13781.602007]  entry_SYSCALL_64_after_hwframe+0x61/0xc6^M
[13781.602909] RIP: 0033:0x7f72c910fe87^M
[13781.603606] Code: Unable to access opcode bytes at RIP 0x7f72c910fe5d.^M
[13781.604714] RSP: 002b:00007ffdd6a3e0d0 EFLAGS: 00000293 ORIG_RAX: 00000000000000e8^M
[13781.606007] RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00007f72c910fe87^M
[13781.607207] RDX: 0000000000000056 RSI: 00007ffdd6a3e110 RDI: 0000000000000004^M
[13781.608400] RBP: 00007ffdd6a3e110 R08: 0000000000000000 R09: 00007ffdd6a3e110^M
[13781.609583] R10: 00000000ffffffff R11: 0000000000000293 R12: 0000000000000056^M
[13781.610764] R13: 00000000ffffffff R14: ffffffffffffffff R15: 00007ffdd6a3e670^M
[13781.611952] task:kthreadd        state:S stack:    0 pid:    2 ppid:     0 flags:0x80004000^M

client:

== sanity test 51b: exceed 64k subdirectory nlink limit on create, verify unlink ========================================================== 14:58:02 (1707145082)
UUID                   1K-blocks        Used   Available Use% Mounted on
lustre-MDT0000_UUID      1096600        7836      991272   1% /mnt/lustre[MDT:0]
lustre-MDT0001_UUID      1096600        5964      993144   1% /mnt/lustre[MDT:1]
lustre-MDT0002_UUID      1096600        3612      995496   1% /mnt/lustre[MDT:2]
lustre-MDT0003_UUID      1096600        4036      995072   1% /mnt/lustre[MDT:3]
lustre-OST0000_UUID      7693660       20252     7237596   1% /mnt/lustre[OST:0]
lustre-OST0001_UUID      7693660       11684     7246164   1% /mnt/lustre[OST:1]
lustre-OST0002_UUID      7693660        3416     7254432   1% /mnt/lustre[OST:2]
lustre-OST0003_UUID      7693660        3424     7254424   1% /mnt/lustre[OST:3]
lustre-OST0004_UUID      7693660       12868     7244980   1% /mnt/lustre[OST:4]
lustre-OST0005_UUID      7693660        3788     7254060   1% /mnt/lustre[OST:5]
lustre-OST0006_UUID      7693660        5564     7252284   1% /mnt/lustre[OST:6]
lustre-OST0007_UUID      7693660        5564     7252284   1% /mnt/lustre[OST:7]
filesystem_summary:     61549280       66560    57996224   1% /mnt/lustre
UUID                      Inodes       IUsed       IFree IUse% Mounted on
lustre-MDT0000_UUID       792800        2023      790777   1% /mnt/lustre[MDT:0]
lustre-MDT0001_UUID       792800         995      791805   1% /mnt/lustre[MDT:1]
lustre-MDT0002_UUID       792800        2392      790408   1% /mnt/lustre[MDT:2]
lustre-MDT0003_UUID       792800        1341      791459   1% /mnt/lustre[MDT:3]
lustre-OST0000_UUID       524288        1492      522796   1% /mnt/lustre[OST:0]
lustre-OST0001_UUID       524288        1289      522999   1% /mnt/lustre[OST:1]
lustre-OST0002_UUID       524288        1245      523043   1% /mnt/lustre[OST:2]
lustre-OST0003_UUID       524288        1246      523042   1% /mnt/lustre[OST:3]
lustre-OST0004_UUID       524288        1251      523037   1% /mnt/lustre[OST:4]
lustre-OST0005_UUID       524288        1246      523042   1% /mnt/lustre[OST:5]
lustre-OST0006_UUID       524288        1251      523037   1% /mnt/lustre[OST:6]
lustre-OST0007_UUID       524288        1312      522976   1% /mnt/lustre[OST:7]
filesystem_summary:      3171200        6751     3164449   1% /mnt/lustre
CMD: trevis-111vm11 /usr/sbin/lctl get_param -n debug
CMD: trevis-108vm3.trevis.whamcloud.com,trevis-108vm4,trevis-111vm1,trevis-111vm11,trevis-111vm13 /usr/sbin/lctl set_param -n debug=0
 - mkdir 131 (time 1707145097.76 total 10.04 last 13.05)
 - mkdir 231 (time 1707145107.92 total 20.20 last 9.84)
 - mkdir 376 (time 1707145117.93 total 30.20 last 14.49)
 - mkdir 463 (time 1707145127.94 total 40.21 last 8.69)
 - mkdir 578 (time 1707145138.01 total 50.29 last 11.41)
<snip...>
 - mkdir 64892 (time 1707149408.16 total 4320.43 last 12.29)
 - mkdir 65069 (time 1707149418.19 total 4330.47 last 17.64)
 - mkdir 65288 (time 1707149428.26 total 4340.53 last 21.76)
 - mkdir 65445 (time 1707149438.29 total 4350.57 last 15.64)
 - mkdir 65617 (time 1707149448.33 total 4360.60 last 17.14)
total: 65636 mkdir in 4361.14 seconds: 15.05 ops/second

 

 

Comment by Arshad Hussain [ 06/Feb/24 ]

Seems to be just slow on aarch64.

Generated at Sat Feb 10 03:35:59 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.