Re: dd hangs when reading large partitions

From: "jianchao.wang" <jianchao.w.wang@oracle.com>
To: Marc Gonzalez <marc.w.gonzalez@free.fr>,
	fsdevel <linux-fsdevel@vger.kernel.org>,
	linux-block <linux-block@vger.kernel.org>
Cc: SCSI <linux-scsi@vger.kernel.org>,
	Alexander Viro <viro@zeniv.linux.org.uk>,
	Jan Kara <jack@suse.com>, Christoph Hellwig <hch@infradead.org>,
	Joao Pinto <jpinto@synopsys.com>, Jens Axboe <axboe@kernel.dk>,
	Fujita Tomonori <fujita.tomonori@lab.ntt.co.jp>,
	Paolo Valente <paolo.valente@linaro.org>
Subject: Re: dd hangs when reading large partitions
Date: Fri, 18 Jan 2019 23:18:49 +0800	[thread overview]
Message-ID: <398a6e83-d482-6e72-5806-6d5bbe8bfdd9@oracle.com> (raw)
In-Reply-To: <f792574c-e083-b218-13b4-c89be6566015@free.fr>

Hello

On 1/18/19 8:10 PM, Marc Gonzalez wrote:
> Hello,
> 
> I'm running into an issue which I don't know how to debug.
> So I'm open to ideas and suggestions :-)
> 
> On my arm64 board, I have enabled Universal Flash Storage support.
> 
> I wanted to benchmark read performance, and noticed that the system
> locks up when I read partitions larger than 3.5 GB, unless I tell
> dd to use direct IO:
> 
> *** WITH O_DIRECT ***
> # dd if=/dev/sda of=/dev/null bs=1M iflag=direct status=progress
> 57892929536 bytes (58 GB, 54 GiB) copied, 697.006 s, 83.1 MB/s 
> 55256+0 records in
> 55256+0 records out
> 57940115456 bytes (58 GB, 54 GiB) copied, 697.575 s, 83.1 MB/s
> 
> *** WITHOUT O_DIRECT ***
> # dd if=/dev/sda of=/dev/null bs=1M status=progress
> 3853516800 bytes (3.9 GB, 3.6 GiB) copied, 49.0002 s, 78.6 MB/s
> 
> 
> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> rcu:    1-...0: (8242 ticks this GP) idle=106/1/0x4000000000000000 softirq=168/171 fqs=2626 
> rcu:    6-...0: (99 GPs behind) idle=ec2/1/0x4000000000000000 softirq=71/71 fqs=2626 
> rcu:    (detected by 7, t=5254 jiffies, g=-275, q=2)
> Task dump for CPU 1:
> kworker/1:1H    R  running task        0   675      2 0x0000002a
> Workqueue: kblockd blk_mq_run_work_fn
> Call trace:
>  __switch_to+0x168/0x1d0

It looks like the blk_mq_run_work_fn went to sleep with rcu lock (preempt), isn't it ?
Can you share the symbol of the following address ?

>  0xffffffc0f6efbbc8

>  blk_mq_run_work_fn+0x28/0x40
>  process_one_work+0x208/0x470
>  worker_thread+0x48/0x460
>  kthread+0x128/0x130
>  ret_from_fork+0x10/0x1c
> Task dump for CPU 6:
> kthreadd        R  running task        0     2      0 0x0000002a
> Call trace:
>  __switch_to+0x168/0x1d0
>  0x5b36396f4e7d4000
> 
> 
> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> rcu:    1-...0: (8242 ticks this GP) idle=106/1/0x4000000000000000 softirq=168/171 fqs=10500 
> rcu:    6-...0: (99 GPs behind) idle=ec2/1/0x4000000000000000 softirq=71/71 fqs=10500 
> rcu:    (detected by 7, t=21009 jiffies, g=-275, q=2)
> Task dump for CPU 1:
> kworker/1:1H    R  running task        0   675      2 0x0000002a
> Workqueue: kblockd blk_mq_run_work_fn
> Call trace:
>  __switch_to+0x168/0x1d0
>  0xffffffc0f6efbbc8
>  blk_mq_run_work_fn+0x28/0x40
>  process_one_work+0x208/0x470
>  worker_thread+0x48/0x460
>  kthread+0x128/0x130
>  ret_from_fork+0x10/0x1c
> Task dump for CPU 6:
> kthreadd        R  running task        0     2      0 0x0000002a
> Call trace:
>  __switch_to+0x168/0x1d0
>  0x5b36396f4e7d4000
> 
> 
> The system always hangs around the 3.6 GiB mark, wherever I start from.
> How can I debug this issue?
> 
> Regards.
> 

Thanks
Jianchao