On 10/23/18 11:40 AM, Benjamin Block wrote:
> On Mon, Oct 22, 2018 at 06:38:36AM -0600, Jens Axboe wrote:
>> On 10/22/18 4:03 AM, Benjamin Block wrote:
>>> On Fri, Oct 19, 2018 at 09:50:53AM -0600, Jens Axboe wrote:
>>>
>>> Ok so, that gets past the stage where we initialize the queues. Simple
>>> SCSI-I/O also seems to work, that is for example an INQUIRY(10), but
>>> transport commands that get passed to the driver break. Tried to send
>>> a FibreChannel GPN_FT (remote port discovery).
>>>
>>> As the BSG interface goes. This is a bidirectional command, that has
>>> both a buffer for the request and for the reply. AFAIR BSG will create a
>>> struct request for each of them. Protocol is BSG_PROTOCOL_SCSI,
>>> Subprotocol BSG_SUB_PROTOCOL_SCSI_TRANSPORT. The rest should be
>>> transparent till we get into the driver.
>>>
>>> First got this:
>>>
>>> [ 566.531100] BUG: sleeping function called from invalid context at mm/slab.h:421
>>> [ 566.531452] in_atomic(): 1, irqs_disabled(): 0, pid: 3104, name: bsg_api_test
>>> [ 566.531460] 1 lock held by bsg_api_test/3104:
>>> [ 566.531466] #0: 00000000cb4b58e8 (rcu_read_lock){....}, at: hctx_lock+0x30/0x118
>>> [ 566.531498] Preemption disabled at:
>>> [ 566.531503] [<00000000008175d0>] __blk_mq_delay_run_hw_queue+0x50/0x218
>>> [ 566.531519] CPU: 3 PID: 3104 Comm: bsg_api_test Tainted: G W 4.19.0-rc6-bb-next+ #1
>>> [ 566.531527] Hardware name: IBM 3906 M03 704 (LPAR)
>>> [ 566.531533] Call Trace:
>>> [ 566.531544] ([<00000000001167fa>] show_stack+0x8a/0xd8)
>>> [ 566.531555] [<0000000000bcc6d2>] dump_stack+0x9a/0xd8
>>> [ 566.531565] [<0000000000196410>] ___might_sleep+0x280/0x298
>>> [ 566.531576] [<00000000003e528c>] __kmalloc+0xbc/0x560
>>> [ 566.531584] [<000000000083186a>] bsg_map_buffer+0x5a/0xb0
>>> [ 566.531591] [<0000000000831948>] bsg_queue_rq+0x88/0x118
>>> [ 566.531599] [<000000000081ab56>] blk_mq_dispatch_rq_list+0x37e/0x670
>>> [ 566.531607] [<000000000082050e>] blk_mq_do_dispatch_sched+0x11e/0x130
>>> [ 566.531615] [<0000000000820dfe>] blk_mq_sched_dispatch_requests+0x156/0x1a0
>>> [ 566.531622] [<0000000000817564>] __blk_mq_run_hw_queue+0x144/0x160
>>> [ 566.531630] [<0000000000817614>] __blk_mq_delay_run_hw_queue+0x94/0x218
>>> [ 566.531638] [<00000000008178b2>] blk_mq_run_hw_queue+0xda/0xf0
>>> [ 566.531645] [<00000000008211d8>] blk_mq_sched_insert_request+0x1a8/0x1e8
>>> [ 566.531653] [<0000000000811ee2>] blk_execute_rq_nowait+0x72/0x80
>>> [ 566.531660] [<0000000000811f66>] blk_execute_rq+0x76/0xb8
>>> [ 566.531778] [<0000000000830d0e>] bsg_ioctl+0x426/0x500
>>> [ 566.531787] [<0000000000440cb4>] do_vfs_ioctl+0x68c/0x710
>>> [ 566.531794] [<0000000000440dac>] ksys_ioctl+0x74/0xa0
>>> [ 566.531801] [<0000000000440e0a>] sys_ioctl+0x32/0x40
>>> [ 566.531808] [<0000000000bf1dd0>] system_call+0xd8/0x2d0
>>> [ 566.531815] 1 lock held by bsg_api_test/3104:
>>> [ 566.531821] #0: 00000000cb4b58e8 (rcu_read_lock){....}, at: hctx_lock+0x30/0x118
>>>
>>
>> The first one is an easy fix, not sure how I missed that. The other
>> one I have no idea, any chance you could try with this one:
>>
>> http://git.kernel.dk/cgit/linux-block/commit/?h=mq-conversions&id=142dc9f36e3113b6a76d472978c33c8c2a2b702c
>>
>> which fixes the first one, and also corrects a wrong end_io call,
>> but I don't think that's the cause of the above.
>>
>> If it crashes, can you figure out where in the source that is?
>> Basically just do
>>
>> gdb vmlinux
>> l *zfcp_fc_exec_bsg_job+0x116
>>
>> assuming that works fine on s390 :-)
>>
>
> So I tried 4.19.0 with only the two patches from you:
> http://git.kernel.dk/cgit/linux-block/commit/?h=mq-conversions&id=2b2ffa16193e9a69a076595ed64429b8cc9b42aa
> http://git.kernel.dk/cgit/linux-block/commit/?h=mq-conversions&id=142dc9f36e3113b6a76d472978c33c8c2a2b702c
>
> This fixed the first warning from before, as you suggested, but it still
> crash like this:
>
> [ ] Unable to handle kernel pointer dereference in virtual kernel address space
> [ ] Failing address: 0000000000000000 TEID: 0000000000000483
> [ ] Fault in home space mode while using kernel ASCE.
> [ ] AS:00000000025f0007 R3:00000000dffb8007 S:00000000dffbf000 P:000000000000013d
> [ ] Oops: 0004 ilc:3 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> [ ] Modules linked in: ....
> [ ] CPU: 2 PID: 609 Comm: kworker/2:1H Kdump: loaded Tainted: G W 4.19.0-bb-next+ #1
> [ ] Hardware name: IBM 3906 M03 704 (LPAR)
> [ ] Workqueue: kblockd blk_mq_run_work_fn
> [ ] Krnl PSW : 0704e00180000000 000003ff806a6b40 (zfcp_fc_exec_bsg_job+0x1c0/0x440 [zfcp])
> [ ] R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:2 PM:0 RI:0 EA:3
> [ ] Krnl GPRS: 0000000000000000 0000000083e0f3c0 0000000000000000 0000030000000000
> [ ] 0000030000000000 000003ff806a6b3a 00000000a86b5948 00000000a86b5988
> [ ] 0000000083e0f3f0 0000000000000000 00000000a86b5938 00000000984aee80
> [ ] 00000000a86b5800 000003ff806ba950 000003ff806a6b3a 0000000098a5ed88
> [ ] Krnl Code: 000003ff806a6b30: b9040029 lgr %r2,%r9
> 000003ff806a6b34: c0e5ffff8b7e brasl %r14,3ff80698230
> #000003ff806a6b3a: e310f0a00004 lg %r1,160(%r15)
> >000003ff806a6b40: e31090000024 stg %r1,0(%r9)
> 000003ff806a6b46: 4120a040 la %r2,64(%r10)
> 000003ff806a6b4a: c0e5ffff8ae7 brasl %r14,3ff80698118
> 000003ff806a6b50: e310a0400004 lg %r1,64(%r10)
> 000003ff806a6b56: e310f0a00024 stg %r1,160(%r15)
> [ ] Call Trace:
> [ ] ([<000003ff806a6aa2>] zfcp_fc_exec_bsg_job+0x122/0x440 [zfcp])
> [ ] [<000003ff8061e928>] fc_bsg_dispatch+0x310/0x398 [scsi_transport_fc]
> [ ] [<0000000000d2995a>] bsg_queue_rq+0x15a/0x198
> [ ] [<0000000000d03566>] blk_mq_dispatch_rq_list+0x966/0xf90
> [ ] [<0000000000d0e37a>] blk_mq_sched_dispatch_requests+0x3fa/0x410
> [ ] [<0000000000cfc230>] __blk_mq_run_hw_queue+0x218/0x248
> [ ] [<00000000001cb124>] process_one_work+0x8c4/0xe90
> [ ] [<00000000001cbe58>] worker_thread+0x768/0xbb0
> [ ] [<00000000001dc67a>] kthread+0x22a/0x248
> [ ] [<000000000137b812>] kernel_thread_starter+0x6/0xc
> [ ] [<000000000137b80c>] kernel_thread_starter+0x0/0xc
> [ ] INFO: lockdep is turned off.
> [ ] Last Breaking-Event-Address:
> [ ] [<00000000005d9b08>] __asan_store8+0x98/0xa0
> [ ]
> [ ] Kernel panic - not syncing: Fatal exception: panic_on_oops
>
> zfcp_fc_exec_bsg_job+0x1c0 is here:
>
> int zfcp_fc_exec_bsg_job(struct bsg_job *job)
> {
> struct Scsi_Host *shost;
> struct zfcp_adapter *adapter;
> struct zfcp_fsf_ct_els *ct_els = job->dd_data;
> struct fc_bsg_request *bsg_request = job->request;
> struct fc_rport *rport = fc_bsg_to_rport(job);
>
> shost = rport ? rport_to_shost(rport) : fc_bsg_to_shost(job);
> adapter = (struct zfcp_adapter *)shost->hostdata[0];
>
> if (!(atomic_read(&adapter->status) & ZFCP_STATUS_COMMON_OPEN))
> return -EINVAL;
>
> ==> ct_els->req = job->request_payload.sg_list;
> ct_els->resp = job->reply_payload.sg_list;
> ct_els->handler_data = job;
>
> switch (bsg_request->msgcode) {
> case FC_BSG_RPT_ELS:
> case FC_BSG_HST_ELS_NOLOGIN:
> return zfcp_fc_exec_els_job(job, adapter);
> case FC_BSG_RPT_CT:
> case FC_BSG_HST_CT:
> return zfcp_fc_exec_ct_job(job, adapter);
> default:
> return -EINVAL;
> }
> }
>
> I took a dump to find out how struct bsg_job looks like when it crashes
> (register clobbering isn't as bad here and I verified that job->dev is valid).
>
> crash> print *((struct bsg_job *)0x00000000a86b5938)
> $5 = {
> dev = 0x9af10358,
> kref = {
> refcount = {
> refs = {
> counter = 0x1
> }
> }
> },
> timeout = 0x384,
> request = 0x83e0f3f0,
> reply = 0x9559d500,
> request_len = 0x14,
> reply_len = 0x0,
> request_payload = {
> payload_len = 0x14,
> sg_cnt = 0x1,
> sg_list = 0x83e0f3c0
> },
> reply_payload = {
> payload_len = 0x1000,
> sg_cnt = 0x1,
> sg_list = 0x83e0f1e0
> },
> result = 0x0,
> reply_payload_rcv_len = 0x0,
> ==> dd_data = 0x0
> }
>
> This is where it breaks, job->dd_data is 0x0, so when it wants to write
> to it, it fails.
>
> So We set
>
> struct fc_function_template zfcp_transport_functions = {
> ....
> .dd_bsg_size = sizeof(struct zfcp_fsf_ct_els);
> ....
> }
>
> We get to zfcp_fc_exec_bsg_job() via fc_bsg_host_dispatch(). Previously
> this was initially allocated in bsg_setup_queue() with:
>
> q->cmd_size = sizeof(struct bsg_job) + dd_job_size;
>
> And then in bsg_initialize_rq() with:
>
> job->dd_data = job + 1;
>
> Sry, I haven't check the rest of your patch yet. But just to
> double-check, I ran some tests against 4.18.15, and there stuff still
> works, so it didn't break w/o me noticing in between (always possible
Doh, yeah it's obvious now. Try this one on top. I missed it due to the
similar naming, I'll kill off q->initalize_rq_fn as well.
diff --git a/block/bsg-lib.c b/block/bsg-lib.c
index 58c9886394d8..198cf42b74a3 100644
--- a/block/bsg-lib.c
+++ b/block/bsg-lib.c
@@ -293,6 +293,7 @@ static const struct blk_mq_ops bsg_mq_ops = {
.queue_rq = bsg_queue_rq,
.init_request = bsg_init_rq,
.exit_request = bsg_exit_rq,
+ .initialize_rq_fn = bsg_initialize_rq,
.complete = bsg_complete,
};
@@ -329,7 +330,6 @@ struct request_queue *bsg_setup_queue(struct device *dev, const char *name,
goto out_queue;
}
- q->initialize_rq_fn = bsg_initialize_rq;
q->queuedata = dev;
q->bsg_job_fn = job_fn;
blk_queue_flag_set(QUEUE_FLAG_BIDI, q);
--
Jens Axboe
