[Letux-kernel] [PATCH 00/20] A bunch of JZ4730 fixups for letux-kernel

[H. Nikolaus Schaller]

> Am 29.12.2020 um 16:26 schrieb H. Nikolaus Schaller <hns at goldelico.com>:
> 
> Basically the hrtimer is initialized by generic_sched_clock_init().
> And the timer frequency defined by cd.wrap_kt. I have not yet printed the
> value but can easily do if needed.
> 
> So I'd say the problem is NOT OTCNT1 but we have learned that the (u16) can
> be removed.
> 
> It is the hrtimer which seems to be broken.

[    6.303246] sched_clock_poll wrap_kt=568880208
[    5.887309] usb 1-2.4: new full-speed USB device number 4 using ohci-platform
[    6.269236] usb 1-2.4: New USB device found, idVendor=0ace, idProduct=1215, bcdDevice=48.10
[    6.009079] usb 1-2.4: New USB device strings: Mfr=16, Product=32, SerialNumber=0
[    6.861666] usb 1-2.4: Product: USB2.0 WLAN
[    6.467343] usb 1-2.4: Manufacturer: ZyDAS
[    6.639496] sched_clock_poll wrap_kt=568880208
[    7.079878] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    7.081545] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    6.945538] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    6.765624] cfg80211: failed to load regulatory.db
[    6.673697] sched_clock_poll wrap_kt=568880208
[    6.530572] usb 1-2.4: reset full-speed USB device number 4 using ohci-platform
[    6.816232] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[    6.768298] zd1211rw 1-2.4:1.0: phy0
[    6.511909] usbcore: registered new interface driver zd1211rw
[    7.504218] sched_clock_poll wrap_kt=568880208
done.
^[[c[    7.572083] sched_clock_poll wrap_kt=568880208

...

[   79.133368] sched_clock_poll wrap_kt=568880208
[   79.630520] sched_clock_poll wrap_kt=568880208

Debian GNU/Linux 8 letux console

letux login: [   80.122152] sched_clock_poll wrap_kt=568880208
[   80.620659] sched_clock_poll wrap_kt=568880208
[   81.112222] sched_clock_poll wrap_kt=568880208
[   81.604565] sched_clock_poll wrap_kt=568880208
[   82.091423] sched_clock_poll wrap_kt=568880208
[   82.587465] sched_clock_poll wrap_kt=568880208
[   83.075520] sched_clock_poll wrap_kt=568880208

If I read the wrap_kt as ns it means the hrtimer is triggered every 0.5 seconds.
This translates in 0.5 seconds increments of the sched_clock() for the
printk statements. Fine.

But it is far to slow compared to your estimate of ca. 25 wraps per second.

So it is probably not even the hrtimer but the calculation of cd.wrap_kt
in sched_timer initialization.

" * @wrap_kt:		Duration for which clock can run before wrapping."

It is calculated by this code:

void __init
sched_clock_register(u64 (*read)(void), int bits, unsigned long rate)
{
	u64 res, wrap, new_mask, new_epoch, cyc, ns;
	u32 new_mult, new_shift;
	unsigned long r, flags;
	char r_unit;
	struct clock_read_data rd;

	if (cd.rate > rate)
		return;

	/* Cannot register a sched_clock with interrupts on */
	local_irq_save(flags);

	/* Calculate the mult/shift to convert counter ticks to ns. */
	clocks_calc_mult_shift(&new_mult, &new_shift, rate, NSEC_PER_SEC, 3600);

	new_mask = CLOCKSOURCE_MASK(bits);
	cd.rate = rate;

	/* Calculate how many nanosecs until we risk wrapping */
	wrap = clocks_calc_max_nsecs(new_mult, new_shift, 0, new_mask, NULL);
	cd.wrap_kt = ns_to_ktime(wrap);
...

So it can only get wrong if 'bits' or 'rate' is wrong (of a compiler bug).

Hm. How and with which parameters is the ingenic-timer setup
calling sched_clock_register()?

BR,
Nikolaus