英文:
What mistake did I make in setting up the iSCSI Target Attach?
问题
As advised by @Mike Andrews, I set NOPIN_TIMEOUT to 0, and the 'Did not receive response to NOPIN on CID: 1, failing connection for I_T Nexus...' message went away!
Thanks @Mike Andrews
However, if tx is sent as shown below and rx does not come for 120 seconds, it is terminated. Any advice on this?
<details>
<summary>英文:</summary>
I built an iscsi gateway using ceph-iscsi and set up an iSCSI target and an initiator that can attach to the target.
And as shown in the figure below, I entered the iSCSI Initiator and Target information in the Server's Bios - Network settings.
[enter image description here](https://i.stack.imgur.com/jMEfL.png)
[enter image description here](https://i.stack.imgur.com/DiUtW.png)
[enter image description here](https://i.stack.imgur.com/1mjGA.png)
The iSCSI connection is failing, I have attached some kernel logs from ceph-iscsi.
Among the logs, 'Did not receive response to NOPIN on CID: 1, failing connection for I_T Nexus iqn.2023-07.com.kakao:initiator1111,i,0x349691d2ea8a,iqn.2023-07.com.kakao:target,t,0x0 after message 'Started NOPIN Response Timer on CID: 1 to 5 seconds' after iSCSI connection 1' is output, and after the iSCSI connection is terminated, the iSCSI connection is tried again from the beginning and repeats.
Please advise what is the problem.
ceph-iscsi kern.log
[507977.797512] iscsi_start_login_thread_timer: Added timeout timer to iSCSI login request for 15 seconds.
[507977.797519] __iscsi_target_login_thread: Moving to TARG_CONN_STATE_XPT_UP.
[507977.797538] rx_data: rx_loop: 48, total_rx: 48, data: 48
[507977.797541] iscsit_get_login_rx: Got Login Command, Flags 0x01, ITT: 0x01000000, CmdSN: 0x01000000, ExpStatSN: 0x00000000, CID: 256, Length: 145
[507977.797548] rx_data: rx_loop: 148, total_rx: 148, data: 148
[507977.797551] __iscsi_target_login_thread: Received iSCSI login request from 192.168.36.100:1029 on iSCSI/TCP Network Portal 192.168.36.5:3260
[507977.797556] __iscsi_target_login_thread: Moving to TARG_CONN_STATE_IN_LOGIN.
[507977.797589] iscsi_target_set_sock_callbacks: Entering iscsi_target_set_sock_callbacks: conn: 000000003f28dd8e
[507977.797596] iscsi_target_locate_portal: Located Storage Object: iqn.2023-07.com.kakao:target
[507977.797600] iscsi_target_locate_portal: Located Portal Group Object: 1
[507977.797798] iscsi_update_param_value: iSCSI Parameter updated to TargetPortalGroupTag=1
[507977.797802] iscsi_update_param_value: iSCSI Parameter updated to ErrorRecoveryLevel=0
[507977.797806] iscsi_decode_text_input: Got key: InitiatorName=iqn.2023-07.com.kakao:initiator1111
[507977.797811] iscsi_update_param_value: iSCSI Parameter updated to InitiatorName=iqn.2023-07.com.kakao:initiator1111
[507977.797814] iscsi_decode_text_input: Got key: SessionType=Normal
[507977.797816] iscsi_update_param_value: iSCSI Parameter updated to SessionType=Normal
[507977.797818] iscsi_decode_text_input: Got key: TargetName=iqn.2023-07.com.kakao:target
[507977.797821] iscsi_update_param_value: iSCSI Parameter updated to TargetName=iqn.2023-07.com.kakao:target
[507977.797823] iscsi_decode_text_input: Got key: AuthMethod=CHAP
[507977.797826] iscsi_update_param_value: iSCSI Parameter updated to AuthMethod=CHAP
[507977.797832] iscsi_encode_text_output: Sending key: AuthMethod=CHAP
[507977.797834] iscsi_encode_text_output: Sending key: TargetAlias=LIO Target
[507977.797836] iscsi_encode_text_output: Sending key: TargetPortalGroupTag=1
[507977.797839] iscsi_target_do_tx_login_io: Sending Login Response, Flags: 0x00, ITT: 0x01000000, ExpCmdSN; 0x00000001, MaxCmdSN: 0x00000001, StatSN: 0xdc4e8515, Length: 62
[507977.797862] tx_data: tx_loop: 112, total_tx: 112, data: 112
[507977.797867] iscsit_alloc_conn: Moving to TARG_CONN_STATE_FREE.
[507980.933577] iscsi_target_sk_data_ready: Entering iscsi_target_sk_data_ready: conn: 000000003f28dd8e
[507980.933620] iscsi_target_do_login_rx: entering iscsi_target_do_login_rx, conn: 000000003f28dd8e, kworker/151:1:1427
[507980.933631] iscsi_target_do_login_rx: Starting login timer for kworker/151:1/1427
[507980.933642] rx_data: rx_loop: 48, total_rx: 48, data: 48
[507980.933646] iscsit_get_login_rx: Got Login Command, Flags 0x01, ITT: 0x01000000, CmdSN: 0x01000000, ExpStatSN: 0x16854edc, CID: 256, Length: 9
[507980.933657] rx_data: rx_loop: 12, total_rx: 12, data: 12
[507980.933661] iscsi_target_do_login_rx: iscsi_target_do_login_rx after rx_login_io, 000000003f28dd8e, kworker/151:1:1427
[507980.933670] iscsi_decode_text_input: Got key: CHAP_A=5
[507980.933683] chap_check_algorithm: Selected md5 Algorithm
[507980.933702] chap_server_open: [server] Got CHAP_A=5
[507980.933704] chap_server_open: [server] Sending CHAP_A=5
[507980.933708] chap_server_open: [server] Sending CHAP_I=3
[507980.933711] chap_gen_challenge: [server] Sending CHAP_C=0xbd0bba967bf1a1b22b327130aa3494ee
[507980.933711]
[507980.933715] iscsi_target_do_authentication: Received OK response from LIO Authentication, continuing.
[507980.933718] iscsi_target_do_tx_login_io: Sending Login Response, Flags: 0x00, ITT: 0x01000000, ExpCmdSN; 0x00000001, MaxCmdSN: 0x00000001, StatSN: 0xdc4e8516, Length: 60
[507980.933759] tx_data: tx_loop: 108, total_tx: 108, data: 108
[507999.109620] iscsi_target_sk_data_ready: Entering iscsi_target_sk_data_ready: conn: 000000003f28dd8e
[507999.109666] iscsi_target_do_login_rx: entering iscsi_target_do_login_rx, conn: 000000003f28dd8e, kworker/151:1:1427
[507999.109673] iscsi_target_do_login_rx: Starting login timer for kworker/151:1/1427
[507999.109682] rx_data: rx_loop: 48, total_rx: 48, data: 48
[507999.109687] iscsit_get_login_rx: Got Login Command, Flags 0x81, ITT: 0x01000000, CmdSN: 0x01000000, ExpStatSN: 0x17854edc, CID: 256, Length: 58
[507999.109699] rx_data: rx_loop: 60, total_rx: 60, data: 60
[507999.109703] iscsi_target_do_login_rx: iscsi_target_do_login_rx after rx_login_io, 000000003f28dd8e, kworker/151:1:1427
[507999.109712] iscsi_decode_text_input: Got key: CHAP_N=lucian86
[507999.109729] chap_server_compute_hash: [server] Got CHAP_N=lucian86
[507999.109733] chap_server_compute_hash: [server] Got CHAP_R=06E3CD958548DF9BBD60741BEAC61020
[507999.109751] chap_server_compute_hash: [server] md5 Server Digest: 06e3cd958548df9bbd60741beac61020
[507999.109755] chap_server_compute_hash: [server] md5 Digests match, CHAP connection successful.
[507999.109755]
[507999.109759] iscsi_target_do_authentication: iSCSI security negotiation completed successfully.
[507999.109770] iscsi_target_do_tx_login_io: Sending Login Response, Flags: 0x81, ITT: 0x01000000, ExpCmdSN; 0x00000001, MaxCmdSN: 0x00000001, StatSN: 0xdc4e8517, Length: 0
[507999.109788] tx_data: tx_loop: 48, total_tx: 48, data: 48
[508072.581782] iscsi_target_sk_data_ready: Entering iscsi_target_sk_data_ready: conn: 000000003f28dd8e
[508072.581839] iscsi_target_do_login_rx: entering iscsi_target_do_login_rx, conn: 000000003f28dd8e, kworker/151:1:1427
[508072.581848] iscsi_target_do_login_rx: Starting login timer for kworker/151:1/1427
[508072.581859] rx_data: rx_loop: 48, total_rx: 48, data: 48
[508072.581865] iscsit_get_login_rx: Got Login Command, Flags 0x87, ITT: 0x01000000, CmdSN: 0x01000000, ExpStatSN: 0x18854edc, CID: 256, Length: 284
[508072.581876] rx_data: rx_loop: 284, total_rx: 284, data: 284
[508072.581879] iscsi_target_do_login_rx: iscsi_target_do_login_rx after rx_login_io, 000000003f28dd8e, kworker/151:1:1427
[508072.581887] iscsi_decode_text_input: Got key: HeaderDigest=None
[508072.581896] iscsi_update_param_value: iSCSI Parameter updated to HeaderDigest=None
[508072.581899] iscsi_decode_text_input: Got key: DataDigest=None
[508072.581902] iscsi_update_param_value: iSCSI Parameter updated to DataDigest=None
[508072.581904] iscsi_decode_text_input: Got key: ErrorRecoveryLevel=0
[508072.581916] iscsi_update_param_value: iSCSI Parameter updated to ErrorRecoveryLevel=0
[508072.581919] iscsi_decode_text_input: Got key: InitialR2T=No
[508072.581921] iscsi_update_param_value: iSCSI Parameter updated to InitialR2T=Yes
[508072.581923] iscsi_decode_text_input: Got key: ImmediateData=Yes
[508072.581926] iscsi_decode_text_input: Got key: MaxRecvDataSegmentLength=65536
[508072.581930] iscsi_update_param_value: iSCSI Parameter updated to MaxRecvDataSegmentLength=65536
[508072.581935] iscsi_check_acceptor_state: Saving op->MaxRecvDataSegmentLength from original initiator received value: 65536
[508072.581938] iscsi_update_param_value: iSCSI Parameter updated to MaxRecvDataSegmentLength=262144
[508072.581941] iscsi_check_acceptor_state: Updated MaxRecvDataSegmentLength to target MXDSL value: 262144
[508072.581943] iscsi_decode_text_input: Got key: MaxBurstLength=262144
[508072.581947] iscsi_update_param_value: iSCSI Parameter updated to MaxBurstLength=262144
[508072.581949] iscsi_decode_text_input: Got key: FirstBurstLength=65536
[508072.581952] iscsi_update_param_value: iSCSI Parameter updated to FirstBurstLength=65536
[508072.581953] iscsi_decode_text_input: Got key: MaxConnections=1
[508072.581956] iscsi_update_param_value: iSCSI Parameter updated to MaxConnections=1
[508072.581958] iscsi_decode_text_input: Got key: DataPDUInOrder=Yes
[508072.581961] iscsi_update_param_value: iSCSI Parameter updated to DataPDUInOrder=Yes
[508072.581963] iscsi_decode_text_input: Got key: DataSequenceInOrder=Yes
[508072.581965] iscsi_update_param_value: iSCSI Parameter updated to DataSequenceInOrder=Yes
[508072.581967] iscsi_decode_text_input: Got key: DefaultTime2Wait=2
[508072.581970] iscsi_update_param_value: iSCSI Parameter updated to DefaultTime2Wait=2
[508072.581972] iscsi_decode_text_input: Got key: DefaultTime2Retain=20
[508072.581975] iscsi_update_param_value: iSCSI Parameter updated to DefaultTime2Retain=20
[508072.581976] iscsi_decode_text_input: Got key: MaxOutstandingR2T=1
[508072.581979] iscsi_update_param_value: iSCSI Parameter updated to MaxOutstandingR2T=1
[508072.581989] iscsi_encode_text_output: Sending key: HeaderDigest=None
[508072.581990] iscsi_encode_text_output: Sending key: DataDigest=None
[508072.581992] iscsi_encode_text_output: Sending key: MaxConnections=1
[508072.581994] iscsi_encode_text_output: Sending key: InitialR2T=Yes
[508072.581996] iscsi_encode_text_output: Sending key: ImmediateData=Yes
[508072.581998] iscsi_encode_text_output: Sending key: MaxRecvDataSegmentLength=262144
[508072.582000] iscsi_encode_text_output: Sending key: MaxBurstLength=262144
[508072.582001] iscsi_encode_text_output: Sending key: FirstBurstLength=65536
[508072.582004] iscsi_encode_text_output: Sending key: DefaultTime2Wait=2
[508072.582006] iscsi_encode_text_output: Sending key: DefaultTime2Retain=20
[508072.582008] iscsi_encode_text_output: Sending key: MaxOutstandingR2T=1
[508072.582010] iscsi_encode_text_output: Sending key: ErrorRecoveryLevel=0
[508072.582013] iscsi_target_restore_sock_callbacks: Entering iscsi_target_restore_sock_callbacks: conn: 000000003f28dd8e
[508072.582017] iscsi_target_do_tx_login_io: Sending Login Response, Flags: 0x87, ITT: 0x01000000, ExpCmdSN; 0x00000001, MaxCmdSN: 0x00000001, StatSN: 0xdc4e8518, Length: 243
[508072.582260] tx_data: tx_loop: 292, total_tx: 292, data: 292
[508072.582267] iscsi_post_login_handler: Moving to TARG_CONN_STATE_LOGGED_IN.
[508072.582269] iscsi_set_connection_parameters: ------------------------------------------------------------------
[508072.582271] iscsi_set_connection_parameters: AuthMethod: CHAP
[508072.582274] iscsi_set_connection_parameters: HeaderDigest: None
[508072.582276] iscsi_set_connection_parameters: DataDigest: None
[508072.582279] iscsi_set_connection_parameters: MaxXmitDataSegmentLength: 262144
[508072.582282] iscsi_set_connection_parameters: MaxRecvDataSegmentLength: 65536
[508072.582286] iscsi_set_connection_parameters: ------------------------------------------------------------------
[508072.582288] iscsi_set_session_parameters: ------------------------------------------------------------------
[508072.582292] iscsi_set_session_parameters: MaxConnections: 1
[508072.582294] iscsi_set_session_parameters: TargetName: iqn.2023-07.com.kakao:target
[508072.582297] iscsi_set_session_parameters: InitiatorName: iqn.2023-07.com.kakao:initiator1111
[508072.582300] iscsi_set_session_parameters: TargetAlias: LIO Target
[508072.582301] iscsi_set_session_parameters: TargetPortalGroupTag: 1
[508072.582304] iscsi_set_session_parameters: InitialR2T: Yes
[508072.582305] iscsi_set_session_parameters: ImmediateData: Yes
[508072.582308] iscsi_set_session_parameters: MaxBurstLength: 262144
[508072.582311] iscsi_set_session_parameters: FirstBurstLength: 65536
[508072.582314] iscsi_set_session_parameters: DefaultTime2Wait: 2
[508072.582316] iscsi_set_session_parameters: DefaultTime2Retain: 20
[508072.582317] iscsi_set_session_parameters: MaxOutstandingR2T: 1
[508072.582319] iscsi_set_session_parameters: DataPDUInOrder: Yes
[508072.582321] iscsi_set_session_parameters: DataSequenceInOrder: Yes
[508072.582322] iscsi_set_session_parameters: ErrorRecoveryLevel: 0
[508072.582325] iscsi_set_session_parameters: SessionType: Normal
[508072.582326] iscsi_set_session_parameters: ------------------------------------------------------------------
[508072.582338] iscsi_post_login_handler: Moving to TARG_SESS_STATE_LOGGED_IN.
[508072.582340] iscsi_post_login_handler: iSCSI Login successful on CID: 1 from 192.168.36.100:1029 to 192.168.36.5:3260,1
[508072.582345] iscsi_post_login_handler: Incremented iSCSI Connection count to 1 from node: iqn.2023-07.com.kakao:initiator1111
[508072.582347] iscsi_post_login_handler: Established iSCSI session from node: iqn.2023-07.com.kakao:initiator1111
[508072.582349] iscsi_post_login_handler: Incremented number of active iSCSI sessions to 1 on iSCSI Target Portal Group: 1
[508072.582354] __iscsit_start_nopin_timer: Started NOPIN Timer on CID: 1 at 5 second interval
[508077.701623] iscsit_start_nopin_response_timer: Started NOPIN Response Timer on CID: 1 to 5 seconds
[508077.701659] iscsit_build_nopin_rsp: Built NOPIN Unsolicited Response ITT: 0xffffffff, TTT: 0x00000000, StatSN: 0xdc4e8519, Length 0
[508077.701671] iscsit_send_unsolicited_nopin: Sending Unsolicited NOPIN TTT: 0x00000000 StatSN: 0xdc4e8519 CID: 1
[508077.701710] tx_data: tx_loop: 48, total_tx: 48, data: 48
[508082.821626] Did not receive response to NOPIN on CID: 1, failing connection for I_T Nexus iqn.2023-07.com.kakao:initiator1111,i,0x349691d2ea8a,iqn.2023-07.com.kakao:target,t,0x01
[508082.840602] rx_data: rx_loop: -512 total_rx: 0
[508082.840612] iscsit_take_action_for_connection_exit: Moving to TARG_CONN_STATE_CLEANUP_WAIT.
[508082.840617] iscsit_handle_connection_cleanup: Performing cleanup for failed iSCSI Connection ID: 1 from iqn.2023-07.com.kakao:initiator1111
[508082.840624] iscsit_close_connection: Closing iSCSI connection CID 1 on SID: 4
[508082.840661] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000081
[508082.840715] iscsit_close_connection: Moving to TARG_CONN_STATE_FREE.
[508082.840719] iscsit_close_connection: Decremented iSCSI connection count to 0 from node: iqn.2023-07.com.kakao:initiator1111
[508082.840743] iscsit_close_session: Moving to TARG_SESS_STATE_FREE.
[508082.840745] iscsit_close_session: Released iSCSI session from node: iqn.2023-07.com.kakao:initiator1111
[508082.840747] iscsit_close_session: Decremented number of active iSCSI Sessions on iSCSI TPG: 1 to 0
It works well to attach iscsi using open-iscsi without using Bios - Network.
--------------------
As advised by @Mike Andrews, I set NOPIN_TIMEOUT to 0, and the 'Did not receive response to NOPIN on CID: 1, failing connection for I_T Nexus...' message went away!
Thanks @Mike Andrews
However, if tx is sent as shown below and rx does not come for 120 seconds, it is terminated. Any advice on this?
...
[558929.675224] iscsi_target_restore_sock_callbacks: Entering iscsi_target_restore_sock_callbacks: conn: 00000000dd3dace4
[558929.675226] iscsi_target_do_tx_login_io: Sending Login Response, Flags: 0x87, ITT: 0x01000000, ExpCmdSN; 0x00000001, MaxCmdSN: 0x00000001, StatSN: 0xd2907d03, Length: 243
[558929.675449] tx_data: tx_loop: 292, total_tx: 292, data: 292
[558929.675453] iscsi_post_login_handler: Moving to TARG_CONN_STATE_LOGGED_IN.
[558929.675456] iscsi_set_connection_parameters: ------------------------------------------------------------------
[558929.675459] iscsi_set_connection_parameters: AuthMethod: CHAP
[558929.675460] iscsi_set_connection_parameters: HeaderDigest: None
[558929.675462] iscsi_set_connection_parameters: DataDigest: None
[558929.675465] iscsi_set_connection_parameters: MaxXmitDataSegmentLength: 262144
[558929.675467] iscsi_set_connection_parameters: MaxRecvDataSegmentLength: 65536
[558929.675471] iscsi_set_connection_parameters: ------------------------------------------------------------------
[558929.675472] iscsi_set_session_parameters: ------------------------------------------------------------------
[558929.675475] iscsi_set_session_parameters: MaxConnections: 1
[558929.675478] iscsi_set_session_parameters: TargetName: iqn.2023-07.com.kakao:target
[558929.675481] iscsi_set_session_parameters: InitiatorName: iqn.2023-07.com.kakao:initiator1111
[558929.675483] iscsi_set_session_parameters: TargetAlias: LIO Target
[558929.675485] iscsi_set_session_parameters: TargetPortalGroupTag: 1
[558929.675487] iscsi_set_session_parameters: InitialR2T: Yes
[558929.675489] iscsi_set_session_parameters: ImmediateData: Yes
[558929.675491] iscsi_set_session_parameters: MaxBurstLength: 262144
[558929.675493] iscsi_set_session_parameters: FirstBurstLength: 65536
[558929.675495] iscsi_set_session_parameters: DefaultTime2Wait: 2
[558929.675497] iscsi_set_session_parameters: DefaultTime2Retain: 20
[558929.675499] iscsi_set_session_parameters: MaxOutstandingR2T: 1
[558929.675501] iscsi_set_session_parameters: DataPDUInOrder: Yes
[558929.675502] iscsi_set_session_parameters: DataSequenceInOrder: Yes
[558929.675504] iscsi_set_session_parameters: ErrorRecoveryLevel: 0
[558929.675506] iscsi_set_session_parameters: SessionType: Normal
[558929.675508] iscsi_set_session_parameters: ------------------------------------------------------------------
[558929.675515] iscsi_post_login_handler: Moving to TARG_SESS_STATE_LOGGED_IN.
[558929.675516] iscsi_post_login_handler: iSCSI Login successful on CID: 2 from 192.168.36.100:1151 to 192.168.36.5:3260,1
[558929.675521] iscsi_post_login_handler: Incremented iSCSI Connection count to 1 from node: iqn.2023-07.com.kakao:initiator1111
[558929.675522] iscsi_post_login_handler: Established iSCSI session from node: iqn.2023-07.com.kakao:initiator1111
[558929.675524] iscsi_post_login_handler: Incremented number of active iSCSI sessions to 1 on iSCSI Target Portal Group: 1
[558929.675652] rx_data: rx_loop: 48, total_rx: 48, data: 48
[558929.675670] iscsit_setup_scsi_cmd: Got SCSI Command, ITT: 0x01000000, CmdSN: 0x01000000, ExpXferLen: 512, Length: 0, CID: 2
[558929.675680] iscsit_check_received_cmdsn: Received CmdSN matches ExpCmdSN, incremented ExpCmdSN to: 0x00000002
[558929.676364] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000081
[558929.676377] iscsit_build_datain_pdu: Built DataIN ITT: 0x01000000, StatSN: 0xd2907d04, DataSN: 0x00000000, Offset: 0, Length: 512, CID: 2
[558929.676439] tx_data: tx_loop: 48, total_tx: 48, data: 48
[558929.882533] rx_data: rx_loop: 48, total_rx: 48, data: 48
[558929.882546] iscsit_setup_scsi_cmd: Got SCSI Command, ITT: 0x02000000, CmdSN: 0x02000000, ExpXferLen: 16384, Length: 0, CID: 2
[558929.882552] iscsit_check_received_cmdsn: Received CmdSN matches ExpCmdSN, incremented ExpCmdSN to: 0x00000003
[558929.882574] lio_release_cmd: Entering lio_release_cmd for se_cmd: 00000000324266a7
[558929.883429] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000082
[558929.883432] iscsit_build_datain_pdu: Built DataIN ITT: 0x02000000, StatSN: 0xd2907d05, DataSN: 0x00000000, Offset: 0, Length: 16384, CID: 2
[558929.883482] tx_data: tx_loop: 48, total_tx: 48, data: 48
[558942.986774] rx_data: rx_loop: 48, total_rx: 48, data: 48
[558942.986792] iscsit_setup_scsi_cmd: Got SCSI Command, ITT: 0x03000000, CmdSN: 0x03000000, ExpXferLen: 16384, Length: 0, CID: 2
[558942.986800] iscsit_check_received_cmdsn: Received CmdSN matches ExpCmdSN, incremented ExpCmdSN to: 0x00000004
[558942.986828] lio_release_cmd: Entering lio_release_cmd for se_cmd: 00000000d821126d
[558943.194949] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000083
[558943.194953] iscsit_build_datain_pdu: Built DataIN ITT: 0x03000000, StatSN: 0xd2907d06, DataSN: 0x00000000, Offset: 0, Length: 16384, CID: 2
[558943.195002] tx_data: tx_loop: 48, total_tx: 48, data: 48
[558956.558319] rx_data: rx_loop: 48, total_rx: 48, data: 48
[558956.558335] iscsit_setup_scsi_cmd: Got SCSI Command, ITT: 0x04000000, CmdSN: 0x04000000, ExpXferLen: 512, Length: 0, CID: 2
[558956.558343] iscsit_check_received_cmdsn: Received CmdSN matches ExpCmdSN, incremented ExpCmdSN to: 0x00000005
[558956.558372] lio_release_cmd: Entering lio_release_cmd for se_cmd: 00000000728b221d
[558958.411518] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000084
[558958.411529] iscsit_build_datain_pdu: Built DataIN ITT: 0x04000000, StatSN: 0xd2907d07, DataSN: 0x00000000, Offset: 0, Length: 512, CID: 2
[558958.411585] tx_data: tx_loop: 48, total_tx: 48, data: 48
[558998.282819] rx_data: rx_loop: 48, total_rx: 48, data: 48
[558998.282838] iscsit_setup_scsi_cmd: Got SCSI Command, ITT: 0x05000000, CmdSN: 0x05000000, ExpXferLen: 512, Length: 0, CID: 2
[558998.282845] iscsit_check_received_cmdsn: Received CmdSN matches ExpCmdSN, incremented ExpCmdSN to: 0x00000006
[558998.282872] lio_release_cmd: Entering lio_release_cmd for se_cmd: 00000000677c3747
[558998.490952] iscsit_increment_maxcmdsn: Updated MaxCmdSN to 0x00000085
[558998.490955] iscsit_build_datain_pdu: Built DataIN ITT: 0x05000000, StatSN: 0xd2907d08, DataSN: 0x00000000, Offset: 0, Length: 512, CID: 2
[558998.490985] tx_data: tx_loop: 48, total_tx: 48, data: 48
[559122.279650] rx_data: rx_loop: -104 total_rx: 0
[559124.299046] iscsit_take_action_for_connection_exit: Moving to TARG_CONN_STATE_CLEANUP_WAIT.
[559124.299057] iscsit_handle_connection_cleanup: Performing cleanup for failed iSCSI Connection ID: 2 from iqn.2023-07.com.kakao:initiator1111
[559124.299061] iscsit_close_connection: Closing iSCSI connection CID 2 on SID: 9
[559124.299146] lio_release_cmd: Entering lio_release_cmd for se_cmd: 00000000e102a5f8
[559124.299183] iscsit_close_connection: Moving to TARG_CONN_STATE_FREE.
[559124.299187] iscsit_close_connection: Decremented iSCSI connection count to 0 from node: iqn.2023-07.com.kakao:initiator1111
[559124.299209] iscsit_close_session: Moving to TARG_SESS_STATE_FREE.
[559124.299211] iscsit_close_session: Released iSCSI session from node: iqn.2023-07.com.kakao:initiator1111
[559124.299213] iscsit_close_session: Decremented number of active iSCSI Sessions on iSCSI TPG: 1 to 0
[559153.291127] iscsi_start_login_thread_timer: Added timeout timer to iSCSI login request for 15 seconds.
[559153.291138] __iscsi_target_login_thread: Moving to TARG_CONN_STATE_XPT_UP.
[559153.291148] rx_data: rx_loop: 48, total_rx: 48, data: 48
[559153.291153] iscsit_get_login_rx: Got Login Command, Flags 0x01, ITT: 0x01000000, CmdSN: 0x01000000, ExpStatSN: 0x00000000, CID: 1024, Length: 145
[559153.291160] rx_data: rx_loop: 148, total_rx: 148, data: 148
[559153.291163] __iscsi_target_login_thread: Received iSCSI login request from 192.168.36.100:1155 on iSCSI/TCP Network Portal 192.168.36.5:3260
[559153.291167] __iscsi_target_login_thread: Moving to TARG_CONN_STATE_IN_LOGIN.
[559153.291197] iscsi_target_set_sock_callbacks: Entering iscsi_target_set_sock_callbacks: conn: 000000004edc1cbe
< repeated >
</details>
# 答案1
**得分**: 0
Linux LIO iSCSI目标通过向initiator发送一个未经请求的NOP-IP PDU来检测其响应性，并期望得到响应。当在5秒内未收到响应时，它将关闭连接。这是一种有点反向的协议交互，可能会很棘手。它以令轻量级iSCSI initiator感到困扰而著称。
如果您查看iPXE的[iSCSI Targets Known to Work with iPXE][ipxe]页面，您将看到如何禁用此行为。（我不知道您的Dell是否运行iPXE initiator，但这是一个很好的参考。）这个命令完全关闭它：
lio_node --setnodeattr <TARGET_IQN> <TPGT> <INITIATOR_IQN> nopin_timeout 0
在Linux内核中，您可以看到将其设置为0会绕过启动计时器的过程。您将不再看到"Started NOPIN Timer..."的调试消息：
``` lang-C
void __iscsit_start_nopin_timer(struct iscsit_conn *conn)
{
struct iscsit_session *sess = conn->sess;
struct iscsi_node_attrib *na = iscsit_tpg_get_node_attrib(sess);
lockdep_assert_held(&conn->nopin_timer_lock);
/*
* NOPIN超时已禁用。
*/
if (!na->nopin_timeout)
return;
if (conn->nopin_timer_flags & ISCSI_TF_RUNNING)
return;
conn->nopin_timer_flags &= ~ISCSI_TF_STOP;
conn->nopin_timer_flags |= ISCSI_TF_RUNNING;
mod_timer(&conn->nopin_timer, jiffies + na->nopin_timeout * HZ);
pr_debug("Started NOPIN Timer on CID: %d at %u second"
" interval\n", conn->cid, na->nopin_timeout);
}
英文:
The Linux LIO iSCSI target probes the initiator's responsiveness by sending an unsolicited NOP-IP PDU back to the initiator and expecting a response. When it doesn't receive one in 5 seconds, it closes the connection. This is kind of a backwards protocol interaction that can be tricky to handle. It's famous for tripping up lightweight iSCSI initiators.
If you look on iPXE's iSCSI Targets Known to Work with iPXE page, you'll see how to disable this behavior. (I don't know that your Dell is running an iPXE initiator, but this is a good reference.) This command turns it off entirely:
lio_node --setnodeattr <TARGET_IQN> <TPGT> <INITIATOR_IQN> nopin_timeout 0
In the Linux kernel, you can see where setting this to 0 short-circuits the process of starting the timer. You shouldn't see the "Started NOPIN Timer..." debug message any longer:
void __iscsit_start_nopin_timer(struct iscsit_conn *conn)
{
struct iscsit_session *sess = conn->sess;
struct iscsi_node_attrib *na = iscsit_tpg_get_node_attrib(sess);
lockdep_assert_held(&conn->nopin_timer_lock);
/*
* NOPIN timeout is disabled.
*/
if (!na->nopin_timeout)
return;
if (conn->nopin_timer_flags & ISCSI_TF_RUNNING)
return;
conn->nopin_timer_flags &= ~ISCSI_TF_STOP;
conn->nopin_timer_flags |= ISCSI_TF_RUNNING;
mod_timer(&conn->nopin_timer, jiffies + na->nopin_timeout * HZ);
pr_debug("Started NOPIN Timer on CID: %d at %u second"
" interval\n", conn->cid, na->nopin_timeout);
}
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库，让每个人都能够通过互相帮助和分享经验来进步。
评论