Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-23 Thread Mike Snitzer 
On Wed, Aug 23 2017 at 11:12am -0400,
Bart Van Assche  wrote:

> On Wed, 2017-08-23 at 19:35 +0800, Ming Lei wrote:
> > soft lockup still can be observed easily with patch d4acf3650c7c(
> > block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a quiet 
> > time),
> > but no hard lockup.
> 
> Hello Ming,
> 
> I never claimed that commit d4acf3650c7c was a full solution to avoid these
> soft lockups. I assume these results mean that patch series "[PATCH 0/7]
> Device mapper and dm-mpath fixes" was not applied to the kernel used in your
> tests? A colleague of you has reported that that patch series is sufficient
> to avoid these soft lockups. See also
> https://www.redhat.com/archives/dm-devel/2017-August/msg00122.html.

FYI, I'll try to review/stage that patchset for 4.14 over the next few
days.

(I'm not yet back to working full-time but will try to handle my
upstream responsibilities)

Mike

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-23 Thread Ming Lei 
On Wed, Aug 23, 2017 at 11:12 PM, Bart Van Assche
 wrote:
> On Wed, 2017-08-23 at 19:35 +0800, Ming Lei wrote:
>> soft lockup still can be observed easily with patch d4acf3650c7c(
>> block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a quiet 
>> time),
>> but no hard lockup.
>
> Hello Ming,
>
> I never claimed that commit d4acf3650c7c was a full solution to avoid these
> soft lockups. I assume these results mean that patch series "[PATCH 0/7]
> Device mapper and dm-mpath fixes" was not applied to the kernel used in your
> tests? A colleague of you has reported that that patch series is sufficient

OK, thanks for your clarification.

I run v4.13-rc6 with block for-next, so these patches are not applied in my
kernel.

-- 
Ming Lei

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-23 Thread Bart Van Assche 
On Wed, 2017-08-23 at 19:35 +0800, Ming Lei wrote:
> soft lockup still can be observed easily with patch d4acf3650c7c(
> block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a quiet time),
> but no hard lockup.

Hello Ming,

I never claimed that commit d4acf3650c7c was a full solution to avoid these
soft lockups. I assume these results mean that patch series "[PATCH 0/7]
Device mapper and dm-mpath fixes" was not applied to the kernel used in your
tests? A colleague of you has reported that that patch series is sufficient
to avoid these soft lockups. See also
https://www.redhat.com/archives/dm-devel/2017-August/msg00122.html.

Bart.

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-23 Thread Ming Lei 
On Wed, Aug 23, 2017 at 07:35:26PM +0800, Ming Lei wrote:
> On Wed, Aug 09, 2017 at 05:10:01PM +, Bart Van Assche wrote:
> > On Wed, 2017-08-09 at 12:43 -0400, Laurence Oberman wrote:
> > > Your latest patch on stock upstream without Ming's latest patches is 
> > > behaving for me.
> > > 
> > > As already mentioned, the requeue -11 and clone failure messages are 
> > > gone and I am not actually seeing any soft lockups or hard lockups.
> > > 
> > > When Ming gets back I will work with him on his patch set and the lockups.
> > > 
> > > Running 10 parallel writes which easily trips into soft lockups on 
> > > Ming's kernel (even with your patch) has been stable here on 4.13-RC3 
> > > with your patch.
> > > 
> > > I will leave it running for a while now but the patch is good.
> > > 
> > > If it survives 4 hours I will add a Tested-by to your latest patch.
> > 
> > Hello Laurence,
> > 
> > I'm working on an additional patch that should reduce unnecessary requeuing
> > even further. I will let you know when it's ready.
> > 
> > Additionally, please trim e-mails when replying such that e-mails do not get
> > too long.
> 
> soft lockup still can be observed easily with patch d4acf3650c7c(
> block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a quiet time),
> but no hard lockup.
> 
> With the patchset of 'blk-mq-sched: improve SCSI-MQ performance', hard
> lockup can be observed following some failure log:
> 
>   [  269.277653] device-mapper: multipath: blk_get_request() returned -11 
> - requeuing
>   [  269.321244] device-mapper: multipath: blk_get_request() returned -11 
> - requeuing
>   ...
>   [  273.421688] scsi host2: SRP abort called
>   [  273.444577] scsi host2: Sending SRP abort for tag 0x6007e
>   [  273.673871] scsi host2: Null scmnd for RSP w/tag 0x06007e 
> received on ch 6 / QP 0x30
>   ...
>   [  274.372110] device-mapper: multipath: blk_get_request() returned -11 
> - requeuing
>   [  278.658671] scsi host2: SRP abort called
>   [  278.690630] scsi host2: SRP abort called
>   [  278.717634] scsi host2: SRP abort called
>   [  278.745629] scsi host2: SRP abort called
>   [  279.083227] multipath_clone_and_map: 1092 callbacks suppressed
>   
>   [  296.210503] scsi host2: SRP reset_device called
>   
>   [  303.784287] NMI watchdog: Watchdog detected hard LOCKUP on cpu 10
> 
> The trick thing is that both hard lockup and soft lockup share
> one same stack trace.

Actually I can reproduce hard lockup too on the latest linus tree(v4.13-rc6+)
by just making the test more aggressive:

1) run hammer_write.sh 32-concurrently. 
2) write 8M each time

So it isn't the patchset of 'blk-mq-sched: improve SCSI-MQ performance'
which causes the lockup.

There must be issue somewhere else, and one thing I saw is that
dm's req's completion handling isn't very efficient:

- when low level driver's req is completed, blk_update_request()
is called from scsi_end_request()

- inside blk_update_request(), end_clone_bio() is called for
each bio

- in end_clone_bio(), blk_update_request() is called to
do partial update for the dm req. That means if one request
has N bios, the same dm req need to do the expensive partial
update N times. In theory, the partial update might be avoided,
I guess the reason is that the dm rq can't be retrieved
via the low level driver's rq.


[1] hard lockup log

[  434.068240] NMI watchdog: Watchdog detected hard LOCKUP on cpu 2
[  434.068243] Modules linked in: dm_round_robin xt_CHECKSUM ipt_MASQUERADE 
nf_nat_masquerade_ipv4 tun ip6t_rpfilter ipt_REJECT nf_reject_ipv4 ip6t_REJECT 
nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge 
stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 
ip6table_mangle ip6table_security ip6table_raw iptable_nat nf_conntrack_ipv4 
nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack rpcrdma iptable_mangle ib_isert 
iscsi_target_mod iptable_security iptable_raw ebtable_filter ebtables 
ip6table_filter ib_iser libiscsi ip6_tables scsi_transport_iscsi iptable_filter 
target_core_mod ib_srp scsi_transport_srp ib_ipoib rdma_ucm ib_ucm ib_uverbs 
ib_umad rdma_cm ib_cm iw_cm mlx5_ib ib_core intel_powerclamp coretemp kvm_intel 
kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel
[  434.068279]  pcbc aesni_intel iTCO_wdt crypto_simd gpio_ich ipmi_si 
iTCO_vendor_support cryptd joydev glue_helper ipmi_devintf hpwdt 
acpi_power_meter hpilo sg ipmi_msghandler lpc_ich i7core_edac pcspkr shpchp 
pcc_cpufreq nfsd auth_rpcgss nfs_acl lockd grace sunrpc dm_multipath ip_tables 
xfs libcrc32c sd_mod amdkfd amd_iommu_v2 radeon mlx5_core i2c_algo_bit 
drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm mlxfw drm ptp 
hpsa pps_core crc32c_intel serio_raw bnx2 i2c_core devlink scsi_transport_sas 
dm_mirror dm_region_hash dm_log dm_mod [last unloaded: ib_srpt]
[  434.068314] CPU: 2 PID: 1039 Comm: dd Tainted: G  I

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-23 Thread Ming Lei 
On Wed, Aug 09, 2017 at 05:10:01PM +, Bart Van Assche wrote:
> On Wed, 2017-08-09 at 12:43 -0400, Laurence Oberman wrote:
> > Your latest patch on stock upstream without Ming's latest patches is 
> > behaving for me.
> > 
> > As already mentioned, the requeue -11 and clone failure messages are 
> > gone and I am not actually seeing any soft lockups or hard lockups.
> > 
> > When Ming gets back I will work with him on his patch set and the lockups.
> > 
> > Running 10 parallel writes which easily trips into soft lockups on 
> > Ming's kernel (even with your patch) has been stable here on 4.13-RC3 
> > with your patch.
> > 
> > I will leave it running for a while now but the patch is good.
> > 
> > If it survives 4 hours I will add a Tested-by to your latest patch.
> 
> Hello Laurence,
> 
> I'm working on an additional patch that should reduce unnecessary requeuing
> even further. I will let you know when it's ready.
> 
> Additionally, please trim e-mails when replying such that e-mails do not get
> too long.

soft lockup still can be observed easily with patch d4acf3650c7c(
block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a quiet time),
but no hard lockup.

With the patchset of 'blk-mq-sched: improve SCSI-MQ performance', hard
lockup can be observed following some failure log:

[  269.277653] device-mapper: multipath: blk_get_request() returned -11 
- requeuing
[  269.321244] device-mapper: multipath: blk_get_request() returned -11 
- requeuing
...
[  273.421688] scsi host2: SRP abort called
[  273.444577] scsi host2: Sending SRP abort for tag 0x6007e
[  273.673871] scsi host2: Null scmnd for RSP w/tag 0x06007e 
received on ch 6 / QP 0x30
...
[  274.372110] device-mapper: multipath: blk_get_request() returned -11 
- requeuing
[  278.658671] scsi host2: SRP abort called
[  278.690630] scsi host2: SRP abort called
[  278.717634] scsi host2: SRP abort called
[  278.745629] scsi host2: SRP abort called
[  279.083227] multipath_clone_and_map: 1092 callbacks suppressed

[  296.210503] scsi host2: SRP reset_device called

[  303.784287] NMI watchdog: Watchdog detected hard LOCKUP on cpu 10

The trick thing is that both hard lockup and soft lockup share
one same stack trace.

Another question, I don't understand why request is allocated with
GFP_ATOMIC in multipath_clone_and_map(), looks it shouldn't be
necessary.


--
Ming

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-09 Thread Bart Van Assche 
On Wed, 2017-08-09 at 12:43 -0400, Laurence Oberman wrote:
> Your latest patch on stock upstream without Ming's latest patches is 
> behaving for me.
> 
> As already mentioned, the requeue -11 and clone failure messages are 
> gone and I am not actually seeing any soft lockups or hard lockups.
> 
> When Ming gets back I will work with him on his patch set and the lockups.
> 
> Running 10 parallel writes which easily trips into soft lockups on 
> Ming's kernel (even with your patch) has been stable here on 4.13-RC3 
> with your patch.
> 
> I will leave it running for a while now but the patch is good.
> 
> If it survives 4 hours I will add a Tested-by to your latest patch.

Hello Laurence,

I'm working on an additional patch that should reduce unnecessary requeuing
even further. I will let you know when it's ready.

Additionally, please trim e-mails when replying such that e-mails do not get
too long.

Thanks,

Bart.

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-09 Thread Laurence Oberman 



On 08/08/2017 10:28 PM, Laurence Oberman wrote:

On Tue, 2017-08-08 at 20:11 -0400, Laurence Oberman wrote:

On Tue, 2017-08-08 at 22:17 +0800, Ming Lei wrote:

Hi Guys,
  
Laurence and I see a system lockup issue when running

concurrent

big buffered write(4M bytes) to IB SRP on v4.13-rc3.
  
1 how to reproduce
  
1) setup IB_SRR & multi path
  
  	#./start_opensm.sh

#./start_srp.sh
  
  	# cat start_opensm.sh

#!/bin/bash
rmmod ib_srpt
opensm -F opensm.1.conf &
opensm -F opensm.2.conf &
  
  	# cat start_srp.sh

run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10

-t 7000

-ance -i mlx5_0 -p 1 1>/root/srp1.log 2>&1 &
run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10

-t 7000

-ance -i mlx5_1 -p 1 1>/root/srp2.log 2>&1 &

  
2) run the following test script
  
  	#./test-mp.sh
  
  	#cat test-mp.sh

#!/bin/sh
DEVS="360014051186d24cc27b4d04994e3
36001405b2b5c6c24c084b6fa4d55da2f
36001405b26ebe76dcb94a489f6f245f8"
  
  	for i in $DEVS; do

for j in `seq 0 15`; do
./hammer_write.sh $i 1>/dev/null 2>&1 &
done
done
  
  	#cat hammer_write.sh

#!/bin/bash
while true; do
dd if=/dev/zero of=/dev/mapper/$1 bs=4096k

count=800

done
  
  
2 lockup log

[root@ibclient ~]# ./test-mp.sh
[root@ibclient ~]# [  169.095494] perf: interrupt took too long
(2575

2500), lowering kernel.perf_event_max_sample_rate to 77000


  
[  178.569124] perf: interrupt took too long (3249 > 3218),

lowering
kernel.perf_event_max_sample_rate to 61000
[  190.586624] perf: interrupt took too long (4066 > 4061),
lowering
kernel.perf_event_max_sample_rate to 49000
[  210.381836] perf: interrupt took too long (5083 > 5082),
lowering
kernel.perf_event_max_sample_rate to 39000
[  240.498659] perf: interrupt took too long (6373 > 6353),
lowering
kernel.perf_event_max_sample_rate to 31000
  
[root@ibclient ~]#

[root@ibclient ~]# [  292.252795] perf: interrupt took too long
(8006

7966), lowering kernel.perf_event_max_sample_rate to 24000


  
[  410.354443] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.432725] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.499530] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.564952] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.644493] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.698091] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.755175] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.796784] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.837690] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  410.878743] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.476823] multipath_clone_and_map: 32 callbacks suppressed
[  463.506773] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.586752] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.656880] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.698919] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.723572] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.751820] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.781110] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.828267] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.856997] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  463.885998] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.572060] multipath_clone_and_map: 5201 callbacks

suppressed

[  468.602191] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.655761] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.697540] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.738610] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.779597] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.820705] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.862712] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.904662] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.945132] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  468.985128] device-mapper: multipath: blk_get_request()

returned

-11 - requeuing
[  473.643013] multipath_clone_and_map: 6569 callbacks

suppressed

[  473.673466] device-mapper: multipath: blk_get_request()

returned

-11 -

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-08 Thread Laurence Oberman 
On Tue, 2017-08-08 at 20:11 -0400, Laurence Oberman wrote:
> > On Tue, 2017-08-08 at 22:17 +0800, Ming Lei wrote:
> > > > Hi Guys,
> > > > 
> > > > Laurence and I see a system lockup issue when running
> > concurrent
> > > > big buffered write(4M bytes) to IB SRP on v4.13-rc3.
> > > > 
> > > > 1 how to reproduce
> > > > 
> > > > 1) setup IB_SRR & multi path
> > > > 
> > > > #./start_opensm.sh
> > > > #./start_srp.sh 
> > > > 
> > > > # cat start_opensm.sh 
> > > > #!/bin/bash
> > > > rmmod ib_srpt
> > > > opensm -F opensm.1.conf &
> > > > opensm -F opensm.2.conf &
> > > > 
> > > > # cat start_srp.sh
> > > > run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10
> > -t 7000
> > > > -ance -i mlx5_0 -p 1 1>/root/srp1.log 2>&1 &
> > > > run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10
> > -t 7000
> > > > -ance -i mlx5_1 -p 1 1>/root/srp2.log 2>&1 &
> > > > 
> > > > 
> > > > 2) run the following test script
> > > > 
> > > > #./test-mp.sh
> > > >  
> > > > #cat test-mp.sh 
> > > > #!/bin/sh
> > > > DEVS="360014051186d24cc27b4d04994e3
> > > > 36001405b2b5c6c24c084b6fa4d55da2f
> > > > 36001405b26ebe76dcb94a489f6f245f8"
> > > > 
> > > > for i in $DEVS; do
> > > > for j in `seq 0 15`; do
> > > > ./hammer_write.sh $i 1>/dev/null 2>&1 &
> > > > done
> > > > done
> > > > 
> > > > #cat hammer_write.sh
> > > > #!/bin/bash
> > > > while true; do
> > > > dd if=/dev/zero of=/dev/mapper/$1 bs=4096k
> > count=800 
> > > > done
> > > > 
> > > > 
> > > > 2 lockup log
> > > > [root@ibclient ~]# ./test-mp.sh 
> > > > [root@ibclient ~]# [  169.095494] perf: interrupt took too long
> > > > (2575
> > > > > > 2500), lowering kernel.perf_event_max_sample_rate to 77000
> > 
> > > > 
> > > > [  178.569124] perf: interrupt took too long (3249 > 3218),
> > > > lowering
> > > > kernel.perf_event_max_sample_rate to 61000
> > > > [  190.586624] perf: interrupt took too long (4066 > 4061),
> > > > lowering
> > > > kernel.perf_event_max_sample_rate to 49000
> > > > [  210.381836] perf: interrupt took too long (5083 > 5082),
> > > > lowering
> > > > kernel.perf_event_max_sample_rate to 39000
> > > > [  240.498659] perf: interrupt took too long (6373 > 6353),
> > > > lowering
> > > > kernel.perf_event_max_sample_rate to 31000
> > > > 
> > > > [root@ibclient ~]# 
> > > > [root@ibclient ~]# [  292.252795] perf: interrupt took too long
> > > > (8006
> > > > > > 7966), lowering kernel.perf_event_max_sample_rate to 24000
> > 
> > > > 
> > > > [  410.354443] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.432725] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.499530] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.564952] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.644493] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.698091] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.755175] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.796784] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.837690] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  410.878743] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.476823] multipath_clone_and_map: 32 callbacks suppressed
> > > > [  463.506773] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.586752] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.656880] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.698919] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.723572] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.751820] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.781110] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.828267] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.856997] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  463.885998] device-mapper: multipath: blk_get_request()
> > returned
> > > > -11 - requeuing
> > > > [  468.572060] multipath_clone_and_map: 5201 callbacks
> > suppressed
> > > > [  468.602191] device-mapper: multipath: blk_get_request()
> > returned
>

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-08 Thread Laurence Oberman 
On Tue, 2017-08-08 at 22:17 +0800, Ming Lei wrote:
> Hi Guys,
> 
> Laurence and I see a system lockup issue when running concurrent
> big buffered write(4M bytes) to IB SRP on v4.13-rc3.
> 
> 1 how to reproduce
> 
> 1) setup IB_SRR & multi path
> 
>   #./start_opensm.sh
>   #./start_srp.sh 
> 
>   # cat start_opensm.sh 
>   #!/bin/bash
>   rmmod ib_srpt
>   opensm -F opensm.1.conf &
>   opensm -F opensm.2.conf &
> 
>   # cat start_srp.sh
>   run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10 -t 7000
> -ance -i mlx5_0 -p 1 1>/root/srp1.log 2>&1 &
>   run_srp_daemon  -f /etc/ddn/srp_daemon.conf -R 30 -T 10 -t 7000
> -ance -i mlx5_1 -p 1 1>/root/srp2.log 2>&1 &
>   
> 
> 2) run the following test script
> 
>   #./test-mp.sh
>  
>   #cat test-mp.sh 
>   #!/bin/sh
>   DEVS="360014051186d24cc27b4d04994e3
> 36001405b2b5c6c24c084b6fa4d55da2f 36001405b26ebe76dcb94a489f6f245f8"
> 
>   for i in $DEVS; do
>   for j in `seq 0 15`; do
>   ./hammer_write.sh $i 1>/dev/null 2>&1 &
>   done
>   done
> 
>   #cat hammer_write.sh
>   #!/bin/bash
>   while true; do
>   dd if=/dev/zero of=/dev/mapper/$1 bs=4096k count=800 
>   done
> 
> 
> 2 lockup log
> [root@ibclient ~]# ./test-mp.sh 
> [root@ibclient ~]# [  169.095494] perf: interrupt took too long (2575
> > 2500), lowering kernel.perf_event_max_sample_rate to 77000
> [  178.569124] perf: interrupt took too long (3249 > 3218), lowering
> kernel.perf_event_max_sample_rate to 61000
> [  190.586624] perf: interrupt took too long (4066 > 4061), lowering
> kernel.perf_event_max_sample_rate to 49000
> [  210.381836] perf: interrupt took too long (5083 > 5082), lowering
> kernel.perf_event_max_sample_rate to 39000
> [  240.498659] perf: interrupt took too long (6373 > 6353), lowering
> kernel.perf_event_max_sample_rate to 31000
> 
> [root@ibclient ~]# 
> [root@ibclient ~]# [  292.252795] perf: interrupt took too long (8006
> > 7966), lowering kernel.perf_event_max_sample_rate to 24000
> [  410.354443] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.432725] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.499530] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.564952] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.644493] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.698091] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.755175] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.796784] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.837690] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  410.878743] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.476823] multipath_clone_and_map: 32 callbacks suppressed
> [  463.506773] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.586752] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.656880] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.698919] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.723572] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.751820] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.781110] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.828267] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.856997] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  463.885998] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.572060] multipath_clone_and_map: 5201 callbacks suppressed
> [  468.602191] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.655761] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.697540] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.738610] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.779597] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.820705] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.862712] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.904662] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.945132] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  468.985128] device-mapper: multipath: blk_get_request() returned
> -11 - requeuing
> [  473.643013] multipath_clone_and_map: 6569 callbacks suppressed
> [  473.673466] device-mapper: multipath: blk_get_request()

Re: [v4.13-rc BUG] system lockup when running big buffered write(4M) to IB SRP via mpath

2017-08-08 Thread Bart Van Assche 
On Tue, 2017-08-08 at 22:17 +0800, Ming Lei wrote:
> Laurence and I see a system lockup issue when running concurrent
> big buffered write(4M bytes) to IB SRP on v4.13-rc3.
> [ ... ] 
>   #cat hammer_write.sh
>   #!/bin/bash
>   while true; do
>   dd if=/dev/zero of=/dev/mapper/$1 bs=4096k count=800
>   done

Hello Laurence,

Is your goal perhaps to simulate a DDN workload? In that case I think you
need oflag=direct to the dd argument list such that the page cache writeback
code does not alter the size of the write requests. Anyway, this test should
not trigger a lockup. Can you check whether the patch below makes the soft
lockup complaints disappear (without changing the hammer_write.sh test
script)?

Thanks,

Bart.

[PATCH] block: Make blk_mq_delay_kick_requeue_list() rerun the queue at a
quiet time

Drivers like dm-mpath requeue requests if no paths are available and
if configured to do so. If the queue depth is sufficiently high and
the queue rerunning delay sufficiently short then .requeue_work can
be queued so often that other work items queued on the same work queue
do not get executed. Avoid that this happens by only rerunning the
queue after no blk_mq_delay_kick_requeue_list() calls have occurred
during @msecs milliseconds. Since the device mapper core is the only
user of blk_mq_delay_kick_requeue_list(), modify the implementation
of this function instead of creating a new function.

Signed-off-by: Bart Van Assche 
---
 block/blk-mq.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/block/blk-mq.c b/block/blk-mq.c
index 041f7b7fa0d6..8bfea36e92f9 100644
--- a/block/blk-mq.c
+++ b/block/blk-mq.c
@@ -679,8 +679,8 @@ EXPORT_SYMBOL(blk_mq_kick_requeue_list);
 void blk_mq_delay_kick_requeue_list(struct request_queue *q,
unsigned long msecs)
 {
-   kblockd_schedule_delayed_work(>requeue_work,
- msecs_to_jiffies(msecs));
+   kblockd_mod_delayed_work_on(WORK_CPU_UNBOUND, >requeue_work,
+   msecs_to_jiffies(msecs));
 }
 EXPORT_SYMBOL(blk_mq_delay_kick_requeue_list);