* [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast @ 2020-07-16 10:02 Hou Pu 2020-07-16 10:02 ` [PATCH v4 1/2] " Hou Pu ` (3 more replies) 0 siblings, 4 replies; 6+ messages in thread From: Hou Pu @ 2020-07-16 10:02 UTC (permalink / raw) To: martin.petersen, linux-scsi, target-devel; +Cc: mchristi, Hou Pu Hi, We encountered "iSCSI Login negotiation failed" several times. After enable debug log in iscsi_target_nego.c of iSCSI target. Error shows: "Got LOGIN_FLAGS_READ_ACTIVE=1, conn: xxxxxxxxxx >>>>" Patch 1 is trying to fix this problem. Please see comment in patch 1 for details. Sorry for delay of v4. Version 3 of this patchset could be found here[1]. Changes from v4: * In iscsi_target_do_login_rx(), call cancel_delayed_work() if it is final login pdu. Also call cancel_delayed_work() if current negotiation is failed. This is advised by Mike Christie. See below[1] for more details. Changes from v3: * Fix style problem found by checkpatch.pl. Changes from v2: * Improve comments in patch #1. * Change bit possition of login_flags in patch #1. [1]: https://www.spinics.net/lists/target-devel/msg18281.html Hou Pu (2): iscsi-target: fix login error when receiving is too fast iscsi-target: Fix inconsistent debug message in __iscsi_target_sk_check_close drivers/target/iscsi/iscsi_target_nego.c | 36 +++++++++++++++++++++++++++----- include/target/iscsi/iscsi_target_core.h | 9 ++++---- 2 files changed, 36 insertions(+), 9 deletions(-) -- 2.11.0 ^ permalink raw reply [flat|nested] 6+ messages in thread
* [PATCH v4 1/2] iscsi-target: fix login error when receiving is too fast 2020-07-16 10:02 [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Hou Pu @ 2020-07-16 10:02 ` Hou Pu 2020-07-16 10:02 ` [PATCH v4 2/2] iscsi-target: Fix inconsistent debug message in __iscsi_target_sk_check_close Hou Pu ` (2 subsequent siblings) 3 siblings, 0 replies; 6+ messages in thread From: Hou Pu @ 2020-07-16 10:02 UTC (permalink / raw) To: martin.petersen, linux-scsi, target-devel; +Cc: mchristi, Hou Pu iscsi_target_sk_data_ready() could be invoked indirectly by iscsi_target_do_login_rx() from workqueue like following: iscsi_target_do_login_rx() iscsi_target_do_login() iscsi_target_do_tx_login_io() iscsit_put_login_tx() iscsi_login_tx_data() tx_data() sock_sendmsg_nosec() tcp_sendmsg() release_sock() sk_backlog_rcv() tcp_v4_do_rcv() tcp_data_ready() iscsi_target_sk_data_ready() At that time LOGIN_FLAGS_READ_ACTIVE is not cleared. and iscsi_target_sk_data_ready will not read data from the socket. And some iscsi initiator(i.e. libiscsi) will wait forever for a reply. LOGIN_FLAGS_READ_ACTIVE should be cleared early just after doing the receive and before writing to the socket in iscsi_target_do_login_rx. But sad news is that LOGIN_FLAGS_READ_ACTIVE is also used by sk_state_change to do login cleanup if a socket was closed at login time. It is supposed to be cleared after the login pdu is successfully processed and replied. So introduce another flag LOGIN_FLAGS_WRITE_ACTIVE to cover the transmit part so that sk_state_change could work well and clear LOGIN_FLAGS_READ_ACTIVE early so that sk_data_ready could also work. While at here, use login_flags more efficient. Signed-off-by: Hou Pu <houpu@bytedance.com> --- drivers/target/iscsi/iscsi_target_nego.c | 34 ++++++++++++++++++++++++++++---- include/target/iscsi/iscsi_target_core.h | 9 +++++---- 2 files changed, 35 insertions(+), 8 deletions(-) diff --git a/drivers/target/iscsi/iscsi_target_nego.c b/drivers/target/iscsi/iscsi_target_nego.c index 685d771b51d4..10477e44d17b 100644 --- a/drivers/target/iscsi/iscsi_target_nego.c +++ b/drivers/target/iscsi/iscsi_target_nego.c @@ -625,13 +625,37 @@ static void iscsi_target_do_login_rx(struct work_struct *work) pr_debug("iscsi_target_do_login_rx after rx_login_io, %p, %s:%d\n", conn, current->comm, current->pid); + /* + * LOGIN_FLAGS_READ_ACTIVE is cleared so that sk_data_ready + * could be trigger again after this. + * + * LOGIN_FLAGS_WRITE_ACTIVE is cleared after we successfully + * process a login pdu, so that sk_state_chage could do login + * cleanup as needed if the socket is closed. If a delayed work is + * ongoing (LOGIN_FLAGS_WRITE_ACTIVE or LOGIN_FLAGS_READ_ACTIVE), + * sk_state_change will leave the cleanup to the delayed work or + * it will schedule a delayed work to do cleanup. + */ + if (conn->sock) { + struct sock *sk = conn->sock->sk; + + write_lock_bh(&sk->sk_callback_lock); + if (!test_bit(LOGIN_FLAGS_INITIAL_PDU, &conn->login_flags)) { + clear_bit(LOGIN_FLAGS_READ_ACTIVE, &conn->login_flags); + set_bit(LOGIN_FLAGS_WRITE_ACTIVE, &conn->login_flags); + } + write_unlock_bh(&sk->sk_callback_lock); + } + rc = iscsi_target_do_login(conn, login); if (rc < 0) { goto err; } else if (!rc) { - if (iscsi_target_sk_check_and_clear(conn, LOGIN_FLAGS_READ_ACTIVE)) + if (iscsi_target_sk_check_and_clear(conn, + LOGIN_FLAGS_WRITE_ACTIVE)) goto err; } else if (rc == 1) { + cancel_delayed_work(&conn->login_work); iscsi_target_nego_release(conn); iscsi_post_login_handler(np, conn, zero_tsih); iscsit_deaccess_np(np, tpg, tpg_np); @@ -640,6 +664,7 @@ static void iscsi_target_do_login_rx(struct work_struct *work) err: iscsi_target_restore_sock_callbacks(conn); + cancel_delayed_work(&conn->login_work); iscsi_target_login_drop(conn, login); iscsit_deaccess_np(np, tpg, tpg_np); } @@ -670,9 +695,10 @@ static void iscsi_target_sk_state_change(struct sock *sk) state = __iscsi_target_sk_check_close(sk); pr_debug("__iscsi_target_sk_close_change: state: %d\n", state); - if (test_bit(LOGIN_FLAGS_READ_ACTIVE, &conn->login_flags)) { - pr_debug("Got LOGIN_FLAGS_READ_ACTIVE=1 sk_state_change" - " conn: %p\n", conn); + if (test_bit(LOGIN_FLAGS_READ_ACTIVE, &conn->login_flags) || + test_bit(LOGIN_FLAGS_WRITE_ACTIVE, &conn->login_flags)) { + pr_debug("Got LOGIN_FLAGS_{READ|WRITE}_ACTIVE=1" + " sk_state_change conn: %p\n", conn); if (state) set_bit(LOGIN_FLAGS_CLOSED, &conn->login_flags); write_unlock_bh(&sk->sk_callback_lock); diff --git a/include/target/iscsi/iscsi_target_core.h b/include/target/iscsi/iscsi_target_core.h index 591cd9e4692c..844bef255e89 100644 --- a/include/target/iscsi/iscsi_target_core.h +++ b/include/target/iscsi/iscsi_target_core.h @@ -566,10 +566,11 @@ struct iscsi_conn { struct socket *sock; void (*orig_data_ready)(struct sock *); void (*orig_state_change)(struct sock *); -#define LOGIN_FLAGS_READ_ACTIVE 1 -#define LOGIN_FLAGS_CLOSED 2 -#define LOGIN_FLAGS_READY 4 -#define LOGIN_FLAGS_INITIAL_PDU 8 +#define LOGIN_FLAGS_READY 0 +#define LOGIN_FLAGS_INITIAL_PDU 1 +#define LOGIN_FLAGS_READ_ACTIVE 2 +#define LOGIN_FLAGS_WRITE_ACTIVE 3 +#define LOGIN_FLAGS_CLOSED 4 unsigned long login_flags; struct delayed_work login_work; struct iscsi_login *login; -- 2.11.0 ^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH v4 2/2] iscsi-target: Fix inconsistent debug message in __iscsi_target_sk_check_close 2020-07-16 10:02 [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Hou Pu 2020-07-16 10:02 ` [PATCH v4 1/2] " Hou Pu @ 2020-07-16 10:02 ` Hou Pu 2020-07-26 2:58 ` [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Mike Christie 2020-07-29 4:10 ` Martin K. Petersen 3 siblings, 0 replies; 6+ messages in thread From: Hou Pu @ 2020-07-16 10:02 UTC (permalink / raw) To: martin.petersen, linux-scsi, target-devel; +Cc: mchristi, Hou Pu The commit 25cdda95fda7 ("iscsi-target: Fix initial login PDU asynchronous socket close OOPs") changed the return value of __iscsi_target_sk_check_close. But the pr_debug is still printing FALSE when returning TRUE which is a little confusing. Signed-off-by: Hou Pu <houpu@bytedance.com> --- drivers/target/iscsi/iscsi_target_nego.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/target/iscsi/iscsi_target_nego.c b/drivers/target/iscsi/iscsi_target_nego.c index 10477e44d17b..701c008d6bd5 100644 --- a/drivers/target/iscsi/iscsi_target_nego.c +++ b/drivers/target/iscsi/iscsi_target_nego.c @@ -481,7 +481,7 @@ static bool __iscsi_target_sk_check_close(struct sock *sk) { if (sk->sk_state == TCP_CLOSE_WAIT || sk->sk_state == TCP_CLOSE) { pr_debug("__iscsi_target_sk_check_close: TCP_CLOSE_WAIT|TCP_CLOSE," - "returning FALSE\n"); + "returning TRUE\n"); return true; } return false; -- 2.11.0 ^ permalink raw reply related [flat|nested] 6+ messages in thread
* Re: [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast 2020-07-16 10:02 [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Hou Pu 2020-07-16 10:02 ` [PATCH v4 1/2] " Hou Pu 2020-07-16 10:02 ` [PATCH v4 2/2] iscsi-target: Fix inconsistent debug message in __iscsi_target_sk_check_close Hou Pu @ 2020-07-26 2:58 ` Mike Christie 2020-07-28 3:16 ` Hou Pu 2020-07-29 4:10 ` Martin K. Petersen 3 siblings, 1 reply; 6+ messages in thread From: Mike Christie @ 2020-07-26 2:58 UTC (permalink / raw) To: Hou Pu, martin.petersen, linux-scsi, target-devel; +Cc: mchristi On 7/16/20 5:02 AM, Hou Pu wrote: > Hi, > We encountered "iSCSI Login negotiation failed" several times. > After enable debug log in iscsi_target_nego.c of iSCSI target. > Error shows: > "Got LOGIN_FLAGS_READ_ACTIVE=1, conn: xxxxxxxxxx >>>>" > > Patch 1 is trying to fix this problem. Please see comment in patch 1 > for details. > > Sorry for delay of v4. Version 3 of this patchset could be found here[1]. > > Changes from v4: > * In iscsi_target_do_login_rx(), call cancel_delayed_work() if it is final > login pdu. Also call cancel_delayed_work() if current negotiation is failed. > This is advised by Mike Christie. See below[1] for more details. > > Changes from v3: > * Fix style problem found by checkpatch.pl. > Ah sorry, I thought I replied a little later about my concerns being overly paranoid and your patch being ok. I don't see it on the list so not sure what happened. If you are still not liking the cancel call, I'm ok with v3. Add my reviewed by to either version you prefer. Reviewed-by: Mike Christie <michael.christie@oracle.com> ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast 2020-07-26 2:58 ` [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Mike Christie @ 2020-07-28 3:16 ` Hou Pu 0 siblings, 0 replies; 6+ messages in thread From: Hou Pu @ 2020-07-28 3:16 UTC (permalink / raw) To: Mike Christie, martin.petersen, linux-scsi, target-devel; +Cc: mchristi On 2020/7/26 10:58 上午, Mike Christie wrote: > On 7/16/20 5:02 AM, Hou Pu wrote: >> Hi, >> We encountered "iSCSI Login negotiation failed" several times. >> After enable debug log in iscsi_target_nego.c of iSCSI target. >> Error shows: >> "Got LOGIN_FLAGS_READ_ACTIVE=1, conn: xxxxxxxxxx >>>>" >> >> Patch 1 is trying to fix this problem. Please see comment in patch 1 >> for details. >> >> Sorry for delay of v4. Version 3 of this patchset could be found here[1]. >> >> Changes from v4: >> * In iscsi_target_do_login_rx(), call cancel_delayed_work() if it is final >> login pdu. Also call cancel_delayed_work() if current negotiation is failed. >> This is advised by Mike Christie. See below[1] for more details. >> >> Changes from v3: >> * Fix style problem found by checkpatch.pl. >> > Ah sorry, I thought I replied a little later about my concerns being overly paranoid and your patch being ok. I don't see it on the list so not sure what happened. > > If you are still not liking the cancel call, I'm ok with v3. Add my reviewed by to either version you prefer. > > Reviewed-by: Mike Christie <michael.christie@oracle.com> > It took me some time to understand how workqueue works and make sure it is safe to cancel it. So it is delayed between v3 and v4. Sorry for that. I think it is necessary to cancel delayed work as your suggestion. Thanks, Hou ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast 2020-07-16 10:02 [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Hou Pu ` (2 preceding siblings ...) 2020-07-26 2:58 ` [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Mike Christie @ 2020-07-29 4:10 ` Martin K. Petersen 3 siblings, 0 replies; 6+ messages in thread From: Martin K. Petersen @ 2020-07-29 4:10 UTC (permalink / raw) To: linux-scsi, target-devel, Hou Pu; +Cc: Martin K . Petersen, mchristi On Thu, 16 Jul 2020 06:02:10 -0400, Hou Pu wrote: > We encountered "iSCSI Login negotiation failed" several times. > After enable debug log in iscsi_target_nego.c of iSCSI target. > Error shows: > "Got LOGIN_FLAGS_READ_ACTIVE=1, conn: xxxxxxxxxx >>>>" > > Patch 1 is trying to fix this problem. Please see comment in patch 1 > for details. > > [...] Applied to 5.9/scsi-queue, thanks! [1/2] scsi: target: iscsi: Fix login error when receiving https://git.kernel.org/mkp/scsi/c/4e108d4f2816 [2/2] scsi: target: iscsi: Fix inconsistent debug message https://git.kernel.org/mkp/scsi/c/df2de6f28629 -- Martin K. Petersen Oracle Linux Engineering ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2020-07-29 4:10 UTC | newest] Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2020-07-16 10:02 [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Hou Pu 2020-07-16 10:02 ` [PATCH v4 1/2] " Hou Pu 2020-07-16 10:02 ` [PATCH v4 2/2] iscsi-target: Fix inconsistent debug message in __iscsi_target_sk_check_close Hou Pu 2020-07-26 2:58 ` [PATCH v4 0/2] iscsi-target: fix login error when receiving is too fast Mike Christie 2020-07-28 3:16 ` Hou Pu 2020-07-29 4:10 ` Martin K. Petersen
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).