From: "Stephen  Bates" <sbates@raithlin.com>
To: "linux-block@vger.kernel.org" <linux-block@vger.kernel.org>,
        "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
CC: Jens Axboe <axboe@fb.com>,
        "Damien.LeMoal@wdc.com" <Damien.LeMoal@wdc.com>
Subject: Kernel Oops: BUG: unable to handle kernel NULL pointer dereference at
 0000000000000050; IP is at blk_mq_poll+0xa0/0x2e0
Thread-Topic: Kernel Oops: BUG: unable to handle kernel NULL pointer
 dereference at 0000000000000050; IP is at blk_mq_poll+0xa0/0x2e0
Thread-Index: AQHStsz6+R/jqwoZMUqwgcOJ+7fQLg==
Date: Sun, 16 Apr 2017 16:17:44 +0000
Message-ID: <558BD27E-FEFA-4281-89CE-4C94964B4346@raithlin.com>
Accept-Language: en-CA, en-US
Content-Language: en-US
user-agent: Microsoft-MacOutlook/f.20.0.170309
spamdiagnosticoutput: 1:99
spamdiagnosticmetadata: NSPM
Content-Type: text/plain; charset="utf-8"
Content-ID: <BED04278BCCB2349B808633200B4C9A1@CANPRD01.PROD.OUTLOOK.COM>
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-originalarrivaltime: 16 Apr 2017 16:17:44.4328
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 18519031-7ff4-4cbb-bbcb-c3252d330f4b
X-MS-Exchange-Transport-CrossTenantHeadersStamped: YTOPR01MB0617
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Transfer-Encoding: 8bit
X-MIME-Autoconverted: from base64 to 8bit by mail.home.local id v3GGI8Y9018065
Content-Length: 4876
Lines: 96

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