On Mon, Nov 17, 2014 at 09:03:33PM +0100, Claudio Jeker wrote:
> On Fri, Nov 14, 2014 at 01:46:20PM +0100, Jasper Lievisse Adriaanse wrote:
> > Hi,
> >
> > While playing with iscsid against a Synology NAS I noticed this
> > reproducable crash.
> > My iscsid.conf:
> > --8<--
> > target "LUN-1" {
> > enabled
> > normal
> > targetaddr 192.168.178.9
> > targetname "iqn.2000-01.com.synology:jabba.Target-1.55f50797a0"
> > }
> > --8<--
> >
> > $ sudo iscsid -d -v
> > startup
> > < now issue iscsictl reload from another terminal, which returns "command
> > successful" >
> > session_fsm[LUN-1]: INIT ev start timeout 0
> > sess_fsm[LUN-1]: INIT ev start
> > new connection to 192.168.178.9:3260
> > conn_fsm[LUN-1]: FREE ev connect
> > conn_fsm[LUN-1]: new state XPT_WAIT
> > sess_fsm[LUN-1]: new state FREE
> > sess_fsm: done
> > conn_fsm[LUN-1]: XPT_WAIT ev connected
> > conn_fsm[LUN-1]: new state IN_LOGIN
> > bad param TargetPortalGroupTag=0: too small
> > SET_NUM: TargetPortalGroupTag = 0
> > conn_parse_kvp: errors found
> > conn_fail
> > conn_fsm[LUN-1]: IN_LOGIN ev fail
> > c_do_fail
> > session_fsm[LUN-1]: FREE ev connection fail timeout 0
> > conn_fsm[LUN-1]: new state FREE
> > iscsid(20532) in free(): error: double free 0x14c3e4abe100
> > [1] 20532 abort sudo iscsid -d -v
> > $
> >
>
> Can you give the following diff a spin (please also test without the
> connection.c change). First of all the TargetPortalGroupTag can be any 16
> bit value which includes 0. Not sure why I limited it to 1 - 2**16.
>
> The other issue is that conn_fail() releases the task and then we call
> conn_task_cleanup() which does the same again and therefor we double free
> or fault on a bad pointer. I removed the extra conn_task_cleanup() from
> the failure path but I'm not entierly happy with it. I need to rethink who
> is responsible for what in the callbacks, etc.
>
> I just compile tested the diff.Can you give the following diff a spin
> (please also test without the connection.c change). First of all the
> TargetPortalGroupTag can be any 16 bit value which includes 0. Not sure
> why I limited it to 1 - 2**16.
>
> The other issue is that conn_fail() releases the task and then we call
> conn_task_cleanup() which does the same again and therefor we double free
> or fault on a bad pointer. I removed the extra conn_task_cleanup() from
> the failure path but I'm not entierly happy with it. I need to rethink who
> is responsible for what in the callbacks, etc.
>
> Disclaimer: I just compile tested the diff
> --
> :wq Claudio
So at least it doesn't crash anymore, with or without the connection.c chunk
applied.
It still doesn't seem to work given the error messages:
[..]
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
[..]
full log:
startup
session_fsm[LUN-1]: INIT ev start timeout 0
sess_fsm[LUN-1]: INIT ev start
new connection to 192.168.178.9:3260
conn_fsm[LUN-1]: FREE ev connect
conn_fsm[LUN-1]: new state XPT_WAIT
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
conn_fsm[LUN-1]: XPT_WAIT ev connected
conn_fsm[LUN-1]: new state IN_LOGIN
SET_NUM: TargetPortalGroupTag = 0
SET_NUM: MaxConnections = 2
SET_BOOL: InitialR2T = 1
SET_BOOL: ImmediateData = 1
SET_NUM: MaxRecvDataSegmentLength = 65536
SET_NUM: MaxBurstLength = 262144
SET_NUM: FirstBurstLength = 65536
SET_NUM: MaxOutstandingR2T = 1
SET_BOOL: DataPDUInOrder = 1
SET_BOOL: DataSequenceInOrder = 1
SET_NUM: ErrorRecoveryLevel = 0
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
c_do_fail
session_fsm[LUN-1]: FREE ev connection fail timeout 0
conn_fsm[LUN-1]: new state FREE
sess_fsm[LUN-1]: FREE ev connection fail
conn_free
session_fsm[LUN-1]: FREE ev start timeout 0
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
sess_fsm[LUN-1]: FREE ev start
new connection to 192.168.178.9:3260
conn_fsm[LUN-1]: FREE ev connect
conn_fsm[LUN-1]: new state XPT_WAIT
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
conn_fsm[LUN-1]: XPT_WAIT ev connected
conn_fsm[LUN-1]: new state IN_LOGIN
SET_NUM: TargetPortalGroupTag = 0
SET_NUM: MaxConnections = 2
SET_BOOL: InitialR2T = 1
SET_BOOL: ImmediateData = 1
SET_NUM: MaxRecvDataSegmentLength = 65536
SET_NUM: MaxBurstLength = 262144
SET_NUM: FirstBurstLength = 65536
SET_NUM: MaxOutstandingR2T = 1
SET_BOOL: DataPDUInOrder = 1
SET_BOOL: DataSequenceInOrder = 1
SET_NUM: ErrorRecoveryLevel = 0
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
c_do_fail
session_fsm[LUN-1]: FREE ev connection fail timeout 0
conn_fsm[LUN-1]: new state FREE
sess_fsm[LUN-1]: FREE ev connection fail
conn_free
session_fsm[LUN-1]: FREE ev start timeout 1
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
sess_fsm[LUN-1]: FREE ev start
new connection to 192.168.178.9:3260
conn_fsm[LUN-1]: FREE ev connect
conn_fsm[LUN-1]: new state XPT_WAIT
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
conn_fsm[LUN-1]: XPT_WAIT ev connected
conn_fsm[LUN-1]: new state IN_LOGIN
SET_NUM: TargetPortalGroupTag = 0
SET_NUM: MaxConnections = 2
SET_BOOL: InitialR2T = 1
SET_BOOL: ImmediateData = 1
SET_NUM: MaxRecvDataSegmentLength = 65536
SET_NUM: MaxBurstLength = 262144
SET_NUM: FirstBurstLength = 65536
SET_NUM: MaxOutstandingR2T = 1
SET_BOOL: DataPDUInOrder = 1
SET_BOOL: DataSequenceInOrder = 1
SET_NUM: ErrorRecoveryLevel = 0
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
c_do_fail
session_fsm[LUN-1]: FREE ev connection fail timeout 0
conn_fsm[LUN-1]: new state FREE
sess_fsm[LUN-1]: FREE ev connection fail
conn_free
session_fsm[LUN-1]: FREE ev start timeout 2
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
sess_fsm[LUN-1]: FREE ev start
new connection to 192.168.178.9:3260
conn_fsm[LUN-1]: FREE ev connect
conn_fsm[LUN-1]: new state XPT_WAIT
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
conn_fsm[LUN-1]: XPT_WAIT ev connected
conn_fsm[LUN-1]: new state IN_LOGIN
SET_NUM: TargetPortalGroupTag = 0
SET_NUM: MaxConnections = 2
SET_BOOL: InitialR2T = 1
SET_BOOL: ImmediateData = 1
SET_NUM: MaxRecvDataSegmentLength = 65536
SET_NUM: MaxBurstLength = 262144
SET_NUM: FirstBurstLength = 65536
SET_NUM: MaxOutstandingR2T = 1
SET_BOOL: DataPDUInOrder = 1
SET_BOOL: DataSequenceInOrder = 1
SET_NUM: ErrorRecoveryLevel = 0
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
c_do_fail
session_fsm[LUN-1]: FREE ev connection fail timeout 0
conn_fsm[LUN-1]: new state FREE
sess_fsm[LUN-1]: FREE ev connection fail
conn_free
session_fsm[LUN-1]: FREE ev start timeout 4
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
sess_fsm[LUN-1]: FREE ev start
new connection to 192.168.178.9:3260
conn_fsm[LUN-1]: FREE ev connect
conn_fsm[LUN-1]: new state XPT_WAIT
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
conn_fsm[LUN-1]: XPT_WAIT ev connected
conn_fsm[LUN-1]: new state IN_LOGIN
SET_NUM: TargetPortalGroupTag = 0
SET_NUM: MaxConnections = 2
SET_BOOL: InitialR2T = 1
SET_BOOL: ImmediateData = 1
SET_NUM: MaxRecvDataSegmentLength = 65536
SET_NUM: MaxBurstLength = 262144
SET_NUM: FirstBurstLength = 65536
SET_NUM: MaxOutstandingR2T = 1
SET_BOOL: DataPDUInOrder = 1
SET_BOOL: DataSequenceInOrder = 1
SET_NUM: ErrorRecoveryLevel = 0
bad param MaxConnections=NotUnderstood: invalid
SET_NUM: MaxConnections = 0
bad param MaxRecvDataSegmentLength=NotUnderstood: invalid
SET_NUM: MaxRecvDataSegmentLength = 0
conn_parse_kvp: errors found
conn_fail
conn_fsm[LUN-1]: IN_LOGIN ev fail
c_do_fail
session_fsm[LUN-1]: FREE ev connection fail timeout 0
conn_fsm[LUN-1]: new state FREE
sess_fsm[LUN-1]: FREE ev connection fail
conn_free
session_fsm[LUN-1]: FREE ev start timeout 8
sess_fsm[LUN-1]: new state FREE
sess_fsm: done
^Cinitiator_shutdown: going down
session[LUN-1] going down
exiting.
Thanks,
Jasper
> Index: connection.c
> ===================================================================
> RCS file: /cvs/src/usr.sbin/iscsid/connection.c,v
> retrieving revision 1.19
> diff -u -p -r1.19 connection.c
> --- connection.c 10 May 2014 11:30:47 -0000 1.19
> +++ connection.c 17 Nov 2014 19:53:56 -0000
> @@ -295,7 +295,7 @@ conn_parse_kvp(struct connection *c, str
> SET_NUM(k, s, DefaultTime2Wait, 0, 3600);
> SET_NUM(k, s, DefaultTime2Retain, 0, 3600);
> SET_NUM(k, s, MaxOutstandingR2T, 1, 65535);
> - SET_NUM(k, s, TargetPortalGroupTag, 1, 65535);
> + SET_NUM(k, s, TargetPortalGroupTag, 0, 65535);
> SET_NUM(k, s, MaxConnections, 1, 65535);
> SET_BOOL(k, s, InitialR2T);
> SET_BOOL(k, s, ImmediateData);
> Index: initiator.c
> ===================================================================
> RCS file: /cvs/src/usr.sbin/iscsid/initiator.c,v
> retrieving revision 1.13
> diff -u -p -r1.13 initiator.c
> --- initiator.c 10 May 2014 11:30:47 -0000 1.13
> +++ initiator.c 17 Nov 2014 19:53:56 -0000
> @@ -433,6 +433,8 @@ initiator_login_cb(struct connection *c,
> break;
> case ISCSI_LOGIN_STG_FULL:
> conn_fsm(c, CONN_EV_LOGGED_IN);
> + conn_task_cleanup(c, &tl->task);
> + free(tl);
> goto done;
> default:
> log_warnx("initiator_login_cb: exit stage left");
> @@ -445,8 +447,6 @@ initiator_login_cb(struct connection *c,
> conn_task_issue(c, &tl->task);
> return;
> done:
> - conn_task_cleanup(c, &tl->task);
> - free(tl);
> if (p)
> pdu_free(p);
> }
> @@ -488,6 +488,8 @@ initiator_discovery_cb(struct connection
> ISCSI_PDU_OPCODE(lresp->opcode));
> fail:
> conn_fail(c);
> + pdu_free(p);
> + return;
> }
> conn_task_cleanup(c, t);
> free(t);
> @@ -528,7 +530,8 @@ initiator_logout_cb(struct connection *c
> default:
> /* need to retry logout after loresp->time2wait secs */
> conn_fail(tl->c);
> - break;
> + pdu_free(p);
> + return;
> }
>
> conn_task_cleanup(c, &tl->task);
> Index: pdu.c
> ===================================================================
> RCS file: /cvs/src/usr.sbin/iscsid/pdu.c,v
> retrieving revision 1.9
> diff -u -p -r1.9 pdu.c
> --- pdu.c 21 Apr 2014 12:26:50 -0000 1.9
> +++ pdu.c 17 Nov 2014 19:53:56 -0000
> @@ -393,8 +393,8 @@ pdu_parse(struct connection *c)
> }
> }
> p->resid = 0; /* reset resid so pdu can be reused */
> - task_pdu_cb(c, p);
> c->prbuf.wip = NULL;
> + task_pdu_cb(c, p);
> }
> } while (1);
> fail:
>
--
jasper
