[Stgt-devel] Open connections
Niels de Carpentier
stgt
Sun Mar 16 03:02:43 CET 2008
Some more info about the reconnect issue:
When the initiator of the diskless system sets up a new connection, the
target actually uses the session details of the old connection. (Which
wasn't closed properly). Since the CmdSN numbers of the initiator and
target don't match (The initiator starts at 0, while the target has the
value of the old connection), the commands are rejected.
Niels
The debug log looks like this:
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 0
tgtd: cmnd_exec_text(788) Text request: 8
tgtd: iscsi_tcp_event_handler(154) connection closed
tgtd: conn_close(88) connection closed
tgtd: iscsi_tcp_event_handler(161) connection closed
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(586) Login request (security negotiation): 0
tgtd: login_start(483) exp_cmd_sn: 0,0
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: session_find_name(45) session_find_name: front_dom0 0 2 3d 1 0 0
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: conn_take_fd(163) 0 5 0 20000013d0200
tgtd: iscsi_scsi_cmd_rx_start(1466) 2 12 0 0 36 1 0
tgtd: iscsi_task_queue(1411) 0 1bf8 1
tgtd: iscsi_task_queue(1437) unexpected cmd_sn (0,7160)
tgtd: iscsi_tcp_event_handler(154) connection closed
tgtd: conn_close(88) connection closed
tgtd: iscsi_tcp_event_handler(161) connection closed
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(586) Login request (security negotiation): 0
tgtd: login_start(483) exp_cmd_sn: 1,16777216
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: session_find_name(45) session_find_name: front_dom0 0 2 3d 1 0 0
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: conn_take_fd(163) 0 5 0 20000013d0200
tgtd: iscsi_scsi_cmd_rx_start(1466) 2 0 0 0 0 1 10000001
tgtd: iscsi_task_queue(1411) 1 1bf8 1
tgtd: iscsi_task_queue(1437) unexpected cmd_sn (1,7160)
tgtd: iscsi_tcp_event_handler(154) connection closed
tgtd: conn_close(88) connection closed
tgtd: iscsi_tcp_event_handler(161) connection closed
tgtd: tgt_mgmt(296) 120 0 1 2 -1 0 0 4839
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(586) Login request (security negotiation): 0
tgtd: login_start(483) exp_cmd_sn: 2,33554432
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: session_find_name(45) session_find_name: front_dom0 0 2 3d 1 0 0
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: conn_take_fd(163) 0 5 0 20000013d0200
tgtd: iscsi_scsi_cmd_rx_start(1466) 2 12 0 0 36 1 20000002
tgtd: iscsi_task_queue(1411) 2 1bf8 1
tgtd: iscsi_task_queue(1437) unexpected cmd_sn (2,7160)
tgtd: iscsi_tcp_event_handler(154) connection closed
tgtd: conn_close(88) connection closed
tgtd: iscsi_tcp_event_handler(161) connection closed
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(586) Login request (security negotiation): 0
tgtd: login_start(483) exp_cmd_sn: 3,50331648
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: session_find_name(45) session_find_name: front_dom0 0 2 3d 1 0 0
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: conn_take_fd(163) 0 5 0 20000013d0200
tgtd: tgt_mgmt(296) 120 0 1 2 -1 0 0 4839
tgtd: iscsi_scsi_cmd_rx_start(1466) 2 0 0 0 0 1 30000003
tgtd: iscsi_task_queue(1411) 3 1bf8 1
tgtd: iscsi_task_queue(1437) unexpected cmd_sn (3,7160)
tgtd: iscsi_tcp_event_handler(154) connection closed
tgtd: conn_close(88) connection closed
tgtd: iscsi_tcp_event_handler(161) connection closed
tgtd: accept_connection(98) 5
tgtd: cmnd_exec_login(586) Login request (security negotiation): 0
tgtd: login_start(483) exp_cmd_sn: 0,0
tgtd: tgt_mgmt(296) 120 0 1 2 -1 0 0 4839
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: cmnd_exec_login(586) Login request (security negotiation): 2
tgtd: session_find_name(45) session_find_name: front_dom0 0 2 3d 2 0 0
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: cmnd_exec_login(623) Login request (operational negotiation): 6
tgtd: it_nexus_create(205) 1 30
tgtd: session_create(135) session_create: 0x30000023d0200
tgtd: conn_take_fd(163) 0 5 0 30000023d0200
> I'm having an issue where old connections keep being listed in tgt, while
> they are not in use anymore.
>
> I'm running a diskless system with an iscsi root, which uses open-iscsi as
> the initiator. The initrd mount does the initial mounting, and on the
> final image iscsid is started, which does a reconnect.
>
> After the system has booted, the follow status is available on the target:
>
> Target 1: iqn.2008-04.com.test:storage.front001
> System information:
> Driver: iscsi
> Status: running
> I_T nexus information:
> I_T nexus: 1
> Initiator: front_dom0
> Connection: 0
> IP Address: 10.0.0.84
> I_T nexus: 2
> Initiator: front_dom0
> Connection: 0
> IP Address: 10.0.0.84
> LUN information:
> LUN: 0
> Type: controller
> SCSI ID: deadbeaf1:0
> SCSI SN: beaf10
> Size: 0 MB
> Online: Yes
> Poweron/Reset: Yes
> Removable media: No
> Backing store: No backing store
> LUN: 1
> Type: disk
> SCSI ID: deadbeaf1:1
> SCSI SN: beaf11
> Size: 2147 MB
> Online: Yes
> Poweron/Reset: No
> Removable media: No
> Backing store: /dev/vg_images/frontend001
> LUN: 2
> Type: disk
> SCSI ID: deadbeaf1:2
> SCSI SN: beaf12
> Size: 1074 MB
> Online: Yes
> Poweron/Reset: No
> Removable media: No
> Backing store: /dev/vg_images/frontend001_swap
> Account information:
> frontend
> ACL information:
> 10.0.0.0/24
>
> However, netstat shows only a single connection active:
>
> netstat -an | grep 3260
>
> tcp 0 0 0.0.0.0:3260 0.0.0.0:*
> LISTEN
> tcp 0 0 10.0.0.17:3260 10.0.0.84:53025
> ESTABLISHED
> tcp 0 0 :::3260 :::*
> LISTEN
>
> If I reboot the iscsi root system without restarting tgtd, the initial
> connect will fail. A logout and a new login is necessary to get a working
> connection in this case.
>
> The following is logged by tgtd during this time:
>
> Mar 15 12:54:58 rbk tgtd: iscsi_task_queue(1437) unexpected cmd_sn
> (0,7551)
> Mar 15 12:55:17 rbk tgtd: iscsi_task_queue(1437) unexpected cmd_sn
> (1,7551)
> Mar 15 12:55:23 rbk tgtd: iscsi_task_queue(1437) unexpected cmd_sn
> (2,7551)
> Mar 15 12:55:42 rbk tgtd: iscsi_task_queue(1437) unexpected cmd_sn
> (3,7551)
>
> I can provide more information on request.
>
> Niels de Carpentier
>
>
>
> _______________________________________________
> Stgt-devel mailing list
> Stgt-devel at lists.berlios.de
> https://lists.berlios.de/mailman/listinfo/stgt-devel
>
More information about the stgt
mailing list