Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[Ming Lei]

On Wed, Nov 15, 2017 at 08:04:49PM +0800, Ming Lei wrote:
> On Wed, Nov 15, 2017 at 07:28:00PM +0900, James Bottomley wrote:
> > On Wed, 2017-11-15 at 18:09 +0800, Ming Lei wrote:
> > > On Tue, Nov 14, 2017 at 10:14:52AM -0800, James Bottomley wrote:
> > > > 
> > > > On Tue, 2017-11-14 at 08:55 +0800, Ming Lei wrote:
> > > > > 
> > > > > Hi James,
> > > > > 
> > > > > On Mon, Nov 13, 2017 at 10:55:52AM -0800, James Bottomley wrote:
> > > > > > 
> > > > > > 
> > > > > > On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> > > > > > > 
> > > > > > > 
> > > > > > > So from CPU1's review, cmd->cmnd is in a remote NUMA node,
> > > > > > > __scsi_format_command() is executed much slower than
> > > > > > > mempool_free().
> > > > > > > So when mempool_free() returns, __scsi_format_command() may
> > > > > > > not fetched the buffer in L1 cache yet, then use-after-free
> > > > > > > is still triggered.
> > > > > > > 
> > > > > > > That is why I say this use-after-free is inevitable no matter
> > > > > > > 'setting SCpnt->cmnd to NULL before calling mempool_free()'
> > > > > > > or not.
> > > > > > 
> > > > > > The bottom line is that there are several creative ways around
> > > > > > this but the proposed code is currently broken and simply
> > > > > > putting a comment in saying so doesn't make it acceptable.
> > > > > 
> > > > > As I explained above, I didn't see one really workable way. Or
> > > > > please correct it if I am wrong.
> > > > 
> > > > I simply can't believe it's beyond the wit of man to solve a use
> > > > after free race.  About 40% of kernel techniques are devoted to
> > > > this.  All I really care about is not losing the PI information we
> > > > previously had.  I agree with Bart that NULL cmnd is a good
> > > > indicator, so it seems reasonable to use it.  If you have another
> > > > mechanism, feel free to propose it.
> > > 
> > > Hi James,
> > > 
> > > This patch is my proposal, no others thought of yet.
> > > 
> > > We can fix the use-after-free easily via lock, rcu and ..., but some
> > > cost has to pay. In this case, we can't wait too long in show_rq(),
> > > otherwise we may lose important debug info, so I do not have better
> > > way.
> > > 
> > > IMO this use-after-free is actually no harm, I don't think we have to
> > > fix it, but it should be better to not let utility warn on this case.
> > 
> > Fine, so lose the snide comment and set the cmnd to NULL *before*
> > calling free so we narrow the race window.
> 
> Hi James,
> 
> Given we can't avoid the use-after-free, how about not do that way so
> we won't lose the precious debug info too early?

Hi James,

Are you fine with V4?

As I explained, the use-after-free can't be avoided, we have to make
scsi_show_rq() to survive that, so we don't need to touch code in free path.
Also we won't lose debug info too early in this way, not like 'set the cmnd
to NULL *before* calling free'.

Thanks,
Ming

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[James Bottomley]

On Wed, 2017-11-15 at 18:09 +0800, Ming Lei wrote:
> On Tue, Nov 14, 2017 at 10:14:52AM -0800, James Bottomley wrote:
> > 
> > On Tue, 2017-11-14 at 08:55 +0800, Ming Lei wrote:
> > > 
> > > Hi James,
> > > 
> > > On Mon, Nov 13, 2017 at 10:55:52AM -0800, James Bottomley wrote:
> > > > 
> > > > 
> > > > On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> > > > > 
> > > > > 
> > > > > So from CPU1's review, cmd->cmnd is in a remote NUMA node,
> > > > > __scsi_format_command() is executed much slower than
> > > > > mempool_free().
> > > > > So when mempool_free() returns, __scsi_format_command() may
> > > > > not fetched the buffer in L1 cache yet, then use-after-free
> > > > > is still triggered.
> > > > > 
> > > > > That is why I say this use-after-free is inevitable no matter
> > > > > 'setting SCpnt->cmnd to NULL before calling mempool_free()'
> > > > > or not.
> > > > 
> > > > The bottom line is that there are several creative ways around
> > > > this but the proposed code is currently broken and simply
> > > > putting a comment in saying so doesn't make it acceptable.
> > > 
> > > As I explained above, I didn't see one really workable way. Or
> > > please correct it if I am wrong.
> > 
> > I simply can't believe it's beyond the wit of man to solve a use
> > after free race.  About 40% of kernel techniques are devoted to
> > this.  All I really care about is not losing the PI information we
> > previously had.  I agree with Bart that NULL cmnd is a good
> > indicator, so it seems reasonable to use it.  If you have another
> > mechanism, feel free to propose it.
> 
> Hi James,
> 
> This patch is my proposal, no others thought of yet.
> 
> We can fix the use-after-free easily via lock, rcu and ..., but some
> cost has to pay. In this case, we can't wait too long in show_rq(),
> otherwise we may lose important debug info, so I do not have better
> way.
> 
> IMO this use-after-free is actually no harm, I don't think we have to
> fix it, but it should be better to not let utility warn on this case.

Fine, so lose the snide comment and set the cmnd to NULL *before*
calling free so we narrow the race window.

James

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[Ming Lei]

On Tue, Nov 14, 2017 at 10:14:52AM -0800, James Bottomley wrote:
> On Tue, 2017-11-14 at 08:55 +0800, Ming Lei wrote:
> > Hi James,
> > 
> > On Mon, Nov 13, 2017 at 10:55:52AM -0800, James Bottomley wrote:
> > > 
> > > On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> > > > 
> > > > So from CPU1's review, cmd->cmnd is in a remote NUMA node,
> > > > __scsi_format_command() is executed much slower than
> > > > mempool_free().
> > > > So when mempool_free() returns, __scsi_format_command() may not
> > > > fetched the buffer in L1 cache yet, then use-after-free
> > > > is still triggered.
> > > > 
> > > > That is why I say this use-after-free is inevitable no matter
> > > > 'setting SCpnt->cmnd to NULL before calling mempool_free()' or
> > > > not.
> > > 
> > > The bottom line is that there are several creative ways around this
> > > but the proposed code is currently broken and simply putting a
> > > comment in saying so doesn't make it acceptable.
> > 
> > As I explained above, I didn't see one really workable way. Or please
> > correct it if I am wrong.
> 
> I simply can't believe it's beyond the wit of man to solve a use after
> free race.  About 40% of kernel techniques are devoted to this.  All I
> really care about is not losing the PI information we previously had.
>  I agree with Bart that NULL cmnd is a good indicator, so it seems
> reasonable to use it.  If you have another mechanism, feel free to
> propose it.

Hi James,

This patch is my proposal, no others thought of yet.

We can fix the use-after-free easily via lock, rcu and ..., but some cost
has to pay. In this case, we can't wait too long in show_rq(), otherwise
we may lose important debug info, so I do not have better way.

IMO this use-after-free is actually no harm, I don't think we have to fix
it, but it should be better to not let utility warn on this case.


Thanks,
Ming

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[James Bottomley]

On Tue, 2017-11-14 at 08:55 +0800, Ming Lei wrote:
> Hi James,
> 
> On Mon, Nov 13, 2017 at 10:55:52AM -0800, James Bottomley wrote:
> > 
> > On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> > > 
> > > So from CPU1's review, cmd->cmnd is in a remote NUMA node,
> > > __scsi_format_command() is executed much slower than
> > > mempool_free().
> > > So when mempool_free() returns, __scsi_format_command() may not
> > > fetched the buffer in L1 cache yet, then use-after-free
> > > is still triggered.
> > > 
> > > That is why I say this use-after-free is inevitable no matter
> > > 'setting SCpnt->cmnd to NULL before calling mempool_free()' or
> > > not.
> > 
> > The bottom line is that there are several creative ways around this
> > but the proposed code is currently broken and simply putting a
> > comment in saying so doesn't make it acceptable.
> 
> As I explained above, I didn't see one really workable way. Or please
> correct it if I am wrong.

I simply can't believe it's beyond the wit of man to solve a use after
free race.  About 40% of kernel techniques are devoted to this.  All I
really care about is not losing the PI information we previously had.
 I agree with Bart that NULL cmnd is a good indicator, so it seems
reasonable to use it.  If you have another mechanism, feel free to
propose it.

James

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[Ming Lei]

Hi James,

On Mon, Nov 13, 2017 at 10:55:52AM -0800, James Bottomley wrote:
> On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> > On Fri, Nov 10, 2017 at 08:51:58AM -0800, James Bottomley wrote:
> > > 
> > > On Fri, 2017-11-10 at 17:01 +0800, Ming Lei wrote:
> > > > 
> > > > cmd->cmnd can be allocated/freed dynamically in case of
> > > > T10_PI_TYPE2_PROTECTION, so we should check it in scsi_show_rq()
> > > > because this request may have been freed already here, and cmd-
> > > > >cmnd has been set as null.
> > > > 
> > > > We choose to accept read-after-free and dump request data as far
> > > > as possible.
> > > > 
> > > > This patch fixs the following kernel crash when dumping request
> > > > via block's debugfs interface:
> > > > 
> > > > [  252.962045] BUG: unable to handle kernel NULL pointer
> > > > dereference
> > > > at   (null)
> > > > [  252.963007] IP: scsi_format_opcode_name+0x1a/0x1c0
> > > > [  252.963007] PGD 25e75a067 P4D 25e75a067 PUD 25e75b067 PMD 0
> > > > [  252.963007] Oops:  [#1] PREEMPT SMP
> > > > [  252.963007] Dumping ftrace buffer:
> > > > [  252.963007](ftrace buffer empty)
> > > > [  252.963007] Modules linked in: scsi_debug ebtable_filter
> > > > ebtables
> > > > ip6table_filter ip6_tables xt_CHECKSUM iptable_mangle
> > > > ipt_MASQUERADE
> > > > nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4
> > > > nf_defrag_ipv4
> > > > nf_nat_ipv4 nf_nat nf_conntrack libcrc32c bridge stp llc
> > > > iptable_filter fuse ip_tables sd_mod sg mptsas mptscsih mptbase
> > > > crc32c_intel ahci libahci nvme serio_raw scsi_transport_sas
> > > > libata
> > > > lpc_ich nvme_core virtio_scsi binfmt_misc dm_mod iscsi_tcp
> > > > libiscsi_tcp libiscsi scsi_transport_iscsi null_blk configs
> > > > [  252.963007] CPU: 1 PID: 1881 Comm: cat Not tainted 4.14.0-
> > > > rc2.blk_mq_io_hang+ #516
> > > > [  252.963007] Hardware name: QEMU Standard PC (Q35 + ICH9,
> > > > 2009),
> > > > BIOS 1.9.3-1.fc25 04/01/2014
> > > > [  252.963007] task: 88025e6f6000 task.stack:
> > > > c90001bd
> > > > [  252.963007] RIP: 0010:scsi_format_opcode_name+0x1a/0x1c0
> > > > [  252.963007] RSP: 0018:c90001bd3c50 EFLAGS: 00010286
> > > > [  252.963007] RAX: 4843 RBX: 0050 RCX:
> > > > 
> > > > [  252.963007] RDX:  RSI: 0050 RDI:
> > > > c90001bd3cd8
> > > > [  252.963007] RBP: c90001bd3c88 R08: 1000 R09:
> > > > 
> > > > [  252.963007] R10: 880275134000 R11: 88027513406c R12:
> > > > 0050
> > > > [  252.963007] R13: c90001bd3cd8 R14:  R15:
> > > > 
> > > > [  252.963007] FS:  7f4d11762700()
> > > > GS:88027fc4()
> > > > knlGS:
> > > > [  252.963007] CS:  0010 DS:  ES:  CR0: 80050033
> > > > [  252.963007] CR2:  CR3: 00025e789003 CR4:
> > > > 003606e0
> > > > [  252.963007] DR0:  DR1:  DR2:
> > > > 
> > > > [  252.963007] DR3:  DR6: fffe0ff0 DR7:
> > > > 0400
> > > > [  252.963007] Call Trace:
> > > > [  252.963007]  __scsi_format_command+0x27/0xc0
> > > > [  252.963007]  scsi_show_rq+0x5c/0xc0
> > > > [  252.963007]  ? seq_printf+0x4e/0x70
> > > > [  252.963007]  ? blk_flags_show+0x5b/0xf0
> > > > [  252.963007]  __blk_mq_debugfs_rq_show+0x116/0x130
> > > > [  252.963007]  blk_mq_debugfs_rq_show+0xe/0x10
> > > > [  252.963007]  seq_read+0xfe/0x3b0
> > > > [  252.963007]  ? __handle_mm_fault+0x631/0x1150
> > > > [  252.963007]  full_proxy_read+0x54/0x90
> > > > [  252.963007]  __vfs_read+0x37/0x160
> > > > [  252.963007]  ? security_file_permission+0x9b/0xc0
> > > > [  252.963007]  vfs_read+0x96/0x130
> > > > [  252.963007]  SyS_read+0x55/0xc0
> > > > [  252.963007]  entry_SYSCALL_64_fastpath+0x1a/0xa5
> > > > [  252.963007] RIP: 0033:0x7f4d1127e9b0
> > > > [  252.963007] RSP: 002b:7ffd27082568 EFLAGS: 0246
> > > > ORIG_RAX:
> > > > 
> > > > [  252.963007] RAX: ffda RBX: 7f4d1154bb20 RCX:
> > > > 7f4d1127e9b0
> > > > [  252.963007] RDX: 0002 RSI: 7f4d115a7000 RDI:
> > > > 0003
> > > > [  252.963007] RBP: 00021010 R08:  R09:
> > > > 
> > > > [  252.963007] R10: 037b R11: 0246 R12:
> > > > 00022000
> > > > [  252.963007] R13: 7f4d1154bb78 R14: 1000 R15:
> > > > 0002
> > > > [  252.963007] Code: c6 e8 1b ca 24 00 eb 8c e8 74 2c ae ff 0f 1f
> > > > 40
> > > > 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 41 54 53 49 89 fd 49 89
> > > > f4
> > > > 48 83 ec 18 <44> 0f b6 32 48 c7 45 c8 00 00 00 00 65 48 8b 04 25
> > > > 28
> > > > 00 00 00
> > > > [  252.963007] RIP: scsi_format_opcode_name+0x1a/0x1c0 RSP:
> > > > c90001bd3c50
> > > > [  252.963007] CR2: 
> > > > [  252.963007] ---[ end 

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[James Bottomley]

On Sat, 2017-11-11 at 10:43 +0800, Ming Lei wrote:
> On Fri, Nov 10, 2017 at 08:51:58AM -0800, James Bottomley wrote:
> > 
> > On Fri, 2017-11-10 at 17:01 +0800, Ming Lei wrote:
> > > 
> > > cmd->cmnd can be allocated/freed dynamically in case of
> > > T10_PI_TYPE2_PROTECTION, so we should check it in scsi_show_rq()
> > > because this request may have been freed already here, and cmd-
> > > >cmnd has been set as null.
> > > 
> > > We choose to accept read-after-free and dump request data as far
> > > as possible.
> > > 
> > > This patch fixs the following kernel crash when dumping request
> > > via block's debugfs interface:
> > > 
> > > [  252.962045] BUG: unable to handle kernel NULL pointer
> > > dereference
> > > at   (null)
> > > [  252.963007] IP: scsi_format_opcode_name+0x1a/0x1c0
> > > [  252.963007] PGD 25e75a067 P4D 25e75a067 PUD 25e75b067 PMD 0
> > > [  252.963007] Oops:  [#1] PREEMPT SMP
> > > [  252.963007] Dumping ftrace buffer:
> > > [  252.963007](ftrace buffer empty)
> > > [  252.963007] Modules linked in: scsi_debug ebtable_filter
> > > ebtables
> > > ip6table_filter ip6_tables xt_CHECKSUM iptable_mangle
> > > ipt_MASQUERADE
> > > nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4
> > > nf_defrag_ipv4
> > > nf_nat_ipv4 nf_nat nf_conntrack libcrc32c bridge stp llc
> > > iptable_filter fuse ip_tables sd_mod sg mptsas mptscsih mptbase
> > > crc32c_intel ahci libahci nvme serio_raw scsi_transport_sas
> > > libata
> > > lpc_ich nvme_core virtio_scsi binfmt_misc dm_mod iscsi_tcp
> > > libiscsi_tcp libiscsi scsi_transport_iscsi null_blk configs
> > > [  252.963007] CPU: 1 PID: 1881 Comm: cat Not tainted 4.14.0-
> > > rc2.blk_mq_io_hang+ #516
> > > [  252.963007] Hardware name: QEMU Standard PC (Q35 + ICH9,
> > > 2009),
> > > BIOS 1.9.3-1.fc25 04/01/2014
> > > [  252.963007] task: 88025e6f6000 task.stack:
> > > c90001bd
> > > [  252.963007] RIP: 0010:scsi_format_opcode_name+0x1a/0x1c0
> > > [  252.963007] RSP: 0018:c90001bd3c50 EFLAGS: 00010286
> > > [  252.963007] RAX: 4843 RBX: 0050 RCX:
> > > 
> > > [  252.963007] RDX:  RSI: 0050 RDI:
> > > c90001bd3cd8
> > > [  252.963007] RBP: c90001bd3c88 R08: 1000 R09:
> > > 
> > > [  252.963007] R10: 880275134000 R11: 88027513406c R12:
> > > 0050
> > > [  252.963007] R13: c90001bd3cd8 R14:  R15:
> > > 
> > > [  252.963007] FS:  7f4d11762700()
> > > GS:88027fc4()
> > > knlGS:
> > > [  252.963007] CS:  0010 DS:  ES:  CR0: 80050033
> > > [  252.963007] CR2:  CR3: 00025e789003 CR4:
> > > 003606e0
> > > [  252.963007] DR0:  DR1:  DR2:
> > > 
> > > [  252.963007] DR3:  DR6: fffe0ff0 DR7:
> > > 0400
> > > [  252.963007] Call Trace:
> > > [  252.963007]  __scsi_format_command+0x27/0xc0
> > > [  252.963007]  scsi_show_rq+0x5c/0xc0
> > > [  252.963007]  ? seq_printf+0x4e/0x70
> > > [  252.963007]  ? blk_flags_show+0x5b/0xf0
> > > [  252.963007]  __blk_mq_debugfs_rq_show+0x116/0x130
> > > [  252.963007]  blk_mq_debugfs_rq_show+0xe/0x10
> > > [  252.963007]  seq_read+0xfe/0x3b0
> > > [  252.963007]  ? __handle_mm_fault+0x631/0x1150
> > > [  252.963007]  full_proxy_read+0x54/0x90
> > > [  252.963007]  __vfs_read+0x37/0x160
> > > [  252.963007]  ? security_file_permission+0x9b/0xc0
> > > [  252.963007]  vfs_read+0x96/0x130
> > > [  252.963007]  SyS_read+0x55/0xc0
> > > [  252.963007]  entry_SYSCALL_64_fastpath+0x1a/0xa5
> > > [  252.963007] RIP: 0033:0x7f4d1127e9b0
> > > [  252.963007] RSP: 002b:7ffd27082568 EFLAGS: 0246
> > > ORIG_RAX:
> > > 
> > > [  252.963007] RAX: ffda RBX: 7f4d1154bb20 RCX:
> > > 7f4d1127e9b0
> > > [  252.963007] RDX: 0002 RSI: 7f4d115a7000 RDI:
> > > 0003
> > > [  252.963007] RBP: 00021010 R08:  R09:
> > > 
> > > [  252.963007] R10: 037b R11: 0246 R12:
> > > 00022000
> > > [  252.963007] R13: 7f4d1154bb78 R14: 1000 R15:
> > > 0002
> > > [  252.963007] Code: c6 e8 1b ca 24 00 eb 8c e8 74 2c ae ff 0f 1f
> > > 40
> > > 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 41 54 53 49 89 fd 49 89
> > > f4
> > > 48 83 ec 18 <44> 0f b6 32 48 c7 45 c8 00 00 00 00 65 48 8b 04 25
> > > 28
> > > 00 00 00
> > > [  252.963007] RIP: scsi_format_opcode_name+0x1a/0x1c0 RSP:
> > > c90001bd3c50
> > > [  252.963007] CR2: 
> > > [  252.963007] ---[ end trace 83c5bddfbaa6573c ]---
> > > [  252.963007] Kernel panic - not syncing: Fatal exception
> > > [  252.963007] Dumping ftrace buffer:
> > > [  252.963007](ftrace buffer empty)
> > > [  252.963007] Kernel Offset: disabled
> > > [  252.963007] ---[ end Kernel panic - not syncing: 

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[Ming Lei]

On Fri, Nov 10, 2017 at 08:51:58AM -0800, James Bottomley wrote:
> On Fri, 2017-11-10 at 17:01 +0800, Ming Lei wrote:
> > cmd->cmnd can be allocated/freed dynamically in case of
> > T10_PI_TYPE2_PROTECTION,
> > so we should check it in scsi_show_rq() because this request may have
> > been freed already here, and cmd->cmnd has been set as null.
> > 
> > We choose to accept read-after-free and dump request data as far as
> > possible.
> > 
> > This patch fixs the following kernel crash when dumping request via
> > block's
> > debugfs interface:
> > 
> > [  252.962045] BUG: unable to handle kernel NULL pointer dereference
> > at   (null)
> > [  252.963007] IP: scsi_format_opcode_name+0x1a/0x1c0
> > [  252.963007] PGD 25e75a067 P4D 25e75a067 PUD 25e75b067 PMD 0
> > [  252.963007] Oops:  [#1] PREEMPT SMP
> > [  252.963007] Dumping ftrace buffer:
> > [  252.963007](ftrace buffer empty)
> > [  252.963007] Modules linked in: scsi_debug ebtable_filter ebtables
> > ip6table_filter ip6_tables xt_CHECKSUM iptable_mangle ipt_MASQUERADE
> > nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4
> > nf_nat_ipv4 nf_nat nf_conntrack libcrc32c bridge stp llc
> > iptable_filter fuse ip_tables sd_mod sg mptsas mptscsih mptbase
> > crc32c_intel ahci libahci nvme serio_raw scsi_transport_sas libata
> > lpc_ich nvme_core virtio_scsi binfmt_misc dm_mod iscsi_tcp
> > libiscsi_tcp libiscsi scsi_transport_iscsi null_blk configs
> > [  252.963007] CPU: 1 PID: 1881 Comm: cat Not tainted 4.14.0-
> > rc2.blk_mq_io_hang+ #516
> > [  252.963007] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009),
> > BIOS 1.9.3-1.fc25 04/01/2014
> > [  252.963007] task: 88025e6f6000 task.stack: c90001bd
> > [  252.963007] RIP: 0010:scsi_format_opcode_name+0x1a/0x1c0
> > [  252.963007] RSP: 0018:c90001bd3c50 EFLAGS: 00010286
> > [  252.963007] RAX: 4843 RBX: 0050 RCX:
> > 
> > [  252.963007] RDX:  RSI: 0050 RDI:
> > c90001bd3cd8
> > [  252.963007] RBP: c90001bd3c88 R08: 1000 R09:
> > 
> > [  252.963007] R10: 880275134000 R11: 88027513406c R12:
> > 0050
> > [  252.963007] R13: c90001bd3cd8 R14:  R15:
> > 
> > [  252.963007] FS:  7f4d11762700() GS:88027fc4()
> > knlGS:
> > [  252.963007] CS:  0010 DS:  ES:  CR0: 80050033
> > [  252.963007] CR2:  CR3: 00025e789003 CR4:
> > 003606e0
> > [  252.963007] DR0:  DR1:  DR2:
> > 
> > [  252.963007] DR3:  DR6: fffe0ff0 DR7:
> > 0400
> > [  252.963007] Call Trace:
> > [  252.963007]  __scsi_format_command+0x27/0xc0
> > [  252.963007]  scsi_show_rq+0x5c/0xc0
> > [  252.963007]  ? seq_printf+0x4e/0x70
> > [  252.963007]  ? blk_flags_show+0x5b/0xf0
> > [  252.963007]  __blk_mq_debugfs_rq_show+0x116/0x130
> > [  252.963007]  blk_mq_debugfs_rq_show+0xe/0x10
> > [  252.963007]  seq_read+0xfe/0x3b0
> > [  252.963007]  ? __handle_mm_fault+0x631/0x1150
> > [  252.963007]  full_proxy_read+0x54/0x90
> > [  252.963007]  __vfs_read+0x37/0x160
> > [  252.963007]  ? security_file_permission+0x9b/0xc0
> > [  252.963007]  vfs_read+0x96/0x130
> > [  252.963007]  SyS_read+0x55/0xc0
> > [  252.963007]  entry_SYSCALL_64_fastpath+0x1a/0xa5
> > [  252.963007] RIP: 0033:0x7f4d1127e9b0
> > [  252.963007] RSP: 002b:7ffd27082568 EFLAGS: 0246 ORIG_RAX:
> > 
> > [  252.963007] RAX: ffda RBX: 7f4d1154bb20 RCX:
> > 7f4d1127e9b0
> > [  252.963007] RDX: 0002 RSI: 7f4d115a7000 RDI:
> > 0003
> > [  252.963007] RBP: 00021010 R08:  R09:
> > 
> > [  252.963007] R10: 037b R11: 0246 R12:
> > 00022000
> > [  252.963007] R13: 7f4d1154bb78 R14: 1000 R15:
> > 0002
> > [  252.963007] Code: c6 e8 1b ca 24 00 eb 8c e8 74 2c ae ff 0f 1f 40
> > 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 41 54 53 49 89 fd 49 89 f4
> > 48 83 ec 18 <44> 0f b6 32 48 c7 45 c8 00 00 00 00 65 48 8b 04 25 28
> > 00 00 00
> > [  252.963007] RIP: scsi_format_opcode_name+0x1a/0x1c0 RSP:
> > c90001bd3c50
> > [  252.963007] CR2: 
> > [  252.963007] ---[ end trace 83c5bddfbaa6573c ]---
> > [  252.963007] Kernel panic - not syncing: Fatal exception
> > [  252.963007] Dumping ftrace buffer:
> > [  252.963007](ftrace buffer empty)
> > [  252.963007] Kernel Offset: disabled
> > [  252.963007] ---[ end Kernel panic - not syncing: Fatal exception
> > 
> > Fixes: 0eebd005dd07(scsi: Implement blk_mq_ops.show_rq())
> > Cc: Bart Van Assche 
> > Cc: Omar Sandoval 
> > Cc: Martin K. Petersen 
> > Cc: James Bottomley 
> > Cc: Hannes Reinecke 

Re: [PATCH V4] scsi_debugfs: fix crash in scsi_show_rq()

[James Bottomley]

On Fri, 2017-11-10 at 17:01 +0800, Ming Lei wrote:
> cmd->cmnd can be allocated/freed dynamically in case of
> T10_PI_TYPE2_PROTECTION,
> so we should check it in scsi_show_rq() because this request may have
> been freed already here, and cmd->cmnd has been set as null.
> 
> We choose to accept read-after-free and dump request data as far as
> possible.
> 
> This patch fixs the following kernel crash when dumping request via
> block's
> debugfs interface:
> 
> [  252.962045] BUG: unable to handle kernel NULL pointer dereference
> at   (null)
> [  252.963007] IP: scsi_format_opcode_name+0x1a/0x1c0
> [  252.963007] PGD 25e75a067 P4D 25e75a067 PUD 25e75b067 PMD 0
> [  252.963007] Oops:  [#1] PREEMPT SMP
> [  252.963007] Dumping ftrace buffer:
> [  252.963007](ftrace buffer empty)
> [  252.963007] Modules linked in: scsi_debug ebtable_filter ebtables
> ip6table_filter ip6_tables xt_CHECKSUM iptable_mangle ipt_MASQUERADE
> nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4
> nf_nat_ipv4 nf_nat nf_conntrack libcrc32c bridge stp llc
> iptable_filter fuse ip_tables sd_mod sg mptsas mptscsih mptbase
> crc32c_intel ahci libahci nvme serio_raw scsi_transport_sas libata
> lpc_ich nvme_core virtio_scsi binfmt_misc dm_mod iscsi_tcp
> libiscsi_tcp libiscsi scsi_transport_iscsi null_blk configs
> [  252.963007] CPU: 1 PID: 1881 Comm: cat Not tainted 4.14.0-
> rc2.blk_mq_io_hang+ #516
> [  252.963007] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009),
> BIOS 1.9.3-1.fc25 04/01/2014
> [  252.963007] task: 88025e6f6000 task.stack: c90001bd
> [  252.963007] RIP: 0010:scsi_format_opcode_name+0x1a/0x1c0
> [  252.963007] RSP: 0018:c90001bd3c50 EFLAGS: 00010286
> [  252.963007] RAX: 4843 RBX: 0050 RCX:
> 
> [  252.963007] RDX:  RSI: 0050 RDI:
> c90001bd3cd8
> [  252.963007] RBP: c90001bd3c88 R08: 1000 R09:
> 
> [  252.963007] R10: 880275134000 R11: 88027513406c R12:
> 0050
> [  252.963007] R13: c90001bd3cd8 R14:  R15:
> 
> [  252.963007] FS:  7f4d11762700() GS:88027fc4()
> knlGS:
> [  252.963007] CS:  0010 DS:  ES:  CR0: 80050033
> [  252.963007] CR2:  CR3: 00025e789003 CR4:
> 003606e0
> [  252.963007] DR0:  DR1:  DR2:
> 
> [  252.963007] DR3:  DR6: fffe0ff0 DR7:
> 0400
> [  252.963007] Call Trace:
> [  252.963007]  __scsi_format_command+0x27/0xc0
> [  252.963007]  scsi_show_rq+0x5c/0xc0
> [  252.963007]  ? seq_printf+0x4e/0x70
> [  252.963007]  ? blk_flags_show+0x5b/0xf0
> [  252.963007]  __blk_mq_debugfs_rq_show+0x116/0x130
> [  252.963007]  blk_mq_debugfs_rq_show+0xe/0x10
> [  252.963007]  seq_read+0xfe/0x3b0
> [  252.963007]  ? __handle_mm_fault+0x631/0x1150
> [  252.963007]  full_proxy_read+0x54/0x90
> [  252.963007]  __vfs_read+0x37/0x160
> [  252.963007]  ? security_file_permission+0x9b/0xc0
> [  252.963007]  vfs_read+0x96/0x130
> [  252.963007]  SyS_read+0x55/0xc0
> [  252.963007]  entry_SYSCALL_64_fastpath+0x1a/0xa5
> [  252.963007] RIP: 0033:0x7f4d1127e9b0
> [  252.963007] RSP: 002b:7ffd27082568 EFLAGS: 0246 ORIG_RAX:
> 
> [  252.963007] RAX: ffda RBX: 7f4d1154bb20 RCX:
> 7f4d1127e9b0
> [  252.963007] RDX: 0002 RSI: 7f4d115a7000 RDI:
> 0003
> [  252.963007] RBP: 00021010 R08:  R09:
> 
> [  252.963007] R10: 037b R11: 0246 R12:
> 00022000
> [  252.963007] R13: 7f4d1154bb78 R14: 1000 R15:
> 0002
> [  252.963007] Code: c6 e8 1b ca 24 00 eb 8c e8 74 2c ae ff 0f 1f 40
> 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 41 54 53 49 89 fd 49 89 f4
> 48 83 ec 18 <44> 0f b6 32 48 c7 45 c8 00 00 00 00 65 48 8b 04 25 28
> 00 00 00
> [  252.963007] RIP: scsi_format_opcode_name+0x1a/0x1c0 RSP:
> c90001bd3c50
> [  252.963007] CR2: 
> [  252.963007] ---[ end trace 83c5bddfbaa6573c ]---
> [  252.963007] Kernel panic - not syncing: Fatal exception
> [  252.963007] Dumping ftrace buffer:
> [  252.963007](ftrace buffer empty)
> [  252.963007] Kernel Offset: disabled
> [  252.963007] ---[ end Kernel panic - not syncing: Fatal exception
> 
> Fixes: 0eebd005dd07(scsi: Implement blk_mq_ops.show_rq())
> Cc: Bart Van Assche 
> Cc: Omar Sandoval 
> Cc: Martin K. Petersen 
> Cc: James Bottomley 
> Cc: Hannes Reinecke 
> Signed-off-by: Ming Lei 
> ---
> V2:
>    - fix typo
> V3:
>    - prefer to dump data and accept read-after-free
>    - add some comment
> V4:
>    - read the two variable into local variable first, for avoiding
>   free between