Subject: [E3-hacking] Why won't my E3 boot?

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 12:00:03 +0100

I know the short answer - because my camera driver has broken it! But I
was hoping that someone may be able to give me some clues as to why.
I'm using nfs root at the moment, and if I build a kernel without the
camera driver enabled it works find. If I build the camera driver as a
module, it works fine. But if I compile the camera driver as a builtin,
it fails to boot because it cannot init the network.

I'm using a Linksys USB Ethernet adapter and the Pegasus driver. I've
attached a side by side diff of the 2 boot logs. In both cases, the
Pegasus driver is started. But in the failing case, the driver init
seems to be delayed until after the IP/TCP/NET init, which I guess it
too late.

Initially, I though that maybe the camera driver has messed up the USB
config, but now I'm not sure since in both cases the ethernet adapter is
found.  But I have a vague memory about someone fixing the USB driver
(something to so with the clocks?) and I'm wondering if that may be the
issue.

Anyone got any ideas/suggestions of things I can try to track this down?

Matt

Starting kernel ...                                             Starting kernel ...

Uncompressing Linux.......................................... | Uncompressing Linux..........................................
Linux version 2.6.16.2-omap2 (matt@fileserver) (gcc version 3 | Linux version 2.6.16.2-omap2 (matt@fileserver) (gcc version 3
CPU: ARM925Tid(wt) [54029252] revision 2 (ARMv4T)               CPU: ARM925Tid(wt) [54029252] revision 2 (ARMv4T)
Machine: Amstrad E3 (Delta)                                     Machine: Amstrad E3 (Delta)
Memory policy: ECC disabled, Data cache writethrough            Memory policy: ECC disabled, Data cache writethrough
OMAP1510 revision 2 handled as 15xx id: 53058f9ab2160e1e        OMAP1510 revision 2 handled as 15xx id: 53058f9ab2160e1e
SRAM: Mapped pa 0x20000000 to va 0xd0000000 size: 0x30000       SRAM: Mapped pa 0x20000000 to va 0xd0000000 size: 0x30000
CPU0: D VIVT write-back cache                                   CPU0: D VIVT write-back cache
CPU0: I cache: 16384 bytes, associativity 2, 16 byte lines, 5   CPU0: I cache: 16384 bytes, associativity 2, 16 byte lines, 5
CPU0: D cache: 8192 bytes, associativity 2, 16 byte lines, 25   CPU0: D cache: 8192 bytes, associativity 2, 16 byte lines, 25
Built 1 zonelists                                               Built 1 zonelists
Kernel command line: mem=32M console=ttyS0,115200n8 nfsroot=1   Kernel command line: mem=32M console=ttyS0,115200n8 nfsroot=1
ams_delta_init_irq                                              ams_delta_init_irq
Clocks: ARM_SYSST: 0x1000 DPLL_CTL: 0x0013 ARM_CKCTL: 0x250e    Clocks: ARM_SYSST: 0x1000 DPLL_CTL: 0x0013 ARM_CKCTL: 0x250e
Clocking rate (xtal/DPLL1/MPU): 12.0/150.0/150.0 MHz            Clocking rate (xtal/DPLL1/MPU): 12.0/150.0/150.0 MHz
Total of 64 interrupts in 2 interrupt banks                     Total of 64 interrupts in 2 interrupt banks
OMAP1510 GPIO hardware                                          OMAP1510 GPIO hardware
PID hash table entries: 256 (order: 8, 4096 bytes)              PID hash table entries: 256 (order: 8, 4096 bytes)
Console: colour dummy device 80x30                              Console: colour dummy device 80x30
Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)   Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)    Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Memory: 32MB = 32MB total                                       Memory: 32MB = 32MB total
Memory: 30124KB available (1732K code, 413K data, 104K init)  | Memory: 30096KB available (1752K code, 418K data, 108K init)
Mount-cache hash table entries: 512                             Mount-cache hash table entries: 512
CPU: Testing write buffer coherency: ok                         CPU: Testing write buffer coherency: ok
NET: Registered protocol family 16                              NET: Registered protocol family 16
ams_delta_init                                                  ams_delta_init
<4>MUX: initialized UART1_TX                                    <4>MUX: initialized UART1_TX
MUX: initialized UART1_RTS                                      MUX: initialized UART1_RTS
Installing fiq handler from c002d868, length 0x1ac            | Installing fiq handler from c002e868, length 0x1ac
request_fiq(): fiq_buffer = c0225610                          | request_fiq(): fiq_buffer = c022c6d0
DMA support for OMAP15xx initialized                            DMA support for OMAP15xx initialized
Initializing OMAP McBSP system                                  Initializing OMAP McBSP system
omap_dsp_init() done                                            omap_dsp_init() done
USB: hmc 16, usb0 2 wires                                       USB: hmc 16, usb0 2 wires
i2c_omap i2c_omap.1: bus 0 rev1.0 at 100 kHz                    i2c_omap i2c_omap.1: bus 0 rev1.0 at 100 kHz
usbcore: registered new driver usbfs                            usbcore: registered new driver usbfs
usbcore: registered new driver hub                              usbcore: registered new driver hub
io scheduler noop registered                                    io scheduler noop registered
io scheduler anticipatory registered (default)                  io scheduler anticipatory registered (default)
io scheduler deadline registered                                io scheduler deadline registered
io scheduler cfq registered                                     io scheduler cfq registered
Amstrad Delta backlight driver initialized.                     Amstrad Delta backlight driver initialized.
omapfb: configured for panel ams-delta                          omapfb: configured for panel ams-delta
omapfb-lcdc: init                                               omapfb-lcdc: init
Console: switching to colour frame buffer device 80x29          Console: switching to colour frame buffer device 80x29
omapfb: initialized vram=1048576 pixclock 3750 kHz hfreq 7.9    omapfb: initialized vram=1048576 pixclock 3750 kHz hfreq 7.9
OMAP RTC Driver                                                 OMAP RTC Driver
omap_rtc: RTC power up reset detected.                          omap_rtc: RTC power up reset detected.
omap_rtc: Enabling RTC.                                         omap_rtc: Enabling RTC.
serio: AMS DELTA keyboard adapter                               serio: AMS DELTA keyboard adapter
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ shar   Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ shar
serial8250: ttyS1 at MMIO 0x4000000 (irq = 162) is a 16550A     serial8250: ttyS1 at MMIO 0x4000000 (irq = 162) is a 16550A
serial8250.0: ttyS0 at MMIO 0xfffb0000 (irq = 46) is a ST1665   serial8250.0: ttyS0 at MMIO 0xfffb0000 (irq = 46) is a ST1665
RAMDISK driver initialized: 16 RAM disks of 8192K size 1024 b   RAMDISK driver initialized: 16 RAM disks of 8192K size 1024 b
loop: loaded (max 8 devices)                                    loop: loaded (max 8 devices)
PPP generic driver version 2.4.2                                PPP generic driver version 2.4.2
i2c /dev entries driver                                         i2c /dev entries driver
Linux video capture interface: v1.00                            Linux video capture interface: v1.00
                                                              > OMAP Camera driver initialzing
                                                              > omap1510_cam_init
                                                              > OV6650 sensor chip
                                                              > 6650sensor_try_format sizeimage=202752
                                                              > omap-camera: OMAP1510 Camera Parallel interface with OV6650 s
                                                              > omap-camera: registered device video0 [v4l2]
usbmon: debugfs is not available                                usbmon: debugfs is not available
ohci ohci: OMAP OHCI                                            ohci ohci: OMAP OHCI
ohci ohci: new USB bus registered, assigned bus number 1        ohci ohci: new USB bus registered, assigned bus number 1
ohci ohci: irq 38, io mem 0xfffba000                            ohci ohci: irq 38, io mem 0xfffba000
usb usb1: configuration #1 chosen from 1 choice                 usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found                                      hub 1-0:1.0: USB hub found
hub 1-0:1.0: 3 ports detected                                   hub 1-0:1.0: 3 ports detected
pegasus: v0.6.13 (2005/11/13), Pegasus/Pegasus II USB Etherne   pegasus: v0.6.13 (2005/11/13), Pegasus/Pegasus II USB Etherne
usb 1-1: new full speed USB device using ohci and address 2   <
usb 1-1: configuration #1 chosen from 1 choice                <
pegasus 1-1:1.0: setup Pegasus II specific registers          <
pegasus 1-1:1.0: eth0, Linksys USB USB100TX, 00:04:5a:90:37:7 <
usbcore: registered new driver pegasus                          usbcore: registered new driver pegasus
mice: PS/2 mouse device common for all mice                     mice: PS/2 mouse device common for all mice
OMAP Keypad Driver                                              OMAP Keypad Driver
input: omap-keypad as /class/input/input0                       input: omap-keypad as /class/input/input0
NET: Registered protocol family 2                               NET: Registered protocol family 2
input: AT Raw Set 2 keyboard as /class/input/input1             input: AT Raw Set 2 keyboard as /class/input/input1
IP route cache hash table entries: 512 (order: -1, 2048 bytes   IP route cache hash table entries: 512 (order: -1, 2048 bytes
TCP established hash table entries: 2048 (order: 1, 8192 byte   TCP established hash table entries: 2048 (order: 1, 8192 byte
TCP bind hash table entries: 2048 (order: 1, 8192 bytes)        TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
TCP: Hash tables configured (established 2048 bind 2048)        TCP: Hash tables configured (established 2048 bind 2048)
TCP reno registered                                             TCP reno registered
TCP bic registered                                              TCP bic registered
NET: Registered protocol family 1                               NET: Registered protocol family 1
NET: Registered protocol family 17                              NET: Registered protocol family 17
Sending DHCP requests ., OK                                   | usb 1-1: new full speed USB device using ohci and address 2
IP-Config: Got DHCP answer from 192.168.1.94, my address is 1 | usb 1-1: configuration #1 chosen from 1 choice
eth0: set allmulti                                            | pegasus 1-1:1.0: setup Pegasus II specific registers
IP-Config: Complete:                                          | IP-Config: No network devices available.
      device=eth0, addr=192.168.1.124, mask=255.255.255.0, gw <
     host=192.168.1.124, domain=mcallow.homelinux.net, nis-do <
     bootserver=192.168.1.94, rootserver=192.168.1.94, rootpa <
Looking up port of RPC 100003/2 on 192.168.1.94                 Looking up port of RPC 100003/2 on 192.168.1.94
                                                              > Root-NFS: Unable to get nfsd port number from server, using d
Looking up port of RPC 100005/1 on 192.168.1.94                 Looking up port of RPC 100005/1 on 192.168.1.94
VFS: Mounted root (nfs filesystem).                           | Root-NFS: Unable to get mountd port number from server, using
Freeing init memory: 104K                                     | Root-NFS: Server returned error -5 while mounting /home/matt/
Initializing random number generator... done.                 | VFS: Unable to mount root fs via NFS, trying floppy.
Starting network...                                           | Kernel panic - not syncing: VFS: Unable to mount root fs on u
modprobe: failed to load module wlan0                         <
Error for wireless request "Set ESSID" (8B1A) :               <
    SET failed on device wlan0 ; Invalid argument.            <
run-parts: /etc/network/if-pre-up.d/wlan exited with return c <
Starting dropbear sshd: OK                                    <
Starting telnetd...                                           <
/etc/init.d/rcS: 26: /etc/init.d/S60mpd: Permission denied    <
                                                              <
                                                              <
BusyBox v1.01 (2006.03.07-08:46+0000) Built-in shell (ash)    <
Enter 'help' for a list of built-in commands.                 <

/ #                                                           <

---

From: Matthew Garrett <[email-masked]>
Date: Mon, 4 Sep 2006 12:04:43 +0100

This is something of a guess, but:

Building drivers into the kernel doesn't guarantee the order that 
they'll be initialised in, and the kernel won't block on enumerating the 
USB bus. If you have the camera module built-in, then it may end up 
altering timing in such a way that the USB device doesn't get bound 
until after the kernel has done IP config. The standard way around this 
is to have a ramdisk that loops until the expected devices are found.

-- 
Matthew Garrett | [email-masked]

---

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 12:21:59 +0100

> is to have a ramdisk that loops until the expected devices are found.
Interesting theory. So maybe I should try booting from a ramdisk and 
then see if the Ethernet works after root has been mounted. That should 
tell me if it's a timing issue or a more serious problem re: interaction 
of the camera driver and usb

Matt

---

From: Jon Masters <[email-masked]>
Date: Mon, 04 Sep 2006 12:34:05 +0100

On Mon, 2006-09-04 at 12:21 +0100, Matt Callow wrote:

> > they'll be initialised in,

Well, if they're in the standard initcall table then the driver init
functions are called in the order the drivers were built into the kernel
- directory order during compile and subsequent built-in.o processing.

Hard to guess right though.

Jon.

---

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 14:54:04 +0100

> is to have a ramdisk that loops until the expected devices are found.
OK, I've gone back to using and ramdisk for rootfs and it works! -
thanks for the advice.
It makes using nfsroot a bit more difficult as I'll have to create a
ramdisk image first and then pivot_root to nfs I guess. In the long
term, I don't see this as a problem as I'll put the rootfs into flash.

That means that I've just got to tidy the camera driver up a bit and
(finally!) I'll post a patch.

Matt

---

From: David Given <[email-masked]>
Date: Mon, 04 Sep 2006 15:31:52 +0100

Jon Masters wrote:
[...]
> - directory order during compile and subsequent built-in.o processing.

Any USB devices will only have their drivers inited after the USB bus
has been enumerated, which happens in the background. This means that
block devices frequently only show up *after* the kernel tries to mount
them, which is a pain. There is a kernel option to deal with this ---
rootdelay --- which causes the kernel to pause for the specified number
of seconds before mounting. You could try fiddling with that...

-- 
+- David Given --McQ-+ "You cannot truly appreciate _Atlas Shrugged_
|  [email-masked]    | until you have read it in the original Klingon."
| ([email-masked]) | --- Sea Wasp on r.a.sf.w
+- www.cowlark.com --+

---

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 15:41:31 +0100

> of seconds before mounting. You could try fiddling with that...
I did try the rootdelay option, but it seems only to delay the rootfs
mounting, not the kernel autoconfig of the network. That still fails

Matt

---

From: Jon Masters <[email-masked]>
Date: Mon, 04 Sep 2006 15:42:34 +0100

> has been enumerated, which happens in the background.

Hmmm. The device will be detected then, but the driver is still built-in
and its init function should therefore still run when the init calls are
processed. It's a question of probing vs. just being built-in.

> This means that

That's a different issue. That's waiting on enumeration, which is not
correctly handled at the moment IMHO (without udev hack jobs). And
rootdelay is widely regarded as a huge giant ugly hack :-)

Jon.

---

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 20:13:20 +0100

> is to have a ramdisk that loops until the expected devices are found.
I've also found a patch
http://www.lammerts.org/software/kernelpatches/nfsroot-hotplug_ethernet.patch
which makes the kernel wait for a network device to appear. Seem to work
too.

Matt

---

From: Jon Masters <[email-masked]>
Date: Mon, 04 Sep 2006 20:26:13 +0100

> which makes the kernel wait for a network device to appear. Seem to work

Sleeps for one second until a network device pops up, then tries using
it. It'll still be ultimately better to pivot into an NFS root since
that's cleaner than using this hack :-)

Jon.

---

From: Matt Callow <[email-masked]>
Date: Mon, 04 Sep 2006 22:15:51 +0100

> that's cleaner than using this hack :-)

I agree, but this was quick and easy. And it allows me to continue
testing the camera driver.

Matt

---

From: Jon Masters <[email-masked]>
Date: Mon, 04 Sep 2006 22:22:39 +0100

> testing the camera driver.

Oh sure, I'm not disagreeing :-)

Actually, I've decided to revive my interest in the E3 now I'm not
working for a certain embedded company. I'm leaving the country in a few
weeks so I'm looking to pick up a couple more E3s to take apart and use
for various purposes (some similar to its original function)...

I'm watching some ebay auctions at the moment (I have only one E3 now
and it's in pieces) since I don't have a handy Tesco and most other
highstreet retailers seem to be fresh out now.

Jon.