[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20171121120935.t3ouyqq7byc5zd43@wfg-t540p.sh.intel.com>
Date: Tue, 21 Nov 2017 20:09:35 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: linux-ide@...r.kernel.org
Cc: Tejun Heo <tj@...nel.org>,
Linus Torvalds <torvalds@...ux-foundation.org>,
Geert Uytterhoeven <geert@...ux-m68k.org>,
Arnd Bergmann <arnd@...db.de>, linux-kernel@...r.kernel.org,
lkp@...org
Subject: [ata_port_probe] BUG: unable to handle kernel NULL pointer
dereference at 0000000000000350
Hello,
FYI this happens in mainline kernel 4.14.0-00902-g43ff2f4.
It looks happen since 4.11.
It occurs in 12 out of 108 boots.
[ 20.057810] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0c8 irq 15
[ 20.219346] ata2.01: NODEV after polling detection
[ 20.222140] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[ 20.232461] ata2.00: configured for MWDMA2
[ 20.235209] ata2.00: disabled
[ 20.247746] BUG: unable to handle kernel NULL pointer dereference at 0000000000000350
[ 20.250638] IP: ata_port_wait_eh+0xa1/0xe5:
ata_port_wait_eh at include/scsi/scsi_host.h:764
[ 20.251018] PGD 0 P4D 0
[ 20.251018] Oops: 0000 [#1] PREEMPT SMP
[ 20.255428] CPU: 1 PID: 5 Comm: kworker/u4:0 Not tainted 4.14.0-00902-g43ff2f4 #1
[ 20.255428] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 20.263368] scsi host0: ata_piix
[ 20.267396] Workqueue: events_unbound async_run_entry_fn
[ 20.270725] scsi host1: ata_piix
[ 20.271036] ata3: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc0c0 irq 14
[ 20.271039] ata4: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0c8 irq 15
[ 20.283654] Rounding down aligned max_sectors from 4294967295 to 4294967288
[ 20.298430] task: ffff8800001e6140 task.stack: ffff8800001e8000
[ 20.298430] RIP: 0010:ata_port_wait_eh+0xa1/0xe5:
ata_port_wait_eh at include/scsi/scsi_host.h:764
[ 20.298430] RSP: 0000:ffff8800001ebdc0 EFLAGS: 00010286
[ 20.304162] mtdoops: mtd device (mtddev=name/number) must be supplied
[ 20.304484] platform physmap-flash.0: failed to claim resource 0: [mem 0x08000000-0x07ffffff]
[ 20.305254] slram: not enough parameters.
[ 20.305257] Ramix PMC551 PCI Mezzanine Ram Driver. (C) 1999,2000 Nortel Networks.
[ 20.305263] pmc551: not detected
[ 20.327390] RAX: ffffffffffffffff RBX: ffff8800198a8000 RCX: ffff88001c80d8c0
[ 20.327390] RDX: 0000000000000000 RSI: 0000000000000003 RDI: 0000000000000246
[ 20.327390] RBP: 0000000000000246 R08: 0000000845a00e34 R09: 0000000000000000
[ 20.337395] R10: ffffffff95122ad0 R11: 0000000000000105 R12: ffff8800198ac008
[ 20.337395] R13: ffff880000081000 R14: 0000000000000000 R15: 0000000000000000
[ 20.347394] FS: 0000000000000000(0000) GS:ffff88001c800000(0000) knlGS:0000000000000000
[ 20.347394] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 20.357398] CR2: 0000000000000350 CR3: 000000001dc69000 CR4: 00000000000006a0
[ 20.357398] Call Trace:
[ 20.357398] ? __list_del_entry+0x1d/0x1d:
rcu_read_unlock at include/linux/rcupdate.h:686
__list_del_entry+0x1d/0x1d:
copy_siginfo at include/linux/signal.h:16
__list_del_entry+0x1d/0x1d:
worker_detach_from_pool at kernel/workqueue.c:1727
__list_del_entry+0x1d/0x1d:
kthread at kernel/kthread.c:190
__list_del_entry+0x1d/0x1d:
attach_task at kernel/sched/fair.c:7239
__list_del_entry+0x1d/0x1d:
rt_se_prio at kernel/sched/rt.c:891
__list_del_entry+0x1d/0x1d:
autoremove_wake_function at kernel/sched/wait.c:376
[ 20.357398] ata_port_probe+0x24/0x28:
ata_port_probe at drivers/ata/libata-core.c:6395
[ 20.367393] async_port_probe+0x2b/0x42:
async_port_probe at drivers/ata/libata-core.c:6415
[ 20.367393] async_run_entry_fn+0x35/0x105:
async_run_entry_fn at kernel/async.c:124
[ 20.367393] process_one_work+0x1c9/0x310:
process_one_work at kernel/workqueue.c:2113
[ 20.377388] ? process_one_work+0x15c/0x310:
process_one_work at kernel/workqueue.c:2084
[ 20.387386] worker_thread+0x1aa/0x25d:
worker_thread at include/linux/compiler.h:178
[ 20.397397] ? process_scheduled_works+0x27/0x27:
worker_thread at kernel/workqueue.c:2190
[ 20.397397] kthread+0xf1/0xf9:
kthread at kernel/kthread.c:233
[ 20.407398] ? __list_del_entry+0x1d/0x1d:
rcu_read_unlock at include/linux/rcupdate.h:686
__list_del_entry+0x1d/0x1d:
copy_siginfo at include/linux/signal.h:16
__list_del_entry+0x1d/0x1d:
worker_detach_from_pool at kernel/workqueue.c:1727
__list_del_entry+0x1d/0x1d:
kthread at kernel/kthread.c:190
__list_del_entry+0x1d/0x1d:
attach_task at kernel/sched/fair.c:7239
__list_del_entry+0x1d/0x1d:
rt_se_prio at kernel/sched/rt.c:891
__list_del_entry+0x1d/0x1d:
autoremove_wake_function at kernel/sched/wait.c:376
[ 20.407398] ret_from_fork+0x1f/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:443
[ 20.407398] Code: 7b 10 48 89 ee e8 ed f3 41 00 e8 55 be 41 00 eb cb 48 89 e6 4c 89 e7 e8 6e d2 9a ff 48 8b 7b 10 48 89 ee e8 cf f3 41 00 48 8b 13 <8b> 82 50 03 00 00 83 e8 05 83 f8 02 76 09 f6 82 00 03 00 00 40
[ 20.437384] RIP: ata_port_wait_eh+0xa1/0xe5:
ata_port_wait_eh at include/scsi/scsi_host.h:764 RSP: ffff8800001ebdc0
[ 20.447382] CR2: 0000000000000350
[ 20.447382] ---[ end trace 28c525956cf088e8 ]---
[ 20.447382] Kernel panic - not syncing: Fatal exception
Attached the full dmesg, kconfig and reproduce scripts.
In 4.11, it took different forms though:
/pkg/linux/x86_64-randconfig-a0-09172309/gcc-6/a351e9b9fc24e982ec2f0e76379a49826036da12/dmesg-vm-lkp-nhm-dp1-yocto-ia32-5:20170920183233:x86_64-randconfig-a0-09172309:4.11.0:1
[ 322.035010] ata2.00: configured for MWDMA2
[ 322.035723] ata2.00: disabled
[ 322.036259] sd 0:0:0:0: [sda] Attached SCSI disk
[ 322.038824] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 322.046217] ==================================================================
[ 322.046951] BUG: KASAN: slab-out-of-bounds in spin_dump+0x39/0x240 at addr ffff88000e84d238
[ 322.047779] Read of size 8 by task kworker/u4:0/5
[ 322.048271] CPU: 0 PID: 5 Comm: kworker/u4:0 Not tainted 4.11.0 #1
[ 322.048873] Workqueue: events_unbound async_run_entry_fn
[ 322.049399] Call Trace:
[ 322.049657] dump_stack+0xb3/0x10b
[ 322.050182] kasan_object_err+0x21/0x70
[ 322.050586] kasan_report+0x34a/0x500
[ 322.050959] ? spin_dump+0x39/0x240
[ 322.051319] ? usleep_range+0x124/0x160
[ 322.051702] __asan_report_load8_noabort+0x19/0x20
[ 322.052171] spin_dump+0x39/0x240
[ 322.052511] ? __wake_up_sync+0x20/0x20
[ 322.052899] do_raw_spin_lock+0x63/0x190
[ 322.053292] _raw_spin_lock_irqsave+0x37/0x40
[ 322.053729] ata_port_wait_eh+0x102/0x2d0
[ 322.053736] sd 0:0:0:0: [sda] 16384 512-byte logical blocks: (8.39 MB/8.00 MiB)
[ 322.054823] ? ata_scsi_cmd_error_handler+0x450/0x450
[ 322.055323] ? __wake_up_common+0x140/0x140
[ 322.055742] ? _raw_spin_unlock_irqrestore+0x41/0x60
[ 322.056240] ata_port_probe+0x7e/0xa0
[ 322.056605] async_port_probe+0xc1/0xe0
[ 322.056987] async_run_entry_fn+0x156/0x5a0
[ 322.057405] process_one_work+0x8c1/0xf60
[ 322.057801] ? finish_task_switch+0x440/0x500
[ 322.058232] worker_thread+0xb27/0xfc0
[ 322.058604] kthread+0x38a/0x3a0
[ 322.058927] ? process_one_work+0xf60/0xf60
[ 322.059381] ? kthread_delayed_work_timer_fn+0x280/0x280
[ 322.059553] sd 0:0:0:0: [sda] Write Protect is off
[ 322.059561] sd 0:0:0:0: [sda] Mode Sense: 73 00 10 08
[ 322.060850] ret_from_fork+0x31/0x40
[ 322.061203] Object at ffff88000e84d228, in cache kmalloc-8 size: 8
[ 322.061800] Allocated:
[ 322.062038] PID = 71
[ 322.062269] save_stack_trace+0x1b/0x20
[ 322.062647] save_stack+0x46/0xd0
[ 322.062978] kasan_kmalloc+0xb6/0xd0
[ 322.063338] kasan_slab_alloc+0x12/0x20
[ 322.063718] __kmalloc_track_caller+0x19c/0x280
[ 322.064161] kstrdup+0x3e/0x70
[ 322.064478] kstrdup_const+0x3e/0x50
[ 322.064835] kvasprintf_const+0x129/0x160
[ 322.065233] kobject_set_name_vargs+0x5a/0x130
[ 322.065670] device_create_groups_vargs+0x1b8/0x220
[ 322.066145] device_create+0xd8/0x100
[ 322.066519] bsg_register_queue+0x282/0x410
[ 322.066932] scsi_sysfs_add_sdev+0x307/0x540
[ 322.067356] do_scan_async+0x2d7/0x450
[ 322.067727] async_run_entry_fn+0x156/0x5a0
[ 322.068137] process_one_work+0x8c1/0xf60
[ 322.068537] worker_thread+0xb27/0xfc0
[ 322.068909] kthread+0x38a/0x3a0
[ 322.069235] ret_from_fork+0x31/0x40
[ 322.069588] Freed:
[ 322.069794] PID = 0
[ 322.070007] (stack is not available)
[ 322.070370] Memory state around the buggy address:
[ 322.070838] ffff88000e84d100: fc fb fc fc fb fc fc fb fc fc fb fc fc fb fc fc
/pkg/linux/x86_64-randconfig-a0-09172309/gcc-6/a351e9b9fc24e982ec2f0e76379a49826036da12/dmesg-vm-lkp-nhm-dp1-yocto-ia32-2:20170920165427:x86_64-randconfig-a0-09172309:4.11.0:1
[ 304.092431] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 304.104438] kasan: CONFIG_KASAN_INLINE enabled
[ 304.104800] sd 0:0:0:0: [sda] 16384 512-byte logical blocks: (8.39 MB/8.00 MiB)
[ 304.104880] scsi host1: ata_piix
[ 304.106268] kasan: GPF could be caused by NULL-ptr deref or user memory access
[ 304.107047] general protection fault: 0000 [#1] PREEMPT SMP KASAN
[ 304.107670] CPU: 0 PID: 5 Comm: kworker/u4:0 Not tainted 4.11.0 #1
[ 304.108295] Workqueue: events_unbound async_run_entry_fn
[ 304.108825] task: ffff88001448a3c0 task.stack: ffff880014498000
[ 304.109431] RIP: 0010:ata_port_wait_eh+0x226/0x2d0
[ 304.109905] RSP: 0000:ffff88001449fc40 EFLAGS: 00010206
[ 304.110438] RAX: 0000000000000047 RBX: ffff8800110c0000 RCX: dffffc0000000000
[ 304.111070] sd 0:0:0:0: [sda] Write Protect is off
[ 304.111078] sd 0:0:0:0: [sda] Mode Sense: 73 00 10 08
[ 304.111127] scsi host2: ata_piix
[ 304.111476] ata3: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc040 irq 14
[ 304.111480] ata4: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc048 irq 15
[ 304.113088] Error: Driver 'pata_platform' is already registered, aborting...
[ 304.114639] RDX: 0000000000000001 RSI: 0000000000000246 RDI: 0000000000000238
[ 304.115367] RBP: ffff88001449fd10 R08: ffff880014e228a0 R09: 0000000000000002
[ 304.116076] R10: ffffffff85007c38 R11: 0000000000000000 R12: ffffed0002218002
[ 304.116953] R13: ffff8800110c3850 R14: 0000000000000000 R15: 0000000000000246
[ 304.117670] FS: 0000000000000000(0000) GS:ffff880014e00000(0000) knlGS:0000000000000000
[ 304.118443] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 304.119008] CR2: 0000000000000000 CR3: 000000000500f000 CR4: 00000000000006b0
[ 304.119709] Call Trace:
[ 304.119963] ? ata_scsi_cmd_error_handler+0x450/0x450
[ 304.120470] ? __wake_up_common+0x140/0x140
[ 304.120892] ? _raw_spin_unlock_irqrestore+0x41/0x60
[ 304.121078] Rounding down aligned max_sectors from 4294967295 to 4294967288
[ 304.122051] ata_port_probe+0x7e/0xa0
[ 304.122414] async_port_probe+0xc1/0xe0
[ 304.122801] async_run_entry_fn+0x156/0x5a0
[ 304.123212] process_one_work+0x8c1/0xf60
[ 304.123606] ? finish_task_switch+0x440/0x500
[ 304.124046] worker_thread+0xb27/0xfc0
[ 304.124325] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
[ 304.125234] kthread+0x38a/0x3a0
[ 304.125558] ? process_one_work+0xf60/0xf60
[ 304.125977] ? kthread_delayed_work_timer_fn+0x280/0x280
[ 304.126496] ret_from_fork+0x31/0x40
[ 304.126888] Code: d8 48 c1 e8 03 80 3c 08 00 74 08 48 89 df e8 52 10 00 fe 4c 8b 33 48 8b 8d 50 ff ff ff 49 8d be 38 02 00 00 48 89 f8 48 c1 e8 03 <0f> b6 04 08 84 c0 74 09 3c 03 7f 05 e8 09 10 00 fe 41 8b 86 38
[ 304.128821] RIP: ata_port_wait_eh+0x226/0x2d0 RSP: ffff88001449fc40
[ 304.129532] ---[ end trace 43acb02bbae190ce ]---
[ 304.129996] Kernel panic - not syncing: Fatal exception
Thanks,
Fengguang
View attachment "dmesg-vm-intel12-yocto-x86_64-4:20171114101205:x86_64-randconfig-s3-11131952:4.14.0-00902-g43ff2f4:1" of type "text/plain" (68439 bytes)
View attachment ".config" of type "text/plain" (103909 bytes)
View attachment "job-script" of type "text/plain" (4092 bytes)
View attachment "reproduce-vm-intel12-yocto-x86_64-4:20171114101205:x86_64-randconfig-s3-11131952:4.14.0-00902-g43ff2f4:1" of type "text/plain" (2111 bytes)
Powered by blists - more mailing lists