[Qemu-devel] Timing.. was : kqemu processor feature question

[Brad Campbell <brad@wasp.net.au>]

Brad Campbell wrote:
> John R. Hogerhuis wrote:
> 
>> Anyway everything seems to be fitting your theory about Athlon
>> extensions. It would be nice to catch it in the act of trying to run an
>> Athlon instruction on a Pentium.
> 
> And it was all a bogus trail.. It's *timer* related!
> I made start_rtc_timer() fail (return -1) unconditionally, and voila it 
> boots first time every time, and any Image I throw at it..
> So something in the win2k loader appears to be timing sensitive. I did 
> try the -win2k-hack for a lark, but that only had random results..
> So there is an issue with the RTC handler on this machine by the looks..
> RTC max freq is 1024, so it's not that.. further debugging required


There is something bogus happening in cpu_calibrate_ticks() on this machine

When it boots windows ok I get this..

bklaptop:/tracks>qemu -hda w2k.img -m 512 -user-net -localtime -enable-audio
timer: min=450 us max=50188 us avg=2424 us avg_freq=412.523 Hz
timer: min=243 us max=53085 us avg=2435 us avg_freq=410.534 Hz
timer: min=80 us max=24302 us avg=2416 us avg_freq=413.747 Hz
timer: min=20 us max=60886 us avg=2837 us avg_freq=352.417 Hz

When it fails to start I get this..

bklaptop:/tracks>qemu -hda w2k.img -m 512 -user-net -localtime -enable-audio
timer: min=194 us max=226993 us avg=21626 us avg_freq=46.239 Hz
timer: min=646 us max=550679 us avg=21923 us avg_freq=45.613 Hz
timer: min=939 us max=203745 us avg=21966 us avg_freq=45.525 Hz
timer: min=171 us max=540720 us avg=28920 us avg_freq=34.577 Hz
timer: min=4641 us max=80171 us avg=21372 us avg_freq=46.789 Hz

I might start qemu 30 times, and get 1 boot from 30 starts..

If the machine is loaded when I start qemu it will start every time. (while true ; do echo -n . ; 
done) in the shell is enough to load it up..
It *almost* looks like the tsc is stopping while the machine is in hlt state and cpu_calibrate_ticks 
is getting bogus figures somewhere..

This machine has SpeedStep, but according to the info in /sys/devices/system/cpu/cpu0/cpufreq/
It has not changed state since boot and the governor is set to max_freq..

<Cue swimmy visual wipe effect> "Some time later......"

By changing cpu_calibrate_ticks to do something silly and keep busy while waiting instead of 
sleeping, I get dead reliable results every time.. (Yes, it's horridly ugly, I know it's ugly but it 
works here)

void cpu_calibrate_ticks(void)
{
     int64_t usec, ticks;

     usec = get_clock();
     ticks = cpu_get_real_ticks();
#ifdef _WIN32
     Sleep(50);
#else
     while (get_clock()-usec < 50000) {
         get_clock();
     }
#endif
     usec = get_clock() - usec;
     ticks = cpu_get_real_ticks() - ticks;
     ticks_per_sec = (ticks * 1000000LL + (usec >> 1)) / usec;
     printf("Ticks_per_sec = %lld\n",ticks_per_sec);
}

bklaptop:/tracks>qemu -hda w2k.img -user-net -m 512 -localtime
timer: min=90 us max=10628 us avg=994 us avg_freq=1005.900 Hz
timer: min=33 us max=22670 us avg=1003 us avg_freq=996.085 Hz
timer: min=305 us max=2995 us avg=980 us avg_freq=1019.897 Hz
timer: min=220 us max=25093 us avg=1020 us avg_freq=979.883 Hz
timer: min=27 us max=9872 us avg=701 us avg_freq=1425.036 Hz

So it appears to give a much more accurate idea of tics_per_sec. (which is where all my timer 
problems on this laptop are coming from)

For testing I run cpu_calibrate_tics 8 times in the init sequence..
This is just changing the above routine only.. no other machine modification or restart...

Before
bklaptop:/tracks>qemu -hda w2k.img -user-net -m 512 -localtime
Ticks_per_sec = 47720193
Ticks_per_sec = 32508223
Ticks_per_sec = 34422776
Ticks_per_sec = 51535607
Ticks_per_sec = 29776765
Ticks_per_sec = 29481406
Ticks_per_sec = 26230393
Ticks_per_sec = 26133451
Winner - RTC enabled
timer: min=2568 us max=850100 us avg=38857 us avg_freq=25.735 Hz
timer: min=5607 us max=153629 us avg=37663 us avg_freq=26.551 Hz

After
bklaptop:/tracks>qemu -hda w2k.img -user-net -m 512 -localtime
Ticks_per_sec = 999800944
Ticks_per_sec = 999876102
Ticks_per_sec = 999892940
Ticks_per_sec = 999842403
Ticks_per_sec = 999893360
Ticks_per_sec = 999882080
Ticks_per_sec = 999877682
Ticks_per_sec = 999871643
Winner - RTC enabled
timer: min=90 us max=10628 us avg=994 us avg_freq=1005.900 Hz
timer: min=33 us max=22670 us avg=1003 us avg_freq=996.085 Hz

It's got me.. I'm off to try and find the processor datasheet on this PIII-M to check the tsc info..

Regards,
Brad
-- 
"Human beings, who are almost unique in having the ability
to learn from the experience of others, are also remarkable
for their apparent disinclination to do so." -- Douglas Adams