[Qemu-discuss] Qemu ARM9 weirdness

[Joel Fernandes]

Hi,

I'm seeing some weirdness debugging a kernel on a ARM925 platform
(cheetah, OMAP1 based).

Qemu version: 2.0.0-rc0
I'm using GDB to step through a mainline Linux kernel, which crashes
very early in boot (crash happens when reading the CPUID using cp15
instruction which is a different issue.)

There appears to be a lag between the "current" register state of the
CPU, and the current instruction being executed as seen in gdb: The
state seems to be updated a couple of instructions after the
instruction intended to cause the side of effect. I believe this is
what causes the kernel crash.


Code being executed (arch/arm/kernel/head.S)

1        mrc     p15, 0, r9, c0, c0              @ get processor id
2        bl      __lookup_processor_type         @ r5=procinfo r9=cpuid
3        movs    r10, r5                         @ invalid processor (r5=0)?


Line 1 is supposed to read the CPU ID from cp15, as per Qemu and Linux
code, this is supposed to be "0x41069260" and is set by qemu in
arm926_initfn.

All good.

Now, I start gdb with -s -S options to halt on startup, and step
through, each time I'm dumping the register set:
..
Reading symbols from /home/joel/data/repo/linux-omap1/vmlinux...done.
(gdb) info registers
r0             0x0      0
r1             0x0      0
r2             0x0      0
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10000000       0x10000000 <stext>
cpsr           0x400001d3       1073742291

(gdb) si
93              mrc     p15, 0, r9, c0, c0              @ get processor id

(gdb) info registers
r0             0x0      0
r1             0x0      0
r2             0x0      0
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10000004       0x10000004 <stext+4>
cpsr           0x400001d3       1073742291

Now on the next step, the mrc coprocessor instruction has to update r9
with the CPU ID (but this doesn't happen until several step throughs
later)

(gdb) si    ; This step should execute the mrc
94              bl      __lookup_processor_type         @ r5=procinfo r9=cpuid

(gdb) info registers ; NO UPDATE (but weirdly enough, an unrelated r1
update happened - which is the machine nr)!!
r0             0x0      0
r1             0x331    817
r2             0x0      0
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10000008       0x10000008 <stext+8>
cpsr           0x400001d3       1073742291

(gdb) si
95              movs    r10, r5

(gdb) info registers
r0             0x0      0
r1             0x331    817
r2             0x10000100       268435712
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x1000000c       0x1000000c <stext+12>
cpsr           0x400001d3       1073742291

(gdb) si
(gdb) info registers

r0             0x0      0
r1             0x331    817
r2             0x10000100       268435712
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10010000       0x10010000 <omap_request_dma+284>
cpsr           0x400001d3       1073742291

(gdb) si
0x10010004      755
(gdb) info registers
r0             0x0      0
r1             0x331    817
r2             0x10000100       268435712
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x0      0
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10010004       0x10010004 <omap_request_dma+288>
cpsr           0x400001d3       1073742291

(gdb) si  ; Finally r9 updated after this step, but its too late
0x10010008      755
(gdb) info registers
r0             0x0      0
r1             0x331    817
r2             0x10000100       268435712
r3             0x0      0
r4             0x0      0
r5             0x0      0
r6             0x0      0
r7             0x0      0
r8             0x0      0
r9             0x41069265       1090949733  <-- r9 updated
r10            0x0      0
r11            0x0      0
r12            0x0      0
sp             0x0      0x0 <__vectors_start>
lr             0x0      0
pc             0x10010008       0x10010008 <omap_request_dma+292>
cpsr           0x400001d3       1073742291
(gdb)


Any idea what could be going wrong and how to proceed? Why is there a
lag? Also, the r0, r1 and r2 registers are supposed to be updated
before starting the kernel. It seems they are updated in a lazy
fashion while the kernel has *already* started executing.

Appreciate any insights, thanks.

-Joel