On 01/15/2018 12:41 AM, Nicholas A. Bellinger wrote: > Hey MNC & Co, > > Ping on the earlier iscsi-target authentication login failures atop > 4.14 + commit e7942d063 removing tcp prequeue support. > > For reference, what is your pre 4.14 environment using for > sysctl_tcp_low_latency..? tcp_low_latency=1. I have tested the current kernel with 1 and 0, and it does not make a difference. > > netdev folks, how would you like to proceed for -rc1..? > > On Mon, 2018-01-08 at 22:32 -0800, Nicholas A. Bellinger wrote: >> Hi MNC & Florian, >> >> (Adding net-dev + DaveM CC') >> >> Catching up on pre-holiday threads, thanks for the heads up. >> >> Comments below. >> >> On Wed, 2017-12-13 at 23:56 -0600, Mike Christie wrote: >>> Hey Nick and Florian, >>> >>> Starting in 4.14 iscsi logins will fail around 50% of the time. >>> >>> I git bisected the issue down to this commit: >>> >>> commit e7942d0633c47c791ece6afa038be9cf977226de >>> Author: Florian Westphal <fw@xxxxxxxxx> >>> Date: Sun Jul 30 03:57:18 2017 +0200 >>> >>> tcp: remove prequeue support >>> >>> Nick, attached is the iscsi target log info when the login fails. >>> >>> You can see at: >>> >>> Dec 13 17:55:01 rhel73n1 kernel: Got Login Command, Flags 0x81, ITT: >>> 0x00000000, CmdSN: 0x00000000, ExpStatSN: 0xf86dc69b, CID: 0, Length: 65 >>> >>> we have got a login command and we seem to then go into >>> iscsit_do_rx_data -> sock_recvmsg >>> >>> We seem to get stuck in there though, because we stay blocked until: >>> >>> Dec 13 17:55:01 rhel73n1 kernel: Entering iscsi_target_sk_data_ready: >>> conn: ffff88b35cbb3000 >>> Dec 13 17:55:01 rhel73n1 kernel: Got LOGIN_FLAGS_READ_ACTIVE=1, conn: >>> ffff88b35cbb3000 >>>> >>> >>> where initiator side timeout fires 15 seconds later and it disconnects >>> the tcp connection, and we eventually break out of the recvmsg call: >>> >>> Dec 13 17:55:16 rhel73n1 kernel: Entering iscsi_target_sk_state_change >>> Dec 13 17:55:16 rhel73n1 kernel: __iscsi_target_sk_check_close: >>> TCP_CLOSE_WAIT|TCP_CLOSE,returning FALSE >>> >>> .... >>> >>> Dec 13 17:55:16 rhel73n1 kernel: rx_loop: 68, total_rx: 68, data: 68 >>> Dec 13 17:55:16 rhel73n1 kernel: iscsi_target_do_login_rx after >>> rx_login_io, ffff88b35cbb3000, kworker/2:2:1829 >>> >> >> Ok, the 3rd third login request payload (65 + 3 padded to 68 bytes) >> containing CHAP_N + CHAP_R keys remains blocked on sock_recvmsg(), until >> TPG login_timeout subsequently fires after 15 seconds of inactivity to >> terminate this login attempt. >> >>> Is the iscsi target doing something incorrect in its use of >>> sk_data_ready and sock_recvmsg or is the tcp patch at fault? >> >> From the logs, sk_data_ready() -> iscsi_target_sk_data_ready() callbacks >> appear firing as expected. >> >> iscsi-target login does iscsit_rx_do_data() -> rx_data() -> >> sock_recvmsg(..., MSG_WAITALL) from a system_wq kworker process context >> after iscsi_target_sk_data_ready() callback queues up >> iscsi_conn->login_work for execution, and sock_recvmsg() uses a single >> struct kvec iovec for struct msg_hdr. >> >> AFAICT, iscsi-target uses blocking kernel socket reads from process >> context, similar to kernel_recvmsg(..., MSG_WAITALL) with DRBD. >> >> Florian + DaveM, any idea why the removal of prequeue support is having >> an effect here..? >> >> -- >> To unsubscribe from this list: send the line "unsubscribe target-devel" in >> the body of a message to majordomo@xxxxxxxxxxxxxxx >> More majordomo info at http://vger.kernel.org/majordomo-info.html > > -- To unsubscribe from this list: send the line "unsubscribe target-devel" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
