[Letux-kernel] jz4730-i2c - clocksource

[H. Nikolaus Schaller]

Hi Paul,

> But it gave me another idea: I can try to log the relationship between
> 
> ingenic_tcu_cevt_set_next() and ingenic_tcu_cevt_cb()
> 
> and the OST0/1 values.

I have added another piece of trace code.

There was another bug that ingenic_tcu_clocksource_init()
did disable the timer underrun interrupt. And it was nowhere
enabled in the driver.

See

	https://git.goldelico.com/?p=letux-kernel.git;a=blob;f=drivers/clocksource/ingenic-timer.c;h=c6c17c856a15078f9da8e10fe57ca6a5adc0c68a;hb=refs/heads/letux/jz4730-v5#l263

The mask also resets TCU_JZ4730_TCSR_EN to 0 disabling underflow interrupts.

Now with my logging code I can see that the timer is decrementing
and when underrunning, OST0 is flagged in ICSR and IPSR.

But this does not trigger any interrupt handler, the bit remains set
and nothing happens.

At least nothing happens within ca. 4m as I can read from the counter
values. This would be a quite long interrupt latency...

Could it be that interrupts are disabled when my logging within
ingenic_tcu_init() is happening?

Or do I try to trace a boot dependency that interrupt scheduling
can not work until timers have been properly initialized?

Any ideas?


Next, here is an excerpt of the L400 boot log

[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000]  Trampoline variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 256
[    0.000000] random: get_random_bytes called from start_kernel+0x720/0x960 with crng_init=0
[    0.000000] clocksource: ingenic-timer: mask: 0xffff max_cycles: 0xffff, max_idle_ns: 7910990 ns
[    0.000013] sched_clock: 16 bits at 3686kHz, resolution 271ns, wraps every 8888753ns
[    0.012394] random: fast init done
[    0.010387] random: crng init done

and one from the RasPi:

[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] 	Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] random: get_random_bytes called from start_kernel+0x2c4/0x4cc with crng_init=0
[    0.000010] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000037] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000094] bcm2835: system timer (irq = 27)
[    0.001165] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.001184] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.001203] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.001218] Switching to timer-based delay loop, resolution 52ns
[    0.001866] Console: colour dummy device 80x30
[    0.001916] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
...
[    1.580219] random: fast init done
[    5.147641] random: crng init done

and here from AM335x:

[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=1.
[    0.000000] 	Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 5.0) with 128 interrupts
[    0.000000] random: get_random_bytes called from start_kernel+0x2c4/0x4cc with crng_init=0
[    0.000000] OMAP clockevent source: timer2 at 24000000 Hz
[    0.000016] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns
[    0.000038] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns
[    0.000051] OMAP clocksource: timer1 at 24000000 Hz
[    0.002592] timer_probe: no matching timers found
[    0.003047] Console: colour dummy device 80x30
[    0.003103] Calibrating delay loop... 996.14 BogoMIPS (lpj=4980736)
...
[    1.296961] random: fast init done
[    1.300695] random: crng init done

Except that we only use 16 bits it looks quite similar. But both ARM systems never
have a backwards running sched_clock for printk...


I now tried again with clocksource=jiffies. In that case the logs are the same,
except that the kernel boots to login:

root at letux:~# cat /proc/interrupts 
           CPU0       
  2:      68254      MIPS   2  SoC intc cascade interrupt
  9:       2791      INTC   9  ttyS0
 14:       8058      INTC  14  10021000.mmc
 15:          0     GPIOA   0  matrix-keypad
 16:          0     GPIOA   1  matrix-keypad
 17:          0     GPIOA   2  matrix-keypad
 18:          0     GPIOA   3  matrix-keypad
 19:          0     GPIOA   4  matrix-keypad
 21:          0      INTC  21  13020000.dma
 24:      57124      INTC  24  TCU0
 29:          0     GPIOA   5  matrix-keypad
 30:        300      INTC  30  ingenic-drm
 31:          0     GPIOA   6  matrix-keypad
 32:          0     GPIOA   7  matrix-keypad
 33:          0     GPIOC   0  10021000.mmc cd
 34:          0     GPIOA  16  Touchpad Left
 35:          0     GPIOA  13  Touchpad Right
ERR:          0
root at letux:~# devmem2 0x10001000
/dev/mem opened.
Memory mapped at address 0x77e0e000.
Value at address 0x10001000 (0x77e0e000): 0x801000
root at letux:~# devmem2 0x10001010
/dev/mem opened.
Memory mapped at address 0x77e5d000.
Value at address 0x10001010 (0x77e5d010): 0x0
root at letux:~# 

So we have a new information:
* cevt is only really used if we have clocksource=ingenic-timer
* there are really no interrupts from TCU1 (OST1) although requested
* someone seems to remove the mask
* cevt interrupts are also not delivered if clocksource=jiffies
* but then it seems to be harmless because scheduling happens differently

In summary the bug may also be in the interrupt controller
and not in the ingenic-timer itself (which also has issues).

Any ideas here?

BR,
Nikolaus