[RFC] Order 4 allocation failures in the MEI client driver

[RFC] Order 4 allocation failures in the MEI client driver

[Rohit Agarwal]

Hi All,

I am seeing an inconsistent allocation (kmalloc) failure in the mei client driver [1]
in chromebooks. The crash indicates the driver is requesting for an order 4 allocation
that is unavailable at that particular snapshot of the system.

I am new to this and do not know the history behind the roundup to order
4 [2]. According to the sources, order 4 allocations are not guaranteed and
should be avoided most of the time. And considering the chromebooks
limited memory, this may become an expected behavior.

Can we have more details on this as to why order 4 allocation is
required? Or can we have a lower order allocation request that can be
helpful for low memory platforms?

Some solutions that I explored and weren't applicable/helpful here:
1. using a vmalloc/kvmalloc instead of kmalloc (Due to DMA usage).
2. using a scatter gather list (Would require a lot of rework in the driver and still
not sure if that would work as it would require changes in the underlying layer as well)
3. retry mechanism (would help in few instances only).
4. allocating from the DMA pool?

Please help in this query and help me correct my understanding wherever wrong.
Thanks in advance!!!

Thanks,
Rohit.

[1] https://github.com/torvalds/linux/blob/master/drivers/misc/mei/client.c#L500
[2] https://lore.kernel.org/lkml/20180731063544.25540-10-tomas.winkler@intel.com/

Re: [RFC] Order 4 allocation failures in the MEI client driver

[Arnd Bergmann]

On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
> Hi All,
>
> I am seeing an inconsistent allocation (kmalloc) failure in the mei 
> client driver [1]
> in chromebooks. The crash indicates the driver is requesting for an 
> order 4 allocation
> that is unavailable at that particular snapshot of the system.
>
> I am new to this and do not know the history behind the roundup to order
> 4 [2]. According to the sources, order 4 allocations are not guaranteed and
> should be avoided most of the time. And considering the chromebooks
> limited memory, this may become an expected behavior.

I don't see how that commit is related to the failure in
mei_cl_alloc_cb(), that one only rounds the size up to a multiple
of four bytes.

What is the call chain you see in the kernel messages? Is it
always the same?

> Can we have more details on this as to why order 4 allocation is
> required? Or can we have a lower order allocation request that can be
> helpful for low memory platforms?
>
> Some solutions that I explored and weren't applicable/helpful here:
> 1. using a vmalloc/kvmalloc instead of kmalloc (Due to DMA usage).
> 2. using a scatter gather list (Would require a lot of rework in the 
> driver and still
> not sure if that would work as it would require changes in the 
> underlying layer as well)
> 3. retry mechanism (would help in few instances only).
> 4. allocating from the DMA pool?

Those (1, 2 and 4) would have been my suggestions as well ;-)
I don't think 4 helps on x86 machines though, since there
is no CMA area (and there should not need to be either).

If this happens during runtime (after the system is alredy
fully booted), another idea would be to move the allocation
to boot time where it is very likely to succeed and just never
free it again. Whether that works or not depends on the
exact call chain.

Allocating 64KB of consecutive pages repeatedly is clearly
a problem at runtime, but having a single allocation during
probe time is not as bad.

       Arnd

RE: [RFC] Order 4 allocation failures in the MEI client driver

[Winkler, Tomas]

> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
> > Hi All,
> >
> > I am seeing an inconsistent allocation (kmalloc) failure in the mei
> > client driver [1] in chromebooks. The crash indicates the driver is
> > requesting for an order 4 allocation that is unavailable at that
> > particular snapshot of the system.
> >
> > I am new to this and do not know the history behind the roundup to
> > order
> > 4 [2]. According to the sources, order 4 allocations are not
> > guaranteed and should be avoided most of the time. And considering the
> > chromebooks limited memory, this may become an expected behavior.
> 
> I don't see how that commit is related to the failure in mei_cl_alloc_cb(), that
> one only rounds the size up to a multiple of four bytes.
> 
> What is the call chain you see in the kernel messages? Is it always the same?

> 
> > Can we have more details on this as to why order 4 allocation is
> > required? Or can we have a lower order allocation request that can be
> > helpful for low memory platforms?

Do we have an log messages for that? Is that during video playback?

> >
> > Some solutions that I explored and weren't applicable/helpful here:
> > 1. using a vmalloc/kvmalloc instead of kmalloc (Due to DMA usage).
> > 2. using a scatter gather list (Would require a lot of rework in the
> > driver and still not sure if that would work as it would require
> > changes in the underlying layer as well) 3. retry mechanism (would
> > help in few instances only).
> > 4. allocating from the DMA pool?
> 
> Those (1, 2 and 4) would have been my suggestions as well ;-) I don't think 4
> helps on x86 machines though, since there is no CMA area (and there should
> not need to be either).
> 
> If this happens during runtime (after the system is alredy fully booted),
> another idea would be to move the allocation to boot time where it is very
> likely to succeed and just never free it again. Whether that works or not
> depends on the exact call chain.
> 
> Allocating 64KB of consecutive pages repeatedly is clearly a problem at
> runtime, but having a single allocation during probe time is not as bad.

Would really helpful if some logs are available.

Thanks
Tomas

Re: [RFC] Order 4 allocation failures in the MEI client driver

[Arnd Bergmann]

On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
> On 19/08/24 6:45 PM, Arnd Bergmann wrote:
>> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
>> 
>> What is the call chain you see in the kernel messages? Is it
>> always the same?
> Yes the call stack is same everytime. This is the call stack
>
> <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0
> <4>[ 2019.101359] warn_alloc+0x10d/0x180
> <4>[ 2019.101363] __alloc_pages_slowpath+0xe3d/0xe80
> <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0
> <4>[ 2019.101369] __kmalloc_large_node+0x9d/0x120
> <4>[ 2019.101373] ? mei_cl_alloc_cb+0x34/0xa0
> <4>[ 2019.101377] ? mei_cl_alloc_cb+0x74/0xa0
> <4>[ 2019.101379] __kmalloc+0x86/0x130
> <4>[ 2019.101382] mei_cl_alloc_cb+0x74/0xa0
> <4>[ 2019.101385] mei_cl_enqueue_ctrl_wr_cb+0x38/0x90

Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb()
doing

        /* for RX always allocate at least client's mtu */
        if (length)
                length = max_t(size_t, length, mei_cl_mtu(cl));

which was added in 3030dc056459 ("mei: add wrapper
for queuing control commands."). All the callers seem
to be passing a short "length" of just a few bytes,
but this would always extend it to 
cl->me_cl->props.max_msg_length in mei_cl_mtu().

Not sure where that part is set.

> <4>[ 2019.101388] mei_cl_read_start+0xb8/0x230
> <4>[ 2019.101391] __mei_cl_recv+0xd3/0x400
> <4>[ 2019.101396] ? __pfx_autoremove_wake_function+0x10/0x10
> <4>[ 2019.101399] mei_pxp_receive_message+0x39/0x60
> <4>[ 2019.101402] intel_pxp_tee_io_message+0x112/0x1e0
> <4>[ 2019.101407] i915_pxp_ops_ioctl+0x536/0x6c0

Curiously, I don't see any evidence of i915_pxp_ops_ioctl()
ever making it into mainline kernels, though I see some
discussion about it on the mailing lists [1]

Do you see the same problem with a mainline kernel?

The only reference I could find to the DRM_IOCTL_I915_PXP_OPS
ioctl in userspace seems to be in
https://chromium.googlesource.com/chromium/src/+/a4de986102a45e29c3ef596f22704bdca244c26c/media/gpu/vaapi/vaapi_wrapper.cc#2004

>> Allocating 64KB of consecutive pages repeatedly is clearly
>> a problem at runtime, but having a single allocation during
>> probe time is not as bad.
> What if the length of the message is greater than 64KB, wouldn't that 
> be an issue?

That would make it an order-5 allocation. 

     Arnd


[1] https://patchwork.kernel.org/project/intel-gfx/patch/20201114014537.25495-5-sean.z.huang@intel.com/#23762967

RE: [RFC] Order 4 allocation failures in the MEI client driver

[Winkler, Tomas]

> 
> On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
> > On 19/08/24 6:45 PM, Arnd Bergmann wrote:
> >> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
> >>
> >> What is the call chain you see in the kernel messages? Is it always
> >> the same?
> > Yes the call stack is same everytime. This is the call stack
> >
> > <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0 <4>[ 2019.101359]
> > warn_alloc+0x10d/0x180 <4>[ 2019.101363]
> > __alloc_pages_slowpath+0xe3d/0xe80
> > <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0 <4>[ 2019.101369]
> > __kmalloc_large_node+0x9d/0x120 <4>[ 2019.101373] ?
> > mei_cl_alloc_cb+0x34/0xa0 <4>[ 2019.101377] ?
> > mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101379] __kmalloc+0x86/0x130 <4>[
> > 2019.101382] mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101385]
> > mei_cl_enqueue_ctrl_wr_cb+0x38/0x90
> 
> Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb() doing
> 
>         /* for RX always allocate at least client's mtu */
>         if (length)
>                 length = max_t(size_t, length, mei_cl_mtu(cl));
> 
> which was added in 3030dc056459 ("mei: add wrapper for queuing control
> commands."). All the callers seem to be passing a short "length" of just a few
> bytes, but this would always extend it to
> cl->me_cl->props.max_msg_length in mei_cl_mtu().
> 
> Not sure where that part is set.

It's allocating maximum header for receiving buffer so it can accommodate any response. 
Looks like this part can be optimized with pre allocated buffer pool.
> 
> > <4>[ 2019.101388] mei_cl_read_start+0xb8/0x230 <4>[ 2019.101391]
> > __mei_cl_recv+0xd3/0x400 <4>[ 2019.101396] ?
> > __pfx_autoremove_wake_function+0x10/0x10
> > <4>[ 2019.101399] mei_pxp_receive_message+0x39/0x60 <4>[
> 2019.101402]
> > intel_pxp_tee_io_message+0x112/0x1e0
> > <4>[ 2019.101407] i915_pxp_ops_ioctl+0x536/0x6c0
> 
> Curiously, I don't see any evidence of i915_pxp_ops_ioctl() ever making it
> into mainline kernels, though I see some discussion about it on the mailing
> lists [1]
> 
> Do you see the same problem with a mainline kernel?
> 
> The only reference I could find to the DRM_IOCTL_I915_PXP_OPS ioctl in
> userspace seems to be in
> https://chromium.googlesource.com/chromium/src/+/a4de986102a45e29c3
> ef596f22704bdca244c26c/media/gpu/vaapi/vaapi_wrapper.cc#2004

This is chrome only mei extension for DRM. 
> 
> >> Allocating 64KB of consecutive pages repeatedly is clearly a problem
> >> at runtime, but having a single allocation during probe time is not
> >> as bad.
> > What if the length of the message is greater than 64KB, wouldn't that
> > be an issue?
> 
> That would make it an order-5 allocation.
> 
>      Arnd
> 
> 
> [1] https://patchwork.kernel.org/project/intel-
> gfx/patch/20201114014537.25495-5-sean.z.huang@intel.com/#23762967

Re: [RFC] Order 4 allocation failures in the MEI client driver

[Arnd Bergmann]

On Thu, Aug 22, 2024, at 13:27, Winkler, Tomas wrote:
>> On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
>> > On 19/08/24 6:45 PM, Arnd Bergmann wrote:
>> >> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
>> >>
>> >> What is the call chain you see in the kernel messages? Is it always
>> >> the same?
>> > Yes the call stack is same everytime. This is the call stack
>> >
>> > <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0 <4>[ 2019.101359]
>> > warn_alloc+0x10d/0x180 <4>[ 2019.101363]
>> > __alloc_pages_slowpath+0xe3d/0xe80
>> > <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0 <4>[ 2019.101369]
>> > __kmalloc_large_node+0x9d/0x120 <4>[ 2019.101373] ?
>> > mei_cl_alloc_cb+0x34/0xa0 <4>[ 2019.101377] ?
>> > mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101379] __kmalloc+0x86/0x130 <4>[
>> > 2019.101382] mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101385]
>> > mei_cl_enqueue_ctrl_wr_cb+0x38/0x90
>> 
>> Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb() doing
>> 
>>         /* for RX always allocate at least client's mtu */
>>         if (length)
>>                 length = max_t(size_t, length, mei_cl_mtu(cl));
>> 
>> which was added in 3030dc056459 ("mei: add wrapper for queuing control
>> commands."). All the callers seem to be passing a short "length" of just a few
>> bytes, but this would always extend it to
>> cl->me_cl->props.max_msg_length in mei_cl_mtu().
>> 
>> Not sure where that part is set.
>
> It's allocating maximum header for receiving buffer so it can 
> accommodate any response. 
> Looks like this part can be optimized with pre allocated buffer pool.

I understand that it's always trying to allocate the maximum, the
question is whether there is ever a need to set the maximum to more
than a page. Pre-allocating a buffer at probe time would also
address the issue, but if it's possible to just make that buffer
smaller, it wouldn't be needed.

Is the 64KB buffer size part of the Chrome specific interface as
well, or is that part of the upstream kernel implementation?

       Arnd

RE: [RFC] Order 4 allocation failures in the MEI client driver

[Winkler, Tomas]

> >> On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
> >> > On 19/08/24 6:45 PM, Arnd Bergmann wrote:
> >> >> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
> >> >>
> >> >> What is the call chain you see in the kernel messages? Is it
> >> >> always the same?
> >> > Yes the call stack is same everytime. This is the call stack
> >> >
> >> > <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0 <4>[ 2019.101359]
> >> > warn_alloc+0x10d/0x180 <4>[ 2019.101363]
> >> > __alloc_pages_slowpath+0xe3d/0xe80
> >> > <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0 <4>[ 2019.101369]
> >> > __kmalloc_large_node+0x9d/0x120 <4>[ 2019.101373] ?
> >> > mei_cl_alloc_cb+0x34/0xa0 <4>[ 2019.101377] ?
> >> > mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101379] __kmalloc+0x86/0x130
> >> > <4>[ 2019.101382] mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101385]
> >> > mei_cl_enqueue_ctrl_wr_cb+0x38/0x90
> >>
> >> Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb() doing
> >>
> >>         /* for RX always allocate at least client's mtu */
> >>         if (length)
> >>                 length = max_t(size_t, length, mei_cl_mtu(cl));
> >>
> >> which was added in 3030dc056459 ("mei: add wrapper for queuing
> >> control commands."). All the callers seem to be passing a short
> >> "length" of just a few bytes, but this would always extend it to
> >> cl->me_cl->props.max_msg_length in mei_cl_mtu().
> >>
> >> Not sure where that part is set.
> >
> > It's allocating maximum header for receiving buffer so it can
> > accommodate any response.
> > Looks like this part can be optimized with pre allocated buffer pool.
> 
> I understand that it's always trying to allocate the maximum, the question is
> whether there is ever a need to set the maximum to more than a page. Pre-
> allocating a buffer at probe time would also address the issue, but if it's
> possible to just make that buffer smaller, it wouldn't be needed.
> 
> Is the 64KB buffer size part of the Chrome specific interface as well, or is that
> part of the upstream kernel implementation?

The upstream solution is for newer graphics cards and overall implementation is different. 
I'm trying to collect more information myself, it's summer vacation time, so it will take few days.
Thanks
Tomas

Re: [RFC] Order 4 allocation failures in the MEI client driver

[Rohit Agarwal]

On 23/08/24 2:30 AM, Winkler, Tomas wrote:
>>>> On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
>>>>> On 19/08/24 6:45 PM, Arnd Bergmann wrote:
>>>>>> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
>>>>>>
>>>>>> What is the call chain you see in the kernel messages? Is it
>>>>>> always the same?
>>>>> Yes the call stack is same everytime. This is the call stack
>>>>>
>>>>> <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0 <4>[ 2019.101359]
>>>>> warn_alloc+0x10d/0x180 <4>[ 2019.101363]
>>>>> __alloc_pages_slowpath+0xe3d/0xe80
>>>>> <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0 <4>[ 2019.101369]
>>>>> __kmalloc_large_node+0x9d/0x120 <4>[ 2019.101373] ?
>>>>> mei_cl_alloc_cb+0x34/0xa0 <4>[ 2019.101377] ?
>>>>> mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101379] __kmalloc+0x86/0x130
>>>>> <4>[ 2019.101382] mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101385]
>>>>> mei_cl_enqueue_ctrl_wr_cb+0x38/0x90
>>>> Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb() doing
>>>>
>>>>          /* for RX always allocate at least client's mtu */
>>>>          if (length)
>>>>                  length = max_t(size_t, length, mei_cl_mtu(cl));
>>>>
>>>> which was added in 3030dc056459 ("mei: add wrapper for queuing
>>>> control commands."). All the callers seem to be passing a short
>>>> "length" of just a few bytes, but this would always extend it to
>>>> cl->me_cl->props.max_msg_length in mei_cl_mtu().
>>>>
>>>> Not sure where that part is set.
>>> It's allocating maximum header for receiving buffer so it can
>>> accommodate any response.
>>> Looks like this part can be optimized with pre allocated buffer pool.
>> I understand that it's always trying to allocate the maximum, the question is
>> whether there is ever a need to set the maximum to more than a page. Pre-
>> allocating a buffer at probe time would also address the issue, but if it's
>> possible to just make that buffer smaller, it wouldn't be needed.
>>
>> Is the 64KB buffer size part of the Chrome specific interface as well, or is that
>> part of the upstream kernel implementation?
> The upstream solution is for newer graphics cards and overall implementation is different.
> I'm trying to collect more information myself, it's summer vacation time, so it will take few days.
> Thanks
> Tomas
>
A gentle reminder.

Thanks,
Rohit.

RE: [RFC] Order 4 allocation failures in the MEI client driver

[Usyskin, Alexander]

> On 23/08/24 2:30 AM, Winkler, Tomas wrote:
> >>>> On Wed, Aug 21, 2024, at 05:20, Rohit Agarwal wrote:
> >>>>> On 19/08/24 6:45 PM, Arnd Bergmann wrote:
> >>>>>> On Tue, Aug 13, 2024, at 10:45, Rohit Agarwal wrote:
> >>>>>>
> >>>>>> What is the call chain you see in the kernel messages? Is it
> >>>>>> always the same?
> >>>>> Yes the call stack is same everytime. This is the call stack
> >>>>>
> >>>>> <4>[ 2019.101352] dump_stack_lvl+0x69/0xa0 <4>[ 2019.101359]
> >>>>> warn_alloc+0x10d/0x180 <4>[ 2019.101363]
> >>>>> __alloc_pages_slowpath+0xe3d/0xe80
> >>>>> <4>[ 2019.101366] __alloc_pages+0x22f/0x2b0 <4>[ 2019.101369]
> >>>>> __kmalloc_large_node+0x9d/0x120 <4>[ 2019.101373] ?
> >>>>> mei_cl_alloc_cb+0x34/0xa0 <4>[ 2019.101377] ?
> >>>>> mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101379] __kmalloc+0x86/0x130
> >>>>> <4>[ 2019.101382] mei_cl_alloc_cb+0x74/0xa0 <4>[ 2019.101385]
> >>>>> mei_cl_enqueue_ctrl_wr_cb+0x38/0x90
> >>>> Ok, so this might be a result of mei_cl_enqueue_ctrl_wr_cb() doing
> >>>>
> >>>>          /* for RX always allocate at least client's mtu */
> >>>>          if (length)
> >>>>                  length = max_t(size_t, length, mei_cl_mtu(cl));
> >>>>
> >>>> which was added in 3030dc056459 ("mei: add wrapper for queuing
> >>>> control commands."). All the callers seem to be passing a short
> >>>> "length" of just a few bytes, but this would always extend it to
> >>>> cl->me_cl->props.max_msg_length in mei_cl_mtu().
> >>>>
> >>>> Not sure where that part is set.
> >>> It's allocating maximum header for receiving buffer so it can
> >>> accommodate any response.
> >>> Looks like this part can be optimized with pre allocated buffer pool.
> >> I understand that it's always trying to allocate the maximum, the question
> is
> >> whether there is ever a need to set the maximum to more than a page.
> Pre-
> >> allocating a buffer at probe time would also address the issue, but if it's
> >> possible to just make that buffer smaller, it wouldn't be needed.
> >>
> >> Is the 64KB buffer size part of the Chrome specific interface as well, or is
> that
> >> part of the upstream kernel implementation?
> > The upstream solution is for newer graphics cards and overall
> implementation is different.
> > I'm trying to collect more information myself, it's summer vacation time, so
> it will take few days.
> > Thanks
> > Tomas
> >
> A gentle reminder.
> 
> Thanks,
> Rohit.

The FW guy say that the biggest buffer there is 33K, and this is already order 4 allocation.
Thus, the MTU size can't be reduced.
The only thing that we can do is to ask pxp to send to mei expected message size and
mei will allocate only that size. This can lead to unexpected behaviour in driver
when FW sends more data then expected by pxp.
This still may fail on big buffer requested by pxp, not sure what is the real message
that Linux pxp module is using.

Is this error can be eliminated by retry from PXP side? 


-- 
Alexander (Sasha) Usyskin

CSE FW Dev – Host SW
Intel Israel (74) Limited