Message-Id: <cb2bd7ca-f240-285e-a804-90fa6f74b682@linux.vnet.ibm.com>
Date:   Thu, 16 Nov 2017 13:38:18 +0100
From:   Steffen Maier <maier@...ux.vnet.ibm.com>
To:     "James E . J . Bottomley" <jejb@...ux.vnet.ibm.com>,
        "Martin K . Petersen" <martin.petersen@...cle.com>,
        Kees Cook <keescook@...omium.org>
Cc:     linux-scsi@...r.kernel.org, linux-s390@...r.kernel.org,
        linux-kernel@...r.kernel.org,
        Martin Schwidefsky <schwidefsky@...ibm.com>,
        Heiko Carstens <heiko.carstens@...ibm.com>,
        Jens Remus <jremus@...ux.vnet.ibm.com>
Subject: Re: [PATCH 3/3] zfcp: drop open coded assignments of
 timer_list.function

If this has not been picked/merged yet (it's not in Linus' tree yet),
could you please drop it because it's buggy?

This would buy me time to come up with a proper solution,
otherwise I would be forced to fix it within 4.15-rc and
am not sure I can make it.

On 11/08/2017 03:17 PM, Steffen Maier wrote:
> The majority of requests is regular SCSI I/O on the hot path.
> Since these use a timeout owned by the block layer, zfcp does not use
> zfcp_fsf_req.timer. Hence, the very early unconditional and even
> incomplete (handler function yet unknown) timer initialization in
> zfcp_fsf_req_create() is not necessary.
> 
> Instead defer the timer initialization to when we know zfcp needs to use
> its own request timeout in zfcp_fsf_start_timer() and
> zfcp_fsf_start_erp_timer().

This means, we no longer always initialize the timer for
any request type, but only for some request types.

However, we still do have 2 unconditional del_timer() calls
independent of the request type.

I don't understand yet why I haven't seen the following on function testing,
but I see it now while working on something else:

[  325.908536] scsi host2: scsi_eh_2: sleeping
[  325.908707] scsi host2: zfcp
[  325.912974] qdio: 0.0.1900 ZFCP on SC 11 using AI:1 QEBSM:1 PRI:1 TDD:1 SIGA: W A 
[  331.112469] scsi 2:0:0:0: scsi scan: INQUIRY pass 1 length 36
[  331.122253] ODEBUG: assert_init not available (active state 0) object type: timer_list hint:           (null)
[  331.122319] ------------[ cut here ]------------
[  331.122332] WARNING: CPU: 0 PID: 2195 at lib/debugobjects.c:291 debug_print_object+0xb4/0xd8
[  331.122339] Modules linked in: xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT nf_reject_ipv4 xt_tcpudp bridge stp llc ip6table_filter ip6_tables iptable_filter sunrpc qeth_l2 rng_core ghash_s390 prng aes_s390 des_s390 des_generic sha512_s390 zfcp sha256_s390 scsi_transport_fc sha1_s390 sha_common dm_multipath qeth qdio scsi_mod vmur ccwgroup dm_mod vhost_net tun vhost tap sch_fq_codel kvm ip_tables x_tables autofs4
[  331.122503] CPU: 0 PID: 2195 Comm: chccwdev Not tainted 4.14.0localversion+ #1
[  331.122510] Hardware name: IBM 2964 N96 702 (z/VM 6.4.0)
[  331.122518] task: 000000004c673200 task.stack: 000000005fdac000
[  331.122599] Krnl PSW : 0704d00180000000 00000000007828cc (debug_print_object+0xb4/0xd8)
[  331.122693]            R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:3 CC:1 PM:0 RI:0 EA:3
[  331.122748] Krnl GPRS: 0000200088a4a0f0 0000000080000100 0000000000000061 0000000000c215b6
[  331.122753]            00000000007828c8 0000000000000000 0000000000c158da 000000004cf57200
[  331.122766]            000000005e462548 000000000201d608 0000000000c65888 0000000000e8dc08
[  331.122830]            000000006fbfb808 0000000000aac910 00000000007828c8 000000006fbfb708
[  331.122843] Krnl Code: 00000000007828bc: c02000271779        larl    %r2,c657ae
                          00000000007828c2: c0e5ffd25793        brasl   %r14,1cd7e8
                         #00000000007828c8: a7f40001            brc     15,7828ca
                         >00000000007828cc: c41d003655b4        lrl     %r1,e4d434
                          00000000007828d2: e340f0e80004        lg      %r4,232(%r15)
                          00000000007828d8: a71a0001            ahi     %r1,1
                          00000000007828dc: eb6ff0a80004        lmg     %r6,%r15,168(%r15)
                          00000000007828e2: c41f003655a9        strl    %r1,e4d434
[  331.123056] Call Trace:
[  331.123065] ([<00000000007828c8>] debug_print_object+0xb0/0xd8)
[  331.123074]  [<0000000000783900>] debug_object_assert_init+0x148/0x180 
[  331.123085]  [<00000000001e8e2c>] del_timer+0x34/0x90 
[  331.123106]  [<000003ff8032fad2>] zfcp_fsf_req_complete+0x2b2/0x7a8 [zfcp] 
[  331.123122]  [<000003ff80331e2e>] zfcp_fsf_reqid_check+0xe6/0x150 [zfcp] 
[  331.123151]  [<000003ff80332be0>] zfcp_qdio_int_resp+0x138/0x180 [zfcp] 
[  331.123167]  [<000003ff801df19e>] qdio_kick_handler+0x1be/0x2c0 [qdio] 
[  331.123178]  [<000003ff801e1ca6>] __tiqdio_inbound_processing+0x466/0xd00 [qdio] 
[  331.123191]  [<000000000014f5e0>] tasklet_action+0x100/0x188 
[  331.123203]  [<0000000000a56af2>] __do_softirq+0x2ca/0x5e0 
[  331.123215]  [<000000000014ec24>] irq_exit+0x74/0xd8 
[  331.123228]  [<000000000010c5c4>] do_IRQ+0xbc/0xf0 
[  331.123278]  [<0000000000a55c2c>] io_int_handler+0x104/0x2d4 
[  331.123354]  [<0000000000168ca6>] queue_work_on+0x8e/0xa8 
[  331.123393] ([<0000000000168ca2>] queue_work_on+0x8a/0xa8)
[  331.123443]  [<000000000080a932>] pty_write+0x62/0x88 
[  331.123454]  [<0000000000801c64>] n_tty_write+0x284/0x4b8 
[  331.123463]  [<00000000007febb6>] tty_write+0x34e/0x378 
[  331.123473]  [<0000000000386db4>] __vfs_write+0x3c/0x178 
[  331.123481]  [<00000000003870dc>] vfs_write+0xbc/0x1a0 
[  331.123490]  [<0000000000387366>] SyS_write+0x66/0xc0 
[  331.123501]  [<0000000000a55900>] system_call+0x290/0x2b0 
[  331.123510] 4 locks held by chccwdev/2195:
[  331.123519]  #0:  (&tty->ldisc_sem){++++}, at: [<0000000000805dc6>] tty_ldisc_ref_wait+0x46/0x70
[  331.123559]  #1:  (&tty->atomic_write_lock){+.+.}, at: [<00000000007fc798>] tty_write_lock+0x38/0x80
[  331.123585]  #2:  (&o_tty->termios_rwsem/1){++++}, at: [<0000000000801a6e>] n_tty_write+0x8e/0x4b8
[  331.123622]  #3:  (&ldata->output_lock){+.+.}, at: [<0000000000801b34>] n_tty_write+0x154/0x4b8
[  331.123735] Last Breaking-Event-Address:
[  331.123742]  [<00000000007828c8>] debug_print_object+0xb0/0xd8
[  331.123750] ---[ end trace 5a8f0aa586510aed ]---
[  331.123977] scsi 2:0:0:0: scsi scan: INQUIRY successful with code 0x0
[  331.124031] scsi 2:0:0:0: scsi scan: INQUIRY pass 2 length 164

> At that point in time we also know the handler
> function. So drop open coded assignments of timer_list.function and
> instead use the new timer API wrapper function timer_setup().
> 
> This way, we don't have to touch zfcp again, when the cast macro
> TIMER_FUNC_TYPE gets removed again after the global conversion to
> timer_setup() is complete.
> 
> Depends-on: v4.14-rc3 commit 686fef928bba ("timer: Prepare to change timer callback argument type")
> Signed-off-by: Steffen Maier <maier@...ux.vnet.ibm.com>
> Reviewed-by: Jens Remus <jremus@...ux.vnet.ibm.com>
> ---
>   drivers/s390/scsi/zfcp_fsf.c | 5 ++---
>   1 file changed, 2 insertions(+), 3 deletions(-)
> 
> diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c
> index 51b81c0a0652..c8e368f0f299 100644
> --- a/drivers/s390/scsi/zfcp_fsf.c
> +++ b/drivers/s390/scsi/zfcp_fsf.c
> @@ -34,7 +34,7 @@ static void zfcp_fsf_request_timeout_handler(struct timer_list *t)
>   static void zfcp_fsf_start_timer(struct zfcp_fsf_req *fsf_req,
>   				 unsigned long timeout)
>   {
> -	fsf_req->timer.function = (TIMER_FUNC_TYPE)zfcp_fsf_request_timeout_handler;
> +	timer_setup(&fsf_req->timer, zfcp_fsf_request_timeout_handler, 0);
>   	fsf_req->timer.expires = jiffies + timeout;
>   	add_timer(&fsf_req->timer);
>   }
> @@ -42,7 +42,7 @@ static void zfcp_fsf_start_timer(struct zfcp_fsf_req *fsf_req,
>   static void zfcp_fsf_start_erp_timer(struct zfcp_fsf_req *fsf_req)
>   {
>   	BUG_ON(!fsf_req->erp_action);
> -	fsf_req->timer.function = (TIMER_FUNC_TYPE)zfcp_erp_timeout_handler;
> +	timer_setup(&fsf_req->timer, zfcp_erp_timeout_handler, 0);
>   	fsf_req->timer.expires = jiffies + 30 * HZ;
>   	add_timer(&fsf_req->timer);
>   }
> @@ -692,7 +692,6 @@ static struct zfcp_fsf_req *zfcp_fsf_req_create(struct zfcp_qdio *qdio,
>   		adapter->req_no++;
> 
>   	INIT_LIST_HEAD(&req->list);
> -	timer_setup(&req->timer, NULL, 0);
>   	init_completion(&req->completion);
> 
>   	req->adapter = adapter;
> 

-- 
Mit freundlichen Grüßen / Kind regards
Steffen Maier

Linux on z Systems Development

IBM Deutschland Research & Development GmbH
Vorsitzende des Aufsichtsrats: Martina Koederitz
Geschaeftsfuehrung: Dirk Wittkopp
Sitz der Gesellschaft: Boeblingen
Registergericht: Amtsgericht Stuttgart, HRB 243294

Powered by blists - more mailing lists