[PATCH 0/2] fix iscsi commands when session is freed

[PATCH 0/2] fix iscsi commands when session is freed

[Dmitry Bogdanov]

The patchset based on 6.3/scsi-queue.

The patchset fixes use-after-free of se_session at commands free.

Dmitry Bogdanov (2):
  target: iscs: reject cmd in closed session
  target: iscsi: free cmds before session free

 drivers/target/iscsi/iscsi_target.c | 14 +++++++++-----
 include/scsi/iscsi_proto.h          |  1 +
 2 files changed, 10 insertions(+), 5 deletions(-)

-- 
2.25.1

[PATCH 1/2] target: iscs: reject cmd in closed session

[Dmitry Bogdanov]

Do not handle incoming commands if the session is already closed.

That patch fixes the following stacktrace:

 Decremented iSCSI connection count to 0 from node: iqn.1996-04.com.local:3
 TARGET_CORE[iSCSI]: Deregistered fabric_sess
 Moving to TARG_SESS_STATE_FREE.
 Released iSCSI session from node: iqn.1996-04.com.local:3
 Decremented number of active iSCSI Sessions on iSCSI TPG: 0 to 1
 rx_loop: 48, total_rx: 48, data: 48
 Got SCSI Command, ITT: 0x2000005d, CmdSN: 0x4a020000, ExpXferLen: 0, Length: 0, CID: 0
BUG: Kernel NULL pointer dereference on read at 0x00000000
  Faulting instruction address: 0xc008000000a9b574
  Oops: Kernel access of bad area, sig: 11 [#1]
  NIP [c008000000a9b574] transport_lookup_cmd_lun+0x37c/0x470 [target_core_mod]
  LR [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
Call Trace:
 [c000000059e4fae0] [c000000059e4fb70] 0xc000000059e4fb70 (unreliable)
 [c000000059e4fb70] [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
 [c000000059e4fc30] [c00800000101c448] iscsit_get_rx_pdu+0x720/0x11d0 [iscsi_target_mod]
 [c000000059e4fd60] [c00800000101ebc8] iscsi_target_rx_thread+0xb0/0x190 [iscsi_target_mod]
 [c000000059e4fdb0] [c00000000018c50c] kthread+0x19c/0x1b0

Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
---
 drivers/target/iscsi/iscsi_target.c | 8 ++++++--
 include/scsi/iscsi_proto.h          | 1 +
 2 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
index baf4da7bb3b4..f6008675dd3f 100644
--- a/drivers/target/iscsi/iscsi_target.c
+++ b/drivers/target/iscsi/iscsi_target.c
@@ -1199,7 +1199,9 @@ int iscsit_setup_scsi_cmd(struct iscsit_conn *conn, struct iscsit_cmd *cmd,
 		hdr->cmdsn, be32_to_cpu(hdr->data_length), payload_length,
 		conn->cid);
 
-	target_get_sess_cmd(&cmd->se_cmd, true);
+	if (target_get_sess_cmd(&cmd->se_cmd, true) < 0)
+		return iscsit_add_reject_cmd(cmd,
+				ISCSI_REASON_WAITING_FOR_LOGOUT, buf);
 
 	cmd->se_cmd.tag = (__force u32)cmd->init_task_tag;
 	cmd->sense_reason = target_cmd_init_cdb(&cmd->se_cmd, cdb,
@@ -2057,7 +2059,9 @@ iscsit_handle_task_mgt_cmd(struct iscsit_conn *conn, struct iscsit_cmd *cmd,
 			  TCM_SIMPLE_TAG, cmd->sense_buffer + 2,
 			  scsilun_to_int(&hdr->lun));
 
-	target_get_sess_cmd(&cmd->se_cmd, true);
+	if (target_get_sess_cmd(&cmd->se_cmd, true) < 0)
+		return iscsit_add_reject_cmd(cmd,
+				ISCSI_REASON_WAITING_FOR_LOGOUT, buf);
 
 	/*
 	 * TASK_REASSIGN for ERL=2 / connection stays inside of
diff --git a/include/scsi/iscsi_proto.h b/include/scsi/iscsi_proto.h
index 7b192d88f186..e3c016b013de 100644
--- a/include/scsi/iscsi_proto.h
+++ b/include/scsi/iscsi_proto.h
@@ -627,6 +627,7 @@ struct iscsi_reject {
 #define ISCSI_REASON_BOOKMARK_INVALID	9
 #define ISCSI_REASON_BOOKMARK_NO_RESOURCES	10
 #define ISCSI_REASON_NEGOTIATION_RESET	11
+#define ISCSI_REASON_WAITING_FOR_LOGOUT	12
 
 /* Max. number of Key=Value pairs in a text message */
 #define MAX_KEY_VALUE_PAIRS	8192
-- 
2.25.1

[PATCH 2/2] target: iscsi: free cmds before session free

[Dmitry Bogdanov]

Commands from recovery entries are freed after its session has been
closed. That leads to use-after-free at command free or NPE with such
call trace:

Time2Retain timer expired for SID: 1, cleaning up iSCSI session.
BUG: kernel NULL pointer dereference, address: 0000000000000140
RIP: 0010:sbitmap_queue_clear+0x3a/0xa0
Call Trace:
 target_release_cmd_kref+0xd1/0x1f0 [target_core_mod]
 transport_generic_free_cmd+0xd1/0x180 [target_core_mod]
 iscsit_free_cmd+0x53/0xd0 [iscsi_target_mod]
 iscsit_free_connection_recovery_entries+0x29d/0x320 [iscsi_target_mod]
 iscsit_close_session+0x13a/0x140 [iscsi_target_mod]
 iscsit_check_post_dataout+0x440/0x440 [iscsi_target_mod]
 call_timer_fn+0x24/0x140

Move cleanup of recovery enrties to before session freeing.

Reported-by: Forza <forza@tnonline.net>
Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
---
 drivers/target/iscsi/iscsi_target.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
index f6008675dd3f..0748cbfb9631 100644
--- a/drivers/target/iscsi/iscsi_target.c
+++ b/drivers/target/iscsi/iscsi_target.c
@@ -4521,6 +4521,9 @@ int iscsit_close_session(struct iscsit_session *sess, bool can_sleep)
 	iscsit_stop_time2retain_timer(sess);
 	spin_unlock_bh(&se_tpg->session_lock);
 
+	if (sess->sess_ops->ErrorRecoveryLevel == 2)
+		iscsit_free_connection_recovery_entries(sess);
+
 	/*
 	 * transport_deregister_session_configfs() will clear the
 	 * struct se_node_acl->nacl_sess pointer now as a iscsi_np process context
@@ -4544,9 +4547,6 @@ int iscsit_close_session(struct iscsit_session *sess, bool can_sleep)
 
 	transport_deregister_session(sess->se_sess);
 
-	if (sess->sess_ops->ErrorRecoveryLevel == 2)
-		iscsit_free_connection_recovery_entries(sess);
-
 	iscsit_free_all_ooo_cmdsns(sess);
 
 	spin_lock_bh(&se_tpg->session_lock);
-- 
2.25.1

Re: [PATCH 1/2] target: iscs: reject cmd in closed session

[Mike Christie]

On 1/25/23 02:33, Dmitry Bogdanov wrote:
> Do not handle incoming commands if the session is already closed.
> 
> That patch fixes the following stacktrace:
> 
>  Decremented iSCSI connection count to 0 from node: iqn.1996-04.com.local:3
>  TARGET_CORE[iSCSI]: Deregistered fabric_sess
>  Moving to TARG_SESS_STATE_FREE.
>  Released iSCSI session from node: iqn.1996-04.com.local:3
>  Decremented number of active iSCSI Sessions on iSCSI TPG: 0 to 1
>  rx_loop: 48, total_rx: 48, data: 48
>  Got SCSI Command, ITT: 0x2000005d, CmdSN: 0x4a020000, ExpXferLen: 0, Length: 0, CID: 0
> BUG: Kernel NULL pointer dereference on read at 0x00000000
>   Faulting instruction address: 0xc008000000a9b574
>   Oops: Kernel access of bad area, sig: 11 [#1]
>   NIP [c008000000a9b574] transport_lookup_cmd_lun+0x37c/0x470 [target_core_mod]
>   LR [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
> Call Trace:
>  [c000000059e4fae0] [c000000059e4fb70] 0xc000000059e4fb70 (unreliable)
>  [c000000059e4fb70] [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
>  [c000000059e4fc30] [c00800000101c448] iscsit_get_rx_pdu+0x720/0x11d0 [iscsi_target_mod]
>  [c000000059e4fd60] [c00800000101ebc8] iscsi_target_rx_thread+0xb0/0x190 [iscsi_target_mod]
>  [c000000059e4fdb0] [c00000000018c50c] kthread+0x19c/0x1b0
> 
> Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
> ---
>  drivers/target/iscsi/iscsi_target.c | 8 ++++++--
>  include/scsi/iscsi_proto.h          | 1 +
>  2 files changed, 7 insertions(+), 2 deletions(-)
> 
> diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
> index baf4da7bb3b4..f6008675dd3f 100644
> --- a/drivers/target/iscsi/iscsi_target.c
> +++ b/drivers/target/iscsi/iscsi_target.c
> @@ -1199,7 +1199,9 @@ int iscsit_setup_scsi_cmd(struct iscsit_conn *conn, struct iscsit_cmd *cmd,
>  		hdr->cmdsn, be32_to_cpu(hdr->data_length), payload_length,
>  		conn->cid);
>  
> -	target_get_sess_cmd(&cmd->se_cmd, true);
> +	if (target_get_sess_cmd(&cmd->se_cmd, true) < 0)
> +		return iscsit_add_reject_cmd(cmd,
> +				ISCSI_REASON_WAITING_FOR_LOGOUT, buf);
> 
Did this require target_stop_session somewhere? I think this is a possible
use after free.

It seems like if we have logged the message:

>  Moving to TARG_SESS_STATE_FREE.

then we called:

transport_deregister_session -> transport_free_session

and freed the se_session.

So above if target_get_sess_cmd returns failure then we have run:

transport_free_session ->transport_uninit_session -> percpu_ref_exit

and transport_free_session could have done:

kmem_cache_free(se_sess_cache, se_sess)

by the time we run the code above and we are now accessing a freed
se_session and iscsit_session.

Re: [PATCH 1/2] target: iscs: reject cmd in closed session

[michael.christie]

On 1/25/23 11:03 AM, Mike Christie wrote:
> On 1/25/23 02:33, Dmitry Bogdanov wrote:
>> Do not handle incoming commands if the session is already closed.
>>
>> That patch fixes the following stacktrace:
>>
>>  Decremented iSCSI connection count to 0 from node: iqn.1996-04.com.local:3
>>  TARGET_CORE[iSCSI]: Deregistered fabric_sess
>>  Moving to TARG_SESS_STATE_FREE.
>>  Released iSCSI session from node: iqn.1996-04.com.local:3
>>  Decremented number of active iSCSI Sessions on iSCSI TPG: 0 to 1
>>  rx_loop: 48, total_rx: 48, data: 48
>>  Got SCSI Command, ITT: 0x2000005d, CmdSN: 0x4a020000, ExpXferLen: 0, Length: 0, CID: 0
>> BUG: Kernel NULL pointer dereference on read at 0x00000000
>>   Faulting instruction address: 0xc008000000a9b574
>>   Oops: Kernel access of bad area, sig: 11 [#1]
>>   NIP [c008000000a9b574] transport_lookup_cmd_lun+0x37c/0x470 [target_core_mod]
>>   LR [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
>> Call Trace:
>>  [c000000059e4fae0] [c000000059e4fb70] 0xc000000059e4fb70 (unreliable)
>>  [c000000059e4fb70] [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
>>  [c000000059e4fc30] [c00800000101c448] iscsit_get_rx_pdu+0x720/0x11d0 [iscsi_target_mod]
>>  [c000000059e4fd60] [c00800000101ebc8] iscsi_target_rx_thread+0xb0/0x190 [iscsi_target_mod]
>>  [c000000059e4fdb0] [c00000000018c50c] kthread+0x19c/0x1b0
>>
>> Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
>> ---
>>  drivers/target/iscsi/iscsi_target.c | 8 ++++++--
>>  include/scsi/iscsi_proto.h          | 1 +
>>  2 files changed, 7 insertions(+), 2 deletions(-)
>>
>> diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
>> index baf4da7bb3b4..f6008675dd3f 100644
>> --- a/drivers/target/iscsi/iscsi_target.c
>> +++ b/drivers/target/iscsi/iscsi_target.c
>> @@ -1199,7 +1199,9 @@ int iscsit_setup_scsi_cmd(struct iscsit_conn *conn, struct iscsit_cmd *cmd,
>>  		hdr->cmdsn, be32_to_cpu(hdr->data_length), payload_length,
>>  		conn->cid);
>>  
>> -	target_get_sess_cmd(&cmd->se_cmd, true);
>> +	if (target_get_sess_cmd(&cmd->se_cmd, true) < 0)
>> +		return iscsit_add_reject_cmd(cmd,
>> +				ISCSI_REASON_WAITING_FOR_LOGOUT, buf);
>>
> Did this require target_stop_session somewhere? I think this is a possible

Oh wait, if there is a use after free like below then iscsit_stop_session
won't help since we are trying to stop incoming commands from referencing
the se_session/iscsit_session. We would need to check something on the
iscsit_conn.

> use after free.
> 
> It seems like if we have logged the message:
> 
>>  Moving to TARG_SESS_STATE_FREE.
> 
> then we called:
> 
> transport_deregister_session -> transport_free_session
> 
> and freed the se_session.
> 
> So above if target_get_sess_cmd returns failure then we have run:
> 
> transport_free_session ->transport_uninit_session -> percpu_ref_exit
> 
> and transport_free_session could have done:
> 
> kmem_cache_free(se_sess_cache, se_sess)
> 
> by the time we run the code above and we are now accessing a freed
> se_session and iscsit_session.

Re: [PATCH 1/2] target: iscs: reject cmd in closed session

[Dmitry Bogdanov]

Hi Mike,

On Wed, Jan 25, 2023 at 11:18:32AM -0600, michael.christie@oracle.com wrote:
> On 1/25/23 11:03 AM, Mike Christie wrote:
> > On 1/25/23 02:33, Dmitry Bogdanov wrote:
> >> Do not handle incoming commands if the session is already closed.
> >>
> >> That patch fixes the following stacktrace:
> >>
> >>  Decremented iSCSI connection count to 0 from node: iqn.1996-04.com.local:3
> >>  TARGET_CORE[iSCSI]: Deregistered fabric_sess
> >>  Moving to TARG_SESS_STATE_FREE.
> >>  Released iSCSI session from node: iqn.1996-04.com.local:3
> >>  Decremented number of active iSCSI Sessions on iSCSI TPG: 0 to 1
> >>  rx_loop: 48, total_rx: 48, data: 48
> >>  Got SCSI Command, ITT: 0x2000005d, CmdSN: 0x4a020000, ExpXferLen: 0, Length: 0, CID: 0
> >> BUG: Kernel NULL pointer dereference on read at 0x00000000
> >>   Faulting instruction address: 0xc008000000a9b574
> >>   Oops: Kernel access of bad area, sig: 11 [#1]
> >>   NIP [c008000000a9b574] transport_lookup_cmd_lun+0x37c/0x470 [target_core_mod]
> >>   LR [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
> >> Call Trace:
> >>  [c000000059e4fae0] [c000000059e4fb70] 0xc000000059e4fb70 (unreliable)
> >>  [c000000059e4fb70] [c008000001017318] iscsit_setup_scsi_cmd+0x520/0x780 [iscsi_target_mod]
> >>  [c000000059e4fc30] [c00800000101c448] iscsit_get_rx_pdu+0x720/0x11d0 [iscsi_target_mod]
> >>  [c000000059e4fd60] [c00800000101ebc8] iscsi_target_rx_thread+0xb0/0x190 [iscsi_target_mod]
> >>  [c000000059e4fdb0] [c00000000018c50c] kthread+0x19c/0x1b0
> >>
> >> Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
> >> ---
> >>  drivers/target/iscsi/iscsi_target.c | 8 ++++++--
> >>  include/scsi/iscsi_proto.h          | 1 +
> >>  2 files changed, 7 insertions(+), 2 deletions(-)
> >>
> >> diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
> >> index baf4da7bb3b4..f6008675dd3f 100644
> >> --- a/drivers/target/iscsi/iscsi_target.c
> >> +++ b/drivers/target/iscsi/iscsi_target.c
> >> @@ -1199,7 +1199,9 @@ int iscsit_setup_scsi_cmd(struct iscsit_conn *conn, struct iscsit_cmd *cmd,
> >>              hdr->cmdsn, be32_to_cpu(hdr->data_length), payload_length,
> >>              conn->cid);
> >>
> >> -    target_get_sess_cmd(&cmd->se_cmd, true);
> >> +    if (target_get_sess_cmd(&cmd->se_cmd, true) < 0)
> >> +            return iscsit_add_reject_cmd(cmd,
> >> +                            ISCSI_REASON_WAITING_FOR_LOGOUT, buf);
> >>
> > Did this require target_stop_session somewhere? I think this is a possible

In my private patchset there the third patch was with
target_stop_session/target_wait_for_sess_cmds right after
scsit_free_connection_recovery_entries(sess) from the second patch.
I did not post it because you are preparing a patchset with
target_wait_for_sess_cmds in iscsi.

Please, take my second patch to your patchset (if Martin will not take
it separately), it is definitely a bugfix.
But, please, take care that after
iscsit_free_connection_recovery_entries iscsi should wait for commands
complete too to fix that use-after-free completely.

> Oh wait, if there is a use after free like below then iscsit_stop_session
> won't help since we are trying to stop incoming commands from referencing
> the se_session/iscsit_session. We would need to check something on the
> iscsit_conn.

Looking at the log snippet now I see that the call trace is not about
new command in the dead session. Because iscsi session is closed only
after both RX and TX threads have been stopped. It was a command in an
alive session.
Most likely, that call trace was due to the problem that I fixed in
dd0a66ada0bd ("scsi: target: core: Fix race during ACL removal") that
was catched on FC. And this one was on iSCSI. They are about the same
age.

I am dropping this (1st) patch as it is for an unreal case and actually does
not solve use-after-free session: iscsit_add_reject_cmd in the end calls
target_put_sess_cmd(se_cmd);
	target_free_tag(sess->se_sess, cmd);
    percpu_ref_put(&se_sess->cmd_count);


> > use after free.
> >
> > It seems like if we have logged the message:
> >
> >>  Moving to TARG_SESS_STATE_FREE.
> >
> > then we called:
> >
> > transport_deregister_session -> transport_free_session
> >
> > and freed the se_session.
> >
> > So above if target_get_sess_cmd returns failure then we have run:
> >
> > transport_free_session ->transport_uninit_session -> percpu_ref_exit
> >
> > and transport_free_session could have done:
> >
> > kmem_cache_free(se_sess_cache, se_sess)
> >
> > by the time we run the code above and we are now accessing a freed
> > se_session and iscsit_session.

 
BR,
 Dmitry

Re: [PATCH 2/2] target: iscsi: free cmds before session free

[Forza]

On 2023-01-25 09:33, Dmitry Bogdanov wrote:
> Commands from recovery entries are freed after its session has been
> closed. That leads to use-after-free at command free or NPE with such
> call trace:
> 
> Time2Retain timer expired for SID: 1, cleaning up iSCSI session.
> BUG: kernel NULL pointer dereference, address: 0000000000000140
> RIP: 0010:sbitmap_queue_clear+0x3a/0xa0
> Call Trace:
>   target_release_cmd_kref+0xd1/0x1f0 [target_core_mod]
>   transport_generic_free_cmd+0xd1/0x180 [target_core_mod]
>   iscsit_free_cmd+0x53/0xd0 [iscsi_target_mod]
>   iscsit_free_connection_recovery_entries+0x29d/0x320 [iscsi_target_mod]
>   iscsit_close_session+0x13a/0x140 [iscsi_target_mod]
>   iscsit_check_post_dataout+0x440/0x440 [iscsi_target_mod]
>   call_timer_fn+0x24/0x140
> 
> Move cleanup of recovery enrties to before session freeing.
> 
> Reported-by: Forza <forza@tnonline.net>
> Signed-off-by: Dmitry Bogdanov <d.bogdanov@yadro.com>
> ---
>   drivers/target/iscsi/iscsi_target.c | 6 +++---
>   1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/target/iscsi/iscsi_target.c b/drivers/target/iscsi/iscsi_target.c
> index f6008675dd3f..0748cbfb9631 100644
> --- a/drivers/target/iscsi/iscsi_target.c
> +++ b/drivers/target/iscsi/iscsi_target.c
> @@ -4521,6 +4521,9 @@ int iscsit_close_session(struct iscsit_session *sess, bool can_sleep)
>   	iscsit_stop_time2retain_timer(sess);
>   	spin_unlock_bh(&se_tpg->session_lock);
>   
> +	if (sess->sess_ops->ErrorRecoveryLevel == 2)
> +		iscsit_free_connection_recovery_entries(sess);
> +
>   	/*
>   	 * transport_deregister_session_configfs() will clear the
>   	 * struct se_node_acl->nacl_sess pointer now as a iscsi_np process context
> @@ -4544,9 +4547,6 @@ int iscsit_close_session(struct iscsit_session *sess, bool can_sleep)
>   
>   	transport_deregister_session(sess->se_sess);
>   
> -	if (sess->sess_ops->ErrorRecoveryLevel == 2)
> -		iscsit_free_connection_recovery_entries(sess);
> -
>   	iscsit_free_all_ooo_cmdsns(sess);
>   
>   	spin_lock_bh(&se_tpg->session_lock);

I have not had any more issues since applying the patch, which is good 
news :)

Will this be backported to earlier stable kernels like 5.15.x and 6.1.x

Regards,
Forza