From mboxrd@z Thu Jan 1 00:00:00 1970 From: Robert LeBlanc Subject: Re: iscsi_trx going into D state Date: Mon, 17 Oct 2016 13:11:34 -0600 Message-ID: References: <880e374c-cf8b-f276-e930-57b09fe1a686@suse.com> Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Return-path: In-Reply-To: Sender: linux-rdma-owner-u79uwXL29TY76Z2rM5mHXA@public.gmane.org To: Zhu Lingshan Cc: linux-rdma-u79uwXL29TY76Z2rM5mHXA@public.gmane.org, linux-scsi-u79uwXL29TY76Z2rM5mHXA@public.gmane.org List-Id: linux-rdma@vger.kernel.org Sorry hit send too soon. In addition, on the client we see: # ps -aux | grep D | grep kworker root 5583 0.0 0.0 0 0 ? D 11:55 0:03 [kworker/1= 1:0] root 7721 0.1 0.0 0 0 ? D 12:00 0:04 [kworker/4= :25] root 10877 0.0 0.0 0 0 ? D 09:27 0:00 [kworker/2= 2:1] root 11246 0.0 0.0 0 0 ? D 10:28 0:00 [kworker/3= 0:2] root 14034 0.0 0.0 0 0 ? D 12:20 0:02 [kworker/1= 9:15] root 14048 0.0 0.0 0 0 ? D 12:20 0:00 [kworker/1= 6:0] root 15871 0.0 0.0 0 0 ? D 12:25 0:00 [kworker/1= 3:0] root 17442 0.0 0.0 0 0 ? D 12:28 0:00 [kworker/9= :1] root 17816 0.0 0.0 0 0 ? D 12:30 0:00 [kworker/1= 1:1] root 18744 0.0 0.0 0 0 ? D 12:32 0:00 [kworker/1= 0:2] root 19060 0.0 0.0 0 0 ? D 12:32 0:00 [kworker/2= 9:0] root 21748 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/2= 1:0] root 21967 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/2= 2:0] root 21978 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/2= 2:2] root 22024 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/2= 2:4] root 22035 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/2= 2:5] root 22060 0.0 0.0 0 0 ? D 12:40 0:00 [kworker/1= 6:1] root 22282 0.0 0.0 0 0 ? D 12:41 0:00 [kworker/2= 6:0] root 22362 0.0 0.0 0 0 ? D 12:42 0:00 [kworker/1= 8:9] root 22426 0.0 0.0 0 0 ? D 12:42 0:00 [kworker/1= 6:3] root 23298 0.0 0.0 0 0 ? D 12:43 0:00 [kworker/1= 2:1] root 23302 0.0 0.0 0 0 ? D 12:43 0:00 [kworker/1= 2:5] root 24264 0.0 0.0 0 0 ? D 12:46 0:00 [kworker/3= 0:1] root 24271 0.0 0.0 0 0 ? D 12:46 0:00 [kworker/1= 4:8] root 24441 0.0 0.0 0 0 ? D 12:47 0:00 [kworker/9= :7] root 24443 0.0 0.0 0 0 ? D 12:47 0:00 [kworker/9= :9] root 25005 0.0 0.0 0 0 ? D 12:48 0:00 [kworker/3= 0:3] root 25158 0.0 0.0 0 0 ? D 12:49 0:00 [kworker/9= :12] root 26382 0.0 0.0 0 0 ? D 12:52 0:00 [kworker/1= 3:2] root 26453 0.0 0.0 0 0 ? D 12:52 0:00 [kworker/2= 1:2] root 26724 0.0 0.0 0 0 ? D 12:53 0:00 [kworker/1= 9:1] root 28400 0.0 0.0 0 0 ? D 05:20 0:00 [kworker/2= 5:1] root 29552 0.0 0.0 0 0 ? D 11:40 0:00 [kworker/1= 7:1] root 29811 0.0 0.0 0 0 ? D 11:40 0:00 [kworker/7= :10] root 31903 0.0 0.0 0 0 ? D 11:43 0:00 [kworker/2= 6:1] And all of the processes have this stack: [] iser_release_work+0x25/0x60 [ib_iser] [] process_one_work+0x14f/0x400 [] worker_thread+0x114/0x470 [] kthread+0xd8/0xf0 [] ret_from_fork+0x3f/0x70 [] 0xffffffffffffffff We are not able to log out of the sessions in all cases. And have to restart the box. iscsiadm -m session will show messages like: iscsiadm: could not read session targetname: 5 iscsiadm: could not find session info for session100 iscsiadm: could not read session targetname: 5 iscsiadm: could not find session info for session101 iscsiadm: could not read session targetname: 5 iscsiadm: could not find session info for session103 ... I can't find any way to force iscsiadm to clean up these sessions possibly due to tasks in D state. ---------------- Robert LeBlanc PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1 On Mon, Oct 17, 2016 at 10:32 AM, Robert LeBlanc wro= te: > Some more info as we hit this this morning. We have volumes mirrored > between two targets and we had one target on the kernel with the three > patches mentioned in this thread [0][1][2] and the other was on a > kernel without the patches. We decided that after a week and a half we > wanted to get both targets on the same kernel so we rebooted the > non-patched target. Within an hour we saw iSCSI in D state with the > same stack trace so it seems that we are not hitting any of the > WARN_ON lines. We are getting both iscsi_trx and iscsi_np both in D > state, this time we have two iscsi_trx processes in D state. I don't > know if stale sessions on the clients could be contributing to this > issue (the target trying to close non-existent sessions??). This is on > 4.4.23. Any more debug info we can throw at this problem to help? > > Thank you, > Robert LeBlanc > > # ps aux | grep D | grep iscsi > root 16525 0.0 0.0 0 0 ? D 08:50 0:00 [iscsi_n= p] > root 16614 0.0 0.0 0 0 ? D 08:50 0:00 [iscsi_t= rx] > root 16674 0.0 0.0 0 0 ? D 08:50 0:00 [iscsi_t= rx] > > # for i in 16525 16614 16674; do echo $i; cat /proc/$i/stack; done > 16525 > [] iscsit_stop_session+0x19f/0x1d0 > [] iscsi_check_for_session_reinstatement+0x1e6/0x270 > [] iscsi_target_check_for_existing_instances+0x30/0x40 > [] iscsi_target_do_login+0x140/0x640 > [] iscsi_target_start_negotiation+0x1c/0xb0 > [] iscsi_target_login_thread+0xa9b/0xfc0 > [] kthread+0xd8/0xf0 > [] ret_from_fork+0x3f/0x70 > [] 0xffffffffffffffff > 16614 > [] target_wait_for_sess_cmds+0x49/0x1a0 > [] isert_wait_conn+0x1ab/0x2f0 [ib_isert] > [] iscsit_close_connection+0x162/0x870 > [] iscsit_take_action_for_connection_exit+0x7f/0x100 > [] iscsi_target_rx_thread+0x5a0/0xe80 > [] kthread+0xd8/0xf0 > [] ret_from_fork+0x3f/0x70 > [] 0xffffffffffffffff > 16674 > [] target_wait_for_sess_cmds+0x49/0x1a0 > [] isert_wait_conn+0x1ab/0x2f0 [ib_isert] > [] iscsit_close_connection+0x162/0x870 > [] iscsit_take_action_for_connection_exit+0x7f/0x100 > [] iscsi_target_rx_thread+0x5a0/0xe80 > [] kthread+0xd8/0xf0 > [] ret_from_fork+0x3f/0x70 > [] 0xffffffffffffffff > > > [0] https://www.spinics.net/lists/target-devel/msg13463.html > [1] http://marc.info/?l=3Dlinux-scsi&m=3D147282568910535&w=3D2 > [2] http://www.spinics.net/lists/linux-scsi/msg100221.html > ---------------- > Robert LeBlanc > PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1 > > > On Fri, Oct 7, 2016 at 8:59 PM, Zhu Lingshan wrote: >> Hi Robert, >> >> I also see this issue, but this is not the only code path can trigger th= is >> problem, I think you may also see iscsi_np in D status. I fixed one code >> path whitch still not merged to mainline. I will forward you my patch la= ter. >> Note: my patch only fixed one code path, you may see other call statck w= ith >> D status. >> >> Thanks, >> BR >> Zhu Lingshan >> >> >> =E5=9C=A8 2016/10/1 1:14, Robert LeBlanc =E5=86=99=E9=81=93: >>> >>> We are having a reoccurring problem where iscsi_trx is going into D >>> state. It seems like it is waiting for a session tear down to happen >>> or something, but keeps waiting. We have to reboot these targets on >>> occasion. This is running the 4.4.12 kernel and we have seen it on >>> several previous 4.4.x and 4.2.x kernels. There is no message in dmesg >>> or /var/log/messages. This seems to happen with increased frequency >>> when we have a disruption in our Infiniband fabric, but can happen >>> without any changes to the fabric (other than hosts rebooting). >>> >>> # ps aux | grep iscsi | grep D >>> root 4185 0.0 0.0 0 0 ? D Sep29 0:00 >>> [iscsi_trx] >>> root 18505 0.0 0.0 0 0 ? D Sep29 0:00 >>> [iscsi_np] >>> >>> # cat /proc/4185/stack >>> [] target_wait_for_sess_cmds+0x49/0x1a0 >>> [] isert_wait_conn+0x1ab/0x2f0 [ib_isert] >>> [] iscsit_close_connection+0x162/0x840 >>> [] iscsit_take_action_for_connection_exit+0x7f/0x100 >>> [] iscsi_target_rx_thread+0x5a0/0xe80 >>> [] kthread+0xd8/0xf0 >>> [] ret_from_fork+0x3f/0x70 >>> [] 0xffffffffffffffff >>> >>> # cat /proc/18505/stack >>> [] iscsit_stop_session+0x1b1/0x1c0 >>> [] iscsi_check_for_session_reinstatement+0x1e6/0x270 >>> [] iscsi_target_check_for_existing_instances+0x30/0x4= 0 >>> [] iscsi_target_do_login+0x140/0x640 >>> [] iscsi_target_start_negotiation+0x1c/0xb0 >>> [] iscsi_target_login_thread+0xa9b/0xfc0 >>> [] kthread+0xd8/0xf0 >>> [] ret_from_fork+0x3f/0x70 >>> [] 0xffffffffffffffff >>> >>> What can we do to help get this resolved? >>> >>> Thanks, >>> >>> ---------------- >>> Robert LeBlanc >>> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1 >>> -- >>> To unsubscribe from this list: send the line "unsubscribe linux-scsi" i= n >>> the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org >>> More majordomo info at http://vger.kernel.org/majordomo-info.html >>> >> -- To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org More majordomo info at http://vger.kernel.org/majordomo-info.html