************************ crashinfo ************************* /exports/testreports/42038/testresults/racer-zfs-DNE-centos7_x86_64-centos7_x86_64/oleg114-server-timeout-core (3.10.0-7.9-debug) +==========================+ | *** Crashinfo v1.3.7 *** | +==========================+ +++WARNING+++ PARTIAL DUMP with size(vmcore) < 25% size(RAM) KERNEL: /tmp/crash-anaysis.AJM0F/vmlinux [TAINTED] DUMPFILE: /exports/testreports/42038/testresults/racer-zfs-DNE-centos7_x86_64-centos7_x86_64/oleg114-server-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Mon Apr 15 15:21:12 EDT 2024 UPTIME: 00:11:57 LOAD AVERAGE: 68.03, 47.60, 22.11 TASKS: 834 NODENAME: oleg114-server.virtnet RELEASE: 3.10.0-7.9-debug VERSION: #1 SMP Sat Mar 26 23:28:42 EDT 2022 MACHINE: x86_64 (2399 Mhz) MEMORY: 4 GB PANIC: "" +--------------------------+ >------------------------| Per-cpu Stacks ('bt -a') |------------------------< +--------------------------+ -- CPU#0 -- PID=0 CPU=0 CMD=swapper/0 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 rest_init+0x8e #7 start_kernel+0x456 #8 x86_64_start_reservations+0x2a #9 x86_64_start_kernel+0x152 #10 start_cpu+0x5 -- CPU#1 -- PID=0 CPU=1 CMD=swapper/1 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 -- CPU#2 -- PID=0 CPU=2 CMD=swapper/2 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 -- CPU#3 -- PID=0 CPU=3 CMD=swapper/3 #-1 native_safe_halt+0xb, 449 bytes of data #0 default_idle+0x1e #1 default_enter_idle+0x45 #2 cpuidle_enter_state+0x40 #3 cpuidle_idle_call+0xd8 #4 arch_cpu_idle+0xe #5 cpu_startup_entry+0x14a #6 start_secondary+0x1eb #7 start_cpu+0x5 +--------------------------------+ >---------------------| How This Dump Has Been Created |---------------------< +--------------------------------+ Cannot identify the specific condition that triggered vmcore +++WARNING+++ High Load Averages: 68.03, 47.60, 22.11 +---------------+ >------------------------------| Tasks Summary |------------------------------< +---------------+ Number of Threads That Ran Recently ----------------------------------- last second 32 last 5s 254 last 60s 540 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 830 TASK_RUNNING 1 +++WARNING+++ There are 3 threads running in their own namespaces Use 'taskinfo --ns' to get more details +-----------------------+ >--------------------------| 5 Most Recent Threads |--------------------------< +-----------------------+ PID CMD Age ARGS ----- -------------- ------ ---------------------------- 12045 mmp 0 ms (no user stack) 3214 monitor_thread 0 ms (no user stack) 11964 z_null_int 0 ms (no user stack) 11963 z_null_iss 0 ms (no user stack) 4791 ll_ost_io00_104 23 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955067 3.6 GB ---- FREE 468825 1.8 GB 49% of TOTAL MEM USED 486242 1.9 GB 50% of TOTAL MEM SHARED 8332 32.5 MB 0% of TOTAL MEM BUFFERS 5093 19.9 MB 0% of TOTAL MEM CACHED 66036 258 MB 6% of TOTAL MEM SLAB 175415 685.2 MB 18% of TOTAL MEM TOTAL HUGE 0 0 ---- HUGE FREE 0 0 0% of TOTAL HUGE TOTAL SWAP 262143 1024 MB ---- SWAP USED 0 0 0% of TOTAL SWAP SWAP FREE 262143 1024 MB 100% of TOTAL SWAP COMMIT LIMIT 739676 2.8 GB ---- COMMITTED 58985 230.4 MB 7% of TOTAL LIMIT +-------------------------------+ >----------------------| Scheduler Runqueues (per CPU) |----------------------< +-------------------------------+ ---+ CPU=0 ---- | CURRENT TASK , CMD=swapper/0 ---+ CPU=1 ---- | CURRENT TASK , CMD=swapper/1 ---+ CPU=2 ---- | CURRENT TASK , CMD=swapper/2 ---+ CPU=3 ---- | CURRENT TASK , CMD=swapper/3 +------------------------+ >-------------------------| Network Status Summary |-------------------------< +------------------------+ TCP Connection Info ------------------- ESTABLISHED 5 LISTEN 3 NAGLE disabled (TCP_NODELAY): 4 user_data set (NFS etc.): 4 UDP Connection Info ------------------- 2 UDP sockets, 0 in ESTABLISHED Unix Connection Info ------------------------ ESTABLISHED 26 CLOSE 17 LISTEN 8 Raw sockets info -------------------- ESTABLISHED 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 715.1 eth0 n/a 1.7 RSS_TOTAL=50240 pages, %mem= 0.8 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012a2fc000 ffff88012a388000 sysfs sysfs /sys ffff88012a2fc1c0 ffff880139944000 proc proc /proc ffff88012a2fc380 ffff880137678000 devtmpfs devtmpfs /dev ffff88012a2fc540 ffff8800b5221000 securityfs securityfs /sys/kernel/security ffff88012a2fc700 ffff88012a388800 tmpfs tmpfs /dev/shm ffff88012a2fc8c0 ffff880137187000 devpts devpts /dev/pts ffff88012a2fca80 ffff88012a389000 tmpfs tmpfs /run ffff88012a2fcc40 ffff88012a389800 tmpfs tmpfs /sys/fs/cgroup ffff88012a2fce00 ffff88012a38a000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012a2fcfc0 ffff88012a38a800 pstore pstore /sys/fs/pstore ffff88012a2fd180 ffff88012a38c800 cgroup cgroup /sys/fs/cgroup/memory ffff88012a2fd340 ffff88012a38c000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012a2fd500 ffff88012a38b800 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012a2fd6c0 ffff88012a38b000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012a2fd880 ffff88012a38d000 cgroup cgroup /sys/fs/cgroup/freezer ffff88012a2fda40 ffff88012a38d800 cgroup cgroup /sys/fs/cgroup/devices ffff88012a2fdc00 ffff88012a38e000 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012a2fddc0 ffff88012a38e800 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012a2fe000 ffff88012a38f000 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012a2fe1c0 ffff88012a38f800 cgroup cgroup /sys/fs/cgroup/pids ffff88012b2c8a80 ffff88012b3fd000 configfs configfs /sys/kernel/config ffff880137668a80 ffff8800b5225800 ext4 /dev/nbd0 / ffff880137668c40 ffff8800b5223000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff88012a2ff340 ffff8800b5226800 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012b2c88c0 ffff8800b51d2800 hugetlbfs hugetlbfs /dev/hugepages ffff88012b2c8fc0 ffff88012b2d0800 mqueue mqueue /dev/mqueue ffff880138ccae00 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012b2c9180 ffff8800b51d6000 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff880138ccafc0 ffff8800b431c800 ramfs none /mnt ffff88012b2c9340 ffff880129d44800 squashfs /dev/vda /home/green/git/lustre-release ffff880137669500 ffff8800b425e000 tmpfs none /var/lib/stateless/writable ffff88012a2ff6c0 ffff8800b425e000 tmpfs none /var/cache/man ffff88012a2ff880 ffff8800b425e000 tmpfs none /var/log ffff88012a2ffa40 ffff8800b425e000 tmpfs none /var/lib/dbus ffff88012a2ffc00 ffff8800b425e000 tmpfs none /tmp ffff88012a2ffdc0 ffff8800b425e000 tmpfs none /var/lib/dhclient ffff88012b2c9500 ffff8800b425e000 tmpfs none /var/tmp ffff8800b2746000 ffff8800b425e000 tmpfs none /var/lib/NetworkManager ffff8800b27461c0 ffff8800b425e000 tmpfs none /var/lib/systemd/random-seed ffff8800b2746380 ffff8800b425e000 tmpfs none /var/spool ffff8801376696c0 ffff8800b425e000 tmpfs none /var/lib/nfs ffff8800b2746540 ffff8800b425e000 tmpfs none /var/lib/gssproxy ffff8800b2746700 ffff8800b425e000 tmpfs none /var/lib/logrotate ffff88012b2c96c0 ffff8800b425e000 tmpfs none /etc ffff8800b27468c0 ffff8800b425e000 tmpfs none /var/lib/rsyslog ffff88012b2c9880 ffff8800b425e000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8800b2746a80 ffff8800b4004000 nfs4 192.168.200.253:/exports/state/oleg114-server.virtnet /var/lib/stateless/state ffff880137669880 ffff8800b4004000 nfs4 192.168.200.253:/exports/state/oleg114-server.virtnet /boot ffff8800b2747180 ffff8800b4004000 nfs4 192.168.200.253:/exports/state/oleg114-server.virtnet /etc/etc/kdump.conf ffff880137669a40 ffff8800b5223000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b1df9500 ffff880129d44800 squashfs /dev/vda /usr/sbin/mount.lustre ffff880137669180 ffff8800ab8b4000 lustre lustre-mdt1/mdt1 /mnt/lustre-mds1 ffff8800b1fbe1c0 ffff8800b4282800 lustre lustre-mdt2/mdt2 /mnt/lustre-mds2 ffff8800a6306000 ffff8800960eb800 lustre lustre-ost1/ost1 /mnt/lustre-ost1 ffff880137668e00 ffff880131f8b000 lustre lustre-ost2/ost2 /mnt/lustre-ost2 +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 389.254649] LustreError: 24591:0:(mdt_open.c:1280:mdt_cross_open()) lustre-MDT0001: [0x240000403:0x3c06:0x0] doesn't exist!: rc = -14 [ 389.260964] LustreError: 24591:0:(mdt_open.c:1280:mdt_cross_open()) Skipped 18 previous similar messages [ 397.643823] LustreError: 6193:0:(mdd_object.c:3829:mdd_close()) lustre-MDD0001: failed to get lu_attr of [0x240000403:0x40f1:0x0]: rc = -2 [ 397.648257] LustreError: 6193:0:(mdd_object.c:3829:mdd_close()) Skipped 1 previous similar message [ 410.968834] Lustre: DEBUG MARKER: == racer test 2: racer rename: oleg114-client.virtnet DURATION=300 ========================================================== 15:16:05 (1713208565) [ 413.443757] Lustre: 16352:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff880086ce8e00 x1796429057017984/t4295127652(0) o101->a5a40117-6b5b-456e-8c23-824f85ebd9df@192.168.201.14@tcp:461/0 lens 376/42304 e 0 to 0 dl 1713208711 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 416.346409] Lustre: 18259:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff880079a44700 x1796429058465344/t4295100608(0) o101->47980c61-e0ea-47be-85f8-9048323bd266@192.168.201.14@tcp:463/0 lens 376/43120 e 0 to 0 dl 1713208713 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 416.355493] Lustre: 18259:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 3 previous similar messages [ 425.670599] Lustre: 10566:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff88011e967100 x1796429062636992/t4295101526(0) o101->47980c61-e0ea-47be-85f8-9048323bd266@192.168.201.14@tcp:473/0 lens 376/46384 e 0 to 0 dl 1713208723 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 436.549059] Lustre: 31217:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff88011fc73100 x1796429066026880/t4295102776(0) o101->a5a40117-6b5b-456e-8c23-824f85ebd9df@192.168.201.14@tcp:484/0 lens 376/46384 e 0 to 0 dl 1713208734 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 436.560381] Lustre: 31217:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 1 previous similar message [ 440.083842] LustreError: 18224:0:(mdt_open.c:1280:mdt_cross_open()) lustre-MDT0000: [0x200000402:0x54c0:0x0] doesn't exist!: rc = -14 [ 440.087886] LustreError: 18224:0:(mdt_open.c:1280:mdt_cross_open()) Skipped 54 previous similar messages [ 452.780063] Lustre: 7774:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff88011a9f1c00 x1796429076043392/t4295104413(0) o101->47980c61-e0ea-47be-85f8-9048323bd266@192.168.201.14@tcp:500/0 lens 376/46384 e 0 to 0 dl 1713208750 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 452.789159] Lustre: 7774:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 9 previous similar messages [ 472.147282] LustreError: 18233:0:(mdt_open.c:1280:mdt_cross_open()) lustre-MDT0000: [0x200000402:0x54c0:0x0] doesn't exist!: rc = -14 [ 472.151288] LustreError: 18233:0:(mdt_open.c:1280:mdt_cross_open()) Skipped 17 previous similar messages [ 475.288694] Lustre: lustre-OST0001-osc-MDT0001: update sequence from 0x2c0000400 to 0x2c0000402 [ 485.331845] Lustre: 19425:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff8800781d5c00 x1796429093391296/t4295107312(0) o101->a5a40117-6b5b-456e-8c23-824f85ebd9df@192.168.201.14@tcp:532/0 lens 376/47296 e 0 to 0 dl 1713208782 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 485.344992] Lustre: 19425:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 8 previous similar messages [ 496.776947] Lustre: lustre-OST0000-osc-MDT0001: update sequence from 0x280000400 to 0x280000402 [ 547.026875] LustreError: 24590:0:(mdt_open.c:1280:mdt_cross_open()) lustre-MDT0000: [0x200000402:0x54c0:0x0] doesn't exist!: rc = -14 [ 547.034216] LustreError: 24590:0:(mdt_open.c:1280:mdt_cross_open()) Skipped 65 previous similar messages [ 548.774605] LustreError: 7766:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.14@tcp ns: mdt-lustre-MDT0000_UUID lock: ffff88007a1d58c0/0x113be8dd5e91982a lrc: 3/0,0 mode: CR/CR res: [0x200000403:0x5b0a:0x0].0x0 bits 0xa/0x0 rrc: 3 type: IBT gid 0 flags: 0x60200400000020 nid: 192.168.201.14@tcp remote: 0x702538b3393218b5 expref: 2398 pid: 18259 timeout: 548 lvb_type: 0 [ 551.756075] Lustre: lustre-OST0001-osc-MDT0001: update sequence from 0x2c0000402 to 0x2c0000403 [ 554.290188] Lustre: 24590:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff8800726b3b80 x1796429115958464/t4295134171(0) o101->a5a40117-6b5b-456e-8c23-824f85ebd9df@192.168.201.14@tcp:601/0 lens 376/45080 e 0 to 0 dl 1713208851 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 554.305802] Lustre: 24590:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 14 previous similar messages [ 562.219170] LustreError: 7774:0:(mdt_handler.c:777:mdt_pack_acl2body()) lustre-MDT0001: unable to read [0x240000404:0x23e5:0x0] ACL: rc = -2 [ 588.460101] Lustre: 18286:0:(lod_lov.c:1433:lod_parse_striping()) lustre-MDT0001-mdtlov: EXTENSION flags=40 set on component[2]=1 of non-SEL file [0x240000404:0x14fd:0x0] with magic=0xbd60bd0 [ 588.469720] Lustre: 18286:0:(lod_lov.c:1433:lod_parse_striping()) Skipped 231 previous similar messages [ 595.928277] Lustre: lustre-OST0000-osc-MDT0001: update sequence from 0x280000402 to 0x280000403 [ 624.153694] Lustre: lustre-OST0001-osc-MDT0000: update sequence from 0x2c0000401 to 0x2c0000404 [ 624.153760] Lustre: lustre-OST0000-osc-MDT0000: update sequence from 0x280000401 to 0x280000404 [ 684.944107] Lustre: 18229:0:(mdt_recovery.c:148:mdt_req_from_lrd()) @@@ restoring transno req@ffff880075f96d80 x1796429169220864/t4295145002(0) o101->47980c61-e0ea-47be-85f8-9048323bd266@192.168.201.14@tcp:732/0 lens 376/47912 e 0 to 0 dl 1713208982 ref 1 fl Interpret:H/202/0 rc 0/0 job:'dd.0' uid:0 gid:0 [ 684.957315] Lustre: 18229:0:(mdt_recovery.c:148:mdt_req_from_lrd()) Skipped 29 previous similar messages [ 699.814579] LustreError: 7766:0:(ldlm_lockd.c:261:expired_lock_main()) ### lock callback timer expired after 100s: evicting client at 192.168.201.14@tcp ns: mdt-lustre-MDT0001_UUID lock: ffff8801207bcb40/0x113be8dd5eda0f81 lrc: 3/0,0 mode: PR/PR res: [0x240000403:0x5529:0x0].0x0 bits 0x13/0x0 rrc: 5 type: IBT gid 0 flags: 0x60200400000020 nid: 192.168.201.14@tcp remote: 0x702538b339559144 expref: 2507 pid: 18286 timeout: 699 lvb_type: 0 [ 699.846624] LustreError: 5152:0:(ldlm_lockd.c:2594:ldlm_cancel_handler()) ldlm_cancel from 192.168.201.14@tcp arrived at 1713208854 with bad export cookie 1241842159731955239 [ 699.979890] LustreError: 24593:0:(mdt_open.c:1280:mdt_cross_open()) lustre-MDT0000: [0x200000402:0x54c0:0x0] doesn't exist!: rc = -14 [ 699.987372] LustreError: 24593:0:(mdt_open.c:1280:mdt_cross_open()) Skipped 41 previous similar messages [ 701.541377] Lustre: lustre-OST0001-osc-MDT0001: update sequence from 0x2c0000403 to 0x2c0000405 ****************************************************************************** ************************ A Summary Of Problems Found ************************* ****************************************************************************** -------------------- A list of all +++WARNING+++ messages -------------------- PARTIAL DUMP with size(vmcore) < 25% size(RAM) High Load Averages: 68.03, 47.60, 22.11 There are 3 threads running in their own namespaces Use 'taskinfo --ns' to get more details ------------------------------------------------------------------------------ ** Execution took 14.28s (real) 9.09s (CPU), Child processes: 5.13s