OMAP baseline test results for v3.7-rc1

Jean Pihet jean.pihet at newoldbits.com
Sat Nov 3 17:39:26 EDT 2012


Hi Paul,

On Thu, Nov 1, 2012 at 8:51 AM, Jean Pihet <jean.pihet at newoldbits.com> wrote:
> Hi Paul,
>
> On Wed, Oct 31, 2012 at 10:44 PM, Paul Walmsley <paul at pwsan.com> wrote:
>> Hi
>>
>> On Wed, 31 Oct 2012, Jean Pihet wrote:
>>
>>> Paul,
>>> Could you please check with the 2 calls to PM QoS from the I2C code
>>> commented out? This will rule out the PM QoS impact.
>>
>> Will be happy to do a test run for you, after the boot log from your local
>> test run is posted:
>>
>> http://marc.info/?l=linux-arm-kernel&m=135167153510814&w=2

Here are some more details after investigation.

The setup is as identical as possible to yours:
- U-Boot 2011.06-dirty (Sep 04 2012 - 17:06:58) from
http://www.pwsan.com/tmp/3530es3beagle-MLO-u-boot-20121023.tar.bz2.
  Please note that the MLO image does not run on my board and so I had
to use my known-to-work image.
- 3.7.0-rc1 kernel, omap2plus_defconfig,
- same kernel parameters,
- Angstrom rootfs from
http://www.pwsan.com/tmp/20121023-beagleboard-angstrom-userspace.tar.bz2

The differences are:
- OMAP revision (ES2.1 vs ES3.0),
- Beagleboard revision (B5 vs Cx),
- RAM amount (128 vs 256MB),
- compiler: gcc version 4.5.1 (Sourcery G++ Lite 2010.09-50) vs 4.5.2
(Sourcery G++ Lite 2011.03-41)

The result is that I could reproduce the issue but it happens much
more rarely on my side (only once vs quasi 100% on ~50 boot cycles).
The issue is triggered by running 'hwclock --systohc'  while the
system is heavily loaded (running depmod etc.). The system recovers
nicely after the issue, the RTC can be used correctly later on.

Here is the log:

U-Boot 2011.06-dirty (Sep 04 2012 - 17:06:58)

OMAP3530-GP ES2.1, CPU-OPP2, L3-165MHz, Max CPU Clock 600 mHz
OMAP3 Beagle board + LPDDR/NAND
I2C:   ready
DRAM:  128 MiB
NAND:  256 MiB
MMC:   OMAP SD/MMC: 0
In:    serial
Out:   serial
Err:   serial
Beagle Rev Ax/Bx
timed out in wait_for_pin: I2C_STAT=0
I2C read: I/O error
Unrecognized expansion board: 0
Die ID #0f6000020000000004013ef109008009
Hit any key to stop autoboot:  0
reading uimage

4148008 bytes read
## Booting kernel from Legacy Image at 80300000 ...
   Image Name:   Linux-3.7.0-rc1
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    4147944 Bytes = 4 MiB
   Load Address: 80008000
   Entry Point:  80008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK
OK

Starting kernel ...

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0
[    0.000000] Linux version 3.7.0-rc1 (def at rachael) (gcc version
4.5.2 (Sourcery G++ Lite 2011.03-41) ) #2 SMP Sat Nov 3 21:56:11 CET
2012
[    0.000000] CPU: ARMv7 Processor [411fc082] revision 2 (ARMv7), cr=10c53c7d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT
nonaliasing instruction cache
[    0.000000] Machine: OMAP3 Beagle Board
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] OMAP3430/3530 ES2.1 (l2cache iva sgx neon isp )
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/500 MHz
[    0.000000] PERCPU: Embedded 9 pages/cpu @c0e40000 s12928 r8192 d15744 u36864
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.
Total pages: 32256
[    0.000000] Kernel command line: console=ttyO2,230400n8
root=/dev/mmcblk0p2 rw rootfstype=ext3 rootwait
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Memory: 127MB = 127MB total
[    0.000000] Memory: 115316k/115316k available, 15756k reserved, 0K highmem
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xc8800000 - 0xff000000   ( 872 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xc8000000   ( 128 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc07037dc   (7150 kB)
[    0.000000]       .init : 0xc0704000 - 0xc0754280   ( 321 kB)
[    0.000000]       .data : 0xc0756000 - 0xc07e15a0   ( 558 kB)
[    0.000000]        .bss : 0xc07e15c4 - 0xc0d3bfac   (5483 kB)
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 96
interrupts
[    0.000000] Total of 96 interrupts on 1 active controller
[    0.000000] OMAP clockevent source: GPTIMER12 at 32768 Hz
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns,
wraps every 131071999ms
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] Console: colour dummy device 80x30
[    0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat,
Inc., Ingo Molnar
[    0.000000] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.000000] ... MAX_LOCK_DEPTH:          48
[    0.000000] ... MAX_LOCKDEP_KEYS:        8191
[    0.000000] ... CLASSHASH_SIZE:          4096
[    0.000000] ... MAX_LOCKDEP_ENTRIES:     16384
[    0.000000] ... MAX_LOCKDEP_CHAINS:      32768
[    0.000000] ... CHAINHASH_SIZE:          16384
[    0.000000]  memory used by lock dependency info: 3695 kB
[    0.000000]  per task-struct memory footprint: 1152 bytes
[    0.001190] Calibrating delay loop... 324.52 BogoMIPS (lpj=1265664)
[    0.106964] pid_max: default: 32768 minimum: 301
[    0.107757] Security Framework initialized
[    0.108001] Mount-cache hash table entries: 512
[    0.114196] CPU: Testing write buffer coherency: ok
[    0.115478] CPU0: thread -1, cpu 0, socket -1, mpidr 0
[    0.115600] Setting up static identity map for 0x8051ebe0 - 0x8051ec50
[    0.119537] Brought up 1 CPUs
[    0.119567] SMP: Total of 1 processors activated (324.52 BogoMIPS).
[    0.142547] pinctrl core: initialized pinctrl subsystem
[    0.151123] regulator-dummy: no parameters
[    0.154083] NET: Registered protocol family 16
[    0.155853] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.158386] omap-gpmc omap-gpmc: GPMC revision 5.0
[    0.175537] OMAP GPIO hardware version 2.5
[    0.202301] omap_mux_init: Add partition: #1: core, flags: 0
[    0.205810] OMAP3 Beagle Rev: Ax/Bx
[    0.236938] Reprogramming SDRC clock to 332000000 Hz
[    0.238708] Found NAND on CS0
[    0.238739] Registering NAND on CS0
[    0.240417] find_device_opp: Invalid parameters
[    0.240661] find_device_opp: Invalid parameters
[    0.240722] find_device_opp: Invalid parameters
[    0.240783] find_device_opp: Invalid parameters
[    0.240844] find_device_opp: Invalid parameters
[    0.241149] hw-breakpoint: debug architecture 0x4 unsupported.
[    0.262451]  omap-mcbsp.2: alias fck already exists
[    0.263702]  omap-mcbsp.3: alias fck already exists
[    0.269287] OMAP DMA hardware revision 4.0
[    0.275695]  arm-pmu: alias fck already exists
[    0.372833] bio: create slab <bio-0> at 0
[    0.504943] omap-dma-engine omap-dma-engine: OMAP DMA engine driver
[    0.513244] SCSI subsystem initialized
[    0.517700] usbcore: registered new interface driver usbfs
[    0.518524] usbcore: registered new interface driver hub
[    0.519470] usbcore: registered new device driver usb
[    0.542327] twl 1-0048: PIH (irq 23) chaining IRQs 338..346
[    0.543212] twl 1-0048: power (irq 343) chaining IRQs 346..353
[    0.547882] twl4030_gpio twl4030_gpio: gpio (irq 338) chaining IRQs 354..371
[    0.560913] vdd_mpu_iva: 600 <--> 1450 mV normal
[    0.564697] vdd_core: 600 <--> 1450 mV normal
[    0.568145] VMMC1: 1850 <--> 3150 mV at 3000 mV normal standby
[    0.572204] VDAC: 1800 mV normal standby
[    0.575622] VDVI: 1800 mV normal standby
[    0.579803] VSIM: 1800 <--> 3000 mV at 1800 mV normal standby
[    0.581176] omap_i2c omap_i2c.1: bus 1 rev1.3.12 at 2600 kHz
[    0.584350] omap_i2c omap_i2c.3: bus 3 rev1.3.12 at 100 kHz
[    0.595794] Switching to clocksource 32k_counter
[    0.784149] NET: Registered protocol family 2
[    0.787017] TCP established hash table entries: 4096 (order: 3, 32768 bytes)
[    0.787414] TCP bind hash table entries: 4096 (order: 5, 147456 bytes)
[    0.790130] TCP: Hash tables configured (established 4096 bind 4096)
[    0.790435] TCP: reno registered
[    0.790496] UDP hash table entries: 256 (order: 2, 20480 bytes)
[    0.790863] UDP-Lite hash table entries: 256 (order: 2, 20480 bytes)
[    0.792205] NET: Registered protocol family 1
[    0.794158] RPC: Registered named UNIX socket transport module.
[    0.794189] RPC: Registered udp transport module.
[    0.794219] RPC: Registered tcp transport module.
[    0.794219] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.795715] NetWinder Floating Point Emulator V0.97 (double precision)
[    0.796173] CPU PMU: probing PMU on CPU 0
[    0.796386] hw perfevents: enabled with ARMv7 Cortex-A8 PMU driver,
5 counters available
[    1.017608] VFS: Disk quotas dquot_6.5.2
[    1.018005] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.022155] NFS: Registering the id_resolver key type
[    1.022857] Key type id_resolver registered
[    1.022888] Key type id_legacy registered
[    1.023101] jffs2: version 2.2. (NAND) (SUMMARY)  © 2001-2006 Red Hat, Inc.
[    1.023986] msgmni has been set to 225
[    1.029388] io scheduler noop registered
[    1.029449] io scheduler deadline registered
[    1.029571] io scheduler cfq registered (default)
[    1.034118] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.044128] omap_uart.0: ttyO0 at MMIO 0x4806a000 (irq = 88) is a OMAP UART0
[    1.047027] omap_uart.1: ttyO1 at MMIO 0x4806c000 (irq = 89) is a OMAP UART1
[    1.049133] omap_uart.2: ttyO2 at MMIO 0x49020000 (irq = 90) is a OMAP UART2
[    1.408569] console [ttyO2] enabled
[    1.459045] brd: module loaded
[    1.491302] loop: module loaded
[    1.504882] mtdoops: mtd device (mtddev=name/number) must be supplied
[    1.509094] NAND device: Manufacturer ID: 0x2c, Chip ID: 0xba
(Micron NAND 256MiB 1,8V 16-bit), page size: 2048, OOB size: 64
[    1.515777] Creating 5 MTD partitions on "omap2-nand.0":
[    1.518737] 0x000000000000-0x000000080000 : "X-Loader"
[    1.531433] 0x000000080000-0x000000260000 : "U-Boot"
[    1.542541] 0x000000260000-0x000000280000 : "U-Boot Env"
[    1.551788] 0x000000280000-0x000000680000 : "Kernel"
[    1.564239] 0x000000680000-0x000010000000 : "File System"
[    1.793273] OneNAND driver initializing
[    1.812469] usbcore: registered new interface driver asix
[    1.816345] usbcore: registered new interface driver cdc_ether
[    1.820343] usbcore: registered new interface driver smsc95xx
[    1.824310] usbcore: registered new interface driver net1080
[    1.828124] usbcore: registered new interface driver cdc_subset
[    1.832153] usbcore: registered new interface driver zaurus
[    1.835937] usbcore: registered new interface driver cdc_ncm
[    1.842102] usbcore: registered new interface driver cdc_wdm
[    1.845184] Initializing USB Mass Storage driver...
[    1.848754] usbcore: registered new interface driver usb-storage
[    1.852020] USB Mass Storage support registered.
[    1.855407] usbcore: registered new interface driver usbtest
[    1.860931] mousedev: PS/2 mouse device common for all mice
[    1.872131] input: twl4030_pwrbutton as
/devices/platform/omap_i2c.1/i2c-1/1-0049/twl4030_pwrbutton/input/input0
[    1.882110] twl_rtc twl_rtc: Enabling TWL-RTC
[    1.890533] twl_rtc twl_rtc: rtc core: registered twl_rtc as rtc0
[    1.897399] i2c /dev entries driver
[    1.903747] Driver for 1-wire Dallas network protocol.
[    1.911224] omap_wdt: OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec
[    1.916412] twl4030_wdt twl4030_wdt: Failed to register misc device
[    1.920318] twl4030_wdt: probe of twl4030_wdt failed with error -16
[    1.929351] omap_hsmmc omap_hsmmc.0: multiblock reads disabled due
to 35xx erratum 2.1.1.128; MMC read performance may suffer
[    1.936065] omap_hsmmc omap_hsmmc.0: Failed to get debounce clk
[    1.939361] omap-dma-engine omap-dma-engine: allocating channel for 62
[    1.943084] omap-dma-engine omap-dma-engine: allocating channel for 61
[    2.332794] usbcore: registered new interface driver usbhid
[    2.335906] usbhid: USB HID core driver
[    2.343688] oprofile: using arm/armv7
[    2.346954] TCP: cubic registered
[    2.348754] Initializing XFRM netlink socket
[    2.351257] NET: Registered protocol family 17
[    2.353790] NET: Registered protocol family 15
[    2.356872] Key type dns_resolver registered
[    2.359313] VFP support v0.3: implementor 41 architecture 3 part 30
variant c rev 1
[    2.376007] omap2_set_init_voltage: unable to find boot up OPP for
vdd_mpu_iva
[    2.380218] omap2_set_init_voltage: unable to set vdd_mpu_iva
[    2.384307] PM: no software I/O chain control; some wakeups may be lost
[    2.388549] ThumbEE CPU extension supported.
[    2.435852] clock: disabling unused clocks to save power
[    2.445678] VDVI: incomplete constraints, leaving on
[    2.448852] VDAC: incomplete constraints, leaving on
[    2.456817] input: gpio-keys as /devices/platform/gpio-keys/input/input1
[    2.465118] twl_rtc twl_rtc: setting system clock to 2010-07-22
02:43:19 UTC (1279766599)
[    2.475555] Waiting for root device /dev/mmcblk0p2...
[    2.499633] mmc0: new SD card at address e624
[    2.506134] mmcblk0: mmc0:e624 SD01G 968 MiB
[    2.520111]  mmcblk0: p1 p2
[    4.051177] kjournald starting.  Commit interval 5 seconds
[    4.059448] EXT3-fs (mmcblk0p2): using internal journal
[    4.067016] EXT3-fs (mmcblk0p2): recovery complete
[    4.069641] EXT3-fs (mmcblk0p2): mounted filesystem with ordered data mode
[    4.074005] VFS: Mounted root (ext3 filesystem) on device 179:2.
[    4.078399] Freeing init memory: 320K
INIT: version 2.86 booting
Starting the hotplug events dispatcher udevd
Synthesizing the initial hotplug events
Remounting root file system...
mount: according to mtab, /proc is already mounted on /proc

WARNING: Couldn't open directory /lib/modules/3.7.0-rc1: No such file
or directory
FATAL: Could not open /lib/modules/3.7.0-rc1/modules.dep.temp for
writing: No such file or directory
root: mount: mount point /proc/bus/usb does not exist
Setting up IP spoofing protection: rp_filter.
Configuring network interfaces... modprobe: FATAL: Could not load
/lib/modules/3.7.0-rc1/modules.dep: No such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

ifconfig: SIOCGIFFLAGS: No such device
modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

eth0      No such device

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

udhcpc: SIOCGIFINDEX: No such device
done.
Starting portmap daemon: portmap.
Fri Jul 22 02:12:00 UTC 2011
[   33.424743] omap_i2c omap_i2c.1: timeout waiting for bus ready
[   34.440338] omap_i2c omap_i2c.1: timeout waiting for bus ready
[   34.443603] twl: i2c_read failed to transfer all messages
[   34.446533] twl_rtc: Could not read TWLregister D - error -110
[   34.449768] twl_rtc twl_rtc: twl_rtc_read_time: reading CTRL_REG, error -110
INIT: Entering runlevel: 5
ALSA: Restoring mixer settings...
/usr/sbin/alsactl: load_state:1327: No soundcards found...
Starting Dropbear SSH server: modprobe: FATAL: Could not load
/lib/modules/3.7.0-rc1/modules.dep: No such file or directory

modprobe: FATAL: Could not load /lib/modules/3.7.0-rc1/modules.dep: No
such file or directory

dropbear.
Starting advanced power management daemon: No APM support in kernel
(failed.)
Starting system message bus: dbus.
Starting syslogd/klogd: start-stop-daemon: lseek: Invalid argument
 * Starting Avahi mDNS/DNS-SD Daemon: avahi-daemon
[ ok ]
Starting Bluetooth subsystem:modprobe: FATAL: Could not load
/lib/modules/3.7.0-rc1/modules.dep: No such file or directory
 hcid
 hid2hci.

.-------.
|       |                  .-.
|   |   |-----.-----.-----.| |   .----..-----.-----.
|       |     | __  |  ---'| '--.|  .-'|     |     |
|   |   |  |  |     |---  ||  --'|  |  |  '  | | | |
'---'---'--'--'--.  |-----''----''--'  '-----'-'-'-'
                -'  |
                '---'

The Angstrom Distribution beagleboard ttyO2

Angstrom 2008.1-test-20080712 beagleboard ttyO2

beagleboard login: root
login[2013]: root login  on `ttyO2'

root at beagleboard:~# hwclock -s
root at beagleboard:~# cat
/sys/devices/platform/omap_i2c.1/i2c-1/1-004b/twl_rtc/rtc/rtc0/date
2011-07-22
root at beagleboard:~# cat
/sys/devices/platform/omap_i2c.1/i2c-1/1-004b/twl_rtc/rtc/rtc0/time
02:12:00
root at beagleboard:~#

>>
>>
>> - Paul

More investigation on-going, so more to come!

Regards,
Jean



More information about the linux-arm-kernel mailing list