Re: [PATCH 2/2] block: remove the ioprio field from struct request

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Sam Protsenko]

Hi Christoph,

This patch causes a regression on E850-96 board. Specifically, there are
two noticeable time lags when booting Debian rootfs:

  1. When systemd reports this stage:

         "Reached target getty.target - Login Prompts."

     it hangs for 5 seconds or so, before going further.

  2. When I'm logging in, the system hangs for 60 seconds or so before
     the shell prompt appears.

It only seems to reproduce the first time (during the boot). My attempt to
re-start the mentioned systemd target or run "login" command again worked
fine.

Reverting commit 6975c1a486a4 ("block: remove the ioprio field from
struct request") fixes the issue for me. Do you have any ideas by chance
what might be the reason? Or maybe you have any pointers on debugging it?

Thanks!

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Christoph Hellwig]

On Thu, Nov 21, 2024 at 11:04:19PM -0600, Sam Protsenko wrote:
> Hi Christoph,
> 
> This patch causes a regression on E850-96 board. Specifically, there are
> two noticeable time lags when booting Debian rootfs:

What storage driver does this board use?  Anything else interesting
about the setup?

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Sam Protsenko]

On Fri, Nov 22, 2024 at 6:04 AM Christoph Hellwig <hch@lst.de> wrote:
>
> On Thu, Nov 21, 2024 at 11:04:19PM -0600, Sam Protsenko wrote:
> > Hi Christoph,
> >
> > This patch causes a regression on E850-96 board. Specifically, there are
> > two noticeable time lags when booting Debian rootfs:
>
> What storage driver does this board use?  Anything else interesting
> about the setup?
>

It's an Exynos based board with eMMC, so it uses DW MMC driver, with
Exynos glue layer on top of it, so:

    drivers/mmc/host/dw_mmc.c
    drivers/mmc/host/dw_mmc-exynos.c

I'm using the regular ARM64 defconfig. Nothing fancy about this setup
neither, the device tree with eMMC definition (mmc_0) is here:

    arch/arm64/boot/dts/exynos/exynos850-e850-96.dts

FWIW, I was able to narrow down the issue to dd_insert_request()
function. With this hack the freeze is gone:

8<-------------------------------------------------------------------->8
diff --git a/block/mq-deadline.c b/block/mq-deadline.c
index acdc28756d9d..83d272b66e71 100644
--- a/block/mq-deadline.c
+++ b/block/mq-deadline.c
@@ -676,7 +676,7 @@ static void dd_insert_request(struct blk_mq_hw_ctx
*hctx, struct request *rq,
        struct request_queue *q = hctx->queue;
        struct deadline_data *dd = q->elevator->elevator_data;
        const enum dd_data_dir data_dir = rq_data_dir(rq);
-       u16 ioprio = req_get_ioprio(rq);
+       u16 ioprio = 0; /* the same as old req->ioprio */
        u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
        struct dd_per_prio *per_prio;
        enum dd_prio prio;
8<-------------------------------------------------------------------->8

Does it tell you anything about where the possible issue can be?

Thanks!

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Bart Van Assche]

On 11/22/24 1:55 PM, Sam Protsenko wrote:
> On Fri, Nov 22, 2024 at 6:04 AM Christoph Hellwig <hch@lst.de> wrote:
>>
>> On Thu, Nov 21, 2024 at 11:04:19PM -0600, Sam Protsenko wrote:
>>> Hi Christoph,
>>>
>>> This patch causes a regression on E850-96 board. Specifically, there are
>>> two noticeable time lags when booting Debian rootfs:
>>
>> What storage driver does this board use?  Anything else interesting
>> about the setup?
>>
> 
> It's an Exynos based board with eMMC, so it uses DW MMC driver, with
> Exynos glue layer on top of it, so:
> 
>      drivers/mmc/host/dw_mmc.c
>      drivers/mmc/host/dw_mmc-exynos.c
> 
> I'm using the regular ARM64 defconfig. Nothing fancy about this setup
> neither, the device tree with eMMC definition (mmc_0) is here:
> 
>      arch/arm64/boot/dts/exynos/exynos850-e850-96.dts
> 
> FWIW, I was able to narrow down the issue to dd_insert_request()
> function. With this hack the freeze is gone:
> 
> 8<-------------------------------------------------------------------->8
> diff --git a/block/mq-deadline.c b/block/mq-deadline.c
> index acdc28756d9d..83d272b66e71 100644
> --- a/block/mq-deadline.c
> +++ b/block/mq-deadline.c
> @@ -676,7 +676,7 @@ static void dd_insert_request(struct blk_mq_hw_ctx
> *hctx, struct request *rq,
>          struct request_queue *q = hctx->queue;
>          struct deadline_data *dd = q->elevator->elevator_data;
>          const enum dd_data_dir data_dir = rq_data_dir(rq);
> -       u16 ioprio = req_get_ioprio(rq);
> +       u16 ioprio = 0; /* the same as old req->ioprio */
>          u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
>          struct dd_per_prio *per_prio;
>          enum dd_prio prio;
> 8<-------------------------------------------------------------------->8
> 
> Does it tell you anything about where the possible issue can be?

It seems like eMMC devices do not tolerate I/O prioritization. How about
disabling I/O prioritization for eMMC setups? Is the ioprio cgroup
controller perhaps activated by the user space software that is running
on this setup?

Thanks,

Bart.

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Sam Protsenko]

Hi Bart,

On Fri, Nov 22, 2024 at 4:18 PM Bart Van Assche <bvanassche@acm.org> wrote:
>
> On 11/22/24 1:55 PM, Sam Protsenko wrote:
> > On Fri, Nov 22, 2024 at 6:04 AM Christoph Hellwig <hch@lst.de> wrote:
> >>
> >> On Thu, Nov 21, 2024 at 11:04:19PM -0600, Sam Protsenko wrote:
> >>> Hi Christoph,
> >>>
> >>> This patch causes a regression on E850-96 board. Specifically, there are
> >>> two noticeable time lags when booting Debian rootfs:
> >>
> >> What storage driver does this board use?  Anything else interesting
> >> about the setup?
> >>
> >
> > It's an Exynos based board with eMMC, so it uses DW MMC driver, with
> > Exynos glue layer on top of it, so:
> >
> >      drivers/mmc/host/dw_mmc.c
> >      drivers/mmc/host/dw_mmc-exynos.c
> >
> > I'm using the regular ARM64 defconfig. Nothing fancy about this setup
> > neither, the device tree with eMMC definition (mmc_0) is here:
> >
> >      arch/arm64/boot/dts/exynos/exynos850-e850-96.dts
> >
> > FWIW, I was able to narrow down the issue to dd_insert_request()
> > function. With this hack the freeze is gone:
> >
> > 8<-------------------------------------------------------------------->8
> > diff --git a/block/mq-deadline.c b/block/mq-deadline.c
> > index acdc28756d9d..83d272b66e71 100644
> > --- a/block/mq-deadline.c
> > +++ b/block/mq-deadline.c
> > @@ -676,7 +676,7 @@ static void dd_insert_request(struct blk_mq_hw_ctx
> > *hctx, struct request *rq,
> >          struct request_queue *q = hctx->queue;
> >          struct deadline_data *dd = q->elevator->elevator_data;
> >          const enum dd_data_dir data_dir = rq_data_dir(rq);
> > -       u16 ioprio = req_get_ioprio(rq);
> > +       u16 ioprio = 0; /* the same as old req->ioprio */
> >          u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
> >          struct dd_per_prio *per_prio;
> >          enum dd_prio prio;
> > 8<-------------------------------------------------------------------->8
> >
> > Does it tell you anything about where the possible issue can be?
>
> It seems like eMMC devices do not tolerate I/O prioritization. How about
> disabling I/O prioritization for eMMC setups? Is the ioprio cgroup
> controller perhaps activated by the user space software that is running
> on this setup?
>

Can you please elaborate on why eMMC devices might not play well with
prios? Do they lack some particular hardware support, like required
commands? Also, I've noticed (probably) the same issue reported
recently [1] for USB SSD drives. so it'd nice to have some references
showing it's actually the case specifically for eMMC.

Do you know if we have any config options to disable I/O
prioritization? Not sure how exactly we can do that specifically for
eMMC devices too. I'm not an expert in block layer, would appreciate
some help with this one.

For ioprio cgroup: CONFIG_BLK_CGROUP_IOPRIO option is disabled in my
case (ARM64 defconfig), so I don't think it has to do with ioprio
cgroup?

[1] https://lore.kernel.org/all/CAP-bSRbCo7=wfUBZ8H7c3Q-7XSG+SB=R4MHHNNGPvBoinsVSZg@mail.gmail.com/

Thanks!

> Thanks,
>
> Bart.

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Christoph Hellwig]

On Fri, Nov 22, 2024 at 03:55:23PM -0600, Sam Protsenko wrote:
> It's an Exynos based board with eMMC, so it uses DW MMC driver, with
> Exynos glue layer on top of it, so:
> 
>     drivers/mmc/host/dw_mmc.c
>     drivers/mmc/host/dw_mmc-exynos.c
> 
> I'm using the regular ARM64 defconfig. Nothing fancy about this setup
> neither, the device tree with eMMC definition (mmc_0) is here:
> 
>     arch/arm64/boot/dts/exynos/exynos850-e850-96.dts

Thanks.  eMMC itself never looks at the ioprio field.

> FWIW, I was able to narrow down the issue to dd_insert_request()
> function. With this hack the freeze is gone:

Sounds like it isn't the driver that matters here, but the scheduler.

> 
> 8<-------------------------------------------------------------------->8
> diff --git a/block/mq-deadline.c b/block/mq-deadline.c
> index acdc28756d9d..83d272b66e71 100644
> --- a/block/mq-deadline.c
> +++ b/block/mq-deadline.c
> @@ -676,7 +676,7 @@ static void dd_insert_request(struct blk_mq_hw_ctx
> *hctx, struct request *rq,
>         struct request_queue *q = hctx->queue;
>         struct deadline_data *dd = q->elevator->elevator_data;
>         const enum dd_data_dir data_dir = rq_data_dir(rq);
> -       u16 ioprio = req_get_ioprio(rq);
> +       u16 ioprio = 0; /* the same as old req->ioprio */
>         u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
>         struct dd_per_prio *per_prio;
>         enum dd_prio prio;
> 8<-------------------------------------------------------------------->8
> 
> Does it tell you anything about where the possible issue can be?

Can you dump the ioprities you see here with and without the reverted
patch?

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Sam Protsenko]

Hi Christoph,

On Mon, Nov 25, 2024 at 1:37 AM Christoph Hellwig <hch@lst.de> wrote:
>
> On Fri, Nov 22, 2024 at 03:55:23PM -0600, Sam Protsenko wrote:
> > It's an Exynos based board with eMMC, so it uses DW MMC driver, with
> > Exynos glue layer on top of it, so:
> >
> >     drivers/mmc/host/dw_mmc.c
> >     drivers/mmc/host/dw_mmc-exynos.c
> >
> > I'm using the regular ARM64 defconfig. Nothing fancy about this setup
> > neither, the device tree with eMMC definition (mmc_0) is here:
> >
> >     arch/arm64/boot/dts/exynos/exynos850-e850-96.dts
>
> Thanks.  eMMC itself never looks at the ioprio field.
>
> > FWIW, I was able to narrow down the issue to dd_insert_request()
> > function. With this hack the freeze is gone:
>
> Sounds like it isn't the driver that matters here, but the scheduler.
>
> >
> > 8<-------------------------------------------------------------------->8
> > diff --git a/block/mq-deadline.c b/block/mq-deadline.c
> > index acdc28756d9d..83d272b66e71 100644
> > --- a/block/mq-deadline.c
> > +++ b/block/mq-deadline.c
> > @@ -676,7 +676,7 @@ static void dd_insert_request(struct blk_mq_hw_ctx
> > *hctx, struct request *rq,
> >         struct request_queue *q = hctx->queue;
> >         struct deadline_data *dd = q->elevator->elevator_data;
> >         const enum dd_data_dir data_dir = rq_data_dir(rq);
> > -       u16 ioprio = req_get_ioprio(rq);
> > +       u16 ioprio = 0; /* the same as old req->ioprio */
> >         u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
> >         struct dd_per_prio *per_prio;
> >         enum dd_prio prio;
> > 8<-------------------------------------------------------------------->8
> >
> > Does it tell you anything about where the possible issue can be?
>
> Can you dump the ioprities you see here with and without the reverted
> patch?
>

Collected the logs for you:
  - with patch reverted (ioprio is always 0): [1]
  - with patch present: [2]

This code was added for printing the traces:

8<---------------------------------------------------------------------->8
 static void dd_insert_request(struct blk_mq_hw_ctx *hctx, struct request *rq,
                               blk_insert_t flags, struct list_head *free)
 {
+#define IOPRIO_N_LIMIT 100
+       static int ioprio_prev = 0, ioprio_n = 0;
        struct request_queue *q = hctx->queue;
        struct deadline_data *dd = q->elevator->elevator_data;
        const enum dd_data_dir data_dir = rq_data_dir(rq);
        u16 ioprio = req_get_ioprio(rq);
        u8 ioprio_class = IOPRIO_PRIO_CLASS(ioprio);
        struct dd_per_prio *per_prio;
        enum dd_prio prio;

+       ioprio_n++;
+       if (ioprio != ioprio_prev || ioprio_n == IOPRIO_N_LIMIT) {
+               pr_err("### %-20d : %d times\n", ioprio_prev, ioprio_n);
+               ioprio_n = 0;
+       }
+       ioprio_prev = ioprio;
+
        lockdep_assert_held(&dd->lock);
8<---------------------------------------------------------------------->8

Specifically I'd pay attention to the next two places in [2], where
the delays were introduced:

1. Starting getty service (5 second delay):

8<---------------------------------------------------------------------->8
[   14.875199] ### 24580                : 1 times
...
[  OK  ] Started getty@tty1.service - Getty on tty1.
[  OK  ] Started serial-getty@ttySAâice - Serial Getty on ttySAC0.
[  OK  ] Reached target getty.target - Login Prompts.
[   19.425354] ### 0                    : 100 times
...
8<---------------------------------------------------------------------->8

2. Login (more than 60 seconds delay):

8<---------------------------------------------------------------------->8
runner-vwmj3eza-project-40964107-concurrent-0 login: root
...
[   22.827432] ### 0                    : 100 times
...
[  100.100402] ### 24580                : 1 times
#
8<---------------------------------------------------------------------->8

I guess the results look similar to the logs from the neighboring
thread [3]. Not sure if those tools (getty service and login tool) are
running ioprio_set() internally, or it's just I/O scheduler acting up,
but the freeze is happening consistently in those two places. Please
let me know if I can help you debug that further. Not a block layer
expert by any means, but that looks like a regression, at least on
E850-96 board. Wonder if it's possible to reproduce that on other
platforms.

Thanks!

[1] https://termbin.com/aus7
[2] https://termbin.com/za3t
[3] https://lore.kernel.org/all/CAP-bSRab1C-_aaATfrgWjt9w0fcYUCQCG7u+TCb1FSPSd6CEaA@mail.gmail.com/

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Christoph Hellwig]

Hi Sam,

please try the patch below:

diff --git a/block/mq-deadline.c b/block/mq-deadline.c
index acdc28756d9d..91b3789f710e 100644
--- a/block/mq-deadline.c
+++ b/block/mq-deadline.c
@@ -685,10 +685,9 @@ static void dd_insert_request(struct blk_mq_hw_ctx *hctx, struct request *rq,
 
 	prio = ioprio_class_to_prio[ioprio_class];
 	per_prio = &dd->per_prio[prio];
-	if (!rq->elv.priv[0]) {
+	if (!rq->elv.priv[0])
 		per_prio->stats.inserted++;
-		rq->elv.priv[0] = (void *)(uintptr_t)1;
-	}
+	rq->elv.priv[0] = per_prio;
 
 	if (blk_mq_sched_try_insert_merge(q, rq, free))
 		return;
@@ -753,18 +752,14 @@ static void dd_prepare_request(struct request *rq)
  */
 static void dd_finish_request(struct request *rq)
 {
-	struct request_queue *q = rq->q;
-	struct deadline_data *dd = q->elevator->elevator_data;
-	const u8 ioprio_class = dd_rq_ioclass(rq);
-	const enum dd_prio prio = ioprio_class_to_prio[ioprio_class];
-	struct dd_per_prio *per_prio = &dd->per_prio[prio];
+	struct dd_per_prio *per_prio = rq->elv.priv[0];
 
 	/*
 	 * The block layer core may call dd_finish_request() without having
 	 * called dd_insert_requests(). Skip requests that bypassed I/O
 	 * scheduling. See also blk_mq_request_bypass_insert().
 	 */
-	if (rq->elv.priv[0])
+	if (per_prio)
 		atomic_inc(&per_prio->stats.completed);
 }
 

Re: [PATCH 2/2] block: remove the ioprio field from struct request

[Sam Protsenko]

On Tue, Nov 26, 2024 at 12:52 AM Christoph Hellwig <hch@lst.de> wrote:
>
> Hi Sam,
>
> please try the patch below:
>

I can confirm the patch fixes the issue on my side. Please add me to
Cc: if you're going to send the fix. And I'm always available to run
more tests on E850-96 board if you need it.

Thanks!

> diff --git a/block/mq-deadline.c b/block/mq-deadline.c
> index acdc28756d9d..91b3789f710e 100644
> --- a/block/mq-deadline.c
> +++ b/block/mq-deadline.c
> @@ -685,10 +685,9 @@ static void dd_insert_request(struct blk_mq_hw_ctx *hctx, struct request *rq,
>
>         prio = ioprio_class_to_prio[ioprio_class];
>         per_prio = &dd->per_prio[prio];
> -       if (!rq->elv.priv[0]) {
> +       if (!rq->elv.priv[0])
>                 per_prio->stats.inserted++;
> -               rq->elv.priv[0] = (void *)(uintptr_t)1;
> -       }
> +       rq->elv.priv[0] = per_prio;
>
>         if (blk_mq_sched_try_insert_merge(q, rq, free))
>                 return;
> @@ -753,18 +752,14 @@ static void dd_prepare_request(struct request *rq)
>   */
>  static void dd_finish_request(struct request *rq)
>  {
> -       struct request_queue *q = rq->q;
> -       struct deadline_data *dd = q->elevator->elevator_data;
> -       const u8 ioprio_class = dd_rq_ioclass(rq);
> -       const enum dd_prio prio = ioprio_class_to_prio[ioprio_class];
> -       struct dd_per_prio *per_prio = &dd->per_prio[prio];
> +       struct dd_per_prio *per_prio = rq->elv.priv[0];
>
>         /*
>          * The block layer core may call dd_finish_request() without having
>          * called dd_insert_requests(). Skip requests that bypassed I/O
>          * scheduling. See also blk_mq_request_bypass_insert().
>          */
> -       if (rq->elv.priv[0])
> +       if (per_prio)
>                 atomic_inc(&per_prio->stats.completed);
>  }
>