************************ crashinfo ************************* /exports/testreports/40195/testresults/conf-sanity-slow-106-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg118-client-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.0K1VZ/vmlinux [TAINTED] DUMPFILE: /exports/testreports/40195/testresults/conf-sanity-slow-106-ldiskfs-DNE-centos7_x86_64-centos7_x86_64/oleg118-client-timeout-core [PARTIAL DUMP] CPUS: 4 DATE: Tue Feb 27 13:34:27 EST 2024 UPTIME: 01:26:15 LOAD AVERAGE: 0.46, 0.47, 0.58 TASKS: 148 NODENAME: oleg118-client.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 ioread8+0x42, 449 bytes of data #0 vp_interrupt+0x1e #1 __handle_irq_event_percpu+0x4e #2 handle_irq_event_percpu+0x32 #3 handle_irq_event+0x3d #4 handle_fasteoi_irq+0x5d #5 handle_irq+0xde #6 do_IRQ+0x4d, 19 bytes of data #7 ret_from_intr+0x0 #-1 native_safe_halt+0xb, 477 bytes of data #8 default_idle+0x1e #9 default_enter_idle+0x45 #10 cpuidle_enter_state+0x40 #11 cpuidle_idle_call+0xd8 #12 arch_cpu_idle+0xe #13 cpu_startup_entry+0x14a #14 rest_init+0x8e #15 start_kernel+0x456 #16 x86_64_start_reservations+0x2a #17 x86_64_start_kernel+0x152 #18 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 +---------------+ >------------------------------| Tasks Summary |------------------------------< +---------------+ Number of Threads That Ran Recently ----------------------------------- last second 25 last 5s 38 last 60s 43 ----- Total Numbers of Threads per State ------ TASK_INTERRUPTIBLE 144 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 ----- -------------- ------ ---------------------------- 1836 socknal_sd01_00 0 ms (no user stack) 21339 createmany 1 ms /home/green/git/lustre-release/lustre/tests/createmany -o /mnt/lustre/d106.conf-sanity/f- 64768 7 migration/0 3 ms (no user stack) 1837 socknal_sd01_01 10 ms (no user stack) 9 rcu_sched 18 ms (no user stack) +------------------------+ >-------------------------| Memory Usage (kmem -i) |-------------------------< +------------------------+ PAGES TOTAL PERCENTAGE TOTAL MEM 955079 3.6 GB ---- FREE 832906 3.2 GB 87% of TOTAL MEM USED 122173 477.2 MB 12% of TOTAL MEM SHARED 10266 40.1 MB 1% of TOTAL MEM BUFFERS 5158 20.1 MB 0% of TOTAL MEM CACHED 45569 178 MB 4% of TOTAL MEM SLAB 37906 148.1 MB 3% 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 739682 2.8 GB ---- COMMITTED 62859 245.5 MB 8% 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 6 LISTEN 3 NAGLE disabled (TCP_NODELAY): 5 user_data set (NFS etc.): 4 UDP Connection Info ------------------- 2 UDP sockets, 0 in ESTABLISHED Unix Connection Info ------------------------ ESTABLISHED 26 CLOSE 18 LISTEN 8 Raw sockets info -------------------- CLOSE 1 Interfaces Info --------------- How long ago (in seconds) interfaces transmitted/received? Name RX TX ---- ---------- --------- lo n/a 5173.1 eth0 n/a 0.0 RSS_TOTAL=80000 pages, %mem= 1.2 +------------+ >-------------------------------| Mounted FS |-------------------------------< +------------+ MOUNT SUPERBLK TYPE DEVNAME DIRNAME ffff880138cca000 ffff880139940800 rootfs rootfs / ffff88012aa4c000 ffff88012aa30000 sysfs sysfs /sys ffff88012aa4c1c0 ffff880139944000 proc proc /proc ffff88012aa4c380 ffff880137668000 devtmpfs devtmpfs /dev ffff88012aa4c540 ffff8800b6ceb000 securityfs securityfs /sys/kernel/security ffff88012aa4c700 ffff88012aa30800 tmpfs tmpfs /dev/shm ffff88012aa4c8c0 ffff880137315000 devpts devpts /dev/pts ffff88012aa4ca80 ffff88012aa31000 tmpfs tmpfs /run ffff88012aa4cc40 ffff88012aa31800 tmpfs tmpfs /sys/fs/cgroup ffff88012aa4ce00 ffff88012aa32000 cgroup cgroup /sys/fs/cgroup/systemd ffff88012aa4cfc0 ffff88012aa32800 pstore pstore /sys/fs/pstore ffff88012aa4d180 ffff88012aa34800 cgroup cgroup /sys/fs/cgroup/net_cls,net_prio ffff88012aa4d340 ffff88012aa34000 cgroup cgroup /sys/fs/cgroup/cpu,cpuacct ffff88012aa4d500 ffff88012aa33800 cgroup cgroup /sys/fs/cgroup/freezer ffff88012aa4d6c0 ffff88012aa33000 cgroup cgroup /sys/fs/cgroup/perf_event ffff88012aa4d880 ffff88012aa35000 cgroup cgroup /sys/fs/cgroup/cpuset ffff88012aa4da40 ffff88012aa35800 cgroup cgroup /sys/fs/cgroup/devices ffff88012aa4dc00 ffff88012aa36000 cgroup cgroup /sys/fs/cgroup/blkio ffff88012aa4ddc0 ffff88012aa36800 cgroup cgroup /sys/fs/cgroup/memory ffff88012aa48000 ffff88012aa37000 cgroup cgroup /sys/fs/cgroup/pids ffff88012aa481c0 ffff88012aa37800 cgroup cgroup /sys/fs/cgroup/hugetlb ffff88012aa48380 ffff8800b6d25000 configfs configfs /sys/kernel/config ffff8801377de1c0 ffff8801377ed800 ext4 /dev/nbd0 / ffff88012aa48540 ffff88013766f000 rpc_pipefs rpc_pipefs /var/lib/nfs/rpc_pipefs ffff8801377de380 ffff8801377ed000 autofs systemd-1 /proc/sys/fs/binfmt_misc ffff88012aa48700 ffff880139947800 debugfs debugfs /sys/kernel/debug ffff88012aa488c0 ffff88012a637000 hugetlbfs hugetlbfs /dev/hugepages ffff8801376528c0 ffff880137316000 mqueue mqueue /dev/mqueue ffff88012aa48a80 ffff88012a5fe800 binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc/ ffff8801377de700 ffff88012a630800 ramfs none /mnt ffff88012aa48c40 ffff8800b63c1000 tmpfs none /var/lib/stateless/writable ffff880138ccb880 ffff88012a5a8800 squashfs /dev/vda /home/green/git/lustre-release ffff880137652a80 ffff8800b63c1000 tmpfs none /var/cache/man ffff880138ccba40 ffff8800b63c1000 tmpfs none /var/log ffff88012aa48e00 ffff8800b63c1000 tmpfs none /var/lib/dbus ffff880137652c40 ffff8800b63c1000 tmpfs none /tmp ffff880137652e00 ffff8800b63c1000 tmpfs none /var/lib/dhclient ffff880138ccbc00 ffff8800b63c1000 tmpfs none /var/tmp ffff880137652fc0 ffff8800b63c1000 tmpfs none /var/lib/NetworkManager ffff880138ccbdc0 ffff8800b63c1000 tmpfs none /var/lib/systemd/random-seed ffff880137653180 ffff8800b63c1000 tmpfs none /var/spool ffff88012aa48fc0 ffff8800b63c1000 tmpfs none /var/lib/nfs ffff880137653340 ffff8800b63c1000 tmpfs none /var/lib/gssproxy ffff880137653500 ffff8800b63c1000 tmpfs none /var/lib/logrotate ffff88012aa49180 ffff8800b63c1000 tmpfs none /etc ffff88012aa49340 ffff8800b63c1000 tmpfs none /var/lib/rsyslog ffff8801376536c0 ffff8800b63c1000 tmpfs none /var/lib/dhclient/var/lib/dhclient ffff8801377de8c0 ffff8800b5c6a800 nfs4 192.168.200.253:/exports/state/oleg118-client.virtnet /var/lib/stateless/state ffff880137653a40 ffff8800b5c6a800 nfs4 192.168.200.253:/exports/state/oleg118-client.virtnet /boot ffff880137653880 ffff8800b5c6a800 nfs4 192.168.200.253:/exports/state/oleg118-client.virtnet /etc/etc/kdump.conf ffff88012aa49500 ffff88013766f000 rpc_pipefs sunrpc /var/lib/nfs/var/lib/nfs/rpc_pipefs ffff8800b3efcfc0 ffff88013766e800 nfs4 192.168.200.253://exports/testreports/40195/testresults/conf-sanity-slow-106-ldiskfs-DNE-centos7_x86_64-centos7_x86_64 /tmp/tmp/testlogs ffff880137653c00 ffff8800b613b000 tmpfs tmpfs /run/user/0 ffff8800b3efd500 ffff88012a5a8800 squashfs /dev/vda /usr/sbin/mount.lustre ffff8800af62a1c0 ffff88012b087800 lustre 192.168.201.118@tcp:/lustre /mnt/lustre +-------------------------------+ >----------------------| Last 40 lines of dmesg buffer |----------------------< +-------------------------------+ [ 167.144809] random: crng init done [ 169.549501] Lustre: DEBUG MARKER: == conf-sanity test 106: check osp llog processing when catalog is wrapped ========================================================== 12:11:00 (1709053860) [ 189.478349] Lustre: DEBUG MARKER: oleg118-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0000-mdc-*.mds_server_uuid [ 190.024891] Lustre: DEBUG MARKER: oleg118-client.virtnet: executing wait_import_state_mount FULL mdc.lustre-MDT0001-mdc-*.mds_server_uuid [ 195.166843] Lustre: DEBUG MARKER: oleg118-client.virtnet: executing wait_import_state_mount (FULL|IDLE) osc.lustre-OST0000-osc-[-0-9a-f]*.ost_server_uuid [ 195.260616] Lustre: Mounted lustre-client [ 227.241946] Lustre: 14703:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709053918/real 1709053918] req@ffff8800a806ed80 x1792072712093632/t0(0) o35->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:23/10 lens 392/624 e 0 to 1 dl 1709053934 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 227.278401] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 227.310206] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 523.539479] Lustre: 14703:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709054215/real 1709054215] req@ffff8800a4760000 x1792072716737856/t0(0) o101->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 648/66320 e 0 to 1 dl 1709054231 ref 2 fl Rpc:ReXPQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 523.558033] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 523.584722] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 587.205577] Lustre: 14703:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709054278/real 1709054278] req@ffff8800a4768380 x1792072717127488/t0(0) o35->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:23/10 lens 392/624 e 0 to 1 dl 1709054294 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 587.221273] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 587.248545] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 657.373088] Lustre: 14703:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709054348/real 1709054348] req@ffff8800a3aee300 x1792072717506496/t0(0) o101->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 648/66320 e 0 to 1 dl 1709054364 ref 2 fl Rpc:ReXPQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 657.382994] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 657.404623] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 713.704750] Lustre: 14703:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709054405/real 1709054405] req@ffff8800a31c1f80 x1792072717832256/t0(0) o35->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:23/10 lens 392/624 e 0 to 1 dl 1709054421 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 713.716149] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 713.738105] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 799.925884] hrtimer: interrupt took 5170110 ns [ 1010.088269] Lustre: 15441:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709054701/real 1709054701] req@ffff8800a2055500 x1792072719170048/t0(0) o36->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 488/624 e 0 to 1 dl 1709054717 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 1010.100088] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1010.126432] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 1423.717898] Lustre: 15441:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709055115/real 1709055115] req@ffff8800a5cdca80 x1792072721648576/t0(0) o36->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 488/624 e 0 to 1 dl 1709055131 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 1423.739977] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 1423.765965] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 4695.486720] Lustre: 20366:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709058387/real 1709058387] req@ffff8800a63db100 x1792072759338048/t0(0) o36->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 488/624 e 0 to 1 dl 1709058403 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 4695.496588] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4695.513254] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 4883.943291] Lustre: 21339:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709058575/real 1709058575] req@ffff88012f3ab800 x1792072762925760/t0(0) o35->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:23/10 lens 392/624 e 0 to 1 dl 1709058591 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 4883.960559] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4883.977780] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 4971.856747] Lustre: 21339:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709058663/real 1709058663] req@ffff8800a4c9dc00 x1792072764143296/t0(0) o35->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:23/10 lens 392/624 e 0 to 1 dl 1709058679 ref 2 fl Rpc:ReXQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 4971.867610] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 4971.890117] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) [ 5039.094635] Lustre: 21339:0:(client.c:2338:ptlrpc_expire_one_request()) @@@ Request sent has failed due to network error: [sent 1709058730/real 1709058730] req@ffff8800a316c000 x1792072764770240/t0(0) o101->lustre-MDT0000-mdc-ffff88012b087800@192.168.201.118@tcp:12/10 lens 648/66320 e 0 to 1 dl 1709058746 ref 2 fl Rpc:ReXPQU/200/ffffffff rc 0/-1 job:'createmany.0' uid:0 gid:0 [ 5039.102331] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection to lustre-MDT0000 (at 192.168.201.118@tcp) was lost; in progress operations using this service will wait for recovery to complete [ 5039.128779] Lustre: lustre-MDT0000-mdc-ffff88012b087800: Connection restored to (at 192.168.201.118@tcp) ****************************************************************************** ************************ A Summary Of Problems Found ************************* ****************************************************************************** -------------------- A list of all +++WARNING+++ messages -------------------- PARTIAL DUMP with size(vmcore) < 25% size(RAM) There are 3 threads running in their own namespaces Use 'taskinfo --ns' to get more details ------------------------------------------------------------------------------ ** Execution took 11.25s (real) 5.76s (CPU), Child processes: 5.42s