394 Star 1.4K Fork 1.3K

GVPopenEuler / kernel

 / 详情

iSER(iSCSI Extensions for RDMA)环境,不跑业务的情况下,空环境出现多个D状态进程

已完成
缺陷
创建于  
2022-01-21 10:07

【标题描述】能够简要描述问题:说明什么场景下,做了什么操作,出现什么问题(尽量使用正向表达方式)
【环境信息】
物理机
openeulerversion=openEuler-20.03-LTS-SP3

【问题复现步骤】
搭建iSER(iSCSI Extensions for RDMA)环境,不跑业务的情况下,空环境出现多个D状态进程。导致无法跑业务。

【预期结果】
可以正常下IO

【实际结果】
出现多个D状态进程,无法下业务。

【附件信息】
Jan 17 16:26:12 ora-storage02 kernel: [ 237.468557] nvme0n1:
Jan 17 16:29:18 ora-storage02 kernel: [ 422.703958] ------------[ cut here ]------------
Jan 17 16:29:18 ora-storage02 kernel: [ 422.703972] percpu_ref_kill_and_confirm called more than once on target_release_sess_cmd_refcnt [target_core_mod]!
Jan 17 16:29:18 ora-storage02 kernel: [ 422.703985] WARNING: CPU: 0 PID: 3024 at lib/percpu-refcount.c:336 percpu_ref_kill_and_confirm+0x7c/0xa0
Jan 17 16:29:18 ora-storage02 kernel: [ 422.703986] Modules linked in: target_core_user uio target_core_pscsi target_core_file target_core_iblock xt_CHECKSUM ipt_MASQUERADE xt_conntrack ipt_REJECT nf_reject_ipv4 ip6table_mangle ip6table_nat nf_nat_ipv6 iptable_mangle iptable_nat nf_nat_ipv4 nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter tun bridge stp llc rfkill intel_rapl_msr intel_rapl_common isst_if_common vfat fat skx_edac nfit libnvdimm rpcrdma sunrpc x86_pkg_temp_thermal coretemp rdma_ucm ib_srpt kvm_intel ib_isert iscsi_target_mod kvm target_core_mod irqbypass crct10dif_pclmul ib_iser rdma_cm crc32_pclmul iw_cm ghash_clmulni_intel libiscsi ib_umad ib_ipoib i40iw scsi_transport_iscsi intel_cstate ib_cm sg ipmi_si pcspkr ipmi_devintf ipmi_msghandler intel_uncore
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704010] intel_rapl_perf ioatdma joydev mei_me wdat_wdt mei i2c_i801 lpc_ich dca acpi_power_meter ip_tables ext4 mbcache jbd2 mlx5_ib ib_uverbs ib_core sd_mod crc32c_intel mlx5_core nvme nvme_core i40e ahci mlxfw libahci uas megaraid_sas host_edma_drv usb_storage libata dm_mirror dm_region_hash dm_log dm_mod
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704023] CPU: 0 PID: 3024 Comm: iscsi_ttx Kdump: loaded Not tainted 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704024] Hardware name: Huawei 2288H V5/BC11SPSCB0, BIOS 7.95 02/05/2021
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704026] RIP: 0010:percpu_ref_kill_and_confirm+0x7c/0xa0
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704028] Code: 38 48 00 80 3d f9 b0 fd 00 00 75 c4 48 8b 53 10 48 c7 c6 20 6d 49 8b 48 c7 c7 30 45 6d 8b c6 05 de b0 fd 00 01 e8 84 6c c6 ff <0f> 0b 48 8b 53 08 eb 9e f0 48 83 2b 01 75 b7 48 8b 43 10 48 89 df
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704029] RSP: 0018:ffffa883cf60fdf8 EFLAGS: 00010082
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704029] RAX: 0000000000000000 RBX: ffff9a7b27db2ad8 RCX: 0000000000000000
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704030] RDX: 0000000000000066 RSI: ffffffff8c0b2aa6 RDI: 0000000000000046
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704031] RBP: 0000000000000246 R08: 0000000000000002 R09: 0000000000022000
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704031] R10: ffffffff8b803d60 R11: ffffffff8b699c00 R12: 0000000000000000
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704032] R13: ffff9a79a0031900 R14: ffffa883cf60fc50 R15: ffffa883cf60fe48
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704033] FS: 0000000000000000(0000) GS:ffff9a987f800000(0000) knlGS:0000000000000000
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704033] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704034] CR2: 00007fd1e90f8578 CR3: 0000000b01a0a003 CR4: 00000000007606f0
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704035] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704035] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704036] PKRU: 55555554
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704036] Call Trace:
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704047] iscsit_close_connection+0x27b/0x940 [iscsi_target_mod]
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704054] ? __schedule+0x298/0x760
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704058] ? iscsit_thread_get_cpumask+0xb0/0xb0 [iscsi_target_mod]
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704062] iscsit_take_action_for_connection_exit+0xec/0x100 [iscsi_target_mod]
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704068] iscsi_target_tx_thread+0x163/0x1f0 [iscsi_target_mod]
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704071] ? finish_wait+0x80/0x80
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704074] kthread+0x113/0x130
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704075] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704078] ret_from_fork+0x1f/0x40
Jan 17 16:29:18 ora-storage02 kernel: [ 422.704079] ---[ end trace c7aeaf7c081068e7 ]---
Jan 17 16:30:13 ora-storage02 kernel: [ 477.691165] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:30:13 ora-storage02 kernel: [ 477.698261] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:30:13 ora-storage02 kernel: [ 477.698290] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:30:13 ora-storage02 kernel: [ 477.698295] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:32:30 ora-storage02 systemd[1]: Starting dnf makecache...
Jan 17 16:32:31 ora-storage02 kernel: [ 615.775791] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776004] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776236] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776481] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776490] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776490] Call Trace:
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776497] ? __schedule+0x290/0x760
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776499] schedule+0x29/0xc0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776502] schedule_timeout+0x1ee/0x3a0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776506] ? __wake_up_common+0x76/0x170
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776508] wait_for_completion+0x12c/0x190
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776513] ? wake_up_q+0x70/0x70
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776525] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776530] process_one_work+0x195/0x3d0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776532] worker_thread+0x30/0x390
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776534] ? process_one_work+0x3d0/0x3d0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776535] kthread+0x113/0x130
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776536] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776538] ret_from_fork+0x1f/0x40
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776572] INFO: task iscsi_ttx:3031 blocked for more than 120 seconds.
Jan 17 16:32:31 ora-storage02 kernel: [ 615.776777] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777002] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777245] iscsi_ttx D 0 3031 2 0x80000084
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777246] Call Trace:
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777249] ? __schedule+0x290/0x760
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777250] schedule+0x29/0xc0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777252] schedule_timeout+0x179/0x3a0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777255] ? __next_timer_interrupt+0xc0/0xc0
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777257] ? prepare_to_wait_event+0x7d/0x150
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777270] target_wait_for_sess_cmds+0x76/0x180 [target_core_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777272] ? finish_wait+0x80/0x80
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777277] iscsit_close_connection+0x287/0x940 [iscsi_target_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777279] ? __schedule+0x298/0x760
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777284] ? iscsit_thread_get_cpumask+0xb0/0xb0 [iscsi_target_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777288] iscsit_take_action_for_connection_exit+0x7a/0x100 [iscsi_target_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777293] iscsi_target_tx_thread+0x163/0x1f0 [iscsi_target_mod]
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777294] ? finish_wait+0x80/0x80
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777295] kthread+0x113/0x130
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777297] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:32:31 ora-storage02 kernel: [ 615.777298] ret_from_fork+0x1f/0x40
Jan 17 16:32:31 ora-storage02 dnf[3043]: Metadata cache refreshed recently.
Jan 17 16:32:31 ora-storage02 systemd[1]: dnf-makecache.service: Succeeded.
Jan 17 16:32:31 ora-storage02 systemd[1]: Started dnf makecache.
Jan 17 16:32:31 ora-storage02 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:32:31 ora-storage02 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dnf-makecache comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656300] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656508] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656741] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656985] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656989] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656990] Call Trace:
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656993] ? __schedule+0x290/0x760
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656994] schedule+0x29/0xc0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656996] schedule_timeout+0x1ee/0x3a0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.656998] ? __wake_up_common+0x76/0x170
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657000] wait_for_completion+0x12c/0x190
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657002] ? wake_up_q+0x70/0x70
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657007] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657009] process_one_work+0x195/0x3d0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657011] worker_thread+0x30/0x390
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657012] ? process_one_work+0x3d0/0x3d0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657013] kthread+0x113/0x130
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657014] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657015] ret_from_fork+0x1f/0x40
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657039] INFO: task iscsi_ttx:3024 blocked for more than 120 seconds.
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657235] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657473] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657710] iscsi_ttx D 0 3024 2 0x80000084
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657711] Call Trace:
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657714] ? __schedule+0x290/0x760
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657715] schedule+0x29/0xc0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657718] schedule_timeout+0x179/0x3a0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657719] ? __next_timer_interrupt+0xc0/0xc0
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657720] ? prepare_to_wait_event+0x7d/0x150
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657728] target_wait_for_sess_cmds+0x76/0x180 [target_core_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657730] ? finish_wait+0x80/0x80
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657736] iscsit_close_connection+0x287/0x940 [iscsi_target_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657737] ? __schedule+0x298/0x760
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657741] ? iscsit_thread_get_cpumask+0xb0/0xb0 [iscsi_target_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657746] iscsit_take_action_for_connection_exit+0xec/0x100 [iscsi_target_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657750] iscsi_target_tx_thread+0x163/0x1f0 [iscsi_target_mod]
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657752] ? finish_wait+0x80/0x80
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657753] kthread+0x113/0x130
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657754] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:34:34 ora-storage02 kernel: [ 738.657756] ret_from_fork+0x1f/0x40
Jan 17 16:36:36 ora-storage02 kernel: [ 861.536779] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:36:36 ora-storage02 kernel: [ 861.536987] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537218] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537465] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537467] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537468] Call Trace:
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537470] ? __schedule+0x290/0x760
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537472] schedule+0x29/0xc0
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537474] schedule_timeout+0x1ee/0x3a0
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537475] ? __wake_up_common+0x76/0x170
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537477] wait_for_completion+0x12c/0x190
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537478] ? wake_up_q+0x70/0x70
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537483] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537485] process_one_work+0x195/0x3d0
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537486] worker_thread+0x30/0x390
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537488] ? process_one_work+0x3d0/0x3d0
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537489] kthread+0x113/0x130
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537490] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:36:36 ora-storage02 kernel: [ 861.537491] ret_from_fork+0x1f/0x40
Jan 17 16:37:30 ora-storage02 systemd[1]: Starting Cleanup of Temporary Directories...
Jan 17 16:37:30 ora-storage02 systemd-tmpfiles[3047]: /usr/lib/tmpfiles.d/pesign.conf:1: Line references path below legacy directory /var/run/, updating /var/run/pesign → /run/pesign; please update the tmpfiles.d/ drop-in file accordingly.
Jan 17 16:37:30 ora-storage02 systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Jan 17 16:37:30 ora-storage02 systemd[1]: Started Cleanup of Temporary Directories.
Jan 17 16:37:30 ora-storage02 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:37:30 ora-storage02 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417277] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417484] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417719] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417963] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417966] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417966] Call Trace:
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417969] ? __schedule+0x290/0x760
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417970] schedule+0x29/0xc0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417972] schedule_timeout+0x1ee/0x3a0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417973] ? __wake_up_common+0x76/0x170
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417975] wait_for_completion+0x12c/0x190
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417977] ? wake_up_q+0x70/0x70
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417981] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417983] process_one_work+0x195/0x3d0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417985] worker_thread+0x30/0x390
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417986] ? process_one_work+0x3d0/0x3d0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417987] kthread+0x113/0x130
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417988] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:38:39 ora-storage02 kernel: [ 984.417989] ret_from_fork+0x1f/0x40
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418001] INFO: task iscsi_ttx:3031 blocked for more than 120 seconds.
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418197] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418435] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418675] iscsi_ttx D 0 3031 2 0x80000084
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418676] Call Trace:
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418678] ? __schedule+0x290/0x760
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418680] schedule+0x29/0xc0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418682] schedule_timeout+0x179/0x3a0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418684] ? __next_timer_interrupt+0xc0/0xc0
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418685] ? prepare_to_wait_event+0x7d/0x150
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418692] target_wait_for_sess_cmds+0x76/0x180 [target_core_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418694] ? finish_wait+0x80/0x80
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418699] iscsit_close_connection+0x287/0x940 [iscsi_target_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418700] ? __schedule+0x298/0x760
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418704] ? iscsit_thread_get_cpumask+0xb0/0xb0 [iscsi_target_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418709] iscsit_take_action_for_connection_exit+0x7a/0x100 [iscsi_target_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418713] iscsi_target_tx_thread+0x163/0x1f0 [iscsi_target_mod]
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418715] ? finish_wait+0x80/0x80
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418716] kthread+0x113/0x130
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418717] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:38:39 ora-storage02 kernel: [ 984.418718] ret_from_fork+0x1f/0x40
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.297778] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.297986] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298218] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298462] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298465] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298466] Call Trace:
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298468] ? __schedule+0x290/0x760
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298469] schedule+0x29/0xc0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298471] schedule_timeout+0x1ee/0x3a0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298472] ? __wake_up_common+0x76/0x170
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298474] wait_for_completion+0x12c/0x190
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298476] ? wake_up_q+0x70/0x70
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298480] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298482] process_one_work+0x195/0x3d0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298483] worker_thread+0x30/0x390
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298484] ? process_one_work+0x3d0/0x3d0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298485] kthread+0x113/0x130
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298487] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298488] ret_from_fork+0x1f/0x40
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298499] INFO: task iscsi_ttx:3024 blocked for more than 120 seconds.
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298694] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.298933] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299171] iscsi_ttx D 0 3024 2 0x80000084
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299173] Call Trace:
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299175] ? __schedule+0x290/0x760
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299176] schedule+0x29/0xc0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299178] schedule_timeout+0x179/0x3a0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299179] ? __next_timer_interrupt+0xc0/0xc0
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299181] ? prepare_to_wait_event+0x7d/0x150
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299187] target_wait_for_sess_cmds+0x76/0x180 [target_core_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299189] ? finish_wait+0x80/0x80
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299194] iscsit_close_connection+0x287/0x940 [iscsi_target_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299196] ? __schedule+0x298/0x760
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299200] ? iscsit_thread_get_cpumask+0xb0/0xb0 [iscsi_target_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299204] iscsit_take_action_for_connection_exit+0xec/0x100 [iscsi_target_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299209] iscsi_target_tx_thread+0x163/0x1f0 [iscsi_target_mod]
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299211] ? finish_wait+0x80/0x80
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299212] kthread+0x113/0x130
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299213] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:40:42 ora-storage02 kernel: [ 1107.299214] ret_from_fork+0x1f/0x40
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178275] INFO: task kworker/u132:0:921 blocked for more than 120 seconds.
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178483] Tainted: G W 4.19.90-2112.1.0.0126.fos.x86_64 #1
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178714] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178960] kworker/u132:0 D 0 921 2 0x80000080
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178963] Workqueue: isert_comp_wq isert_do_control_comp [ib_isert]
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178963] Call Trace:
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178966] ? __schedule+0x290/0x760
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178967] schedule+0x29/0xc0
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178969] schedule_timeout+0x1ee/0x3a0
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178970] ? __wake_up_common+0x76/0x170
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178972] wait_for_completion+0x12c/0x190
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178973] ? wake_up_q+0x70/0x70
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178978] iscsit_logout_post_handler+0x172/0x210 [iscsi_target_mod]
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178979] process_one_work+0x195/0x3d0
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178981] worker_thread+0x30/0x390
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178982] ? process_one_work+0x3d0/0x3d0
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178983] kthread+0x113/0x130
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178984] ? kthread_create_worker_on_cpu+0x70/0x70
Jan 17 16:42:45 ora-storage02 kernel: [ 1230.178985] ret_from_fork+0x1f/0x40
Jan 17 16:44:37 ora-storage02 kernel: [ 1341.659629] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:44:37 ora-storage02 kernel: [ 1341.660466] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:44:37 ora-storage02 kernel: [ 1341.661734] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:44:37 ora-storage02 kernel: [ 1341.663802] iSCSI/iqn.2022-01.com.dbn01: Unsupported SCSI Opcode 0xa3, sending CHECK_CONDITION.
Jan 17 16:55:37 ora-storage02 kernel: [ 2002.277395] iSCSI Login timeout on Network Portal 0.0.0.0:3260
Jan 17 17:07:44 ora-storage02 systemd[1]: Reloading.
Jan 17 17:07:44 ora-storage02 systemd-rc-local-generator[3116]: [ 2728.603674] /etc/rc.d/rc.local is not marked executable, skipping.
Jan 17 17:07:44 ora-storage02 systemd[1]: /usr/lib/systemd/system/dbus.socket:5: ListenStream= references a path below legacy directory /var/run/, updating /var/run/dbus/system_bus_socket → /run/dbus/system_bus_socket; please update the unit file accordingly.
Jan 17 17:07:44 ora-storage02 systemd[1]: Starting Restore LIO kernel target configuration...

详细日志见附件

评论 (4)

wujiangtao_cn 创建了缺陷

Hi wujiangtao_cn, welcome to the openEuler Community.
I'm the Bot here serving you. You can find the instructions on how to interact with me at Here.
If you have any questions, please contact the SIG: Kernel, and any of the maintainers: @YangYingliang , @pi3orama , @成坚 (CHENG Jian) , @zhengzengkai , @Xie XiuQi

openeuler-ci-bot 添加了
 
sig/Kernel
标签
wujiangtao_cn 修改了描述

一共8个进程进入D状态:
crash> ps -m | grep UN
[0 00:00:26.755] [UN] PID: 3052 TASK: ffff9a7b2c213d00 CPU: 0 COMMAND: "iscsi_ttx"
[0 00:01:24.099] [UN] PID: 3041 TASK: ffff9a799c3bbd00 CPU: 0 COMMAND: "iscsi_ttx"
[0 00:01:52.771] [UN] PID: 3031 TASK: ffff9a799c3bdb80 CPU: 0 COMMAND: "iscsi_ttx"
[0 00:02:29.635] [UN] PID: 3024 TASK: ffff9a99011bdb80 CPU: 0 COMMAND: "iscsi_ttx"
[0 18:13:28.633] [UN] PID: 3123 TASK: ffff9a9907b4bd00 CPU: 53 COMMAND: "targetctl"
[0 18:25:49.447] [UN] PID: 3014 TASK: ffff9a7a10320000 CPU: 32 COMMAND: "iscsi_np"
[0 18:38:51.248] [UN] PID: 2855 TASK: ffff9a79ecfe9e80 CPU: 12 COMMAND: "kworker/u132:1"
[0 18:51:54.700] [UN] PID: 921 TASK: ffff9a799cd4bd00 CPU: 32 COMMAND: "kworker/u132:0"

问题根因:
percpu_ref_kill被调用了多次,导致se_session的cmd_count引用计数变成-1了,导致调用流程无限等待。

openEuler-20.03-LTS-SP3 漏合如下补丁导致:
807b9515b7d0 scsi: Revert "target: iscsi: Wait for all commands to finish before freeing a session"

合入该补丁后验证,不再出现这8个D状态进程。

Thanks,我们已经在开展分析和验证,该补丁会在近期合入,请关注下。

诚邀Issue的创建人,负责人,协作人以及评论人对此次Issue解决过程给予评价:

   0   1   2   3   4   5   6   7   8   9   10  

 不满意                        非常满意

登录 后才可以发表评论

状态
负责人
项目
里程碑
Pull Requests
关联的 Pull Requests 被合并后可能会关闭此 issue
分支
开始日期   -   截止日期
-
置顶选项
优先级
预计工期 (小时)
参与者(4)
5329419 openeuler ci bot 1632792936 9968373 openeuler survey bot 1637036855
C
1
https://gitee.com/openeuler/kernel.git
git@gitee.com:openeuler/kernel.git
openeuler
kernel
kernel

搜索帮助