Kernel Oops: BUG: unable to handle kernel NULL pointer dereference at 0000000000000050; IP is at blk_mq_poll+0xa0/0x2e0

[Stephen Bates]

Hi All

As part of my testing of IO polling [1] I am seeing a NULL pointer dereference oops that seems to have been introduced in the preparation for 4.11. The kernel oops output is below and this seems to be due to blk_mq_tag_to_rq returning NULL in blk_mq_poll in blk-mq.c. I have not had a chance to bisect this down to a single commit yet but the same test works fine in 4.10 but not in 4.11-rc6. I will try and get a better bisect and send on more information when I get it. 

I am running the following simple shell script which always triggers the Oops. Note this script needs some tweaking to work on 4.11 and earlier since the some things were moved from sysfs to debugfs in the 4.11 and 4.12 trees.

#!/bin/bash
BLOCK=nvme1n1
DEV=/dev/${BLOCK}

echo "Testing polling on ${DEV}"

# Display the inital polling settings for this device...

cat /sys/block/${BLOCK}/queue/io_poll
cat /sys/block/${BLOCK}/queue/io_poll_delay

# Display the polling results and stats

cat /sys/kernel/debug/block/${BLOCK}/mq/poll_stat
cat /sys/kernel/debug/block/${BLOCK}/mq/0/io_poll

# Now do some polling IO against the block device in question.

fio --filename=${DEV} --size=100% --numjobs=1 --iodepth=1 \
    --bs=4k --number_ios=1k --runtime=60 --ioengine=pvsync2 --hipri \
    --rw=randrw --random_generator=lfsr --direct=1 --group_reporting=1 \
    --rwmixread=100 --loops=1 --name poll.fio

# Display the polling results and stats

cat /sys/kernel/debug/block/${BLOCK}/mq/poll_stat
cat /sys/kernel/debug/block/${BLOCK}/mq/0/io_poll

[   26.024529] BUG: unable to handle kernel NULL pointer dereference at 0000000000000050
[   26.027167] IP: blk_mq_poll+0xa0/0x2e0
[   26.027326] PGD 7ad51067 
[   26.027584] PUD 7adbe067 
[   26.028006] PMD 0 
[   26.028234] 
[   26.029319] Oops: 0000 [#1] SMP
[   26.030405] CPU: 0 PID: 1474 Comm: fio Not tainted 4.11.0-rc6 #42
[   26.031678] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.7.5-0-ge51488c-20140602_164612-nilsson.home.kraxel.org 04/01/2014
[   26.033749] task: ffff88007cf75a00 task.stack: ffffc9000069c000
[   26.034575] RIP: 0010:blk_mq_poll+0xa0/0x2e0
[   26.035234] RSP: 0018:ffffc9000069fa38 EFLAGS: 00000216
[   26.036269] RAX: ffff88007c5d5000 RBX: 0000000000000000 RCX: 0000000000000000
[   26.037330] RDX: ffff88007c56d1e8 RSI: 00000000000000a7 RDI: 0000000000000000
[   26.039285] RBP: ffffc9000069fad0 R08: 0000000000000000 R09: 00000000800000a7
[   26.040962] R10: ffffc9000069faa0 R11: 0000000000001000 R12: ffff88007c561fe0
[   26.042005] R13: ffffc9000069fd01 R14: ffff88007d3f8a98 R15: ffff88007c772800
[   26.043734] FS:  00007f8808d7c580(0000) GS:ffff88007fc00000(0000) knlGS:0000000000000000
[   26.045366] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   26.047239] CR2: 0000000000000050 CR3: 000000007ad4d000 CR4: 00000000000006f0
[   26.048801] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   26.049898] DR3: 0000000000000000 DR6: 0000000000000000 DR7: 0000000000000000
[   26.051300] Call Trace:
[   26.052580]  ? generic_make_request+0xfb/0x2a0
[   26.053869]  ? submit_bio+0x64/0x120
[   26.054123]  ? submit_bio+0x64/0x120
[   26.054989]  __blkdev_direct_IO_simple+0x1bc/0x2f0
[   26.055978]  ? __d_lookup_done+0x79/0xe0
[   26.057009]  ? blkdev_fsync+0x50/0x50
[   26.058382]  blkdev_direct_IO+0x37d/0x390
[   26.059320]  ? blkdev_direct_IO+0x37d/0x390
[   26.059939]  generic_file_read_iter+0x2c2/0x8c0
[   26.060488]  ? generic_file_read_iter+0x2c2/0x8c0
[   26.060656]  ? path_openat+0x6e4/0x1320
[   26.060910]  blkdev_read_iter+0x35/0x40
[   26.061430]  __do_readv_writev+0x1ef/0x3b0
[   26.061609]  do_readv_writev+0x7d/0xb0
[   26.062629]  ? handle_mm_fault+0x88/0x150
[   26.062895]  vfs_readv+0x39/0x50
[   26.063291]  ? vfs_readv+0x39/0x50
[   26.063666]  do_preadv+0xb1/0xd0
[   26.063975]  SyS_preadv2+0x17/0x30
[   26.064175]  entry_SYSCALL_64_fastpath+0x1a/0xa9
[   26.064682] RIP: 0033:0x7f88064e30f9
[   26.064875] RSP: 002b:00007fff74a1b4f8 EFLAGS: 00000202 ORIG_RAX: 0000000000000147
[   26.065538] RAX: ffffffffffffffda RBX: 0000000002413500 RCX: 00007f88064e30f9
[   26.066274] RDX: 0000000000000001 RSI: 000000000240d770 RDI: 0000000000000003
[   26.066701] RBP: 00007f87eebb8000 R08: 0000000000000000 R09: 0000000000000001
[   26.066868] R10: 00000000266fb000 R11: 0000000000000202 R12: 0000000000000000
[   26.067384] R13: 0000000000001000 R14: 0000000002413528 R15: 00007f87eebb8000
[   26.067877] Code: 01 00 00 0f b7 f3 48 c1 e0 21 48 c1 e8 31 85 db 4c 8b 3c c2 0f 88 b4 01 00 00 49 8b 87 f0 00 00 00 31 db 39 30 0f 87 b4 01 00 00 <48> 8b 43 50 4d 8b b7 80 00 00 00 a8 04 0f 85 e8 00 00 00 41 8b 
[   26.073821] RIP: blk_mq_poll+0xa0/0x2e0 RSP: ffffc9000069fa38
[   26.074078] CR2: 0000000000000050
[   26.076101] ---[ end trace 9f9566455cd27c22 ]---

Cheers
 
Stephen

[1] http://marc.info/?l=linux-block&m=149156785215919&w=2