It''s everytime when cpufreq_ondemand or cpufreq-set changes the
frequency, aprox. 3 messages per event.
Is that occasional? I tend to say: no. Please see an excerpt below. And if
it''s not occasional, what
could I do? And by the way: I found no code that TSC will get adjusted, so I
think it will get worse
over the time...
Thanks, Carsten.
messages.0:Jan 9 12:25:15 data kernel: Timer ISR/1: Time went backwards:
delta=-12018171 delta_cpu=115981829 shadow=75780489375160 off=410607630
processed=75780912000000 cpu_processed=75780784000000
messages.0:Jan 9 12:25:16 data kernel: Timer ISR/1: Time went backwards:
delta=-16026092 delta_cpu=75973908 shadow=75780489375160 off=806599392
processed=75781312000000 cpu_processed=75781220000000
messages.0:Jan 9 12:25:17 data kernel: Timer ISR/0: Time went backwards:
delta=-740021307 delta_cpu=39978693 shadow=75780512149240 off=999830312
processed=75782252000000 cpu_processed=75781472000000
messages.0:Jan 9 12:30:14 data kernel: Timer ISR/0: Time went backwards:
delta=-88031200 delta_cpu=39968800 shadow=76078328190440 off=999778806
processed=76079416000000 cpu_processed=76079288000000
messages.0:Jan 9 12:30:16 data kernel: Timer ISR/0: Time went backwards:
delta=-785869130 delta_cpu=6130870 shadow=76079431383280 off=998748426
processed=76081216000000 cpu_processed=76080424000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/0: Time went backwards:
delta=-308640982 delta_cpu=7359018 shadow=76678234607036 off=976752607
processed=76679520000000 cpu_processed=76679204000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/0: Time went backwards:
delta=-311783977 delta_cpu=8216023 shadow=76678234607036 off=981609505
processed=76679528000000 cpu_processed=76679208000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-12010703 delta_cpu=7989297 shadow=76679516186720 off=51803565
processed=76679580000000 cpu_processed=76679560000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-16804204 delta_cpu=31195796 shadow=76679516186720 off=79009670
processed=76679612000000 cpu_processed=76679564000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-12015144 delta_cpu=23984856 shadow=76679516186720 off=99798703
processed=76679628000000 cpu_processed=76679592000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-16002390 delta_cpu=47997610 shadow=76679516186720 off=143812049
processed=76679676000000 cpu_processed=76679612000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-16002306 delta_cpu=99997694 shadow=76679516186720 off=311812214
processed=76679844000000 cpu_processed=76679728000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-20009989 delta_cpu=119990011 shadow=76679516186720 off=427804685
processed=76679964000000 cpu_processed=76679824000000
messages.0:Jan 9 12:40:14 data kernel: Timer ISR/1: Time went backwards:
delta=-20003075 delta_cpu=51996925 shadow=76679516186720 off=475811309
processed=76680012000000 cpu_processed=76679940000000
messages.0:Jan 9 12:40:15 data kernel: Timer ISR/1: Time went backwards:
delta=-20022020 delta_cpu=3977980 shadow=76679516186720 off=663792405
processed=76680200000000 cpu_processed=76680176000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-19489274 delta_cpu=4510726 shadow=76977914783244 off=441746174
processed=76978376000000 cpu_processed=76978352000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-18731547 delta_cpu=25268453 shadow=76977914783244 off=594486759
processed=76978528000000 cpu_processed=76978484000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-29511790 delta_cpu=10488210 shadow=76977914783244 off=731707417
processed=76978676000000 cpu_processed=76978636000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-36343330 delta_cpu=67656670 shadow=76977914783244 off=796875850
processed=76978748000000 cpu_processed=76978644000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-25173167 delta_cpu=22826833 shadow=76977914783244 off=816046030
processed=76978756000000 cpu_processed=76978708000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-16590822 delta_cpu=35409178 shadow=76977914783244 off=848626988
processed=76978780000000 cpu_processed=76978728000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-11911350 delta_cpu=8088650 shadow=76977914783244 off=853307168
processed=76978780000000 cpu_processed=76978760000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-36157180 delta_cpu=19842820 shadow=76977914783244 off=929060430
processed=76978880000000 cpu_processed=76978824000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-51943502 delta_cpu=20056498 shadow=76978916907554 off=11149402
processed=76978980000000 cpu_processed=76978908000000
messages.0:Jan 9 12:45:13 data kernel: Timer ISR/0: Time went backwards:
delta=-47941739 delta_cpu=4058261 shadow=76978916907554 off=15150923
processed=76978980000000 cpu_processed=76978928000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-11693183 delta_cpu=104306817 shadow=77277628116247 off=532206689
processed=77278172000000 cpu_processed=77278056000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-19598845 delta_cpu=116401155 shadow=77277628116247 off=644286629
processed=77278292000000 cpu_processed=77278156000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-23368732 delta_cpu=124631268 shadow=77277628116247 off=764516809
processed=77278416000000 cpu_processed=77278268000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-35459200 delta_cpu=48540800 shadow=77277628116247 off=808424847
processed=77278472000000 cpu_processed=77278388000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-43213786 delta_cpu=16786214 shadow=77277628116247 off=820670725
processed=77278492000000 cpu_processed=77278432000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-27893067 delta_cpu=68106933 shadow=77277628116247 off=887992064
processed=77278544000000 cpu_processed=77278448000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/1: Time went backwards:
delta=-15504501 delta_cpu=48495499 shadow=77277628116247 off=936380582
processed=77278580000000 cpu_processed=77278516000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/0: Time went backwards:
delta=-18471272 delta_cpu=5528728 shadow=77278556697207 off=284832106
processed=77278860000000 cpu_processed=77278836000000
messages.0:Jan 9 12:50:13 data kernel: Timer ISR/0: Time went backwards:
delta=-20029777 delta_cpu=35970223 shadow=77278556697207 off=359273478
processed=77278936000000 cpu_processed=77278880000000
messages.0:Jan 9 12:50:14 data kernel: Timer ISR/0: Time went backwards:
delta=-28038759 delta_cpu=15961241 shadow=77278556697207 off=875264595
processed=77279460000000 cpu_processed=77279416000000
messages.0:Jan 9 12:55:14 data kernel: Timer ISR/1: Time went backwards:
delta=-23993106 delta_cpu=100006894 shadow=77578619176253 off=868843079
processed=77579512000000 cpu_processed=77579388000000
messages.0:Jan 9 12:55:14 data kernel: Timer ISR/1: Time went backwards:
delta=-15993587 delta_cpu=64006413 shadow=77578619176253 off=932831052
processed=77579568000000 cpu_processed=77579488000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-20019563 delta_cpu=11980437 shadow=77579572937147 off=823043738
processed=77580416000000 cpu_processed=77580384000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-13777491 delta_cpu=10222509 shadow=77579572937147 off=829285587
processed=77580416000000 cpu_processed=77580392000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-24449294 delta_cpu=19550706 shadow=77579572937147 off=878613859
processed=77580476000000 cpu_processed=77580432000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-18397840 delta_cpu=9602160 shadow=77579572937147 off=884665174
processed=77580476000000 cpu_processed=77580448000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-20040885 delta_cpu=19959115 shadow=77579572937147 off=975022465
processed=77580568000000 cpu_processed=77580528000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/1: Time went backwards:
delta=-164032408 delta_cpu=39967592 shadow=77579619178732 off=996789362
processed=77580780000000 cpu_processed=77580576000000
messages.0:Jan 9 12:55:15 data kernel: Timer ISR/0: Time went backwards:
delta=-16015520 delta_cpu=47984480 shadow=77580769972800 off=94012230
processed=77580880000000 cpu_processed=77580816000000
messages.0:Jan 9 12:55:16 data kernel: Timer ISR/0: Time went backwards:
delta=-16020854 delta_cpu=31979146 shadow=77580769972800 off=494006895
processed=77581280000000 cpu_processed=77581232000000
messages.0:Jan 9 13:00:13 data kernel: Timer ISR/1: Time went backwards:
delta=-14462502 delta_cpu=81537498 shadow=77877559766287 off=881791414
processed=77878456000000 cpu_processed=77878360000000
messages.0:Jan 9 13:00:13 data kernel: Timer ISR/1: Time went backwards:
delta=-11934544 delta_cpu=28065456 shadow=77877559766287 off=908301089
processed=77878480000000 cpu_processed=77878440000000
messages.0:Jan 9 13:00:13 data kernel: Timer ISR/1: Time went backwards:
delta=-11697161 delta_cpu=16302839 shadow=77877559766287 off=924537397
processed=77878496000000 cpu_processed=77878468000000
messages.0:Jan 9 13:00:16 data kernel: Timer ISR/1: Time went backwards:
delta=-1018449317 delta_cpu=57550683 shadow=77879559836710 off=977714939
processed=77881556000000 cpu_processed=77880480000000
messages.0:Jan 9 13:00:16 data kernel: Timer ISR/1: Time went backwards:
delta=-1022454873 delta_cpu=5545127 shadow=77879559836710 off=981709100
processed=77881564000000 cpu_processed=77880536000000
messages.0:Jan 9 13:00:17 data kernel: Timer ISR/0: Time went backwards:
delta=-11993711 delta_cpu=28006289 shadow=77881558973360 off=985033887
processed=77882556000000 cpu_processed=77882516000000
----- Originalnachricht -----
Von: Keir Fraser <keir.fraser@eu.citrix.com>
Gesendet: Mon, 12.1.2009 10:52
An: Carsten Schiers <carsten@schiers.de> ; xen-devel@lists.xensource.com
Betreff: Re: [Xen-devel] Clocksources and other mysteries
On 12/01/2009 09:43, "Carsten Schiers" <carsten@schiers.de>
wrote:
> First mystery: when jiffies is used as clocksource, why is the system
checking
> and complaining about deltas in TSC? Can I thus ignore them?
>
> Second mystery: when Xen reports:(XEN) Platform timer is 25.000MHz HPET,
why
> isn''t Xen using it? Shouldn''t it? Wouldn''t be
the HPET the best choice for my
> non-TSC-invariant CPU?
Fine-grained system time is computed from TSC, calibrated periodically to
the platform timesource (HPET). Xen kernels compute jiffies from Xen system
time, hence computed from TSC.
If the time went backwards messages are occasional you can ignore them, or
even disable them.
-- Keir
_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel