Bug: broken /proc/kcore in 6.13

Bug: broken /proc/kcore in 6.13

[Alexandre Ferrieux]

Hi,

Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
possible to disassemble the running kernel from gdb through /proc/kcore.

More precisely:

 - look up a function in /proc/kallsyms => 0xADDRESS
 - tell gdb to "core /proc/kcore"
 - tell gdb to "disass 0xADDRESS,+LENGTH" (no need for a symbol table)

 * if the function is within the main kernel text, it is okay
 * if the function is within a module's text, an infinite loop happens:


Example:

 # egrep -w ice_process_skb_fields\|ksys_write /proc/kallsyms
 ffffffffaf296c80 T ksys_write
 ffffffffc0b67180 t ice_process_skb_fields       [ice]

 # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffaf296c80,+256" -ex quit
 ...
 Dump of assembler code from 0xffffffffaf296c80 to 0xffffffffaf296d80:
   ...
 End of assembler dump.

 # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffc0b67180,+256" -ex quit
 ...
 Dump of assembler code from 0xffffffffc0b67180 to 0xffffffffc0b67280:
 (***NOTHING***)
 ^C <= inefficient, need kill -9


Ftrace (see below) shows in this case read_kcore_iter() calls vread_iter() in an
infinite loop:

        while (true) {
                read += vread_iter(iter, src, left);
                if (read == tsz)
                        break;

                src += read;
                left -= read;

                if (fault_in_iov_iter_writeable(iter, left)) {
                        ret = -EFAULT;
                        goto out;
                }
        }

As it turns out, in the offending situation, vread_iter() keeps returning 0,
with "read" staying at its initial value of 0, and "tsz" nonzero. As a
consequence, "src" stays stuck in a place where vread_iter() fails.

A cursory "git blame" shows that this interplay (vread_iter() legitimately
returning zero, and read_kcore_iter() *not* testing it) has been there from
quite some time. So, while this is arguably fragile, possibly the new situation
lies in the actual memory layout that triggers the failing path.

Thanks for any insight, as this completely breaks debugging the running kernel
in 6.13.

-Alex


------------
# tracer: nop
#
# entries-in-buffer/entries-written: 0/0   #P:48
#
#           TASK-PID     CPU#     TIMESTAMP  FUNCTION
#              | |         |         |         |
           <...>-3304    [045]    487.295283: kprobe_read_kcore_iter:
(read_kcore_iter+0x4/0xae0) pos=0x7fffc0b6b000
           <...>-3304    [045]    487.295298: kprobe_vread_iter:
(vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
           <...>-3304    [045]    487.295326: kretprobe_vread_iter:
(read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
           <...>-3304    [045]    487.295329: kprobe_vread_iter:
(vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
           <...>-3304    [045]    487.295338: kretprobe_vread_iter:
(read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
           <...>-3304    [045]    487.295339: kprobe_vread_iter:
(vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
           <...>-3304    [045]    487.295345: kretprobe_vread_iter:
(read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
           <...>-3304    [045]    487.295347: kprobe_vread_iter:
(vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
           <...>-3304    [045]    487.295352: kretprobe_vread_iter:
(read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
           <...>-3304    [045]    487.295353: kprobe_vread_iter:
(vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
...

Re: Bug: broken /proc/kcore in 6.13

[Steven Rostedt]

[ Cc'ing the proper folks ]

-- Steve


On Fri, 17 Jan 2025 11:36:05 +0100
Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:

> Hi,
> 
> Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
> possible to disassemble the running kernel from gdb through /proc/kcore.
> 
> More precisely:
> 
>  - look up a function in /proc/kallsyms => 0xADDRESS
>  - tell gdb to "core /proc/kcore"
>  - tell gdb to "disass 0xADDRESS,+LENGTH" (no need for a symbol table)
> 
>  * if the function is within the main kernel text, it is okay
>  * if the function is within a module's text, an infinite loop happens:
> 
> 
> Example:
> 
>  # egrep -w ice_process_skb_fields\|ksys_write /proc/kallsyms
>  ffffffffaf296c80 T ksys_write
>  ffffffffc0b67180 t ice_process_skb_fields       [ice]
> 
>  # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffaf296c80,+256" -ex quit
>  ...
>  Dump of assembler code from 0xffffffffaf296c80 to 0xffffffffaf296d80:
>    ...
>  End of assembler dump.
> 
>  # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffc0b67180,+256" -ex quit
>  ...
>  Dump of assembler code from 0xffffffffc0b67180 to 0xffffffffc0b67280:
>  (***NOTHING***)
>  ^C <= inefficient, need kill -9
> 
> 
> Ftrace (see below) shows in this case read_kcore_iter() calls vread_iter() in an
> infinite loop:
> 
>         while (true) {
>                 read += vread_iter(iter, src, left);
>                 if (read == tsz)
>                         break;
> 
>                 src += read;
>                 left -= read;
> 
>                 if (fault_in_iov_iter_writeable(iter, left)) {
>                         ret = -EFAULT;
>                         goto out;
>                 }
>         }
> 
> As it turns out, in the offending situation, vread_iter() keeps returning 0,
> with "read" staying at its initial value of 0, and "tsz" nonzero. As a
> consequence, "src" stays stuck in a place where vread_iter() fails.
> 
> A cursory "git blame" shows that this interplay (vread_iter() legitimately
> returning zero, and read_kcore_iter() *not* testing it) has been there from
> quite some time. So, while this is arguably fragile, possibly the new situation
> lies in the actual memory layout that triggers the failing path.
> 
> Thanks for any insight, as this completely breaks debugging the running kernel
> in 6.13.
> 
> -Alex
> 
> 
> ------------
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 0/0   #P:48
> #
> #           TASK-PID     CPU#     TIMESTAMP  FUNCTION
> #              | |         |         |         |
>            <...>-3304    [045]    487.295283: kprobe_read_kcore_iter:
> (read_kcore_iter+0x4/0xae0) pos=0x7fffc0b6b000
>            <...>-3304    [045]    487.295298: kprobe_vread_iter:
> (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
>            <...>-3304    [045]    487.295326: kretprobe_vread_iter:
> (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
>            <...>-3304    [045]    487.295329: kprobe_vread_iter:
> (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
>            <...>-3304    [045]    487.295338: kretprobe_vread_iter:
> (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
>            <...>-3304    [045]    487.295339: kprobe_vread_iter:
> (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
>            <...>-3304    [045]    487.295345: kretprobe_vread_iter:
> (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
>            <...>-3304    [045]    487.295347: kprobe_vread_iter:
> (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
>            <...>-3304    [045]    487.295352: kretprobe_vread_iter:
> (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
>            <...>-3304    [045]    487.295353: kprobe_vread_iter:
> (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> ...
> 

Re: Bug: broken /proc/kcore in 6.13

[Lorenzo Stoakes]

On Fri, Jan 17, 2025 at 08:40:38AM -0500, Steven Rostedt wrote:
>
> [ Cc'ing the proper folks ]
>
> -- Steve

Thanks Steve!

>
>
> On Fri, 17 Jan 2025 11:36:05 +0100
> Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:
>
> > Hi,
> >
> > Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
> > possible to disassemble the running kernel from gdb through /proc/kcore.

Thanks for the report! Much appreciated.

I may try to bisect here also unless you're close to finding the commit that
broke this?

> >
> > More precisely:
> >
> >  - look up a function in /proc/kallsyms => 0xADDRESS
> >  - tell gdb to "core /proc/kcore"
> >  - tell gdb to "disass 0xADDRESS,+LENGTH" (no need for a symbol table)
> >
> >  * if the function is within the main kernel text, it is okay
> >  * if the function is within a module's text, an infinite loop happens:
> >
> >
> > Example:
> >
> >  # egrep -w ice_process_skb_fields\|ksys_write /proc/kallsyms
> >  ffffffffaf296c80 T ksys_write
> >  ffffffffc0b67180 t ice_process_skb_fields       [ice]
> >
> >  # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffaf296c80,+256" -ex quit
> >  ...
> >  Dump of assembler code from 0xffffffffaf296c80 to 0xffffffffaf296d80:
> >    ...
> >  End of assembler dump.
> >
> >  # gdb -ex "core /proc/kcore" -ex "disass 0xffffffffc0b67180,+256" -ex quit
> >  ...
> >  Dump of assembler code from 0xffffffffc0b67180 to 0xffffffffc0b67280:
> >  (***NOTHING***)
> >  ^C <= inefficient, need kill -9
> >
> >
> > Ftrace (see below) shows in this case read_kcore_iter() calls vread_iter() in an
> > infinite loop:
> >
> >         while (true) {
> >                 read += vread_iter(iter, src, left);
> >                 if (read == tsz)
> >                         break;
> >
> >                 src += read;
> >                 left -= read;
> >
> >                 if (fault_in_iov_iter_writeable(iter, left)) {
> >                         ret = -EFAULT;
> >                         goto out;
> >                 }
> >         }
> >
> > As it turns out, in the offending situation, vread_iter() keeps returning 0,
> > with "read" staying at its initial value of 0, and "tsz" nonzero. As a
> > consequence, "src" stays stuck in a place where vread_iter() fails.
> >

Yikes, this is my fault. Sorry about that!

There was some discussion at the time about the infinite loop, obviously with
the understanding that vread_iter() should never return 0 in this scenario
(where we had identified the _category_ of kernel memory being accessed), which
is obviously now rendered false.

The fact that it can is (obviously) rather problematic... obviously we need to
patch this, if this were possible in real scenarios in the past we would
probably also want to backport a fix.

In any case I think we need an explicit check here no matter the cause so we can
never loop like this. This was just an oversight at the time given this is a
documented behaviour.

My instinct is to error out if this returns 0, because that would indicate that
the address is not part of the vmalloc area.

But then it seems add_modules_range() is just adding the module range under
category KCORE_VMALLOC despite it not being in the vmalloc range :/ which is
really odd. This was added a long time ago so clearly not what triggered this
but odd.

In any case, let me go have a look at this...

> > A cursory "git blame" shows that this interplay (vread_iter() legitimately
> > returning zero, and read_kcore_iter() *not* testing it) has been there from
> > quite some time. So, while this is arguably fragile, possibly the new situation
> > lies in the actual memory layout that triggers the failing path.
> >
> > Thanks for any insight, as this completely breaks debugging the running kernel
> > in 6.13.

Apologies again. Let's figure this out and get this fixed!

Cheers, Lorenzo

> >
> > -Alex
> >
> >
> > ------------
> > # tracer: nop
> > #
> > # entries-in-buffer/entries-written: 0/0   #P:48
> > #
> > #           TASK-PID     CPU#     TIMESTAMP  FUNCTION
> > #              | |         |         |         |
> >            <...>-3304    [045]    487.295283: kprobe_read_kcore_iter:
> > (read_kcore_iter+0x4/0xae0) pos=0x7fffc0b6b000
> >            <...>-3304    [045]    487.295298: kprobe_vread_iter:
> > (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> >            <...>-3304    [045]    487.295326: kretprobe_vread_iter:
> > (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
> >            <...>-3304    [045]    487.295329: kprobe_vread_iter:
> > (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> >            <...>-3304    [045]    487.295338: kretprobe_vread_iter:
> > (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
> >            <...>-3304    [045]    487.295339: kprobe_vread_iter:
> > (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> >            <...>-3304    [045]    487.295345: kretprobe_vread_iter:
> > (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
> >            <...>-3304    [045]    487.295347: kprobe_vread_iter:
> > (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> >            <...>-3304    [045]    487.295352: kretprobe_vread_iter:
> > (read_kcore_iter+0x3e6/0xae0 <- vread_iter) arg1=0
> >            <...>-3304    [045]    487.295353: kprobe_vread_iter:
> > (vread_iter+0x4/0x4e0) addr=0xffffffffc0b67000 len=384
> > ...
> >
>

Re: Bug: broken /proc/kcore in 6.13

[Alexandre Ferrieux]

On 17/01/2025 15:44, Lorenzo Stoakes wrote:
> 
>> Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:
>>
>> > Hi,
>> >
>> > Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
>> > possible to disassemble the running kernel from gdb through /proc/kcore.
> 
> Thanks for the report! Much appreciated.
> 
> I may try to bisect here also unless you're close to finding the commit that
> broke this?

I'm currently homing in on copy_page_to_iter_nofault(), will report shortly :)

> Yikes, this is my fault. Sorry about that!

Wow. I'm so happy we connected, no problem :)

> There was some discussion at the time about the infinite loop, obviously with
> the understanding that vread_iter() should never return 0 in this scenario
> (where we had identified the _category_ of kernel memory being accessed), which
> is obviously now rendered false.
> 
> The fact that it can is (obviously) rather problematic... obviously we need to
> patch this, if this were possible in real scenarios in the past we would
> probably also want to backport a fix.
> 
> In any case I think we need an explicit check here no matter the cause so we can
> never loop like this. This was just an oversight at the time given this is a
> documented behaviour.
> 
> My instinct is to error out if this returns 0, because that would indicate that
> the address is not part of the vmalloc area.

Yes, I did the naive patch below; it does the job, breaking out of the loop, but
does not cure the access problem, so gdb just sees zeroes :(

diff --git a/fs/proc/kcore.c b/fs/proc/kcore.c
index e376f48c4b8b..8c5f29240542 100644
--- a/fs/proc/kcore.c
+++ b/fs/proc/kcore.c
@@ -531,7 +531,13 @@ static ssize_t read_kcore_iter(struct kiocb *iocb, struct
iov_iter *iter)
                         * again until we are done.
                         */
                        while (true) {
-                               read += vread_iter(iter, src, left);
+                               long res;
+                               res = vread_iter(iter, src, left);
+                               if (!res) {
+                                       ret = -EFAULT;
+                                       goto out;
+                               }
+                               read += res;
                                if (read == tsz)
                                        break;

> But then it seems add_modules_range() is just adding the module range under
> category KCORE_VMALLOC despite it not being in the vmalloc range :/ which is
> really odd. This was added a long time ago so clearly not what triggered this
> but odd.
> 
> In any case, let me go have a look at this...

Ok, staying eagerly tuned !

Best regards,

-Alex

Re: Bug: broken /proc/kcore in 6.13

[Alexandre Ferrieux]

On 17/01/2025 16:19, Alexandre Ferrieux wrote:
> On 17/01/2025 15:44, Lorenzo Stoakes wrote:
>>> Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:
>>>
>>>> Hi,
>>>>
>>>> Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
>>>> possible to disassemble the running kernel from gdb through /proc/kcore.
>> Thanks for the report! Much appreciated.
>>
>> I may try to bisect here also unless you're close to finding the commit that
>> broke this?
>
> I'm currently homing in on copy_page_to_iter_nofault(), will report shortly :)

Hmm, actually, that baby ain't cooperative:

  [Fri Jan 17 15:23:05 2025] trace_kprobe: Could not probe notrace function
  copy_page_to_iter_nofault

... if I cannot insert kprobes to sniff around, I'm a bit stuck :}
So I think you'll reach the goal faster than me !

PS: For your bisection: the last working kernel I know of is Debian's 6.12 final:

  ii  linux-image-6.12.9-amd64         6.12.9-1                         amd64
    Linux 6.12 for 64-bit PCs (signed)

Re: Bug: broken /proc/kcore in 6.13

[Lorenzo Stoakes]

On Fri, Jan 17, 2025 at 04:28:32PM +0100, Alexandre Ferrieux wrote:
>
>
> On 17/01/2025 16:19, Alexandre Ferrieux wrote:
> > On 17/01/2025 15:44, Lorenzo Stoakes wrote:
> >>> Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:
> >>>
> >>>> Hi,
> >>>>
> >>>> Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
> >>>> possible to disassemble the running kernel from gdb through /proc/kcore.
> >> Thanks for the report! Much appreciated.
> >>
> >> I may try to bisect here also unless you're close to finding the commit that
> >> broke this?
> >
> > I'm currently homing in on copy_page_to_iter_nofault(), will report shortly :)
>
> Hmm, actually, that baby ain't cooperative:
>
>   [Fri Jan 17 15:23:05 2025] trace_kprobe: Could not probe notrace function
>   copy_page_to_iter_nofault
>
> ... if I cannot insert kprobes to sniff around, I'm a bit stuck :}
> So I think you'll reach the goal faster than me !
>
> PS: For your bisection: the last working kernel I know of is Debian's 6.12 final:
>
>   ii  linux-image-6.12.9-amd64         6.12.9-1                         amd64
>     Linux 6.12 for 64-bit PCs (signed)
>
>

Cheers much appreciated, have been able to repro and am bisecting now! Will
update with results when done.

Re: Bug: broken /proc/kcore in 6.13

[Lorenzo Stoakes]

+cc Mike

OK so nothing to worry about here - the feature that causes this problem
has been completely disabled. This may not be in Linus's tree yet but will
be for 6.13 release [0].

I think the vread_iter() check for 0 can wait for 6.14, as once the area of
memory is identified this should never happen, but we do want to pick up on
it, with a WARN_ON_ONCE() to catch stuff like this right away.

Thanks so much for the repro, though I observed the 'core /proc/kcore'
command freezing up before any 'disass' in my qemu setup, interestingly!

[0]:https://lore.kernel.org/all/20250113112934.GA8385@noisy.programming.kicks-ass.net/

On Fri, Jan 17, 2025 at 04:31:54PM +0000, Lorenzo Stoakes wrote:
> On Fri, Jan 17, 2025 at 04:28:32PM +0100, Alexandre Ferrieux wrote:
> >
> >
> > On 17/01/2025 16:19, Alexandre Ferrieux wrote:
> > > On 17/01/2025 15:44, Lorenzo Stoakes wrote:
> > >>> Alexandre Ferrieux <alexandre.ferrieux@gmail.com> wrote:
> > >>>
> > >>>> Hi,
> > >>>>
> > >>>> Somewhere in the 6.13 branch (not bisected yet, sorry), it stopped being
> > >>>> possible to disassemble the running kernel from gdb through /proc/kcore.
> > >> Thanks for the report! Much appreciated.
> > >>
> > >> I may try to bisect here also unless you're close to finding the commit that
> > >> broke this?
> > >
> > > I'm currently homing in on copy_page_to_iter_nofault(), will report shortly :)
> >
> > Hmm, actually, that baby ain't cooperative:
> >
> >   [Fri Jan 17 15:23:05 2025] trace_kprobe: Could not probe notrace function
> >   copy_page_to_iter_nofault
> >
> > ... if I cannot insert kprobes to sniff around, I'm a bit stuck :}
> > So I think you'll reach the goal faster than me !
> >
> > PS: For your bisection: the last working kernel I know of is Debian's 6.12 final:
> >
> >   ii  linux-image-6.12.9-amd64         6.12.9-1                         amd64
> >     Linux 6.12 for 64-bit PCs (signed)
> >
> >
>
> Cheers much appreciated, have been able to repro and am bisecting now! Will
> update with results when done.

OK I bisected this to commit 5185e7f9f3bd ("x86/module: enable ROX caches for
module text on 64 bit").

It seems that vmalloc logic is used to handle module memory too in
vread_iter(), and somehow the execmem stuff is breaking this.

So this would explain why this worked previously, and it was in fact ok to
assume vread_iter() should never return 0 (though I believe we should now
definitely check this and error out if so).

I have tracked it down to (forgive me Alexandre, I realise I'm duplicating
some of your analysis, I'm just doing things from the kernel side here :>)

read_kcore_iter()
-> vread_iter()
-> aligned_vread_iter() (returns 0, indicating error on copy)
  -> gets page via vmalloc_to_page()
-> copy_page_to_iter_nofault()
-> copy_to_user_iter_nofault()
-> copy_to_user_nofault()
-> __copy_to_user_inatomic()
-> raw_copy_to_user()
-> copy_user_generic() [page fault]

In discussion with Mike, he pointed me at execmem_cache_populate() marking
the region as not being direct-map valid via execmem_set_direct_map_valid().

However it seems the problem is that the above logic results in the
following calls:

copy_page_to_iter_nofault() -> kmap_local_page() -> page_to_virt()

Which _assume_ the mapping is in the direct map afaict. It's not, so we get
a page fault, which is fixed up and results in the 0 result and the whole
problem.

So I think this code would have to be modified to be aware of such
non-direct map memory for this to work.

In any case it's moot as this feature is now disabled. But hopefully the
analysis helps Mike in the next spin of his ROX series!

Re: Bug: broken /proc/kcore in 6.13

[Alexandre Ferrieux]

On 17/01/2025 19:13, Lorenzo Stoakes wrote:
> 
> +cc Mike
> 
> OK so nothing to worry about here - the feature that causes this problem
> has been completely disabled. This may not be in Linus's tree yet but will
> be for 6.13 release [0].
> 
> I think the vread_iter() check for 0 can wait for 6.14, as once the area of
> memory is identified this should never happen, but we do want to pick up on
> it, with a WARN_ON_ONCE() to catch stuff like this right away.
> 
> Thanks so much for the repro, though I observed the 'core /proc/kcore'
> command freezing up before any 'disass' in my qemu setup, interestingly!
> 
> [0]:https://lore.kernel.org/all/20250113112934.GA8385@noisy.programming.kicks-ass.net/

Thank you for the fast fix, I'm back on track :)

 Dump of assembler code for function ice_process_skb_fields:
    0xffffffffc0fc1eb0 <+0>:     nopw   (%rax)
    0xffffffffc0fc1eb4 <+4>:     nopl   0x0(%rax,%rax,1)
    0xffffffffc0fc1eb9 <+9>:     push   %r14
    0xffffffffc0fc1ebb <+11>:    push   %r13

-Alex