linux-ext4.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
       [not found] <1520942674.10285.8.camel@synopsys.com>
@ 2018-03-13 14:05 ` Adrian Hunter
  2018-03-13 15:56   ` Evgeniy Didin
  0 siblings, 1 reply; 11+ messages in thread
From: Adrian Hunter @ 2018-03-13 14:05 UTC (permalink / raw)
  To: Evgeniy Didin
  Cc: ulf.hansson@linaro.org, linux-ext4, Theodore Ts'o,
	linus.walleij@linaro.org, Alexey Brodkin,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com, Andreas Dilger,
	linux-snps-arc@lists.infradead.org, Eugeniy Paltsev

On 13/03/18 14:04, Evgeniy Didin wrote:
> Hello Adrian,
> 
> I have discovered, that beggining with 4.16-rc1 bonnie++ benchmark
> runs with errors on arc/hsdk board. After bisecting between 4.15 and 4.16-rc1,
> I have found that errors started after 
> commit 81196976ed94 (mmc: block: Add blk-mq support).
> 
> Error message is like:
> 
> | # bonnie++ -u root -r 256 -s 512 -x 1 -d  /mnt 
> | Using uid:0, gid:0.
> | Writing with putc()...random: crng init done
> | done
> | Writing intelligently...INFO: task kworker/u8:0:5 blocked for more than 10 seconds.
> |      Not tainted 4.15.0-rc3-00012-g81196976ed94-dirty #1
> | "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> | kworker/u8:0    D    0     5      2 0x00000000
> | Workqueue: writeback wb_workfn (flush-179:0)
> |
> | Stack Trace:
> |  __switch_to+0x0/0xac
> |  __schedule+0x1b8/0x738
> |  io_schedule+0x5c/0xc0
> |  bit_wait_io+0xc/0x48
> |  out_of_line_wait_on_bit+0x78/0xc0
> |  do_get_write_access+0x1aa/0x4cc
> |  jbd2_journal_get_write_access+0x32/0x74
> |  __ext4_journal_get_write_access+0x3a/0xac
> |  ext4_mb_mark_diskspace_used+0x66/0x5b0
> |  ext4_mb_new_blocks+0x1ee/0x830
> |  ext4_ext_map_blocks+0x504/0xcac
> |  ext4_map_blocks+0x262/0x5e8
> |  mpage_map_and_submit_extent+0xb8/0x648
> |  ext4_writepages+0x5ce/0x6b4
> |  do_writepages+0x20/0x84
> |  __writeback_single_inode+0x2a/0x154
> |  wb_writeback+0x538/0xae0
> |  wb_workfn+0x17c/0x334
> |  process_one_work+0x1a6/0x350
> |  worker_thread+0xf2/0x478
> |  kthread+0x120/0x13c
> |  ret_from_fork+0x18/0x1c
> 
> There are some details of hsdk_defconfig presented bellow:
> 
> SOFTLOCKUP_DETECTOR=y
> DETECT_HUNG_TASK=y
> DEFAULT_HUNG_TASK_TIMEOUT=10
> MMC_DW=y
> MMC_DW_PLTFM=y
> 
> I have also tested bonnie++ on Wandboard on v4.16-rc5 with the same
> DEFAULT_HUNG_TASK_TIMEOUT=10, but there were no errors.
> 
> Even though it is not critical error and we see bonnie++ test proceeds to the end,
> still it is strange, that some process is running in kernel space for a long time (at least 10sec).
> What is strange, before metioned commit I can't reproduce this behaviour.
> 
> I am wondering is this expected behaviour? 

Was the performance affected? i.e. the results from bonnie++

What mount options did you use?

_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-13 14:05 ` mmc: block: bonnie++ runs with errors on arc/hsdk board Adrian Hunter
@ 2018-03-13 15:56   ` Evgeniy Didin
  2018-03-14 12:32     ` Evgeniy Didin
  0 siblings, 1 reply; 11+ messages in thread
From: Evgeniy Didin @ 2018-03-13 15:56 UTC (permalink / raw)
  To: adrian.hunter@intel.com, Evgeniy.Didin@synopsys.com
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

On Tue, 2018-03-13 at 16:05 +0200, Adrian Hunter wrote:
> On 13/03/18 14:04, Evgeniy Didin wrote:
> > Hello Adrian,
> > 
> > I have discovered, that beggining with 4.16-rc1 bonnie++ benchmark
> > runs with errors on arc/hsdk board. After bisecting between 4.15 and 4.16-rc1,
> > I have found that errors started after 
> > commit 81196976ed94 (mmc: block: Add blk-mq support).
> > 
> > Error message is like:
> > 
> > > # bonnie++ -u root -r 256 -s 512 -x 1 -d  /mnt 
> > > Using uid:0, gid:0.
> > > Writing with putc()...random: crng init done
> > > done
> > > Writing intelligently...INFO: task kworker/u8:0:5 blocked for more than 10 seconds.
> > >       Not tainted 4.15.0-rc3-00012-g81196976ed94-dirty #1
> > > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > > kworker/u8:0    D    0     5      2 0x00000000
> > > Workqueue: writeback wb_workfn (flush-179:0)
> > > 
> > > Stack Trace:
> > >   __switch_to+0x0/0xac
> > >   __schedule+0x1b8/0x738
> > >   io_schedule+0x5c/0xc0
> > >   bit_wait_io+0xc/0x48
> > >   out_of_line_wait_on_bit+0x78/0xc0
> > >   do_get_write_access+0x1aa/0x4cc
> > >   jbd2_journal_get_write_access+0x32/0x74
> > >   __ext4_journal_get_write_access+0x3a/0xac
> > >   ext4_mb_mark_diskspace_used+0x66/0x5b0
> > >   ext4_mb_new_blocks+0x1ee/0x830
> > >   ext4_ext_map_blocks+0x504/0xcac
> > >   ext4_map_blocks+0x262/0x5e8
> > >   mpage_map_and_submit_extent+0xb8/0x648
> > >   ext4_writepages+0x5ce/0x6b4
> > >   do_writepages+0x20/0x84
> > >   __writeback_single_inode+0x2a/0x154
> > >   wb_writeback+0x538/0xae0
> > >   wb_workfn+0x17c/0x334
> > >   process_one_work+0x1a6/0x350
> > >   worker_thread+0xf2/0x478
> > >   kthread+0x120/0x13c
> > >   ret_from_fork+0x18/0x1c
> > 
> > There are some details of hsdk_defconfig presented bellow:
> > 
> > SOFTLOCKUP_DETECTOR=y
> > DETECT_HUNG_TASK=y
> > DEFAULT_HUNG_TASK_TIMEOUT=10
> > MMC_DW=y
> > MMC_DW_PLTFM=y
> > 
> > I have also tested bonnie++ on Wandboard on v4.16-rc5 with the same
> > DEFAULT_HUNG_TASK_TIMEOUT=10, but there were no errors.
> > 
> > Even though it is not critical error and we see bonnie++ test proceeds to the end,
> > still it is strange, that some process is running in kernel space for a long time (at least 10sec).
> > What is strange, before metioned commit I can't reproduce this behaviour.
> > 
> > I am wondering is this expected behaviour? 
> 
> Was the performance affected? i.e. the results from bonnie++
I have run bonnie++ several times before and after mentioned commit. Here is output:
--------------------------------------------------<8-------------------------------------------------------------------------
Before commit:
ARCLinux,512M,6442,50,7211,0,5333,0,12954,99,345638,100,+++++,+++,16,22322,100,+++++,+++,32735,99,22921,100,+++++,+++,32211,100
ARCLinux,512M,6611,51,7248,0,5162,0,12951,99,344763,99,+++++,+++,16,22649,99,+++++,+++,32723,99,22572,100,+++++,+++,31697,100
ARCLinux,512M,6597,52,7307,0,5368,0,12934,99,343987,99,+++++,+++,16,22775,100,+++++,+++,32713,99,22832,100,+++++,+++,31899,99
After commit:
ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
ARCLinux,512M,5159,42,6944,1,5658,0,12945,99,344290,100,+++++,+++,16,22295,100,+++++,+++,32715,99,22888,99,+++++,+++,32007,99
ARCLinux,512M,5170,42,6840,2,5315,0,12946,99,343889,100,+++++,+++,16,22445,100,+++++,+++,32681,99,22967,100,+++++,+++,32117,99
--------------------------------------------------<8------------------------------------------------------------------------
              ^^^^ 
If i understand correctly, in third column is shown "sequential output" per character speed (K/sec), which decreased.

> What mount options did you use?
I didn't use any options. Simply:
# mount /dev/mmcblk0p1 /mnt

Best regards,
Evgeniy Didin
_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-13 15:56   ` Evgeniy Didin
@ 2018-03-14 12:32     ` Evgeniy Didin
  2018-03-15  9:27       ` Adrian Hunter
  0 siblings, 1 reply; 11+ messages in thread
From: Evgeniy Didin @ 2018-03-14 12:32 UTC (permalink / raw)
  To: adrian.hunter@intel.com
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

Hi Adrian,
> > 
> > Was the performance affected? i.e. the results from bonnie++
> 
> I have run bonnie++ several times before and after mentioned commit. Here is output:
> --------------------------------------------------<8-------------------------------------------------------------------------
> Before commit:
> ARCLinux,512M,6442,50,7211,0,5333,0,12954,99,345638,100,+++++,+++,16,22322,100,+++++,+++,32735,99,22921,100,+++++,+++,32211,100
> ARCLinux,512M,6611,51,7248,0,5162,0,12951,99,344763,99,+++++,+++,16,22649,99,+++++,+++,32723,99,22572,100,+++++,+++,31697,100
> ARCLinux,512M,6597,52,7307,0,5368,0,12934,99,343987,99,+++++,+++,16,22775,100,+++++,+++,32713,99,22832,100,+++++,+++,31899,99
> After commit:
> ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
> ARCLinux,512M,5159,42,6944,1,5658,0,12945,99,344290,100,+++++,+++,16,22295,100,+++++,+++,32715,99,22888,99,+++++,+++,32007,99
> ARCLinux,512M,5170,42,6840,2,5315,0,12946,99,343889,100,+++++,+++,16,22445,100,+++++,+++,32681,99,22967,100,+++++,+++,32117,99
> --------------------------------------------------<8------------------------------------------------------------------------
>               ^^^^ 
> If i understand correctly, in third column is shown "sequential output" per character speed (K/sec), which decreased.
> 
> > What mount options did you use?
> 
> I didn't use any options. Simply:
> # mount /dev/mmcblk0p1 /mnt

Note that the file system on SDcard was ext4. 

Best regards,
Evgeniy Didin
_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-14 12:32     ` Evgeniy Didin
@ 2018-03-15  9:27       ` Adrian Hunter
  2018-03-15 15:08         ` Evgeniy Didin
  2018-03-15 16:38         ` Vineet Gupta
  0 siblings, 2 replies; 11+ messages in thread
From: Adrian Hunter @ 2018-03-15  9:27 UTC (permalink / raw)
  To: Evgeniy Didin
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

On 14/03/18 14:32, Evgeniy Didin wrote:
> Hi Adrian,
>>>
>>> Was the performance affected? i.e. the results from bonnie++
>>
>> I have run bonnie++ several times before and after mentioned commit. Here is output:
>> --------------------------------------------------<8-------------------------------------------------------------------------
>> Before commit:
>> ARCLinux,512M,6442,50,7211,0,5333,0,12954,99,345638,100,+++++,+++,16,22322,100,+++++,+++,32735,99,22921,100,+++++,+++,32211,100
>> ARCLinux,512M,6611,51,7248,0,5162,0,12951,99,344763,99,+++++,+++,16,22649,99,+++++,+++,32723,99,22572,100,+++++,+++,31697,100
>> ARCLinux,512M,6597,52,7307,0,5368,0,12934,99,343987,99,+++++,+++,16,22775,100,+++++,+++,32713,99,22832,100,+++++,+++,31899,99
>> After commit:
>> ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
>> ARCLinux,512M,5159,42,6944,1,5658,0,12945,99,344290,100,+++++,+++,16,22295,100,+++++,+++,32715,99,22888,99,+++++,+++,32007,99
>> ARCLinux,512M,5170,42,6840,2,5315,0,12946,99,343889,100,+++++,+++,16,22445,100,+++++,+++,32681,99,22967,100,+++++,+++,32117,99
>> --------------------------------------------------<8------------------------------------------------------------------------
>>               ^^^^ 
>> If i understand correctly, in third column is shown "sequential output" per character speed (K/sec), which decreased.
>>
>>> What mount options did you use?
>>
>> I didn't use any options. Simply:
>> # mount /dev/mmcblk0p1 /mnt
> 
> Note that the file system on SDcard was ext4. 

Please try:

	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt

and share the resulting perf.data file when you are able
to reproduce the hung task message.

You may want to add this patch first:

	https://marc.info/?l=linux-mmc&m=152110580324200

_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-15  9:27       ` Adrian Hunter
@ 2018-03-15 15:08         ` Evgeniy Didin
  2018-03-16 12:12           ` Adrian Hunter
  2018-03-15 16:38         ` Vineet Gupta
  1 sibling, 1 reply; 11+ messages in thread
From: Evgeniy Didin @ 2018-03-15 15:08 UTC (permalink / raw)
  To: adrian.hunter@intel.com, Evgeniy.Didin@synopsys.com
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

[-- Attachment #1: Type: text/plain, Size: 2480 bytes --]

Hi Adrian,

> On 14/03/18 14:32, Evgeniy Didin wrote:
> > Hi Adrian,
> > > > 
> > > > Was the performance affected? i.e. the results from bonnie++
> > > 
> > > I have run bonnie++ several times before and after mentioned commit. Here is output:
> > > --------------------------------------------------<8-------------------------------------------------------------------------
> > > Before commit:
> > > ARCLinux,512M,6442,50,7211,0,5333,0,12954,99,345638,100,+++++,+++,16,22322,100,+++++,+++,32735,99,22921,100,+++++,+++,32211,100
> > > ARCLinux,512M,6611,51,7248,0,5162,0,12951,99,344763,99,+++++,+++,16,22649,99,+++++,+++,32723,99,22572,100,+++++,+++,31697,100
> > > ARCLinux,512M,6597,52,7307,0,5368,0,12934,99,343987,99,+++++,+++,16,22775,100,+++++,+++,32713,99,22832,100,+++++,+++,31899,99
> > > After commit:
> > > ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
> > > ARCLinux,512M,5159,42,6944,1,5658,0,12945,99,344290,100,+++++,+++,16,22295,100,+++++,+++,32715,99,22888,99,+++++,+++,32007,99
> > > ARCLinux,512M,5170,42,6840,2,5315,0,12946,99,343889,100,+++++,+++,16,22445,100,+++++,+++,32681,99,22967,100,+++++,+++,32117,99
> > > --------------------------------------------------<8------------------------------------------------------------------------
> > >               ^^^^ 
> > > If i understand correctly, in third column is shown "sequential output" per character speed (K/sec), which decreased.
> > > 
> > > > What mount options did you use?
> > > 
> > > I didn't use any options. Simply:
> > > # mount /dev/mmcblk0p1 /mnt
> > 
> > Note that the file system on SDcard was ext4. 
> 
> Please try:
> 
> 	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt
> and share the resulting perf.data file when you are able
> to reproduce the hung task message.
> 

I have applied the patch below and collected perf.data using command above, hung message also appeared. Is this the information you needed?
(perf.data is in attachments to this
message).
 
> You may want to add this patch first:
> 
> 	https://urldefense.proofpoint.com/v2/url?u=https-3A__marc.info_-3Fl-3Dlinux-2Dmmc-26m-3D152110580324200&d=DwIDaQ&c=DPL6_X_6JkXFx7AXWqB0tg&r=vQk-RIbjwN0zvlwiMSpq3LYUTNf7Gqc4
> ujhosYITtAw&m=LeVFmgzU0ydw-qHaAVh-kZI-v4mldnCycYxIGxqDexU&s=SyGvsVJBOzegO2Mz3hQ5j6CY8KrjLWJERVHfosSmKSs&e=

Best regards,
Evgeniy Didin

[-- Attachment #2: perf.data.gz --]
[-- Type: application/gzip, Size: 648026 bytes --]

[-- Attachment #3: Type: text/plain, Size: 169 bytes --]

_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-15  9:27       ` Adrian Hunter
  2018-03-15 15:08         ` Evgeniy Didin
@ 2018-03-15 16:38         ` Vineet Gupta
  2018-03-15 17:21           ` Alexey Brodkin
  1 sibling, 1 reply; 11+ messages in thread
From: Vineet Gupta @ 2018-03-15 16:38 UTC (permalink / raw)
  To: Adrian Hunter, Evgeniy Didin
  Cc: ulf.hansson@linaro.org, linux-snps-arc@lists.infradead.org,
	tytso@mit.edu, Vince Weaver, Peter Zijlstra,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-ext4@vger.kernel.org,
	Eugeniy.Paltsev@synopsys.com

On 03/15/2018 02:27 AM, Adrian Hunter wrote:
> Please try:
> 
> 	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt
> 
> and share the resulting perf.data file when you are able
> to reproduce the hung task message.
> 
> You may want to add this patch first:
> 
> 	https://marc.info/?l=linux-mmc&m=152110580324200

While this SoC has perf counters, Unfortunately the overflow interrupts are not 
wired up. We can do perf stats but not sampling.

Peter was it you or Vince trying to use timer interrupts to emulate perf sampling 
on some ARM SoC ?

Thing is we have a spare hardware timer per core (TIMER1) which is not usabel for 
otherwise gtod function in SMP and could well be repurposed for perf needs.

-Vineet

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-15 16:38         ` Vineet Gupta
@ 2018-03-15 17:21           ` Alexey Brodkin
  2018-03-16  7:20             ` Adrian Hunter
  0 siblings, 1 reply; 11+ messages in thread
From: Alexey Brodkin @ 2018-03-15 17:21 UTC (permalink / raw)
  To: Vineet Gupta, adrian.hunter@intel.com
  Cc: Evgeniy.Didin@synopsys.com, ulf.hansson@linaro.org,
	linux-ext4@vger.kernel.org, tytso@mit.edu,
	vincent.weaver@maine.edu, peterz@infradead.org,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

Hi Vineet,

On Thu, 2018-03-15 at 09:38 -0700, Vineet Gupta wrote:
> On 03/15/2018 02:27 AM, Adrian Hunter wrote:
> > Please try:
> > 
> > 	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt
> > 
> > and share the resulting perf.data file when you are able
> > to reproduce the hung task message.
> > 
> > You may want to add this patch first:
> > 
> > 	https://marc.info/?l=linux-mmc&m=152110580324200
> 
> While this SoC has perf counters, Unfortunately the overflow interrupts are not 
> wired up. We can do perf stats but not sampling.

I guess here Adrian was asking for pure software MMC-related events which are
orthogonal to CPU's perf interrupts.

Adrian?

-Alexey

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-15 17:21           ` Alexey Brodkin
@ 2018-03-16  7:20             ` Adrian Hunter
  0 siblings, 0 replies; 11+ messages in thread
From: Adrian Hunter @ 2018-03-16  7:20 UTC (permalink / raw)
  To: Alexey Brodkin, Vineet Gupta
  Cc: Evgeniy.Didin@synopsys.com, ulf.hansson@linaro.org,
	linux-ext4@vger.kernel.org, tytso@mit.edu,
	vincent.weaver@maine.edu, peterz@infradead.org,
	linus.walleij@linaro.org, linux-mmc@vger.kernel.org,
	jh80.chung@samsung.com, adilger.kernel@dilger.ca,
	linux-snps-arc@lists.infradead.org, Eugeniy.Paltsev@synopsys.com

On 15/03/18 19:21, Alexey Brodkin wrote:
> Hi Vineet,
> 
> On Thu, 2018-03-15 at 09:38 -0700, Vineet Gupta wrote:
>> On 03/15/2018 02:27 AM, Adrian Hunter wrote:
>>> Please try:
>>>
>>> 	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt
>>>
>>> and share the resulting perf.data file when you are able
>>> to reproduce the hung task message.
>>>
>>> You may want to add this patch first:
>>>
>>> 	https://marc.info/?l=linux-mmc&m=152110580324200
>>
>> While this SoC has perf counters, Unfortunately the overflow interrupts are not 
>> wired up. We can do perf stats but not sampling.
> 
> I guess here Adrian was asking for pure software MMC-related events which are
> orthogonal to CPU's perf interrupts.
> 
> Adrian?

Yes, these are mmc tracepoints which are software events.  The file is full
of them, so it certainly worked.

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-15 15:08         ` Evgeniy Didin
@ 2018-03-16 12:12           ` Adrian Hunter
  2018-03-16 17:10             ` Evgeniy Didin
  0 siblings, 1 reply; 11+ messages in thread
From: Adrian Hunter @ 2018-03-16 12:12 UTC (permalink / raw)
  To: Evgeniy Didin
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

On 15/03/18 17:08, Evgeniy Didin wrote:
> Hi Adrian,
> 
>> On 14/03/18 14:32, Evgeniy Didin wrote:
>>> Hi Adrian,
>>>>>
>>>>> Was the performance affected? i.e. the results from bonnie++
>>>>
>>>> I have run bonnie++ several times before and after mentioned commit. Here is output:
>>>> --------------------------------------------------<8-------------------------------------------------------------------------
>>>> Before commit:
>>>> ARCLinux,512M,6442,50,7211,0,5333,0,12954,99,345638,100,+++++,+++,16,22322,100,+++++,+++,32735,99,22921,100,+++++,+++,32211,100
>>>> ARCLinux,512M,6611,51,7248,0,5162,0,12951,99,344763,99,+++++,+++,16,22649,99,+++++,+++,32723,99,22572,100,+++++,+++,31697,100
>>>> ARCLinux,512M,6597,52,7307,0,5368,0,12934,99,343987,99,+++++,+++,16,22775,100,+++++,+++,32713,99,22832,100,+++++,+++,31899,99
>>>> After commit:
>>>> ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
>>>> ARCLinux,512M,5159,42,6944,1,5658,0,12945,99,344290,100,+++++,+++,16,22295,100,+++++,+++,32715,99,22888,99,+++++,+++,32007,99
>>>> ARCLinux,512M,5170,42,6840,2,5315,0,12946,99,343889,100,+++++,+++,16,22445,100,+++++,+++,32681,99,22967,100,+++++,+++,32117,99
>>>> --------------------------------------------------<8------------------------------------------------------------------------
>>>>               ^^^^ 
>>>> If i understand correctly, in third column is shown "sequential output" per character speed (K/sec), which decreased.
>>>>
>>>>> What mount options did you use?
>>>>
>>>> I didn't use any options. Simply:
>>>> # mount /dev/mmcblk0p1 /mnt
>>>
>>> Note that the file system on SDcard was ext4. 
>>
>> Please try:
>>
>> 	perf record -a -e mmc:* -- bonnie++ -u root -r 256 -s 512 -x 1 -d /mnt
>> and share the resulting perf.data file when you are able
>> to reproduce the hung task message.
>>
> 
> I have applied the patch below and collected perf.data using command above, hung message also appeared. Is this the information you needed?
> (perf.data is in attachments to this
> message).

Yes.  Unfortunately the clock used is not accurate enough to correctly order
the events across different CPUs, which makes it very hard to see delays
between requests.  You could try a different clock - refer the --clockid
option to perf record.

Nevertheless it shows there are no I/O errors which means the error recovery
can be ruled out as a problem.

The issue could be caused by the I/O scheduler.  Under blk-mq the default
scheduler is the mq-deadline scheduler whereas without blk-mq you would
probably have been using cfq by default.  You could try the bfq scheduler:

	echo bfq > /sys/block/mmcblk0/queue/scheduler

But you might need to add it to the kernel config i.e.

	CONFIG_IOSCHED_BFQ=y

Alternatively you could fiddle with the scheduler parameters:

With mq-deadline they are:

# grep -H . /sys/block/mmcblk0/queue/iosched/*
/sys/block/mmcblk0/queue/iosched/fifo_batch:16
/sys/block/mmcblk0/queue/iosched/front_merges:1
/sys/block/mmcblk0/queue/iosched/read_expire:500
/sys/block/mmcblk0/queue/iosched/write_expire:5000
/sys/block/mmcblk0/queue/iosched/writes_starved:2

You could try decreasing the write_expire and/or fifo_batch.

>  
>> You may want to add this patch first:
>>
>> 	https://urldefense.proofpoint.com/v2/url?u=https-3A__marc.info_-3Fl-3Dlinux-2Dmmc-26m-3D152110580324200&d=DwIDaQ&c=DPL6_X_6JkXFx7AXWqB0tg&r=vQk-RIbjwN0zvlwiMSpq3LYUTNf7Gqc4
>> ujhosYITtAw&m=LeVFmgzU0ydw-qHaAVh-kZI-v4mldnCycYxIGxqDexU&s=SyGvsVJBOzegO2Mz3hQ5j6CY8KrjLWJERVHfosSmKSs&e=
> 
> Best regards,
> Evgeniy Didin
> 


_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-16 12:12           ` Adrian Hunter
@ 2018-03-16 17:10             ` Evgeniy Didin
  2018-03-20  8:29               ` Adrian Hunter
  0 siblings, 1 reply; 11+ messages in thread
From: Evgeniy Didin @ 2018-03-16 17:10 UTC (permalink / raw)
  To: adrian.hunter@intel.com, Evgeniy.Didin@synopsys.com
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

Hello Adrian,

> Yes.  Unfortunately the clock used is not accurate enough to correctly order
> the events across different CPUs, which makes it very hard to see delays
> between requests.  You could try a different clock - refer the --clockid
> option to perf record.
> 
> Nevertheless it shows there are no I/O errors which means the error recovery
> can be ruled out as a problem.
> 
> The issue could be caused by the I/O scheduler.  Under blk-mq the default
> scheduler is the mq-deadline scheduler whereas without blk-mq you would
> probably have been using cfq by default.  You could try the bfq scheduler:
> 
> 	echo bfq > /sys/block/mmcblk0/queue/scheduler
> 
> But you might need to add it to the kernel config i.e.
> 
> 	CONFIG_IOSCHED_BFQ=y
> 
Switching from mq-deadline scheduler to bfq fixed the issue.
Also bonnie++ results have changed:
-----------------------------------------------<8----------------------------------------------------------------------------
bfq scheduler:
ARCLinux,512M,6463,87,7297,0,5450,0,9827,99,342952,99,+++++,+++,16,17525,100,+++++,+++,24329,99,17621,100,+++++,+++,24001,101

mq-deadline scheduler:
ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
-----------------------------------------------<8----------------------------------------------------------------------------
As I see, the performance of sequential input per char and of file operations have decreased for ~25%.

Do you have any idea what could be a reason for such a long stalling in case of mq-deadline IOscheduler? I would expect if there is 
some long async operation, kernel should not be blocked. But what we see using mq-deadline is kernel blocked in bit_wait_io().
Do you think this is a valid behavior at least in case of mq-deadline IOscheduler?

> Alternatively you could fiddle with the scheduler parameters:
> 
> With mq-deadline they are:
> 
> # grep -H . /sys/block/mmcblk0/queue/iosched/*
> /sys/block/mmcblk0/queue/iosched/fifo_batch:16
> /sys/block/mmcblk0/queue/iosched/front_merges:1
> /sys/block/mmcblk0/queue/iosched/read_expire:500
> /sys/block/mmcblk0/queue/iosched/write_expire:5000
> /sys/block/mmcblk0/queue/iosched/writes_starved:2
> 
> You could try decreasing the write_expire and/or fifo_batch.
It seems that decreasing doesn't affect on this issue.

Best regards,
Evgeniy Didin
_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

* Re: mmc: block: bonnie++ runs with errors on arc/hsdk board
  2018-03-16 17:10             ` Evgeniy Didin
@ 2018-03-20  8:29               ` Adrian Hunter
  0 siblings, 0 replies; 11+ messages in thread
From: Adrian Hunter @ 2018-03-20  8:29 UTC (permalink / raw)
  To: Evgeniy Didin
  Cc: ulf.hansson@linaro.org, linux-ext4@vger.kernel.org, tytso@mit.edu,
	linus.walleij@linaro.org, Alexey.Brodkin@synopsys.com,
	linux-mmc@vger.kernel.org, jh80.chung@samsung.com,
	adilger.kernel@dilger.ca, linux-snps-arc@lists.infradead.org,
	Eugeniy.Paltsev@synopsys.com

On 16/03/18 19:10, Evgeniy Didin wrote:
> Hello Adrian,
> 
>> Yes.  Unfortunately the clock used is not accurate enough to correctly order
>> the events across different CPUs, which makes it very hard to see delays
>> between requests.  You could try a different clock - refer the --clockid
>> option to perf record.
>>
>> Nevertheless it shows there are no I/O errors which means the error recovery
>> can be ruled out as a problem.
>>
>> The issue could be caused by the I/O scheduler.  Under blk-mq the default
>> scheduler is the mq-deadline scheduler whereas without blk-mq you would
>> probably have been using cfq by default.  You could try the bfq scheduler:
>>
>> 	echo bfq > /sys/block/mmcblk0/queue/scheduler
>>
>> But you might need to add it to the kernel config i.e.
>>
>> 	CONFIG_IOSCHED_BFQ=y
>>
> Switching from mq-deadline scheduler to bfq fixed the issue.
> Also bonnie++ results have changed:
> -----------------------------------------------<8----------------------------------------------------------------------------
> bfq scheduler:
> ARCLinux,512M,6463,87,7297,0,5450,0,9827,99,342952,99,+++++,+++,16,17525,100,+++++,+++,24329,99,17621,100,+++++,+++,24001,101
> 
> mq-deadline scheduler:
> ARCLinux,512M,4453,36,6474,1,5852,0,12940,99,344329,100,+++++,+++,16,22168,98,+++++,+++,32760,99,22755,100,+++++,+++,32205,100
> -----------------------------------------------<8----------------------------------------------------------------------------
> As I see, the performance of sequential input per char and of file
> operations have decreased for ~25%.

You may need to aggregate more runs, and also compare to BFQ with blk-mq
against CFQ without blk-mq.  If you think BFQ is under-performing, then
contact the BFQ maintainers.

> 
> Do you have any idea what could be a reason for such a long stalling in
> case of mq-deadline IOscheduler?

Write starvation.

>                                 I would expect if there is some long
> async operation, kernel should not be blocked.

The kernel is not blocked.  AFAICT it is the EXT4 journal that is
blocked waiting on a write.

>                                                But what we see using
> mq-deadline is kernel blocked in bit_wait_io(). Do you think this is a
> valid behavior at least in case of mq-deadline IOscheduler?

mq-deadline is designed to favour reads over writes, so in that sense some
amount of write-starvation is normal.

> 
>> Alternatively you could fiddle with the scheduler parameters:
>>
>> With mq-deadline they are:
>>
>> # grep -H . /sys/block/mmcblk0/queue/iosched/*
>> /sys/block/mmcblk0/queue/iosched/fifo_batch:16
>> /sys/block/mmcblk0/queue/iosched/front_merges:1
>> /sys/block/mmcblk0/queue/iosched/read_expire:500
>> /sys/block/mmcblk0/queue/iosched/write_expire:5000
>> /sys/block/mmcblk0/queue/iosched/writes_starved:2
>>
>> You could try decreasing the write_expire and/or fifo_batch.
> It seems that decreasing doesn't affect on this issue.

That is surprising.  You could also try writes_starved=1 or
writes_starved=0.

_______________________________________________
linux-snps-arc mailing list
linux-snps-arc@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-snps-arc

^ permalink raw reply	[flat|nested] 11+ messages in thread

end of thread, other threads:[~2018-03-20  8:29 UTC | newest]

Thread overview: 11+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
     [not found] <1520942674.10285.8.camel@synopsys.com>
2018-03-13 14:05 ` mmc: block: bonnie++ runs with errors on arc/hsdk board Adrian Hunter
2018-03-13 15:56   ` Evgeniy Didin
2018-03-14 12:32     ` Evgeniy Didin
2018-03-15  9:27       ` Adrian Hunter
2018-03-15 15:08         ` Evgeniy Didin
2018-03-16 12:12           ` Adrian Hunter
2018-03-16 17:10             ` Evgeniy Didin
2018-03-20  8:29               ` Adrian Hunter
2018-03-15 16:38         ` Vineet Gupta
2018-03-15 17:21           ` Alexey Brodkin
2018-03-16  7:20             ` Adrian Hunter

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).