------- Comment From dnban...@us.ibm.com 2018-04-24 10:52 EDT-------
<continuing from #169>
Obviously this corruption happened a while ago. I poked around a
bit to see if there is any smoking gun around but nothing that
meets the eye. Since we have been seeing all this in the context
of other qla2xxx issues (where there were trails), I tried to see
if we can find those actors here. And indeed they are in this
scene too:
PID: 1085 TASK: c000200e48e2e000 CPU: 94 COMMAND: "kworker/94:1"
#0 [c000200e48de7940] __schedule at c000000000d05d24
#1 [c000200e48de7a10] schedule at c000000000d065b0
#2 [c000200e48de7a30] schedule_timeout at c000000000d0b3d0
#3 [c000200e48de7b30] msleep at c0000000001b5e2c
#4 [c000200e48de7b60] qlt_free_session_done at c00800000ef1faf0 [qla2xxx]
#5 [c000200e48de7c90] process_one_work at c000000000132bd8
#6 [c000200e48de7d20] worker_thread at c000000000132f78
#7 [c000200e48de7dc0] kthread at c00000000013bba8
#8 [c000200e48de7e30] ret_from_kernel_thread at c00000000000b528
PID: 1750 TASK: c000200e4daf3c00 CPU: 94 COMMAND: "kworker/94:2"
#0 [c000200e4db17940] __schedule at c000000000d05d24
#1 [c000200e4db17a10] schedule at c000000000d065b0
#2 [c000200e4db17a30] schedule_timeout at c000000000d0b3d0
#3 [c000200e4db17b30] msleep at c0000000001b5e2c
#4 [c000200e4db17b60] qlt_free_session_done at c00800000ef1faf0 [qla2xxx]
#5 [c000200e4db17c90] process_one_work at c000000000132bd8
#6 [c000200e4db17d20] worker_thread at c000000000132f78
#7 [c000200e4db17dc0] kthread at c00000000013bba8
#8 [c000200e4db17e30] ret_from_kernel_thread at c00000000000b528
PID: 3937 TASK: c000200e3b1a3f00 CPU: 94 COMMAND: "kworker/94:3"
#0 [c000200e3b2f3940] __schedule at c000000000d05d24
#1 [c000200e3b2f3a10] schedule at c000000000d065b0
#2 [c000200e3b2f3a30] schedule_timeout at c000000000d0b3d0
#3 [c000200e3b2f3b30] msleep at c0000000001b5e2c
#4 [c000200e3b2f3b60] qlt_free_session_done at c00800000ef1faf0 [qla2xxx]
#5 [c000200e3b2f3c90] process_one_work at c000000000132bd8
#6 [c000200e3b2f3d20] worker_thread at c000000000132f78
#7 [c000200e3b2f3dc0] kthread at c00000000013bba8
#8 [c000200e3b2f3e30] ret_from_kernel_thread at c00000000000b528
While they are all sleeping on cpu 94's worker threads, they do
belong to different fc_ports. However, their existence and
their propensity to cause issues because of the way they can be
scheduled does give pause for thought.
While I didn't want to be tunnel visioned w.r.t. free_work/del_work
issues we have seen elsewhere for qla2xxx, I did want to include
the information for completeness. And also, we haven't seen this
with the patch encoding the initial expt w.r.t (free_/del_)work
described in #132.
I then decided to take a look at the bug again, back in history.
And then this thing caught my eye! It was captured in a log by
Indira.
[31751.586142] Sending NMI from CPU 104 to CPUs 1:
[31751.586257] NMI backtrace for cpu 1
[31751.586260] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.15.0-15-generic
#16-Ubuntu
[31751.586262] NIP: c0000000000a40b4 LR: c0000000000a40b4 CTR: c000000000008000
[31751.586264] REGS: c000000ff91bbc40 TRAP: 0100 Not tainted
(4.15.0-15-generic)
[31751.586265] MSR: 9000000000001033 <SF,HV,ME,IR,DR,RI,LE> CR: 24004482
XER: 00000000
[31751.586270] CFAR: c000000ff91bbda0 SOFTE: -4611685949823549440
[31751.586270] GPR00: c0000000000a40b4 c000000ff91bbda0 c0000000016eb400
c000000ff91bbc40
[31751.586270] GPR04: b000000000cpu 0x79: Vector: 700 (Program Check) at
[c000200e5831b450]
pc: c00000000038ba38: kmem_cache_free+0xc8/0x2b0
lr: c0000000002dfd4c: mempool_free_slab+0x2c/0x40
sp: c000200e5831b6d0
msr: 9000000000029033
current = 0xc000200e58205c00
paca = 0xc000000007a73300 softe: 0 irq_happened: 0x01
pid = 0, comm = swapper/121
kernel BUG at /build/linux-QzAGR9/linux-4.15.0/mm/slub.c:296!
Linux version 4.15.0-15-generic (buildd@bos02-ppc64el-002) (gcc version 7.3.0
(Ubuntu 7.3.0-14ubuntu1)) #16-Ubuntu SMP Wed Apr 4 13:57:51 UTC 2018 (Ubuntu
4.15.0-15.16-generic 4.15.15)
cpu 0x9: Vector: 100 (System Reset) at [c000000007f39d80]
pc: c0000000000ed874: kvmppc_got_guest+0x1cc/0x380
lr: c0000000000ed7f0: kvmppc_got_guest+0x148/0x380
sp: c00000042754f4d0
msr: 9000000102883003
current = 0xc0000003a3e87300
paca = 0xc000000007a26300 softe: 0 irq_happened: 0x01
pid = 33539, comm = CPU 3/KVM
Linux version 4.15.0-15-generic (buildd@bos02-ppc64el-002) (gcc version 7.3.0
(Ubuntu 7.3.0-14ubuntu1)) #16-Ubuntu SMP Wed Apr 4 13:57:51 UTC 2018 (Ubuntu
4.15.0-15.16-generic 4.15.15)
cpu 0x22: Vector: 100 (System Reset) at [c000000007e0dd80]
pc: c0000000000eddb8: mc_cont+0x38/0x13c
lr: c0000000000ee5b0: hcall_try_real_mode+0x60/0x7c
sp: c0000004275374d0
msr: 9000000000081033
current = 0xc0000003a3eb8100
paca = 0xc000000007a37600 softe: 0 irq_happened: 0x01
pid = 33540, comm = CPU 4/KVM
Linux version 4.15.0-15-generic (buildd@bos02-ppc64el-002) (gcc version 7.3.0
(Ubuntu 7.3.0-14ubuntu1)) #16-Ubuntu SMP Wed Apr 4 13:57:51 UTC 2018 (Ubuntu
4.15.0-15.16-generic 4.15.15)
cpu 0x31: Vector: 100 (System Reset) at [c000000007d59d80]
pc: c0000000000ed8a8: kvmppc_got_guest+0x200/0x380
lr: c0000000000ed7f0: kvmppc_got_guest+0x148/0x380
sp: c00000048c9c34d0
msr: 9000000102883003
current = 0xc000000429a12b00
paca = 0xc000000007a41b00 softe: 0 irq_happened: 0x01
pid = 33549, comm = CPU 13/KVM
Linux version 4.15.0-15-generic (buildd@bos02-ppc64el-002) (gcc version 7.3.0
(Ubuntu 7.3.0-14ubuntu1)) #16-Ubuntu SMP Wed Apr 4 13:57:51 UTC 2018 (Ubuntu
4.15.0-15.16-generic 4.15.15)
enter ? for help
[c000200e5831b750] c0000000002dfd4c mempool_free_slab+0x2c/0x40
[c000200e5831b770] c0000000002dfc2c mempool_free+0x5c/0x110
[c000200e5831b7b0] c00800000ee9f2c0 qla2x00_sp_free+0x78/0xa0 [qla2xxx]
[c000200e5831b7e0] c00800000ee9f200 qla2x00_sp_timeout+0x98/0xe0 [qla2xxx]
[c000200e5831b820] c0000000001b46b0 call_timer_fn+0x50/0x1c0
[c000200e5831b8a0] c0000000001b4958 expire_timers+0x138/0x1f0
[c000200e5831b910] c0000000001b4b18 run_timer_softirq+0x108/0x270
[c000200e5831b9b0] c000000000d0d6c8 __do_softirq+0x158/0x3e4
[c000200e5831ba90] c000000000114be8 irq_exit+0xe8/0x120
[c000200e5831bab0] c000000000024d0c timer_interrupt+0x9c/0xe0
[c000200e5831bae0] c000000000009014 decrementer_common+0x114/0x120
--- Exception: 901 (Decrementer) at c00000000000a724
replay_interrupt_return+0x0/0x4
[link register ] c000000000016e74 arch_local_irq_restore+0x74/0x90
[c000200e5831bdd0] 0000000000000079 (unreliable)
[c000200e5831bdf0] c000000000acf0b0 cpuidle_enter_state+0xf0/0x450
[c000200e5831be50] c00000000017239c call_cpuidle+0x4c/0x90
[c000200e5831be70] c0000000001727b0 do_idle+0x2b0/0x330
[c000200e5831bec0] c000000000172a68 cpu_startup_entry+0x38/0x50
[c000200e5831bef0] c000000000049db0 start_secondary+0x4f0/0x510
[c000200e5831bf90] c00000000000aa6c start_secondary_prolog+0x10/0x14
And the trap happened because of the following:
BUG_ON(object == fp); /* naive detection of double free or corruption */
So qla2x00_sp_timeout
-> qla2x00_sp_free
-> qla2x00_rel_sp
-> mempool_free(sp, sp->vha->hw->srb_mempool)
has a double free problem!!!
The sp (i.e. srb_t) double free will likely corrupt the
corresponding kmem cache.
It is easy to think of a scenario:
-- T1 frees sp
-- T2 thinks sp is valid and performs operations on it say
increment by 1
-- T2 tries to free sp (double free) and CRASH!
qla2x00_get_sp
-> sp = mempool_alloc(vha->hw->srb_mempool, flag)
qla2x00_mem_alloc
-> ha->srb_mempool = mempool_create_slab_pool(SRB_MIN_REQ, srb_cachep)
In cases where this kind of execution goes untrapped. We were
extremely lucky to get this break in #25 where the new free matched
the free head, i.e. it was barely released. Had slub debug been ON
at that time and we had a dump/log we likely would have info about
who had released it. this will effectively corrupt the freelist
just as we observed in this crash.
>From the code it looks like the sp is allocated & the timer started
for several operations with generally similar formats. Example:
qla2x00_async_login
sp = qla2x00_get_sp(vha, fcport, GFP_KERNEL)
-> sp = mempool_alloc(vha->hw->srb_mempool, flag
sp->type = SRB_LOGIN_CMD
sp->name = "login";
qla2x00_init_timer(sp, qla2x00_get_async_timeout(vha) + 2);
lio = &sp->u.iocb_cmd;
lio->timeout = qla2x00_async_iocb_timeout;
sp->done = qla2x00_async_login_sp_done
rval = qla2x00_start_sp(sp)
return rval
if error
sp->free(sp)
return rval
It'd appear that there is at least one scenario where the timer is
started for an operation and after that for whatever reason the
sp is freed. When the timer pops, it deletes the timer entry
and tries to free the (already freed) sp and crashes.
Unfortunately, the instance in #25 didn't capture enough data
to point to the parallel path.
------- Comment From dnban...@us.ibm.com 2018-04-24 10:57 EDT-------
At this point, I decided to search to see if any double free issues
have been observed for this driver (possibly for this structure
srb_t i.e. sp) and came across the following.
commit eaf75d1815dad230dac2f1e8f1dc0349b2d50071
Author: Quinn Tran <quinn.t...@cavium.com>
Date: Thu Feb 1 10:33:17 2018 -0800
scsi: qla2xxx: Fix double free bug after firmware timeout
This patch is based on Max's original patch.
When the qla2xxx firmware is unavailable, eventually
qla2x00_sp_timeout() is reached, which calls the timeout function and
frees the srb_t instance.
The timeout function always resolves to qla2x00_async_iocb_timeout(),
which invokes another callback function called "done". All of these
qla2x00_*_sp_done() callbacks also free the srb_t instance; after
returning to qla2x00_sp_timeout(), it is freed again.
The fix is to remove the "sp->free(sp)" call from qla2x00_sp_timeout()
and add it to those code paths in qla2x00_async_iocb_timeout() which
do not already free the object.
This is how it looks like with KASAN:
BUG: KASAN: use-after-free in qla2x00_sp_timeout+0x228/0x250
Read of size 8 at addr ffff88278147a590 by task swapper/2/0
Allocated by task 1502:
save_stack+0x33/0xa0
kasan_kmalloc+0xa0/0xd0
kmem_cache_alloc+0xb8/0x1c0
mempool_alloc+0xd6/0x260
qla24xx_async_gnl+0x3c5/0x1100
Freed by task 0:
save_stack+0x33/0xa0
kasan_slab_free+0x72/0xc0
kmem_cache_free+0x75/0x200
qla24xx_async_gnl_sp_done+0x556/0x9e0
qla2x00_async_iocb_timeout+0x1c7/0x420
qla2x00_sp_timeout+0x16d/0x250
call_timer_fn+0x36/0x200
The buggy address belongs to the object at ffff88278147a440
which belongs to the cache qla2xxx_srbs of size 344
The buggy address is located 336 bytes inside of
344-byte region [ffff88278147a440, ffff88278147a598)
Reported-by: Max Kellermann <m...@cm4all.com>
Signed-off-by: Quinn Tran <quinn.t...@cavium.com>
Signed-off-by: Himanshu Madhani <himanshu.madh...@cavium.com>
Cc: Max Kellermann <m...@cm4all.com>
Signed-off-by: Martin K. Petersen <martin.peter...@oracle.com>
diff --git a/drivers/scsi/qla2xxx/qla_init.c b/drivers/scsi/qla2xxx/qla_init.c
index aececf66..2dea112 100644
--- a/drivers/scsi/qla2xxx/qla_init.c
+++ b/drivers/scsi/qla2xxx/qla_init.c
@@ -59,8 +59,6 @@ static void qla24xx_handle_prli_done_event(struct
scsi_qla_host *,
req->outstanding_cmds[sp->handle] = NULL;
iocb = &sp->u.iocb_cmd;
iocb->timeout(sp);
- if (sp->type != SRB_ELS_DCMD)
- sp->free(sp);
spin_unlock_irqrestore(&vha->hw->hardware_lock, flags);
}
@@ -102,7 +100,6 @@ static void qla24xx_handle_prli_done_event(struct
scsi_qla_host *,
srb_t *sp = data;
fc_port_t *fcport = sp->fcport;
struct srb_iocb *lio = &sp->u.iocb_cmd;
- struct event_arg ea;
if (fcport) {
ql_dbg(ql_dbg_disc, fcport->vha, 0x2071,
@@ -117,25 +114,13 @@ static void qla24xx_handle_prli_done_event(struct
scsi_qla_host *,
switch (sp->type) {
case SRB_LOGIN_CMD:
- if (!fcport)
- break;
/* Retry as needed. */
lio->u.logio.data[0] = MBS_COMMAND_ERROR;
lio->u.logio.data[1] = lio->u.logio.flags & SRB_LOGIN_RETRIED ?
QLA_LOGIO_LOGIN_RETRIED : 0;
- memset(&ea, 0, sizeof(ea));
- ea.event = FCME_PLOGI_DONE;
- ea.fcport = sp->fcport;
- ea.data[0] = lio->u.logio.data[0];
- ea.data[1] = lio->u.logio.data[1];
- ea.sp = sp;
- qla24xx_handle_plogi_done_event(fcport->vha, &ea);
+ sp->done(sp, QLA_FUNCTION_TIMEOUT);
break;
case SRB_LOGOUT_CMD:
- if (!fcport)
- break;
- qlt_logo_completion_handler(fcport, QLA_FUNCTION_TIMEOUT);
- break;
case SRB_CT_PTHRU_CMD:
case SRB_MB_IOCB:
case SRB_NACK_PLOGI:
@@ -235,12 +220,10 @@ static void qla24xx_handle_prli_done_event(struct
scsi_qla_host *,
qla2x00_async_logout_sp_done(void *ptr, int res)
{
srb_t *sp = ptr;
- struct srb_iocb *lio = &sp->u.iocb_cmd;
sp->fcport->flags &= ~(FCF_ASYNC_SENT | FCF_ASYNC_ACTIVE);
- if (!test_bit(UNLOADING, &sp->vha->dpc_flags))
- qla2x00_post_async_logout_done_work(sp->vha, sp->fcport,
- lio->u.logio.data);
+ sp->fcport->login_gen++;
+ qlt_logo_completion_handler(sp->fcport, res);
sp->free(sp);
}
This patch needs to be pulled in too to address the double free issue we have
seen. One can hope that this (and the others) will cover the kmem cache
corruption we have seen as well since such kmem cache corruption can
clearly be a consequence of data access after free and double free.
--
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to linux in Ubuntu.
https://bugs.launchpad.net/bugs/1762844
Title:
ISST-LTE:KVM:Ubuntu1804:BostonLC:boslcp3: Host crashed & enters into
xmon after moving to 4.15.0-15.16 kernel
Status in The Ubuntu-power-systems project:
Incomplete
Status in linux package in Ubuntu:
Incomplete
Status in linux source package in Bionic:
Incomplete
Bug description:
Problem Description:
===================
Host crashed & enters into xmon after updating to 4.15.0-15.16 kernel kernel.
Steps to re-create:
==================
1. boslcp3 is up with BMC:118 & PNOR: 20180330 levels
2. Installed boslcp3 with latest kernel
4.15.0-13-generic
3. Enabled "-proposed" kernel in /etc/apt/sources.list file
4. Ran sudo apt-get update & apt-get upgrade
5. root@boslcp3:~# ls /boot
abi-4.15.0-13-generic retpoline-4.15.0-13-generic
abi-4.15.0-15-generic retpoline-4.15.0-15-generic
config-4.15.0-13-generic System.map-4.15.0-13-generic
config-4.15.0-15-generic System.map-4.15.0-15-generic
grub vmlinux
initrd.img vmlinux-4.15.0-13-generic
initrd.img-4.15.0-13-generic vmlinux-4.15.0-15-generic
initrd.img-4.15.0-15-generic vmlinux.old
initrd.img.old
6. Rebooted & booted with 4.15.0-15 kernel
7. Enabled xmon by editing file "vi /etc/default/grub" and ran update-grub
8. Rebooted host.
9. Booted with 4.15.0-15 & provided root/password credentials in login
prompt
10. Host crashed & enters into XMON state with 'Unable to handle
kernel paging request'
root@boslcp3:~# [ 66.295233] Unable to handle kernel paging request for
data at address 0x8882f6ed90e9151a
[ 66.295297] Faulting instruction address: 0xc00000000038a110
cpu 0x50: Vector: 380 (Data Access Out of Range) at [c00000000692f650]
pc: c00000000038a110: kmem_cache_alloc_node+0x2f0/0x350
lr: c00000000038a0fc: kmem_cache_alloc_node+0x2dc/0x350
sp: c00000000692f8d0
msr: 9000000000009033
dar: 8882f6ed90e9151a
current = 0xc00000000698fd00
paca = 0xc00000000fab7000 softe: 0 irq_happened: 0x01
pid = 1762, comm = systemd-journal
Linux version 4.15.0-15-generic (buildd@bos02-ppc64el-002) (gcc version 7.3.0
(Ubuntu 7.3.0-14ubuntu1)) #16-Ubuntu SMP Wed Apr 4 13:57:51 UTC 2018 (Ubuntu
4.15.0-15.16-generic 4.15.15)
enter ? for help
[c00000000692f8d0] c000000000389fd4 kmem_cache_alloc_node+0x1b4/0x350
(unreliable)
[c00000000692f940] c000000000b2ec6c __alloc_skb+0x6c/0x220
[c00000000692f9a0] c000000000b30b6c alloc_skb_with_frags+0x7c/0x2e0
[c00000000692fa30] c000000000b247cc sock_alloc_send_pskb+0x29c/0x2c0
[c00000000692fae0] c000000000c5705c unix_dgram_sendmsg+0x15c/0x8f0
[c00000000692fbc0] c000000000b1ec64 sock_sendmsg+0x64/0x90
[c00000000692fbf0] c000000000b20abc ___sys_sendmsg+0x31c/0x390
[c00000000692fd90] c000000000b221ec __sys_sendmsg+0x5c/0xc0
[c00000000692fe30] c00000000000b184 system_call+0x58/0x6c
--- Exception: c00 (System Call) at 000074826f6fa9c4
SP (7ffff5dc5510) is in userspace
50:mon>
50:mon>
10. Attached Host console logs
I rebooted the host just to see if it would hit the issue again and
this time I didn't even get to the login prompt but it crashed in the
same location:
50:mon> r
R00 = c000000000389fd4 R16 = c000200e0b20fdc0
R01 = c000200e0b20f8d0 R17 = 0000000000000048
R02 = c0000000016eb400 R18 = 000000000001fe80
R03 = 0000000000000001 R19 = 0000000000000000
R04 = 0048ca1cff37803d R20 = 0000000000000000
R05 = 0000000000000688 R21 = 0000000000000000
R06 = 0000000000000001 R22 = 0000000000000048
R07 = 0000000000000687 R23 = 4882d6e3c8b7ab55
R08 = 48ca1cff37802b68 R24 = c000200e5851df01
R09 = 0000000000000000 R25 = 8882f6ed90e67454
R10 = 0000000000000000 R26 = c000000000b2ec6c
R11 = c000000000d10f78 R27 = c000000ff901ee00
R12 = 0000000000002000 R28 = ffffffffffffffff
R13 = c00000000fab7000 R29 = 00000000015004c0
R14 = c000200e4c973fc8 R30 = c000200e5851df01
R15 = c000200e4c974238 R31 = c000000ff901ee00
pc = c00000000038a110 kmem_cache_alloc_node+0x2f0/0x350
cfar= c000000000016e1c arch_local_irq_restore+0x1c/0x90
lr = c00000000038a0fc kmem_cache_alloc_node+0x2dc/0x350
msr = 9000000000009033 cr = 28002844
ctr = c00000000061e1b0 xer = 0000000000000000 trap = 380
dar = 8882f6ed90e67454 dsisr = c000200e40bd8400
50:mon> t
[c000200e0b20f8d0] c000000000389fd4 kmem_cache_alloc_node+0x1b4/0x350
(unreliable)
[c000200e0b20f940] c000000000b2ec6c __alloc_skb+0x6c/0x220
[c000200e0b20f9a0] c000000000b30b6c alloc_skb_with_frags+0x7c/0x2e0
[c000200e0b20fa30] c000000000b247cc sock_alloc_send_pskb+0x29c/0x2c0
[c000200e0b20fae0] c000000000c56ae4 unix_stream_sendmsg+0x264/0x5c0
[c000200e0b20fbc0] c000000000b1ec64 sock_sendmsg+0x64/0x90
[c000200e0b20fbf0] c000000000b20abc ___sys_sendmsg+0x31c/0x390
[c000200e0b20fd90] c000000000b221ec __sys_sendmsg+0x5c/0xc0
[c000200e0b20fe30] c00000000000b184 system_call+0x58/0x6c
--- Exception: c01 (System Call) at 00007d16a993a940
SP (7ffffbee2270) is in userspace
Mirroring to Canonical to advise them that this might be possible
regression. Didn't see any obvious changes in this area in the
changelog published at
https://launchpad.net/ubuntu/+source/linux/4.15.0-15.16 but it would
be good to have Canonical help reviewing the deltas as we try to
isolate this further.
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-power-systems/+bug/1762844/+subscriptions
--
Mailing list: https://launchpad.net/~kernel-packages
Post to : kernel-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~kernel-packages
More help : https://help.launchpad.net/ListHelp
