[ata_port_probe] BUG: unable to handle kernel NULL pointer dereference at 0000000000000350
From: Fengguang Wu <hidden>
Date: 2017-11-21 12:09:51
Also in:
lkml, oe-lkp
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
Attachments
- dmesg-vm-intel12-yocto-x86_64-4:20171114101205:x86_64-randconfig-s3-11131952:4.14.0-00902-g43ff2f4:1 [text/plain] 68439 bytes · preview
- .config [text/plain] 103909 bytes · preview
- job-script [text/plain] 4092 bytes · preview
- reproduce-vm-intel12-yocto-x86_64-4:20171114101205:x86_64-randconfig-s3-11131952:4.14.0-00902-g43ff2f4:1 [text/plain] 2110 bytes · preview