[PATCH] fio: fix hangs due to iodepth_low

[PATCH] fio: fix hangs due to iodepth_low

[Robert Elliott]

With some combinations of iodepth, iodepth_batch, iodepth_batch_complete,
and io_depth_low, do_io hangs after reaping the first set of completions
since io_u_queued_complete is called requesting more completions than
td->cur_depth.

Example printing min_evts and td->cur_depth in the do/while loop:
waiting on min=96 cd=627
waiting on min=96 cd=531
waiting on min=96 cd=435
waiting on min=96 cd=339
waiting on min=96 cd=243
waiting on min=96 cd=147
waiting on min=96 cd=51
Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 00m:09s]
...
Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 2863d:18h:28m:38s]
<fio never exits>

Fix this by adjusting min_evts to the current_depth if that is smaller.

Tested with a jobfile including:
iodepth=1011
iodepth_batch=96
iodepth_batch_complete=96
iodepth_low=1
runtime=15
time_based

Made the same change to do_verify, but not tested there.

Signed-off-by: Robert Elliott <elliott@hp.com>
---
 backend.c |    4 ++++
 1 files changed, 4 insertions(+), 0 deletions(-)

diff --git a/backend.c b/backend.c
index 7cb0a39..ce97f6d 100644
--- a/backend.c
+++ b/backend.c
@@ -606,6 +606,8 @@ reap:
 				 * and do the verification on them through
 				 * the callback handler
 				 */
+				if (min_events < td->cur_depth)
+					min_events = td->cur_depth;
 				if (io_u_queued_complete(td, min_events, bytes_done) < 0) {
 					ret = -1;
 					break;
@@ -873,6 +875,8 @@ reap:
 				fio_gettime(&comp_time, NULL);
 
 			do {
+				if (min_evts < td->cur_depth)
+					min_evts = td->cur_depth;
 				ret = io_u_queued_complete(td, min_evts, bytes_done);
 				if (ret < 0)
 					break;

[PATCH] fio: fix hangs due to iodepth_low

[Robert Elliott]

With some combinations of iodepth, iodepth_batch, iodepth_batch_complete,
and io_depth_low, do_io hangs after reaping the first set of completions
since io_u_queued_complete is called requesting more completions than
td->cur_depth.

Example printing min_evts and td->cur_depth in the do/while loop:
waiting on min=96 cd=627
waiting on min=96 cd=531
waiting on min=96 cd=435
waiting on min=96 cd=339
waiting on min=96 cd=243
waiting on min=96 cd=147
waiting on min=96 cd=51
Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 00m:09s]
...
Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 2863d:18h:28m:38s]
<fio never exits>

Fix this by adjusting min_evts to the current_depth if that is smaller.

Tested with a jobfile including:
iodepth=1011
iodepth_batch=96
iodepth_batch_complete=96
iodepth_low=1
runtime=15
time_based

Made the same change to do_verify, but not tested there.

Signed-off-by: Robert Elliott <elliott@hp.com>
---
 backend.c |    4 ++++
 1 files changed, 4 insertions(+), 0 deletions(-)

diff --git a/backend.c b/backend.c
index 7cb0a39..ce97f6d 100644
--- a/backend.c
+++ b/backend.c
@@ -606,6 +606,8 @@ reap:
 				 * and do the verification on them through
 				 * the callback handler
 				 */
+				if (min_events < td->cur_depth)
+					min_events = td->cur_depth;
 				if (io_u_queued_complete(td, min_events, bytes_done) < 0) {
 					ret = -1;
 					break;
@@ -873,6 +875,8 @@ reap:
 				fio_gettime(&comp_time, NULL);
 
 			do {
+				if (min_evts < td->cur_depth)
+					min_evts = td->cur_depth;
 				ret = io_u_queued_complete(td, min_evts, bytes_done);
 				if (ret < 0)
 					break;

Re: [PATCH] fio: fix hangs due to iodepth_low

[Stephen Cameron]

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

Huh.  Wonder if that's what I hit a week or two ago.

-- steve



On Wed, Sep 3, 2014 at 7:23 PM, Robert Elliott <elliott@hp.com> wrote:

> With some combinations of iodepth, iodepth_batch, iodepth_batch_complete,
> and io_depth_low, do_io hangs after reaping the first set of completions
> since io_u_queued_complete is called requesting more completions than
> td->cur_depth.
>
> Example printing min_evts and td->cur_depth in the do/while loop:
> waiting on min=96 cd=627
> waiting on min=96 cd=531
> waiting on min=96 cd=435
> waiting on min=96 cd=339
> waiting on min=96 cd=243
> waiting on min=96 cd=147
> waiting on min=96 cd=51
> Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta
> 00m:09s]
> ...
> Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta
> 2863d:18h:28m:38s]
> <fio never exits>
>
> Fix this by adjusting min_evts to the current_depth if that is smaller.
>
> Tested with a jobfile including:
> iodepth=1011
> iodepth_batch=96
> iodepth_batch_complete=96
> iodepth_low=1
> runtime=15
> time_based
>
> Made the same change to do_verify, but not tested there.
>
> Signed-off-by: Robert Elliott <elliott@hp.com>
> ---
>  backend.c |    4 ++++
>  1 files changed, 4 insertions(+), 0 deletions(-)
>
> diff --git a/backend.c b/backend.c
> index 7cb0a39..ce97f6d 100644
> --- a/backend.c
> +++ b/backend.c
> @@ -606,6 +606,8 @@ reap:
>                                  * and do the verification on them through
>                                  * the callback handler
>                                  */
> +                               if (min_events < td->cur_depth)
> +                                       min_events = td->cur_depth;
>                                 if (io_u_queued_complete(td, min_events,
> bytes_done) < 0) {
>                                         ret = -1;
>                                         break;
> @@ -873,6 +875,8 @@ reap:
>                                 fio_gettime(&comp_time, NULL);
>
>                         do {
> +                               if (min_evts < td->cur_depth)
> +                                       min_evts = td->cur_depth;
>                                 ret = io_u_queued_complete(td, min_evts,
> bytes_done);
>                                 if (ret < 0)
>                                         break;
>
> --
> To unsubscribe from this list: send the line "unsubscribe fio" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

[-- Attachment #2: Type: text/html, Size: 3570 bytes --]

Re: [PATCH] fio: fix hangs due to iodepth_low

[Jens Axboe]

On 2014-09-03 18:23, Robert Elliott wrote:
> With some combinations of iodepth, iodepth_batch, iodepth_batch_complete,
> and io_depth_low, do_io hangs after reaping the first set of completions
> since io_u_queued_complete is called requesting more completions than
> td->cur_depth.
>
> Example printing min_evts and td->cur_depth in the do/while loop:
> waiting on min=96 cd=627
> waiting on min=96 cd=531
> waiting on min=96 cd=435
> waiting on min=96 cd=339
> waiting on min=96 cd=243
> waiting on min=96 cd=147
> waiting on min=96 cd=51
> Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 00m:09s]
> ...
> Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops] [eta 2863d:18h:28m:38s]
> <fio never exits>
>
> Fix this by adjusting min_evts to the current_depth if that is smaller.
>
> Tested with a jobfile including:
> iodepth=1011
> iodepth_batch=96
> iodepth_batch_complete=96
> iodepth_low=1
> runtime=15
> time_based
>
> Made the same change to do_verify, but not tested there.
>
> Signed-off-by: Robert Elliott <elliott@hp.com>
> ---
>   backend.c |    4 ++++
>   1 files changed, 4 insertions(+), 0 deletions(-)
>
> diff --git a/backend.c b/backend.c
> index 7cb0a39..ce97f6d 100644
> --- a/backend.c
> +++ b/backend.c
> @@ -606,6 +606,8 @@ reap:
>   				 * and do the verification on them through
>   				 * the callback handler
>   				 */
> +				if (min_events < td->cur_depth)
> +					min_events = td->cur_depth;

Did you reverse these? From the description and debug output, seems it 
should be:

	if (min_events > td->cur_depth)
		min_events = td->cur_depth;

and we should probably put this logic in io_u_queued_complete(), I think 
that would be a safer alternative instead of near the callers.

-- 
Jens Axboe

Re: [PATCH] fio: fix hangs due to iodepth_low

[Jens Axboe]

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

On 2014-09-03 19:34, Jens Axboe wrote:
> On 2014-09-03 18:23, Robert Elliott wrote:
>> With some combinations of iodepth, iodepth_batch, iodepth_batch_complete,
>> and io_depth_low, do_io hangs after reaping the first set of completions
>> since io_u_queued_complete is called requesting more completions than
>> td->cur_depth.
>>
>> Example printing min_evts and td->cur_depth in the do/while loop:
>> waiting on min=96 cd=627
>> waiting on min=96 cd=531
>> waiting on min=96 cd=435
>> waiting on min=96 cd=339
>> waiting on min=96 cd=243
>> waiting on min=96 cd=147
>> waiting on min=96 cd=51
>> Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops]
>> [eta 00m:09s]
>> ...
>> Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops]
>> [eta 2863d:18h:28m:38s]
>> <fio never exits>
>>
>> Fix this by adjusting min_evts to the current_depth if that is smaller.
>>
>> Tested with a jobfile including:
>> iodepth=1011
>> iodepth_batch=96
>> iodepth_batch_complete=96
>> iodepth_low=1
>> runtime=15
>> time_based
>>
>> Made the same change to do_verify, but not tested there.
>>
>> Signed-off-by: Robert Elliott <elliott@hp.com>
>> ---
>>   backend.c |    4 ++++
>>   1 files changed, 4 insertions(+), 0 deletions(-)
>>
>> diff --git a/backend.c b/backend.c
>> index 7cb0a39..ce97f6d 100644
>> --- a/backend.c
>> +++ b/backend.c
>> @@ -606,6 +606,8 @@ reap:
>>                    * and do the verification on them through
>>                    * the callback handler
>>                    */
>> +                if (min_events < td->cur_depth)
>> +                    min_events = td->cur_depth;
>
> Did you reverse these? From the description and debug output, seems it
> should be:
>
>      if (min_events > td->cur_depth)
>          min_events = td->cur_depth;
>
> and we should probably put this logic in io_u_queued_complete(), I think
> that would be a safer alternative instead of near the callers.

Ala the attached.

-- 
Jens Axboe


[-- Attachment #2: depth.patch --]
[-- Type: text/x-patch, Size: 372 bytes --]

diff --git a/io_u.c b/io_u.c
index ba192a32a985..be2f242a6e2b 100644
--- a/io_u.c
+++ b/io_u.c
@@ -1792,6 +1792,8 @@ int io_u_queued_complete(struct thread_data *td, int min_evts,
 
 	if (!min_evts)
 		tvp = &ts;
+	else if (min_evts > td->cur_depth)
+		min_evts = td->cur_depth;
 
 	ret = td_io_getevents(td, min_evts, td->o.iodepth_batch_complete, tvp);
 	if (ret < 0) {

RE: [PATCH] fio: fix hangs due to iodepth_low

[Elliott, Robert (Server Storage)]

> -----Original Message-----
> From: Jens Axboe [mailto:axboe@kernel.dk]
> Sent: Wednesday, September 03, 2014 8:34 PM
> To: Elliott, Robert (Server Storage); fio@vger.kernel.org;
> scameron@beardog.cce.hp.com
> Subject: Re: [PATCH] fio: fix hangs due to iodepth_low
> 
> On 2014-09-03 18:23, Robert Elliott wrote:
> > With some combinations of iodepth, iodepth_batch,
> iodepth_batch_complete,
> > and io_depth_low, do_io hangs after reaping the first set of
> completions
> > since io_u_queued_complete is called requesting more completions than
> > td->cur_depth.
> >
> > Example printing min_evts and td->cur_depth in the do/while loop:
> > waiting on min=96 cd=627
> > waiting on min=96 cd=531
> > waiting on min=96 cd=435
> > waiting on min=96 cd=339
> > waiting on min=96 cd=243
> > waiting on min=96 cd=147
> > waiting on min=96 cd=51
> > Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops]
> [eta 00m:09s]
> > ...
> > Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops]
> [eta 2863d:18h:28m:38s]
> > <fio never exits>
> >
> > Fix this by adjusting min_evts to the current_depth if that is
> smaller.
> >
> > Tested with a jobfile including:
> > iodepth=1011
> > iodepth_batch=96
> > iodepth_batch_complete=96
> > iodepth_low=1
> > runtime=15
> > time_based
> >
> > Made the same change to do_verify, but not tested there.
> >
> > Signed-off-by: Robert Elliott <elliott@hp.com>
> > ---
> >   backend.c |    4 ++++
> >   1 files changed, 4 insertions(+), 0 deletions(-)
> >
> > diff --git a/backend.c b/backend.c
> > index 7cb0a39..ce97f6d 100644
> > --- a/backend.c
> > +++ b/backend.c
> > @@ -606,6 +606,8 @@ reap:
> >   				 * and do the verification on them through
> >   				 * the callback handler
> >   				 */
> > +				if (min_events < td->cur_depth)
> > +					min_events = td->cur_depth;
> 
> Did you reverse these? From the description and debug output, seems it
> should be:
> 
> 	if (min_events > td->cur_depth)
> 		min_events = td->cur_depth;
> 
> and we should probably put this logic in io_u_queued_complete(), I think
> that would be a safer alternative instead of near the callers.
> 
> --
> Jens Axboe

Sorry, yes - I didn't put it back right after adding code
to inject the error.

I will send an updated patch tomorrow putting the check into
io_u_queued_complete (if that has access to td).

Re: [PATCH] fio: fix hangs due to iodepth_low

[Jens Axboe]

On 2014-09-03 20:08, Elliott, Robert (Server Storage) wrote:
>
>
>> -----Original Message-----
>> From: Jens Axboe [mailto:axboe@kernel.dk]
>> Sent: Wednesday, September 03, 2014 8:34 PM
>> To: Elliott, Robert (Server Storage); fio@vger.kernel.org;
>> scameron@beardog.cce.hp.com
>> Subject: Re: [PATCH] fio: fix hangs due to iodepth_low
>>
>> On 2014-09-03 18:23, Robert Elliott wrote:
>>> With some combinations of iodepth, iodepth_batch,
>> iodepth_batch_complete,
>>> and io_depth_low, do_io hangs after reaping the first set of
>> completions
>>> since io_u_queued_complete is called requesting more completions than
>>> td->cur_depth.
>>>
>>> Example printing min_evts and td->cur_depth in the do/while loop:
>>> waiting on min=96 cd=627
>>> waiting on min=96 cd=531
>>> waiting on min=96 cd=435
>>> waiting on min=96 cd=339
>>> waiting on min=96 cd=243
>>> waiting on min=96 cd=147
>>> waiting on min=96 cd=51
>>> Jobs: 12 (f=12): [r(12)] [43.8% done] [0KB/0KB/0KB /s] [0/0/0 iops]
>> [eta 00m:09s]
>>> ...
>>> Jobs: 12 (f=12): [r(12)] [0.0% done] [0KB/0KB/0KB /s] [0/0/0 iops]
>> [eta 2863d:18h:28m:38s]
>>> <fio never exits>
>>>
>>> Fix this by adjusting min_evts to the current_depth if that is
>> smaller.
>>>
>>> Tested with a jobfile including:
>>> iodepth=1011
>>> iodepth_batch=96
>>> iodepth_batch_complete=96
>>> iodepth_low=1
>>> runtime=15
>>> time_based
>>>
>>> Made the same change to do_verify, but not tested there.
>>>
>>> Signed-off-by: Robert Elliott <elliott@hp.com>
>>> ---
>>>    backend.c |    4 ++++
>>>    1 files changed, 4 insertions(+), 0 deletions(-)
>>>
>>> diff --git a/backend.c b/backend.c
>>> index 7cb0a39..ce97f6d 100644
>>> --- a/backend.c
>>> +++ b/backend.c
>>> @@ -606,6 +606,8 @@ reap:
>>>    				 * and do the verification on them through
>>>    				 * the callback handler
>>>    				 */
>>> +				if (min_events < td->cur_depth)
>>> +					min_events = td->cur_depth;
>>
>> Did you reverse these? From the description and debug output, seems it
>> should be:
>>
>> 	if (min_events > td->cur_depth)
>> 		min_events = td->cur_depth;
>>
>> and we should probably put this logic in io_u_queued_complete(), I think
>> that would be a safer alternative instead of near the callers.
>>
>> --
>> Jens Axboe
>
> Sorry, yes - I didn't put it back right after adding code
> to inject the error.
>
> I will send an updated patch tomorrow putting the check into
> io_u_queued_complete (if that has access to td).

Thanks, much appreciated! The fix is the easy part, the diagnosing was 
the hard part.

-- 
Jens Axboe

RE: [PATCH] fio: fix hangs due to iodepth_low

[Elliott, Robert (Server Storage)]

> > should be:
> >
> >      if (min_events > td->cur_depth)
> >          min_events = td->cur_depth;
> >
> > and we should probably put this logic in io_u_queued_complete(), I
> think
> > that would be a safer alternative instead of near the callers.

io_u_quisce, which calls io_u_queued_complete with an argument 
of 1, includes this comment:
         * and cur_depth is meaningless for sync engines.

If that is invoked during sync traffic too, then putting this
change inside io_u_queued_complete might not work right.


---
Rob Elliott    HP Server Storage

Re: [PATCH] fio: fix hangs due to iodepth_low

[Jens Axboe]

On 09/04/2014 08:27 AM, Elliott, Robert (Server Storage) wrote:
>>> should be:
>>>
>>>      if (min_events > td->cur_depth)
>>>          min_events = td->cur_depth;
>>>
>>> and we should probably put this logic in io_u_queued_complete(), I
>> think
>>> that would be a safer alternative instead of near the callers.
> 
> io_u_quisce, which calls io_u_queued_complete with an argument 
> of 1, includes this comment:
>          * and cur_depth is meaningless for sync engines.
> 
> If that is invoked during sync traffic too, then putting this
> change inside io_u_queued_complete might not work right.

It's good enough for this use case. And it doesn't really matter if it's
near the caller or in the function from this point of view, since there
will be nothing (0) to complete for sync engines. By their very nature,
they have nothing pending at that point. So I think the patch is fine as
I sent out.

-- 
Jens Axboe

RE: [PATCH] fio: fix hangs due to iodepth_low

[Elliott, Robert (Server Storage)]

> -----Original Message-----
> From: Jens Axboe [mailto:axboe@kernel.dk]
> Sent: Thursday, 04 September, 2014 9:39 AM
> To: Elliott, Robert (Server Storage); fio@vger.kernel.org;
> scameron@beardog.cce.hp.com
> Subject: Re: [PATCH] fio: fix hangs due to iodepth_low
> 
> On 09/04/2014 08:27 AM, Elliott, Robert (Server Storage) wrote:
> >>> should be:
> >>>
> >>>      if (min_events > td->cur_depth)
> >>>          min_events = td->cur_depth;
> >>>
> >>> and we should probably put this logic in io_u_queued_complete(),
> I
> >> think
> >>> that would be a safer alternative instead of near the callers.
> >
> > io_u_quisce, which calls io_u_queued_complete with an argument
> > of 1, includes this comment:
> >          * and cur_depth is meaningless for sync engines.
> >
> > If that is invoked during sync traffic too, then putting this
> > change inside io_u_queued_complete might not work right.
> 
> It's good enough for this use case. And it doesn't really matter if
> it's
> near the caller or in the function from this point of view, since
> there
> will be nothing (0) to complete for sync engines. By their very
> nature,
> they have nothing pending at that point. So I think the patch is fine
> as
> I sent out.

I ran this version through similar tests and it works as well.

Re: [PATCH] fio: fix hangs due to iodepth_low

[Jens Axboe]

On 09/04/2014 01:42 PM, Elliott, Robert (Server Storage) wrote:
> 
> 
>> -----Original Message-----
>> From: Jens Axboe [mailto:axboe@kernel.dk]
>> Sent: Thursday, 04 September, 2014 9:39 AM
>> To: Elliott, Robert (Server Storage); fio@vger.kernel.org;
>> scameron@beardog.cce.hp.com
>> Subject: Re: [PATCH] fio: fix hangs due to iodepth_low
>>
>> On 09/04/2014 08:27 AM, Elliott, Robert (Server Storage) wrote:
>>>>> should be:
>>>>>
>>>>>      if (min_events > td->cur_depth)
>>>>>          min_events = td->cur_depth;
>>>>>
>>>>> and we should probably put this logic in io_u_queued_complete(),
>> I
>>>> think
>>>>> that would be a safer alternative instead of near the callers.
>>>
>>> io_u_quisce, which calls io_u_queued_complete with an argument
>>> of 1, includes this comment:
>>>          * and cur_depth is meaningless for sync engines.
>>>
>>> If that is invoked during sync traffic too, then putting this
>>> change inside io_u_queued_complete might not work right.
>>
>> It's good enough for this use case. And it doesn't really matter if
>> it's
>> near the caller or in the function from this point of view, since
>> there
>> will be nothing (0) to complete for sync engines. By their very
>> nature,
>> they have nothing pending at that point. So I think the patch is fine
>> as
>> I sent out.
> 
> I ran this version through similar tests and it works as well.

Great thanks Rob, I committed that fix.

-- 
Jens Axboe