Bug 617043

Summary:	kernel: Timer ISR/0: Time went backwards
Product:	Red Hat Enterprise Linux 5	Reporter:	Pengzhen Cao <pcao>
Component:	kernel-xen	Assignee:	Paolo Bonzini <pbonzini>
Status:	CLOSED WONTFIX	QA Contact:	Virtualization Bugs <virt-bugs>
Severity:	high	Docs Contact:
Priority:	high
Version:	5.6	CC:	atodorov, borgan, drjones, jlaska, jlv, leiwang, lersek, llim, mbooth, mrezanin, mshao, pbonzini, peterm, prarit, rwu, xen-maint
Target Milestone:	rc
Target Release:	---
Hardware:	x86_64
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:	437252	Environment:
Last Closed:	2011-08-11 09:01:41 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:	437252
Bug Blocks:	514490

Comment 2 Paolo Bonzini 2010-11-23 12:35:03 UTC

I don't think this is a regression, the keyword simply got cloned from BZ437252.  However, I'm not yet removing the keyword until I can play with this a bit more.

Comment 3 Lawrence Lim 2010-11-25 00:14:55 UTC

Moving to 5.7 based on Comment #2.

Comment 5 RHEL Program Management 2011-02-01 17:03:22 UTC

This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux maintenance release.  Product Management has requested
further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed
products.  This request is not yet committed for inclusion in an Update
release.

Comment 8 Paolo Bonzini 2011-03-16 15:02:07 UTC

Considering that this issue is happening only on these two amd-B95-8 machines, I'm thinking that it is a hardware problem.  The jitter that is recorded by the "Time went backwards" message is usually 10-13 ms, just above the amount that is filtered out by the kernel (10 ms).

I'll run http://people.redhat.com/mingo/time-warp-test/time-warp-test.c for a while on bare metal.

Comment 9 Paolo Bonzini 2011-03-16 15:35:04 UTC

Also interesting is that in all the messages ISR/3 was never affected, and the delta_cpu was always "healthy".  So it looks like CPU#3's clock is "running" a bit:

Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-12145463 delta_cpu=67854537 shadow=6073175928765 off=259926793 processed=6073448000000 cpu_processed=6073368000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11993129 delta_cpu=68006871 shadow=6073305804630 off=130203554 processed=6073448000000 cpu_processed=6073368000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-11715806 delta_cpu=16284194 shadow=6073205801641 off=230484230 processed=6073448000000 cpu_processed=6073420000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-10145658 delta_cpu=37854342 shadow=6073175928765 off=289926625 processed=6073476000000 cpu_processed=6073428000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-12516891 delta_cpu=27483109 shadow=6073305804630 off=161680093 processed=6073480000000 cpu_processed=6073440000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-10962292 delta_cpu=25037708 shadow=6073205801641 off=263237639 processed=6073480000000 cpu_processed=6073444000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11991343 delta_cpu=28008657 shadow=6073175928765 off=312080755 processed=6073500000000 cpu_processed=6073460000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-10486461 delta_cpu=13513539 shadow=6073205801641 off=283712904 processed=6073500000000 cpu_processed=6073476000000
Mar 16 14:05:49 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-12550304 delta_cpu=19449696 shadow=6073305804630 off=185646644 processed=6073504000000 cpu_processed=6073472000000
Mar 16 14:05:50 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11964746 delta_cpu=48035254 shadow=6073175928765 off=520107479 processed=6073708000000 cpu_processed=6073648000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11830700 delta_cpu=96169300 shadow=25491484146960 off=700262189 processed=25492196000000 cpu_processed=25492088000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11832640 delta_cpu=48167360 shadow=25491484146960 off=740021278 processed=25492236000000 cpu_processed=25492176000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-10286669 delta_cpu=49713331 shadow=25491724151346 off=501563312 processed=25492236000000 cpu_processed=25492176000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-12464368 delta_cpu=35535632 shadow=25491604148821 off=623388465 processed=25492240000000 cpu_processed=25492192000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-10342917 delta_cpu=13657083 shadow=25491604148821 off=633509267 processed=25492248000000 cpu_processed=25492224000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-12340559 delta_cpu=11659441 shadow=25491604148821 off=643511526 processed=25492260000000 cpu_processed=25492236000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-10783990 delta_cpu=13216010 shadow=25491484146960 off=765070493 processed=25492260000000 cpu_processed=25492236000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11649232 delta_cpu=36350768 shadow=25491724151346 off=532201074 processed=25492268000000 cpu_processed=25492220000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-10097618 delta_cpu=13902382 shadow=25491604148821 off=653754554 processed=25492268000000 cpu_processed=25492244000000
Mar 16 19:29:29 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-10989884 delta_cpu=17010116 shadow=25491484146960 off=780864736 processed=25492276000000 cpu_processed=25492248000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11452027 delta_cpu=8547973 shadow=30271537542189 off=787246947 processed=30272336000000 cpu_processed=30272316000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-12448491 delta_cpu=15551509 shadow=30271417606000 off=909946750 processed=30272340000000 cpu_processed=30272312000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11956470 delta_cpu=20043530 shadow=30271417604910 off=914440212 processed=30272344000000 cpu_processed=30272312000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-14427823 delta_cpu=17572177 shadow=30271417606000 off=919966807 processed=30272352000000 cpu_processed=30272320000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11959900 delta_cpu=24040100 shadow=30271537542189 off=806499571 processed=30272356000000 cpu_processed=30272320000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-12176552 delta_cpu=11823448 shadow=30271417606000 off=930218574 processed=30272360000000 cpu_processed=30272336000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-11802402 delta_cpu=24197598 shadow=30271417604910 off=934594354 processed=30272364000000 cpu_processed=30272328000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-13501251 delta_cpu=18498749 shadow=30271537542189 off=816958141 processed=30272368000000 cpu_processed=30272336000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-14175859 delta_cpu=13824141 shadow=30271417606000 off=940219380 processed=30272372000000 cpu_processed=30272344000000
Mar 16 20:49:10 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-10699754 delta_cpu=13300246 shadow=30271537542189 off=827758968 processed=30272376000000 cpu_processed=30272352000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-12118996 delta_cpu=43881004 shadow=32894867874170 off=900244472 processed=32895780000000 cpu_processed=32895724000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11915855 delta_cpu=52084145 shadow=32894867876930 off=908208878 processed=32895788000000 cpu_processed=32895724000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-10350502 delta_cpu=57649498 shadow=32894867880213 off=909770813 processed=32895788000000 cpu_processed=32895720000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-11962467 delta_cpu=12037533 shadow=32894867874170 off=920164534 processed=32895800000000 cpu_processed=32895776000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-14402441 delta_cpu=17597559 shadow=32894867876930 off=921722237 processed=32895804000000 cpu_processed=32895772000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-13844487 delta_cpu=10155513 shadow=32894867874170 off=930282424 processed=32895812000000 cpu_processed=32895788000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-11841402 delta_cpu=12158598 shadow=32894867874170 off=940285054 processed=32895820000000 cpu_processed=32895796000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/0: Time went backwards: delta=-13692482 delta_cpu=10307518 shadow=32894867874170 off=950434055 processed=32895832000000 cpu_processed=32895808000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/1: Time went backwards: delta=-11984238 delta_cpu=36015762 shadow=32894867876930 off=956140575 processed=32895836000000 cpu_processed=32895788000000
Mar 16 21:32:53 amd-B95-8-2 kernel: Warning Timer ISR/2: Time went backwards: delta=-10427895 delta_cpu=57572105 shadow=32894867880213 off=957693528 processed=32895836000000 cpu_processed=32895768000000

Comment 10 Andrew Jones 2011-03-24 10:49:25 UTC

I'd like the keyword Regression removed if older kernels exhibit these problems on this exact hardware. Otherwise we could bisect where the issue starts. Furthermore, it's too late for 5.7 to determine how to correct it for this specific hardware. Moving to 5.8.

Comment 14 Miroslav Rezanina 2011-08-11 09:01:41 UTC

Testing shows that baremetal jitter on problematic machine is just bellow ignorable limit, on xen is this limit hit and problem reported. As the problem is limit to specific machine we will not investigate it further.