[Openpxa-users] Linux udelay() is way off

[Openpxa-users] Linux udelay() is way off

[Marek Vasut]

On Thursday 20 January 2011 17:09:00 Bj?rn Forsman wrote:
> Hi,
> 
> On my Colibri PXA310, I see that Linux udelay() is only 30 % of the
> length it's supposed to. This is way off and cause problems (e.g.
> 1-Wire device driver breaks). I'm running OpenPXA bootloaders (OBM2 +
> U-Boot) and mainline Linux 2.6.36.
> 
> Any ideas how to fix this?
> 
> Could it be that U-Boot sets up the system clock to something
> different than what Linux "expects" so that loops_per_jiffy becomes
> wrong? I see some clock setup in <u-boot-pxa>/arch/arm/cpu/pxa/start.S
> but I'm not sure what to do with it (yet). I'd like to try out
> different clock speeds to see if it helps. Any pointers?
> 
> I also have a workaround in mind: Try out different lpj= settings on
> the kernel command line until a udelay(1000) actually is 1000 us. Is
> this a sane thing to do?

CCing relevant people.

And no, linux kernel should derive it's timing properly so it's a kernel bug.

Cheers
> 
> Best regards,
> Bj?rn Forsman
> 
> ---------------------------------------------------------------------------
> --- Protect Your Site and Customers from Malware Attacks
> Learn about various malware tactics and how to avoid them. Understand
> malware threats, the impact they can have on your business, and how you
> can protect your company and customers by using code signing.
> http://p.sf.net/sfu/oracle-sfdevnl
> _______________________________________________
> Openpxa-users mailing list
> Openpxa-users at lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/openpxa-users

[Openpxa-users] Linux udelay() is way off

[Russell King - ARM Linux]

On Thu, Jan 20, 2011 at 06:00:04PM +0100, Marek Vasut wrote:
> On Thursday 20 January 2011 17:09:00 Bj?rn Forsman wrote:
> > Hi,
> > 
> > On my Colibri PXA310, I see that Linux udelay() is only 30 % of the
> > length it's supposed to. This is way off and cause problems (e.g.
> > 1-Wire device driver breaks). I'm running OpenPXA bootloaders (OBM2 +
> > U-Boot) and mainline Linux 2.6.36.
> > 
> > Any ideas how to fix this?
> > 
> > Could it be that U-Boot sets up the system clock to something
> > different than what Linux "expects" so that loops_per_jiffy becomes
> > wrong? I see some clock setup in <u-boot-pxa>/arch/arm/cpu/pxa/start.S
> > but I'm not sure what to do with it (yet). I'd like to try out
> > different clock speeds to see if it helps. Any pointers?
> > 
> > I also have a workaround in mind: Try out different lpj= settings on
> > the kernel command line until a udelay(1000) actually is 1000 us. Is
> > this a sane thing to do?
> 
> CCing relevant people.
> 
> And no, linux kernel should derive it's timing properly so it's a kernel bug.

I recently looked into the udelay() timing accuracy, and I saw it only
being reduced by .7% at boot time - due to the cycles stolen by the timer
IRQ handler.

The delay calibration algorithm shouldn't produce big errors due to the
way it works.  It first tries to find a delay longer than the timer tick.
It then uses a successive approximation technique over about 9 bits of
loops_per_jiffy value.

So, I wouldn't expect the boot time lpj value to be significantly out.

However, what might be happening is you boot at X MHz.  You then use cpufreq
and drop the frequency to Y MHz.  You then suspend and resume.  On resume,
the boot loader starts the processor again at X MHz, but the kernel still
assumes that you're running at Y MHz and has not adjusted the delay loop
accordingly.

This will result in a much shorter than expected delay.

So, the first thing that needs doing is to ascertain when the delay
becomes wrong.

The other thing to check is whether you're suffering from rounding errors
in the us-to-loops calculation - 56949d4 (ARM: udelay: prevent math
rounding resulting in short udelays) which aren't calibrated away.
(The lpj delay testing bypasses the calculation as its dealing with
number of loops, not us.)

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

On 20 January 2011 18:55, Russell King - ARM Linux
<linux@arm.linux.org.uk> wrote:
> On Thu, Jan 20, 2011 at 06:00:04PM +0100, Marek Vasut wrote:
>> On Thursday 20 January 2011 17:09:00 Bj?rn Forsman wrote:
>> > Hi,
>> >
>> > On my Colibri PXA310, I see that Linux udelay() is only 30 % of the
>> > length it's supposed to. This is way off and cause problems (e.g.
>> > 1-Wire device driver breaks). I'm running OpenPXA bootloaders (OBM2 +
>> > U-Boot) and mainline Linux 2.6.36.
>> >
>> > Any ideas how to fix this?
>> >
>> > Could it be that U-Boot sets up the system clock to something
>> > different than what Linux "expects" so that loops_per_jiffy becomes
>> > wrong? I see some clock setup in <u-boot-pxa>/arch/arm/cpu/pxa/start.S
>> > but I'm not sure what to do with it (yet). I'd like to try out
>> > different clock speeds to see if it helps. Any pointers?
>> >
>> > I also have a workaround in mind: Try out different lpj= settings on
>> > the kernel command line until a udelay(1000) actually is 1000 us. Is
>> > this a sane thing to do?
>>
>> CCing relevant people.
>>
>> And no, linux kernel should derive it's timing properly so it's a kernel bug.
>
> I recently looked into the udelay() timing accuracy, and I saw it only
> being reduced by .7% at boot time - due to the cycles stolen by the timer
> IRQ handler.
>
> The delay calibration algorithm shouldn't produce big errors due to the
> way it works. ?It first tries to find a delay longer than the timer tick.
> It then uses a successive approximation technique over about 9 bits of
> loops_per_jiffy value.
>
> So, I wouldn't expect the boot time lpj value to be significantly out.
>
> However, what might be happening is you boot at X MHz. ?You then use cpufreq
> and drop the frequency to Y MHz. ?You then suspend and resume. ?On resume,
> the boot loader starts the processor again at X MHz, but the kernel still
> assumes that you're running at Y MHz and has not adjusted the delay loop
> accordingly.
>
> This will result in a much shorter than expected delay.
>
> So, the first thing that needs doing is to ascertain when the delay
> becomes wrong.

I'm not doing any suspend/resume stuff.

But I did have cpufreq enabled (using default 'performance' governor).
Disabling cpufreq makes udelay() correct. Yay!

In order to try diagnosing the problem I re-enabled cpufreq and booted
with cpufreq.debug=7.

Here is dmesg | grep -E freq\|performance:

[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/nfs
nfsroot=10.1.11.41:/srv/nfs ip=dhcp video=pxafb:vmem:4M consoleblank=0
cpufreq.debug=7
[   11.422325] cpufreq-core: trying to register driver pxa3xx-cpufreq
[   11.422491] cpufreq-core: adding CPU 0
[   11.422636] freq-table: table entry 0: 104000 kHz, 0 index
[   11.422758] freq-table: table entry 1: 208000 kHz, 1 index
[   11.422876] freq-table: table entry 2: 416000 kHz, 2 index
[   11.422995] freq-table: table entry 3: 624000 kHz, 3 index
[   11.423630] cpufreq-core: setting new policy for CPU 0: 104000 - 624000 kHz
[   11.423777] freq-table: request for verification of policy (104000
- 624000 kHz) for cpu 0
[   11.423932] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   11.424074] freq-table: request for verification of policy (104000
- 624000 kHz) for cpu 0
[   11.424223] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   11.424356] cpufreq-core: new min and max freqs are 104000 - 624000 kHz
[   11.424464] cpufreq-core: governor switch
[   11.424567] cpufreq-core: __cpufreq_governor for CPU 0, event 1
[   11.424689] performance: setting to 624000 kHz because of event 1
[   11.424817] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   11.424952] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   11.425091] freq-table: target is 3 (624000 kHz, 3)
[   11.425207] cpufreq-core: notification 0 of frequency transition to
624000 kHz
[   11.425363] cpufreq-core: saving 518144 as reference value for
loops_per_jiffy; freq is 312000 kHz
[   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
frequency 624000 kHz
[   11.425659] cpufreq-core: notification 1 of frequency transition to
624000 kHz
[   11.425681] cpufreq-core: FREQ: 624000 - CPU: 0
[   11.425698] cpufreq-core: governor: change or update limits
[   11.425717] cpufreq-core: __cpufreq_governor for CPU 0, event 3
[   11.425738] performance: setting to 624000 kHz because of event 3
[   11.425760] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   11.425781] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   11.425804] freq-table: target is 3 (624000 kHz, 3)
[   11.426249] cpufreq-core: initialization complete
[   11.426285] cpufreq-core: driver pxa3xx-cpufreq up and running
[   13.177169] cpufreq-core: updating policy for CPU 0
[   13.177214] cpufreq-core: setting new policy for CPU 0: 104000 - 624000 kHz
[   13.177242] freq-table: request for verification of policy (104000
- 624000 kHz) for cpu 0
[   13.177271] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   13.177302] freq-table: request for verification of policy (104000
- 624000 kHz) for cpu 0
[   13.177328] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   13.177353] cpufreq-core: new min and max freqs are 104000 - 624000 kHz
[   13.177373] cpufreq-core: governor: change or update limits
[   13.177395] cpufreq-core: __cpufreq_governor for CPU 0, event 3
[   13.177417] performance: setting to 624000 kHz because of event 3
[   13.177440] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   13.177465] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   13.177491] freq-table: target is 3 (624000 kHz, 3)

See attached dmesg.txt for full output.

The kernel ends up with

Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)

in both cases (with/without cpufreq).

Best regards,
Bj?rn Forsman
-------------- next part --------------
[    0.000000] Linux version 2.6.36-00038-g92080b9 (bjornfor at bjornfor-desktop) (gcc version 4.3.5 (Buildroot 2010.11-git) ) #3 PREEMPT Thu Jan 20 19:41:51 CET 2011
[    0.000000] CPU: XScale-V3 based processor [69056892] revision 2 (ARMv5TE), cr=0000397f
[    0.000000] CPU: VIVT data cache, VIVT instruction cache
[    0.000000] Machine: Toradex Colibri PXA300
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] RO Mode clock: 60.00MHz (inactive)
[    0.000000] Run Mode clock: 312.00MHz (*24)
[    0.000000] Turbo Mode clock: 624.00MHz (*2, inactive)
[    0.000000] HSIO bus clock: 312.00MHz
[    0.000000] On node 0 totalpages: 32768
[    0.000000] free_area_init_node: node 0, pgdat c03f1484, node_mem_map c0448000
[    0.000000]   Normal zone: 256 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 32512 pages, LIFO batch:7
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/nfs nfsroot=10.1.11.41:/srv/nfs ip=dhcp video=pxafb:vmem:4M consoleblank=0 cpufreq.debug=7
[    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: 128MB = 128MB total
[    0.000000] Memory: 125568k/125568k available, 5504k 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]     DMA     : 0xffc00000 - 0xffe00000   (   2 MB)
[    0.000000]     vmalloc : 0xc8800000 - 0xe8000000   ( 504 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xc8000000   ( 128 MB)
[    0.000000]     modules : 0xbf000000 - 0xc0000000   (  16 MB)
[    0.000000]       .init : 0xc0008000 - 0xc0029000   ( 132 kB)
[    0.000000]       .text : 0xc0029000 - 0xc03ce000   (3732 kB)
[    0.000000]       .data : 0xc03ce000 - 0xc03f1ba0   ( 143 kB)
[    0.000000] SLUB: Genslabs=11, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Preemptable hierarchical RCU implementation.
[    0.000000] 	RCU-based detection of stalled CPUs is disabled.
[    0.000000] 	Verbose stalled-CPUs detection is disabled.
[    0.000000] NR_IRQS:288
[    0.000000] Console: colour dummy device 80x30
[   10.834173] Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)
[   11.014293] pid_max: default: 32768 minimum: 301
[   11.014769] Mount-cache hash table entries: 512
[   11.016528] CPU: Testing write buffer coherency: ok
[   11.020107] devtmpfs: initialized
[   11.042976] NET: Registered protocol family 16
[   11.090264] colibri_pxa3xx_init_eth(): no valid serial boot tag found, taking MAC from device
[   11.092588] colibri_pxa3xx_init_eth(): no valid serial boot tag found, taking MAC from device
[   11.218487] bio: create slab <bio-0> at 0
[   11.229147] SCSI subsystem initialized
[   11.232169] usbcore: registered new interface driver usbfs
[   11.234980] usbcore: registered new interface driver hub
[   11.236852] usbcore: registered new device driver usb
[   11.244693] I2C: i2c-0: PXA I2C adapter
[   11.256367] Switching to clocksource oscr0
[   11.411734] NET: Registered protocol family 2
[   11.412437] IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
[   11.413961] TCP established hash table entries: 4096 (order: 3, 32768 bytes)
[   11.414750] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[   11.415257] TCP: Hash tables configured (established 4096 bind 4096)
[   11.415360] TCP reno registered
[   11.415462] UDP hash table entries: 256 (order: 0, 4096 bytes)
[   11.415663] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[   11.416416] NET: Registered protocol family 1
[   11.419072] RPC: Registered udp transport module.
[   11.419190] RPC: Registered tcp transport module.
[   11.419277] RPC: Registered tcp NFSv4.1 backchannel transport module.
[   11.422325] cpufreq-core: trying to register driver pxa3xx-cpufreq
[   11.422491] cpufreq-core: adding CPU 0
[   11.422636] freq-table: table entry 0: 104000 kHz, 0 index
[   11.422758] freq-table: table entry 1: 208000 kHz, 1 index
[   11.422876] freq-table: table entry 2: 416000 kHz, 2 index
[   11.422995] freq-table: table entry 3: 624000 kHz, 3 index
[   11.423083] CPUFREQ support for PXA3xx initialized
[   11.423630] cpufreq-core: setting new policy for CPU 0: 104000 - 624000 kHz
[   11.423777] freq-table: request for verification of policy (104000 - 624000 kHz) for cpu 0
[   11.423932] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   11.424074] freq-table: request for verification of policy (104000 - 624000 kHz) for cpu 0
[   11.424223] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   11.424356] cpufreq-core: new min and max freqs are 104000 - 624000 kHz
[   11.424464] cpufreq-core: governor switch
[   11.424567] cpufreq-core: __cpufreq_governor for CPU 0, event 1
[   11.424689] performance: setting to 624000 kHz because of event 1
[   11.424817] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   11.424952] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   11.425091] freq-table: target is 3 (624000 kHz, 3)
[   11.425207] cpufreq-core: notification 0 of frequency transition to 624000 kHz
[   11.425363] cpufreq-core: saving 518144 as reference value for loops_per_jiffy; freq is 312000 kHz
[   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for frequency 624000 kHz
[   11.425659] cpufreq-core: notification 1 of frequency transition to 624000 kHz
[   11.425681] cpufreq-core: FREQ: 624000 - CPU: 0
[   11.425698] cpufreq-core: governor: change or update limits
[   11.425717] cpufreq-core: __cpufreq_governor for CPU 0, event 3
[   11.425738] performance: setting to 624000 kHz because of event 3
[   11.425760] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   11.425781] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   11.425804] freq-table: target is 3 (624000 kHz, 3)
[   11.426249] cpufreq-core: initialization complete
[   11.426285] cpufreq-core: driver pxa3xx-cpufreq up and running
[   11.426306] NetWinder Floating Point Emulator V0.97 (double precision)
[   11.430543] JFFS2 version 2.2. (NAND) ? 2001-2006 Red Hat, Inc.
[   11.431042] msgmni has been set to 245
[   11.432666] io scheduler noop registered
[   11.432697] io scheduler deadline registered
[   11.432739] io scheduler cfq registered (default)
[   11.470434] Console: switching to colour frame buffer device 100x37
[   12.276781] pxa2xx-uart.0: ttyS0 at MMIO 0x40100000 (irq = 22) is a FFUART
[   12.657045] console [ttyS0] enabled
[   12.662430] pxa2xx-uart.1: ttyS1 at MMIO 0x40200000 (irq = 21) is a BTUART
[   12.671456] pxa2xx-uart.2: ttyS2 at MMIO 0x40700000 (irq = 20) is a STUART
[   12.716603] NAND device: Manufacturer ID: 0xec, Chip ID: 0xdc (Samsung NAND 512MiB 3,3V 8-bit)
[   12.725823] Bad block table found at page 262080, version 0x01
[   12.726664] Bad block table found at page 262016, version 0x01
[   12.727100] nand_read_bbt: Bad block at 0x000001480000
[   12.727119] nand_read_bbt: Bad block at 0x0000014a0000
[   12.727134] nand_read_bbt: Bad block at 0x0000014c0000
[   12.727149] nand_read_bbt: Bad block at 0x0000014e0000
[   12.727165] nand_read_bbt: Bad block at 0x000001500000
[   12.727180] nand_read_bbt: Bad block at 0x000001520000
[   12.727196] nand_read_bbt: Bad block at 0x000001540000
[   12.727211] nand_read_bbt: Bad block at 0x000001560000
[   12.727227] nand_read_bbt: Bad block at 0x000001580000
[   12.727243] nand_read_bbt: Bad block at 0x0000015a0000
[   12.727258] nand_read_bbt: Bad block at 0x0000015c0000
[   12.727274] nand_read_bbt: Bad block at 0x0000015e0000
[   12.727289] nand_read_bbt: Bad block at 0x000001600000
[   12.727305] nand_read_bbt: Bad block at 0x000001620000
[   12.727320] nand_read_bbt: Bad block at 0x000001640000
[   12.727336] nand_read_bbt: Bad block at 0x000001660000
[   12.727472] nand_read_bbt: Bad block at 0x00001e720000
[   12.727617] Creating 6 MTD partitions on "NAND 512MiB 3,3V 8-bit":
[   12.733793] 0x000000000000-0x000000100000 : "bootloader (read-only)"
[   12.744713] 0x000000100000-0x000001100000 : "kernel (read-only)"
[   12.755315] 0x000001100000-0x000002100000 : "kernel"
[   12.764900] 0x000002100000-0x000010700000 : "rootfs"
[   12.774960] 0x000010700000-0x00001ed00000 : "spare"
[   12.784986] 0x00001ed00000-0x000020000000 : "Bad Block Table"
[   12.798200] ax88796 ax88796.0: 16bit, irq 122, c887c000, MAC: 00:11:22:33:44:24
[   12.807141] ax88796 ax88796.1: 16bit, irq 210, c88b6000, MAC: 00:00:00:00:00:24
[   12.819055] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[   12.825221] ohci_hcd: block sizes: ed 64 td 64
[   12.825381] In ohci_hcd_pxa27x_drv_probe
[   12.825581] pxa27x-ohci pxa27x-ohci: PXA27x OHCI
[   12.830620] drivers/usb/core/inode.c: creating file 'devices'
[   12.830669] drivers/usb/core/inode.c: creating file '001'
[   12.831981] pxa27x-ohci pxa27x-ohci: new USB bus registered, assigned bus number 1
[   12.839865] pxa27x-ohci pxa27x-ohci: irq 3, io mem 0x4c000000
[   12.845590] pxa27x-ohci pxa27x-ohci: ohci_pxa27x_start, ohci:c7a054dc
[   12.845720] pxa27x-ohci pxa27x-ohci: created debug files
[   12.899228] pxa27x-ohci pxa27x-ohci: OHCI controller state
[   12.899264] pxa27x-ohci pxa27x-ohci: OHCI 1.0, NO legacy support registers
[   12.899294] pxa27x-ohci pxa27x-ohci: control 0x083 HCFS=operational CBSR=3
[   12.899319] pxa27x-ohci pxa27x-ohci: cmdstatus 0x00000 SOC=0
[   12.899345] pxa27x-ohci pxa27x-ohci: intrstatus 0x00000004 SF
[   12.899370] pxa27x-ohci pxa27x-ohci: intrenable 0x8000005a MIE RHSC UE RD WDH
[   12.899393] pxa27x-ohci pxa27x-ohci: hcca frame #0003
[   12.899420] pxa27x-ohci pxa27x-ohci: roothub.a 04000202 POTPGT=4 NPS NDP=2(3)
[   12.899444] pxa27x-ohci pxa27x-ohci: roothub.b 00000000 PPCM=0000 DR=0000
[   12.899469] pxa27x-ohci pxa27x-ohci: roothub.status 00008000 DRWE
[   12.899500] pxa27x-ohci pxa27x-ohci: roothub.portstatus [0] 0x00000100 PPS
[   12.899527] pxa27x-ohci pxa27x-ohci: roothub.portstatus [1] 0x00000100 PPS
[   12.899555] pxa27x-ohci pxa27x-ohci: roothub.portstatus [2] 0x00000100 PPS
[   12.899686] usb usb1: default language 0x0409
[   12.899740] usb usb1: udev 1, busnum 1, minor = 0
[   12.899762] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[   12.906576] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   12.913749] usb usb1: Product: PXA27x OHCI
[   12.917853] usb usb1: Manufacturer: Linux 2.6.36-00038-g92080b9 ohci_hcd
[   12.924509] usb usb1: SerialNumber: pxa27x
[   12.930219] usb usb1: usb_probe_device
[   12.930262] usb usb1: configuration #1 chosen from 1 choice
[   12.930355] usb usb1: adding 1-0:1.0 (config #1, interface 0)
[   12.931071] hub 1-0:1.0: usb_probe_interface
[   12.931109] hub 1-0:1.0: usb_probe_interface - got id
[   12.931130] hub 1-0:1.0: USB hub found
[   12.934910] hub 1-0:1.0: 3 ports detected
[   12.939107] hub 1-0:1.0: standalone hub
[   12.939130] hub 1-0:1.0: no power switching (usb 1.0)
[   12.939148] hub 1-0:1.0: global over-current protection
[   12.939168] hub 1-0:1.0: power on to power good time: 8ms
[   12.939225] hub 1-0:1.0: local power source is good
[   12.939245] hub 1-0:1.0: no over-current condition exists
[   12.939268] hub 1-0:1.0: trying to enable port power on non-switchable hub
[   12.940082] drivers/usb/core/inode.c: creating file '001'
[   12.941378] usbcore: registered new interface driver usblp
[   12.947093] Initializing USB Mass Storage driver...
[   12.952559] usbcore: registered new interface driver usb-storage
[   12.958787] USB Mass Storage support registered.
[   12.963387] pxa27x_udc: version 2008-04-18
[   12.968624] g_ether gadget: using random self ethernet address
[   12.974462] g_ether gadget: using random host ethernet address
[   12.981582] usb0: MAC 0e:86:76:80:dd:3e
[   12.985414] usb0: HOST MAC a2:8d:9a:ce:d5:15
[   12.989942] g_ether gadget: Ethernet Gadget, version: Memorial Day 2008
[   12.996648] g_ether gadget: g_ether ready
[   13.036694] hub 1-0:1.0: state 7 ports 3 chg 0000 evt 0000
[   13.109010] mice: PS/2 mouse device common for all mice
[   13.115691] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[   13.126971] pxa-rtc pxa-rtc: rtc core: registered pxa-rtc as rtc0
[   13.133585] i2c /dev entries driver
[   13.139495] Driver for 1-wire Dallas network protocol.
[   13.177169] cpufreq-core: updating policy for CPU 0
[   13.177214] cpufreq-core: setting new policy for CPU 0: 104000 - 624000 kHz
[   13.177242] freq-table: request for verification of policy (104000 - 624000 kHz) for cpu 0
[   13.177271] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   13.177302] freq-table: request for verification of policy (104000 - 624000 kHz) for cpu 0
[   13.177328] freq-table: verification lead to (104000 - 624000 kHz) for cpu 0
[   13.177353] cpufreq-core: new min and max freqs are 104000 - 624000 kHz
[   13.177373] cpufreq-core: governor: change or update limits
[   13.177395] cpufreq-core: __cpufreq_governor for CPU 0, event 3
[   13.177417] performance: setting to 624000 kHz because of event 3
[   13.177440] cpufreq-core: target for CPU 0: 624000 kHz, relation 1
[   13.177465] freq-table: request for target 624000 kHz (relation: 1) for cpu 0
[   13.177491] freq-table: target is 3 (624000 kHz, 3)
[   13.181540] Registered led device: a
[   13.184429] usbcore: registered new interface driver usbhid
[   13.190197] usbhid: USB HID core driver
[   13.194452] TCP cubic registered
[   13.197939] XScale iWMMXt coprocessor detected.
[   13.208609] pxa-rtc pxa-rtc: setting system clock to 2000-01-01 00:00:14 UTC (946684814)
[   13.344919] mmc0: host does not support reading read-only switch. assuming write-enable.
[   13.353163] mmc0: new SD card at address 8c4f
[   13.358624] mmcblk0: mmc0:8c4f S016B 14.2 MiB 
[   13.365410]  mmcblk0: p1
[   14.736538] Sending DHCP requests .., OK
[   18.676544] IP-Config: Got DHCP answer from 0.0.0.0, my address is 10.1.11.70
[   18.717261] IP-Config: Complete:
[   18.720322]      device=eth0, addr=10.1.11.70, mask=255.255.128.0, gw=10.1.10.20,
[   18.727786]      host=10.1.11.70, domain=creo.dev, nis-domain=(none),
[   18.734182]      bootserver=0.0.0.0, rootserver=10.1.11.41, rootpath=
[   18.741328] Looking up port of RPC 100003/2 on 10.1.11.41
[   18.757623] Looking up port of RPC 100005/1 on 10.1.11.41
[   18.779602] VFS: Mounted root (nfs filesystem) on device 0:15.
[   18.786304] devtmpfs: mounted
[   18.789527] Freeing init memory: 132K

[Openpxa-users] Linux udelay() is way off

[Russell King - ARM Linux]

On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
> [   11.425363] cpufreq-core: saving 518144 as reference value for
> loops_per_jiffy; freq is 312000 kHz
> [   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
> frequency 624000 kHz

So despite scaling lpj by a factor of two for the doubling in clock
frequency, we see a 30% error in it?

Is it possible to boot at 624MHz and report the resulting lpj?
Alternatively, call calibrate_delay() after the cpufreq switch to
624MHz, disabling the 'printed' stuff and see what it reports.

I wonder if this is a case where it scales according to

	new_lpj = ref_lpj * (new_freq / ref_freq) + some_offset

rather than just

	new_lpj = ref_lpj * (new_freq / ref_freq)

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
>> [ ? 11.425363] cpufreq-core: saving 518144 as reference value for
>> loops_per_jiffy; freq is 312000 kHz
>> [ ? 11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
>> frequency 624000 kHz
>
> So despite scaling lpj by a factor of two for the doubling in clock
> frequency, we see a 30% error in it?

No. udelay() is ~30 % of what it should be. My gpio + oscilloscope
test showed that udelay(50) => 16 us in real time with cpufreq
enabled. This gives 16/50 = 0.32.

> Is it possible to boot at 624MHz and report the resulting lpj?

I think I need some help doing that. I found some clock setup in
<u-boot-pxa>/arch/arm/cpu/pxa/start.S (OpenPXA tree) but I'm not
familiar with it.

> Alternatively, call calibrate_delay() after the cpufreq switch to
> 624MHz, disabling the 'printed' stuff and see what it reports.

First attempts at moving calibrate_delay() after freq switch failed. I
will try more. Just had to send this so stop the misunderstanding
about how much udelay() is off...

What do you mean by disabling the 'printed' stuff? The cpufreq debug stuff?

Best regards,
Bj?rn Forsman

> I wonder if this is a case where it scales according to
>
> ? ? ? ?new_lpj = ref_lpj * (new_freq / ref_freq) + some_offset
>
> rather than just
>
> ? ? ? ?new_lpj = ref_lpj * (new_freq / ref_freq)

[Openpxa-users] Linux udelay() is way off

[Russell King - ARM Linux]

On Thu, Jan 20, 2011 at 09:25:36PM +0100, Bj?rn Forsman wrote:
> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
> >> [ ? 11.425363] cpufreq-core: saving 518144 as reference value for
> >> loops_per_jiffy; freq is 312000 kHz
> >> [ ? 11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
> >> frequency 624000 kHz
> >
> > So despite scaling lpj by a factor of two for the doubling in clock
> > frequency, we see a 30% error in it?
> 
> No. udelay() is ~30 % of what it should be. My gpio + oscilloscope
> test showed that udelay(50) => 16 us in real time with cpufreq
> enabled. This gives 16/50 = 0.32.
> 
> > Is it possible to boot at 624MHz and report the resulting lpj?
> 
> I think I need some help doing that. I found some clock setup in
> <u-boot-pxa>/arch/arm/cpu/pxa/start.S (OpenPXA tree) but I'm not
> familiar with it.
> 
> > Alternatively, call calibrate_delay() after the cpufreq switch to
> > 624MHz, disabling the 'printed' stuff and see what it reports.
> 
> First attempts at moving calibrate_delay() after freq switch failed. I
> will try more. Just had to send this so stop the misunderstanding
> about how much udelay() is off...

Not a good idea to remove it from its current location.  I was suggesting
adding another call to calibrate_delay() after the cpufreq stuff has
initialized.

> What do you mean by disabling the 'printed' stuff? The cpufreq debug stuff?

See calibrate_delay() in init/calibrate.c.  'static bool printed;'  It's
set true after the first run, and there after it won't print the
information again.  So if you want to see it from subsequent runs, you
need to defeat it.

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> On Thu, Jan 20, 2011 at 09:25:36PM +0100, Bj?rn Forsman wrote:
>> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
>> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
>> >> [ ? 11.425363] cpufreq-core: saving 518144 as reference value for
>> >> loops_per_jiffy; freq is 312000 kHz
>> >> [ ? 11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
>> >> frequency 624000 kHz
>> >
>> > So despite scaling lpj by a factor of two for the doubling in clock
>> > frequency, we see a 30% error in it?
>>
>> No. udelay() is ~30 % of what it should be. My gpio + oscilloscope
>> test showed that udelay(50) => 16 us in real time with cpufreq
>> enabled. This gives 16/50 = 0.32.
>>
>> > Is it possible to boot at 624MHz and report the resulting lpj?
>>
>> I think I need some help doing that. I found some clock setup in
>> <u-boot-pxa>/arch/arm/cpu/pxa/start.S (OpenPXA tree) but I'm not
>> familiar with it.
>>
>> > Alternatively, call calibrate_delay() after the cpufreq switch to
>> > 624MHz, disabling the 'printed' stuff and see what it reports.
>>
>> First attempts at moving calibrate_delay() after freq switch failed. I
>> will try more. Just had to send this so stop the misunderstanding
>> about how much udelay() is off...
>
> Not a good idea to remove it from its current location. ?I was suggesting
> adding another call to calibrate_delay() after the cpufreq stuff has
> initialized.

Ok, thanks!

>> What do you mean by disabling the 'printed' stuff? The cpufreq debug stuff?
>
> See calibrate_delay() in init/calibrate.c. ?'static bool printed;' ?It's
> set true after the first run, and there after it won't print the
> information again. ?So if you want to see it from subsequent runs, you
> need to defeat it.

Thanks for the pointers!

Best regards,
Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
>> [ ? 11.425363] cpufreq-core: saving 518144 as reference value for
>> loops_per_jiffy; freq is 312000 kHz
>> [ ? 11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
>> frequency 624000 kHz

[snip]

> Is it possible to boot at 624MHz and report the resulting lpj?
> Alternatively, call calibrate_delay() after the cpufreq switch to
> 624MHz, disabling the 'printed' stuff and see what it reports.

Now I have an extra calibrate_delay() after cpufreq changes the frequency.

First call:
Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)

Second call:
Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)

(udelay() is correct when having that second call.)

It seems cpufreq thinks it transitions from 312 to 624 MHz, but in
reality it may be transitioning from 104 to 624 MHz (because it now
runs 6 times as fast according to lpj). This may explain the udelay()
error ratio (~0.32):

  104 MHz / 312 MHz = 0.3333..

I think this means either the clock speed or the jiffies interval do
not match what the kernel thinks.

I also did some tests changing the clock speed in the bootloader. It
seems like the only thing that works for the kernel is booting with a
104 MHz clock. Any other frequency and cpufreq will do bad things to
udelay().

Any thoughts?

BTW, I failed at locating the jiffies implementation for PXA310. Any pointers?

Best regards,
Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Marek Vasut]

On Friday 21 January 2011 18:46:48 Bj?rn Forsman wrote:
> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
> >> [   11.425363] cpufreq-core: saving 518144 as reference value for
> >> loops_per_jiffy; freq is 312000 kHz
> >> [   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
> >> frequency 624000 kHz
> 
> [snip]
> 
> > Is it possible to boot at 624MHz and report the resulting lpj?
> > Alternatively, call calibrate_delay() after the cpufreq switch to
> > 624MHz, disabling the 'printed' stuff and see what it reports.
> 
> Now I have an extra calibrate_delay() after cpufreq changes the frequency.
> 
> First call:
> Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)
> 
> Second call:
> Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
> 
> (udelay() is correct when having that second call.)
> 
> It seems cpufreq thinks it transitions from 312 to 624 MHz, but in
> reality it may be transitioning from 104 to 624 MHz (because it now
> runs 6 times as fast according to lpj). This may explain the udelay()
> error ratio (~0.32):
> 
>   104 MHz / 312 MHz = 0.3333..
> 
> I think this means either the clock speed or the jiffies interval do
> not match what the kernel thinks.
> 
> I also did some tests changing the clock speed in the bootloader.

Hi,
how did you change the speed in the bootloader? Didn't you just adjust the 
apropriate registers? Don't forget, you need to issue CP15 (maybe CP14) 
coprocessor call.

Well, just my quick thought.

btw. Bjorn, I just dug out the pxa320 board, maybe I can also find the pxa310/300 
cards, mind IRC-ing ? ;-)
> It
> seems like the only thing that works for the kernel is booting with a
> 104 MHz clock. Any other frequency and cpufreq will do bad things to
> udelay().
> 
> Any thoughts?
> 
> BTW, I failed at locating the jiffies implementation for PXA310. Any
> pointers?
> 
> Best regards,
> Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/21 Marek Vasut <marek.vasut@gmail.com>:

[snip]

> Hi,
> how did you change the speed in the bootloader? Didn't you just adjust the
> apropriate registers? Don't forget, you need to issue CP15 (maybe CP14)
> coprocessor call.

Here's my quick & dirty OBM2 work-in-progress patch:

diff --git a/OBM2/plat/colibri_pxa310.c b/OBM2/plat/colibri_pxa310.c
index 9c7ccfc..557aca7 100644
--- a/OBM2/plat/colibri_pxa310.c
+++ b/OBM2/plat/colibri_pxa310.c
@@ -87,13 +87,26 @@ inline void plat_init(void)
        writel(GPIO_BASE, 0x274, 0xb881);       /* IO15 */

        /* CPU speed settings */
-       accr = 0x028fd200;
+       /* SMC_S: 208 MHz
+        * VAUF_S: 104 MHz
+        * SFL_S: 312 MHz
+        * XSPCLK_S: no clocks being used during frequency changes
+        * 0xd/orig: HSS_S: 312 MHz system bus freq
+        * 0xb/new: HSS_S: 208 MHz system bus freq
+        * 0xd/orig: DMC_S: 0x01 (reserved)
+        * 0xb/new: DMC_S: 0x11 (130 MHz SDRAM clock)
+        * XN_S: 0x2 (turbo-mode-to-run-mode ratio status)
+        * XL_S: 0x18 (run-mode-to-processor (13 MHz) oscillator ratio status)
+        */
+       //accr = 0x028fb300;
        if (cpu_type(PXA300))
                accr |= 0x08;
        else
                accr |= 0x18;
+       //accr = 0x30033108; // this works!!! 104 MHz Linux
+       accr = 0x32EFB218; // 624 MHz in Linux
        writel(0x41340000, 0x00, accr);
-       asm volatile("mcr p14, 0, %0, c6, c0, 0"::"r"(2));
+       asm volatile("mcr p14, 0, %0, c6, c0, 0"::"r"(3));
        while (((readl(0x41340000, 0x04) >> 28) & 0x3) != 0x3);
 }


The comments in the patch may be wrong, I may have mixed up ACCR and
ACSR registers when decoding them :-)

> Well, just my quick thought.
>
> btw. Bjorn, I just dug out the pxa320 board, maybe I can also find the pxa310/300
> cards, mind IRC-ing ? ;-)

Maybe pxa320 behaves like pxa310? Try changing core clock in OBM2 and
see if it changes Linux jpj/BogoMIPS. It seems to me that lpj is the
same no matter what the bootloader sets the core clock to. Weird.

IRC? Yes, #openpxa here I come. But I'm about to go home for the
weekend now and won't have access to the target board until monday.

Best regards,
Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Marek Vasut]

On Friday 21 January 2011 18:46:48 Bj?rn Forsman wrote:
> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
> >> [   11.425363] cpufreq-core: saving 518144 as reference value for
> >> loops_per_jiffy; freq is 312000 kHz
> >> [   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
> >> frequency 624000 kHz
> 
> [snip]
> 
> > Is it possible to boot at 624MHz and report the resulting lpj?
> > Alternatively, call calibrate_delay() after the cpufreq switch to
> > 624MHz, disabling the 'printed' stuff and see what it reports.
> 
> Now I have an extra calibrate_delay() after cpufreq changes the frequency.
> 
> First call:
> Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)
> 
> Second call:
> Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
> 
> (udelay() is correct when having that second call.)
> 
> It seems cpufreq thinks it transitions from 312 to 624 MHz, but in
> reality it may be transitioning from 104 to 624 MHz (because it now
> runs 6 times as fast according to lpj). This may explain the udelay()
> error ratio (~0.32):
> 
>   104 MHz / 312 MHz = 0.3333..
> 
> I think this means either the clock speed or the jiffies interval do
> not match what the kernel thinks.
> 
> I also did some tests changing the clock speed in the bootloader. It
> seems like the only thing that works for the kernel is booting with a
> 104 MHz clock. Any other frequency and cpufreq will do bad things to
> udelay().
> 
> Any thoughts?
> 
> BTW, I failed at locating the jiffies implementation for PXA310. Any
> pointers?

DAMN.

I cannot replicate this. Bjorn, can you please write me a step-by-step howto for 
morons?

Ah, also, please update your OBM2 and u-boot from openpxa_new branch ;-)

Cheers, thanks
> 
> Best regards,
> Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/23 Marek Vasut <marek.vasut@gmail.com>:
> On Friday 21 January 2011 18:46:48 Bj?rn Forsman wrote:
>> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
>> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
>> >> [ ? 11.425363] cpufreq-core: saving 518144 as reference value for
>> >> loops_per_jiffy; freq is 312000 kHz
>> >> [ ? 11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
>> >> frequency 624000 kHz
>>
>> [snip]
>>
>> > Is it possible to boot at 624MHz and report the resulting lpj?
>> > Alternatively, call calibrate_delay() after the cpufreq switch to
>> > 624MHz, disabling the 'printed' stuff and see what it reports.
>>
>> Now I have an extra calibrate_delay() after cpufreq changes the frequency.
>>
>> First call:
>> Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)
>>
>> Second call:
>> Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
>>
>> (udelay() is correct when having that second call.)
>>
>> It seems cpufreq thinks it transitions from 312 to 624 MHz, but in
>> reality it may be transitioning from 104 to 624 MHz (because it now
>> runs 6 times as fast according to lpj). This may explain the udelay()
>> error ratio (~0.32):
>>
>> ? 104 MHz / 312 MHz = 0.3333..
>>
>> I think this means either the clock speed or the jiffies interval do
>> not match what the kernel thinks.
>>
>> I also did some tests changing the clock speed in the bootloader. It
>> seems like the only thing that works for the kernel is booting with a
>> 104 MHz clock. Any other frequency and cpufreq will do bad things to
>> udelay().
>>
>> Any thoughts?
>>
>> BTW, I failed at locating the jiffies implementation for PXA310. Any
>> pointers?
>
> DAMN.
>
> I cannot replicate this. Bjorn, can you please write me a step-by-step howto for
> morons?
>
> Ah, also, please update your OBM2 and u-boot from openpxa_new branch ;-)

I updated OBM2, U-Boot and the kernel. The issue is now gone and
udelay is correct. Yay!

Below is a diff of two boot logs, one with old bootloaders and one
with new. Notice the difference in kernel lpj and whether it thinks turbo
mode is enabled or not. Both boots are with the same kernel (2.6.38-rc2).

Any idea why new bootloaders cause "write buffer coherency" failure
(see below)? Do we need to worry?

--- boot.log	2011-01-25 17:24:37.000000000 +0100
+++ boot2_openpxa_new.log	2011-01-25 17:24:39.000000000 +0100
@@ -1,8 +1,10 @@
-U-Boot 2010.06-00741-g48e5192-dirty (Dec 09 2010 - 10:13:49)
+OpenPXA OBM 2, booting ... OK
+
+U-Boot 2010.12-02373-ga7a4c08 (Jan 24 2011 - 14:42:56)

 CPU: Marvell PXA31x A2
 Clock: Core: 312MHz ; Turbo: x2
-       [ SMC: 208MHz ; SRAM: 312MHz ; BUS: 312MHz ; DMC: 312MHz ]
+       [ SMC: 208MHz ; SRAM: 312MHz ; BUS: 208MHz ; DMC: 260MHz ]
 DRAM:  128 MiB
 NAND:  512 MiB
 In:    serial
@@ -36,8 +38,8 @@
 Memory policy: ECC disabled, Data cache writeback
 RO Mode clock: 60.00MHz (inactive)
 Run Mode clock: 312.00MHz (*24)
-Turbo Mode clock: 624.00MHz (*2, inactive)
-HSIO bus clock: 312.00MHz
+Turbo Mode clock: 624.00MHz (*2, active)
+HSIO bus clock: 208.00MHz
 Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
 Kernel command line: console=ttyS0,115200 root=/dev/nfs
nfsroot=10.1.11.41:/srv/nfs ip=0
 PID hash table entries: 512 (order: -1, 2048 bytes)
@@ -59,10 +61,10 @@
 NR_IRQS:288 nr_irqs:288 288
 sched_clock: 32 bits at 3250kHz, resolution 307ns, wraps every 1321528ms
 Console: colour dummy device 80x30
-Calibrating delay loop... 103.83 BogoMIPS (lpj=519168)
+Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
 pid_max: default: 32768 minimum: 301
 Mount-cache hash table entries: 512
-CPU: Testing write buffer coherency: ok
+CPU: Testing write buffer coherency: failed, enabling work-around
 NET: Registered protocol family 16
 colibri_pxa3xx_init_eth(): no valid serial boot tag found, taking MAC
from device
 bio: create slab <bio-0> at 0

Best regards,
Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Marek Vasut]

On Tuesday 25 January 2011 18:45:54 Bj?rn Forsman wrote:
> 2011/1/23 Marek Vasut <marek.vasut@gmail.com>:
> > On Friday 21 January 2011 18:46:48 Bj?rn Forsman wrote:
> >> 2011/1/20 Russell King - ARM Linux <linux@arm.linux.org.uk>:
> >> > On Thu, Jan 20, 2011 at 08:18:10PM +0100, Bj?rn Forsman wrote:
> >> >> [   11.425363] cpufreq-core: saving 518144 as reference value for
> >> >> loops_per_jiffy; freq is 312000 kHz
> >> >> [   11.425523] cpufreq-core: scaling loops_per_jiffy to 1036288 for
> >> >> frequency 624000 kHz
> >> 
> >> [snip]
> >> 
> >> > Is it possible to boot at 624MHz and report the resulting lpj?
> >> > Alternatively, call calibrate_delay() after the cpufreq switch to
> >> > 624MHz, disabling the 'printed' stuff and see what it reports.
> >> 
> >> Now I have an extra calibrate_delay() after cpufreq changes the
> >> frequency.
> >> 
> >> First call:
> >> Calibrating delay loop... 103.62 BogoMIPS (lpj=518144)
> >> 
> >> Second call:
> >> Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
> >> 
> >> (udelay() is correct when having that second call.)
> >> 
> >> It seems cpufreq thinks it transitions from 312 to 624 MHz, but in
> >> reality it may be transitioning from 104 to 624 MHz (because it now
> >> runs 6 times as fast according to lpj). This may explain the udelay()
> >> error ratio (~0.32):
> >> 
> >>   104 MHz / 312 MHz = 0.3333..
> >> 
> >> I think this means either the clock speed or the jiffies interval do
> >> not match what the kernel thinks.
> >> 
> >> I also did some tests changing the clock speed in the bootloader. It
> >> seems like the only thing that works for the kernel is booting with a
> >> 104 MHz clock. Any other frequency and cpufreq will do bad things to
> >> udelay().
> >> 
> >> Any thoughts?
> >> 
> >> BTW, I failed at locating the jiffies implementation for PXA310. Any
> >> pointers?
> > 
> > DAMN.
> > 
> > I cannot replicate this. Bjorn, can you please write me a step-by-step
> > howto for morons?
> > 
> > Ah, also, please update your OBM2 and u-boot from openpxa_new branch ;-)
> 
> I updated OBM2, U-Boot and the kernel. The issue is now gone and
> udelay is correct. Yay!

Yay!
> 
> Below is a diff of two boot logs, one with old bootloaders and one
> with new. Notice the difference in kernel lpj and whether it thinks turbo
> mode is enabled or not. Both boots are with the same kernel (2.6.38-rc2).

Which means linux kernel probably blindly believes in what's in ACCR or whatever 
... which obviously isn't correct ? I smell a bug still.

> 
> Any idea why new bootloaders cause "write buffer coherency" failure
> (see below)? Do we need to worry?

We do, uboot left icache or dcache enabled, I'm not sure if it's disabled now 
before boot. But that shouldn't cause this, right ?

Cheers
> 
> --- boot.log	2011-01-25 17:24:37.000000000 +0100
> +++ boot2_openpxa_new.log	2011-01-25 17:24:39.000000000 +0100
> @@ -1,8 +1,10 @@
> -U-Boot 2010.06-00741-g48e5192-dirty (Dec 09 2010 - 10:13:49)
> +OpenPXA OBM 2, booting ... OK
> +
> +U-Boot 2010.12-02373-ga7a4c08 (Jan 24 2011 - 14:42:56)
> 
>  CPU: Marvell PXA31x A2
>  Clock: Core: 312MHz ; Turbo: x2
> -       [ SMC: 208MHz ; SRAM: 312MHz ; BUS: 312MHz ; DMC: 312MHz ]
> +       [ SMC: 208MHz ; SRAM: 312MHz ; BUS: 208MHz ; DMC: 260MHz ]
>  DRAM:  128 MiB
>  NAND:  512 MiB
>  In:    serial
> @@ -36,8 +38,8 @@
>  Memory policy: ECC disabled, Data cache writeback
>  RO Mode clock: 60.00MHz (inactive)
>  Run Mode clock: 312.00MHz (*24)
> -Turbo Mode clock: 624.00MHz (*2, inactive)
> -HSIO bus clock: 312.00MHz
> +Turbo Mode clock: 624.00MHz (*2, active)
> +HSIO bus clock: 208.00MHz
>  Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
>  Kernel command line: console=ttyS0,115200 root=/dev/nfs
> nfsroot=10.1.11.41:/srv/nfs ip=0
>  PID hash table entries: 512 (order: -1, 2048 bytes)
> @@ -59,10 +61,10 @@
>  NR_IRQS:288 nr_irqs:288 288
>  sched_clock: 32 bits at 3250kHz, resolution 307ns, wraps every 1321528ms
>  Console: colour dummy device 80x30
> -Calibrating delay loop... 103.83 BogoMIPS (lpj=519168)
> +Calibrating delay loop... 622.59 BogoMIPS (lpj=3112960)
>  pid_max: default: 32768 minimum: 301
>  Mount-cache hash table entries: 512
> -CPU: Testing write buffer coherency: ok
> +CPU: Testing write buffer coherency: failed, enabling work-around
>  NET: Registered protocol family 16
>  colibri_pxa3xx_init_eth(): no valid serial boot tag found, taking MAC
> from device
>  bio: create slab <bio-0> at 0
> 
> Best regards,
> Bj?rn Forsman

[Openpxa-users] Linux udelay() is way off

[Saravana Kannan]

On 01/20/2011 11:18 AM, Bj?rn Forsman wrote:
> On 20 January 2011 18:55, Russell King - ARM Linux
> <linux@arm.linux.org.uk>  wrote:
>> On Thu, Jan 20, 2011 at 06:00:04PM +0100, Marek Vasut wrote:
>>> On Thursday 20 January 2011 17:09:00 Bj?rn Forsman wrote:
>>>> Hi,
>>>>
>>>> On my Colibri PXA310, I see that Linux udelay() is only 30 % of the
>>>> length it's supposed to. This is way off and cause problems (e.g.
>>>> 1-Wire device driver breaks). I'm running OpenPXA bootloaders (OBM2 +
>>>> U-Boot) and mainline Linux 2.6.36.
>>>>
>>>> Any ideas how to fix this?
>>>>
>>>> Could it be that U-Boot sets up the system clock to something
>>>> different than what Linux "expects" so that loops_per_jiffy becomes
>>>> wrong? I see some clock setup in<u-boot-pxa>/arch/arm/cpu/pxa/start.S
>>>> but I'm not sure what to do with it (yet). I'd like to try out
>>>> different clock speeds to see if it helps. Any pointers?
>>>>
>>>> I also have a workaround in mind: Try out different lpj= settings on
>>>> the kernel command line until a udelay(1000) actually is 1000 us. Is
>>>> this a sane thing to do?
>>>
>>> CCing relevant people.
>>>
>>> And no, linux kernel should derive it's timing properly so it's a kernel bug.
>>
>> I recently looked into the udelay() timing accuracy, and I saw it only
>> being reduced by .7% at boot time - due to the cycles stolen by the timer
>> IRQ handler.
>>
>> The delay calibration algorithm shouldn't produce big errors due to the
>> way it works.  It first tries to find a delay longer than the timer tick.
>> It then uses a successive approximation technique over about 9 bits of
>> loops_per_jiffy value.
>>
>> So, I wouldn't expect the boot time lpj value to be significantly out.
>>
>> However, what might be happening is you boot at X MHz.  You then use cpufreq
>> and drop the frequency to Y MHz.  You then suspend and resume.  On resume,
>> the boot loader starts the processor again at X MHz, but the kernel still
>> assumes that you're running at Y MHz and has not adjusted the delay loop
>> accordingly.
>>
>> This will result in a much shorter than expected delay.
>>
>> So, the first thing that needs doing is to ascertain when the delay
>> becomes wrong.
>
> I'm not doing any suspend/resume stuff.
>
> But I did have cpufreq enabled (using default 'performance' governor).
> Disabling cpufreq makes udelay() correct. Yay!
>
> In order to try diagnosing the problem I re-enabled cpufreq and booted
> with cpufreq.debug=7.
>

Bjorn,

Assuming your hardware is not weird at scaling and needs something like 
Russell said:
	new_lpj = ref_lpj * (new_freq / ref_freq) + some_offset

The most likely scenario seems to be that the CPU freq driver that's 
specific to your CPU is not setting the CPU to the frequency it thinks 
it's setting it to. It might THINK it's running at 624 MHz, but it might 
really be at 310 MHz or 100 MHz or something. Since, if the frequency at 
which the calibration was done or if the new frequencies are not what 
really what they are reported to be, then the math will go wrong and you 
would see these kind of issues.

If you can somehow measure your CPU freq with an oscilloscope, measure 
these two:
- Just before calibrate_delay is run for the first time.
- When you are seeing the udelay to be wrong.

One of these two won't match what you think the CPU is running at.

-Saravana
-- 
Sent by an employee of the Qualcomm Innovation Center, Inc.
The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum.

[Openpxa-users] Linux udelay() is way off

[Bjørn Forsman]

2011/1/21 Saravana Kannan <skannan@codeaurora.org>:

[snip]

> The most likely scenario seems to be that the CPU freq driver that's
> specific to your CPU is not setting the CPU to the frequency it thinks it's
> setting it to. It might THINK it's running at 624 MHz, but it might really
> be at 310 MHz or 100 MHz or something. Since, if the frequency at which the
> calibration was done or if the new frequencies are not what really what they
> are reported to be, then the math will go wrong and you would see these kind
> of issues.

Yes, I'm thinking the same.

> If you can somehow measure your CPU freq with an oscilloscope, measure these
> two:
> - Just before calibrate_delay is run for the first time.
> - When you are seeing the udelay to be wrong.
>
> One of these two won't match what you think the CPU is running at.

The processor has an external 13 MHz crystal and the CPU frequency is
set by internal multipliers. I don't think the actual CPU clock (after
multipliers) is available on any of the chip pins. But thanks for the
tip.

Best regards,
Bj?rn Forsman