On 6 Apr 1996, Steven L Baur wrote:
>
> #1:
> Apr 6 15:01:07 deanna kernel: Unable to handle kernel paging request at virtual address 00000004
> Apr 6 15:01:08 deanna kernel: current->tss.cr3 = 014b7000, xr3 = 014b7000
> Apr 6 15:01:08 deanna kernel: *pde = 00000000
> Apr 6 15:01:08 deanna kernel: Oops: 0002
> Apr 6 15:01:08 deanna kernel: CPU: 0
> Apr 6 15:01:08 deanna kernel: EIP: 0010:[generic_file_read+580/996]
> Apr 6 15:01:08 deanna kernel: EFLAGS: 00010206
> Apr 6 15:01:08 deanna kernel: eax: 00ccbc0c ebx: 00001000 ecx: 00000400 edx: 01ca3000
> Apr 6 15:01:08 deanna kernel: esi: 01ca3000 edi: 08724000 ebp: 00001000 esp: 01ab5f5c
> Apr 6 15:01:08 deanna kernel: ds: 0018 es: 002b fs: 002b gs: 002b ss: 0018
> Apr 6 15:01:08 deanna kernel: Process xemacs (pid: 1874, process nr: 31, stackpage=01ab5000)
> Apr 6 15:01:08 deanna kernel: Stack: 00250018 008d2210 00010000 00a4aa50 08720000 00008000 00008000 00292a94
> Apr 6 15:01:08 deanna kernel: 01ca3000 00000000 00000000 00004000 00004000 00000000 0011fbe4 00a4aa50
> Apr 6 15:01:08 deanna kernel: 008d2210 08724000 0000c000 00ccbc0c 00010000 08720000 bffdaa9c 0010a2b9
> Apr 6 15:01:08 deanna kernel: Call Trace: [sys_read+128/144] [system_call+89/160]
> Apr 6 15:01:08 deanna kernel: Code: f3 a5 83 e3 03 89 d9 f3 a4 07 6a 00 8b 74 24 20 56 e8 3e 32
>
> This maps back to attempting to load a file into an XEmacs buffer. I
> haven't had a crash quite like this one before with XEmacs.
Umm. I hate to say this, but this looks like a hardware problem after all.
Because the above kernel panic not only makes no sense, it looks _wrong_.
Let me explain:
The "Code:" part disassembles to
repz movsl %ds:(%esi),%es:(%edi)
andl $0x3,%ebx
movl %ebx,%ecx
repz movsb %ds:(%esi),%es:(%edi)
popl %es
pushl $0x0
movl 0x20(%esp,1),%esi
Now, the above makes perfect sense: it's the code sequence to copy the
kernel buffer cache to user space. The faulting instruction (rep movsl)
does the 4-bytes-at-a-time move, with the count in %ecx, and the source
in %esi (from the %ds segment - that's kernel) and the destination in
%edi (in the %es segment: thats a few instructions earlier been set up
with the user segment).
Now, the register dump also tells us:
count = %ecx = 0x00000400 = 1024
this is normal: we're copying the whole page cache page to a user buffer
(1024 long-word copies gives 4kB = PAGE_SIZE).
source = %esi = 0x01ca3000
which is also totally believable (notice that it's a page-aligned
address, and that it's within the kernel address space: it's around the
30MB mark). Finally the destination is
dest = %edi = 0x08724000
which is the user virtual address. Once more this is completely
believable: that's a normal address for a ELF binary data segment.
Ok, so far so good. HOWEVER, that instruction then traps with:
Unable to handle kernel paging request at virtual address 00000004
even though virtual address 0x00000004 never even enters the picture. In
short, that particular instruction should under no circumstances be able
to trap with that address.
> Apr 6 20:18:39 deanna kernel: Unable to handle kernel paging request at virtual address 00000004
> Apr 6 20:18:40 deanna kernel: current->tss.cr3 = 004a0000, xr3 = 004a0000
> Apr 6 20:18:40 deanna kernel: *pde = 00000000
> Apr 6 20:18:40 deanna kernel: Oops: 0002
> Apr 6 20:18:40 deanna kernel: CPU: 0
> Apr 6 20:18:41 deanna kernel: EIP: 0010:[memcpy_toiovec+85/136]
> Apr 6 20:18:41 deanna kernel: EFLAGS: 00013202
> Apr 6 20:18:41 deanna kernel: eax: 0000f12c ebx: 000005b4 ecx: 000000ca edx: 402ced74
> Apr 6 20:18:41 deanna kernel: esi: 0030aae4 edi: 402cf000 ebp: 0138af74 esp: 0138aecc
> Apr 6 20:18:41 deanna kernel: ds: 0018 es: 002b fs: 002b gs: 002b ss: 0018
> Apr 6 20:18:41 deanna kernel: Process X (pid: 1063, process nr: 26, stackpage=0138a000)
> Apr 6 20:18:41 deanna kernel: Stack: 00300018 0030ae10 000005b4 00000000 00f11410 000005b4 001428e6 0138af74
> Apr 6 20:18:41 deanna kernel: 0030a858 000005b4 00f11410 0138af80 00000000 00000800 00f1142c 000005b4
> Apr 6 20:18:41 deanna kernel: 002eb414 0138af0c b089a9b0 0014c996 00f11410 0138af7c 0000f12c 00000800
> Apr 6 20:18:41 deanna kernel: Call Trace: [tcp_recvmsg+802/1196] [inet_recvmsg+118/140] [sock_read+171/192] [sys_read+128/144] [system_call+89/160]
> Apr 6 20:18:41 deanna kernel: Code: f3 a5 83 e3 03 89 d9 f3 a4 07 8b 5c 24 10 01 5c 24 1c 29 5c
Ok, totally different place, but if you look at the code sequence you
start to see the similarities. Again, that sequence is part of the code
for the inline "memcpy_tofs()", and it's doing the same thing (the last
bytes are different, because that's after the end of the memcpy
function).
Again, the source is believable (it's not page-aligned this time, because
it's not a page cache access: it's copying data from a network buffer
into user space). The count is also believable (0xca = 202 = 808 bytes
copied) and the destination looks fine (0x402cf000 looks like a shared
library data segment address).
Again, the panic message claims that the faulting virtual address is
0x00000004, which should never enter the picture...
> Apr 6 20:18:41 deanna kernel: double lock on socket at 00142cb4
> Apr 6 20:20:39 deanna kernel: Unable to handle kernel NULL pointer dereference at virtual address c0000059
> Apr 6 20:20:39 deanna kernel: current->tss.cr3 = 00101000, xr3 = 00101000
> Apr 6 20:20:39 deanna kernel: *pde = 00102067
> Apr 6 20:20:39 deanna kernel: *pte = 00000027
> Apr 6 20:20:39 deanna kernel: Oops: 0000
> Apr 6 20:20:39 deanna kernel: CPU: 0
> Apr 6 20:20:39 deanna kernel: EIP: 0010:[wake_up_interruptible+34/216]
> Apr 6 20:20:39 deanna kernel: EFLAGS: 00010216
> Apr 6 20:20:39 deanna kernel: eax: 01656134 ebx: 0138af0c ecx: 00000000 edx: 00000059
> Apr 6 20:20:39 deanna kernel: esi: 01656174 edi: 01656134 ebp: 00458f44 esp: 00458f38
> Apr 6 20:20:39 deanna kernel: ds: 0018 es: 0018 fs: 002b gs: 002b ss: 0018
> Apr 6 20:20:39 deanna kernel: Process X (pid: 4140, process nr: 12, stackpage=00458000)
> Apr 6 20:20:39 deanna kernel: Stack: 018caa04 01656174 01656174 00000001 0014be53 01656134 0014c279 018caa04
> Apr 6 20:20:39 deanna kernel: 016560f0 00000000 00132874 01656174 00000000 016560f0 016560f0 00000000
> Apr 6 20:20:39 deanna kernel: 00000000 00132aad 01656174 01684570 0011f7e2 016560f0 01684570 00000000
> Apr 6 20:20:39 deanna kernel: Call Trace: [def_callback1+23/28] [inet_release+29/116] [sock_release+92/156] [sock_close+37/44] [close_fp+94/132] [do_exit+222/436] [sys_exit+14/16]
> Apr 6 20:20:39 deanna kernel: [system_call+89/160]
> Apr 6 20:20:39 deanna kernel: Code: 8b 02 83 f8 01 75 61 9c 5e fa c7 02 00 00 00 00 83 7a 4c 00
Now, this looks like a "real" panic dump: the code disassembles to
movl (%edx),%eax
cmpl $0x1,%eax
jne *+x
...
and %edx is 0x00000059, which does indeed translate to virtual address
0xc0000059 (the kernel segments are offset by 0xc0000000).
However, to be quite frank, after the above bogus panics I suspect that
there might be some memory corruption that is the reason for the third
(real) panic (if the "rep movsl" can result in bogus page faults I
suspect it might also occasionally use the wrong addresses or something
for the data transfer, resulting in memory corruption).
Now, I don't know why this happens only in 1.3.x for you, and not in
1.2.x, but a lot of things have changed in between, and maybe the new
kernels just show the problem more clearly.
What you could do, for example, is to take the "__generic_memcpy_tofs()"
from 1.2.13 (it's in include/asm-i386/segment.h) and use that in 1.3.84.
The code has changed, but they do the same thing (but the 1.3.x kernel
does it faster: maybe that's why you didn't see it with old kernels).
Oh, you'd probably better do the same thing to memcpy_fromfs too..
Linus