Bug 14258

Summary: the system clock runs too slow on some kernels > 2.6.18
Product: Sisyphus Reporter: Ivan Zakharyaschev <imz>
Component: kernel-image-std-defAssignee: Vitaly Chikunov <vt>
Status: CLOSED WORKSFORME QA Contact: qa-sisyphus
Severity: normal    
Priority: P2 CC: kernelbot, vt
Version: unstable   
Hardware: all   
OS: Linux   
Attachments:
Description Flags
sysreport-20080206.tar.bz2
none
/proc/acpi/dsdt
none
/proc/timer_list
none
dmesg output (2.6.24-wks-smp-alt1+acpi_pm)
none
/proc/timer_list (2.6.24-wks-smp-alt1+acpi_pm)
none
dmesg output (2.6.24-wks-smp-alt1+tsc)
none
/proc/timer_list (2.6.24-wks-smp-alt1+tsc) none

Description Ivan Zakharyaschev 2008-01-31 08:22:01 MSK
kernel-image-wks-smp-2.6.24-alt0.8

After circa 3 days uptime, the system time is about 15 min behind the real time.
(Of course, no time synchronization is used, otherwise I wouldn't report this
bug for kernel.)

I observed this bug also on some other kernels > 2.6.18 I tried, perhaps I will
post this information later. (If I remember correctly, the kernels without this
bug were "not good" because they didn't put the processor into "inactive" states.)

This is observed on a Dell Latitude D610. 
This is not observed on a PentiumII on P2B computer.

$ rpm -q kernel-image-wks-smp-2.6.24-alt0.8 -i
Name        : kernel-image-wks-smp         Relocations: (not relocateable)
Version     : 2.6.24                            Vendor: ALT Linux Team
Release     : alt0.8                        Build Date: Пнд 17 Дек 2007 00:10:05
Install date: Пнд 17 Дек 2007 21:15:16      Build Host: lakostis.hasher.altlinux.org
Group       : System/Kernel and hardware    Source RPM:
kernel-image-wks-smp-2.6.24-alt0.8.src.rpm
Size        : 56544563                         License: GPL
Packager    : Konstantin A. Lepikhov <lakostis@altlinux.ru>
URL         : http://www.kernel.org/
Summary     : The Linux kernel (the core of the Linux operating system)
Description :
<...>

$ cat /proc/cpuinfo 
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 13
model name      : Intel(R) Pentium(R) M processor 2.00GHz
stepping        : 8
cpu MHz         : 2000.000
cache size      : 2048 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
pat clflush dts acpi mmx fxsr sse sse2 ss tm pbe nx up bts est tm2
bogomips        : 3982.56
clflush size    : 64

$ 

# lspci
0000:00:00.0 Host bridge: Intel Corporation Mobile 915GM/PM/GMS/910GML Express
Processor to DRAM Controller (rev 03)
0000:00:02.0 VGA compatible controller: Intel Corporation Mobile
915GM/GMS/910GML Express Graphics Controller (rev 03)
0000:00:02.1 Display controller: Intel Corporation Mobile 915GM/GMS/910GML
Express Graphics Controller (rev 03)
0000:00:1c.0 PCI bridge: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family)
PCI Express Port 1 (rev 03)
0000:00:1d.0 USB Controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6
Family) USB UHCI #1 (rev 03)
0000:00:1d.1 USB Controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6
Family) USB UHCI #2 (rev 03)
0000:00:1d.2 USB Controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6
Family) USB UHCI #3 (rev 03)
0000:00:1d.3 USB Controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6
Family) USB UHCI #4 (rev 03)
0000:00:1d.7 USB Controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6
Family) USB2 EHCI Controller (rev 03)
0000:00:1e.0 PCI bridge: Intel Corporation 82801 Mobile PCI Bridge (rev d3)
0000:00:1e.2 Multimedia audio controller: Intel Corporation
82801FB/FBM/FR/FW/FRW (ICH6 Family) AC'97 Audio Controller (rev 03)
0000:00:1f.0 ISA bridge: Intel Corporation 82801FBM (ICH6M) LPC Interface Bridge
(rev 03)
0000:00:1f.2 IDE interface: Intel Corporation 82801FBM (ICH6M) SATA Controller
(rev 03)
0000:00:1f.3 SMBus: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) SMBus
Controller (rev 03)
0000:02:00.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5751 Gigabit
Ethernet PCI Express (rev 01)
0000:03:01.0 CardBus bridge: Texas Instruments PCI6515 Cardbus Controller
0000:03:01.5 Communication controller: Texas Instruments PCI6515 SmartCard
Controller
0000:03:03.0 Network controller: Intel Corporation PRO/Wireless 2200BG Network
Connection (rev 05)
# 

Steps to Reproduce:
1.set correct time with `date'
2.remove /etc/adjtime
3.service clock sync
4.remove /etc/adjtime
5.wait 3 days
Actual Results:  
$ date
Чтв Янв 31 07:58:27 MSK 2008


Expected Results:  
Real time: 08:13
Comment 1 Ivan Zakharyaschev 2008-02-02 12:20:38 MSK
Hardware time remains correct. The system time runs too slow.

I reproduced the experiment on 2.6.24-wks-smp-alt0.8:

I set the time to the correct time at about Jan 31 08:52. 

hwclock; date gave:
Thu Jan 31 05:52:48 2008  -2.115300 seconds MSK
Thu Jan 31 08:52:46 MSK 2008

No significant difference (/etc/adjtime was removed, that's the reason for the 3
hours difference).

Now, about 2 days later:

# date; hwclock; date
Sat Feb  2 12:10:32 MSK 2008
Sat Feb  2 09:18:45 2008  -2.339343 seconds MSK
Sat Feb  2 12:10:34 MSK 2008
# 

The difference is about 8 minutes. The hardware clock is close to the correct time.
Comment 2 Ivan Zakharyaschev 2008-02-03 17:14:32 MSK
The same on 2.6.24-wks-smp-alt1:

uptime 1 day,  3:57, the difference is more than 4 minutes:

# date; hwclock ; date
Sun Feb  3 17:06:56 MSK 2008
Sun Feb  3 17:11:24 2008  -0.353278 seconds MSK
Sun Feb  3 17:06:56 MSK 2008
# 

The hardware clock is close to the correct time.
Comment 3 Ivan Zakharyaschev 2008-02-05 04:56:29 MSK
the same on 2.6.22-wks-smp-alt0.6:

uptime 1 day, 11:07; the difference between clocks is about 6 min., the clock
close to the correct time is the hardware clock:

# date; hwclock ; date
Tue Feb  5 04:42:27 MSK 2008
Tue Feb  5 04:48:05 2008  -3.010491 seconds MSK
Tue Feb  5 04:42:30 MSK 2008
# 

So, I wasn't right in the initial report that this bad behavior correlates with
the CPU not entering "inactive" Cn states under a certain kernel. (This is one
of such kernels I've tested -- I look at the Cn states in powertop.)

$ rpm -q kernel-image-wks-smp-2.6.22-alt0.6 -i
Name        : kernel-image-wks-smp         Relocations: (not relocateable)
Version     : 2.6.22                            Vendor: ALT Linux Team
Release     : alt0.6                        Build Date: Пнд 12 Ноя 2007 03:24:35
Install date: Втр 13 Ноя 2007 20:17:24      Build Host: lakostis.hasher.altlinux.org
Group       : System/Kernel and hardware    Source RPM:
kernel-image-wks-smp-2.6.22-alt0.6.src.rpm
Size        : 48268215                         License: GPL
Packager    : Konstantin A. Lepikhov <lakostis@altlinux.ru>
<...>
Comment 4 Konstantin A Lepikhov (L.A. Kostis) 2008-02-05 10:34:09 MSK
Can you attach the archive generated by system-report utility (it can be found
in branch/4.0 and Sisyphus)? I'm need the dmidecode results and /proc/dsdt contents.
Comment 5 Ivan Zakharyaschev 2008-02-05 23:03:22 MSK
This bug is not present in 2.6.18-std-smp-alt8:
uptime: up 17:30
no significant divergence between the clocks:
# date; hwclock ; date
Tue Feb  5 23:01:55 MSK 2008
Tue Feb  5 23:01:54 2008  -0.125768 seconds MSK
Tue Feb  5 23:01:56 MSK 2008
# 
Comment 6 Ivan Zakharyaschev 2008-02-06 01:40:51 MSK
Created attachment 2416 [details]
sysreport-20080206.tar.bz2

(In reply to comment #4)
> Can you attach the archive generated by system-report utility (it can be
found
> in branch/4.0 and Sisyphus)?
Comment 7 Ivan Zakharyaschev 2008-02-06 01:48:44 MSK
(In reply to comment #4)
>  and /proc/dsdt contents.

I have no /proc/dsdt.
Comment 8 Konstantin A Lepikhov (L.A. Kostis) 2008-02-06 02:09:36 MSK
(In reply to comment #7)
> (In reply to comment #4)
> >  and /proc/dsdt contents.
> 
> I have no /proc/dsdt.
> 

sorry, /proc/acpi/dsdt of course.
Comment 9 Ivan Zakharyaschev 2008-02-06 02:17:47 MSK
Created attachment 2417 [details]
/proc/acpi/dsdt
Comment 10 Konstantin A Lepikhov (L.A. Kostis) 2008-02-06 02:49:54 MSK
Does the situation is changed when you try to pass the clocksource=tsc or
clocksource=acpi_pm in kernel cmdline?

PS please post the /proc/timers_list contents.
Comment 11 Ivan Zakharyaschev 2008-02-06 03:21:47 MSK
Created attachment 2418 [details]
/proc/timer_list
Comment 12 Ivan Zakharyaschev 2008-02-06 04:23:36 MSK
Created attachment 2419 [details]
dmesg output (2.6.24-wks-smp-alt1+acpi_pm)

2.6.24-wks-smp-alt1 + clocksource=acpi_pm -- no changes, uptime: 51 min, the
clocks:

# date; hwclock ; date
Wed Feb  6 04:20:59 MSK 2008
Wed Feb  6 04:21:08 2008  -0.607247 seconds MSK
Wed Feb  6 04:20:59 MSK 2008
# 

So, the drift is about -10 sec per 1 hour, the same as it was.

(Going to test clocksource=tsc, will report results tomorrow.)
Comment 13 Ivan Zakharyaschev 2008-02-06 04:24:21 MSK
Created attachment 2420 [details]
/proc/timer_list (2.6.24-wks-smp-alt1+acpi_pm)
Comment 14 Ivan Zakharyaschev 2008-02-06 17:45:20 MSK
Created attachment 2422 [details]
dmesg output (2.6.24-wks-smp-alt1+tsc)

2.6.24-wks-smp-alt1 + clocksource=tsc -- again this effect, uptime: 12:52, the
clocks:

# date; hwclock ; date
Wed Feb  6 17:42:18 MSK 2008
Wed Feb  6 14:44:48 2008  -0.910568 seconds MSK
Wed Feb  6 17:42:19 MSK 2008
# 

So, the drift is a bit more than -10 sec per 1 hour.
Comment 15 Ivan Zakharyaschev 2008-02-06 17:46:12 MSK
Created attachment 2423 [details]
/proc/timer_list (2.6.24-wks-smp-alt1+tsc)
Comment 16 Ivan Zakharyaschev 2008-02-06 18:58:42 MSK
Some strange effects of clocksource=tsc seen in the system init sequence:
https://bugzilla.altlinux.org/show_bug.cgi?id=14343 ,
https://bugzilla.altlinux.org/show_bug.cgi?id=14345 .
Comment 17 Ivan Zakharyaschev 2008-02-07 03:23:58 MSK
This effect is not observed on 2.6.24-std-def-alt2: uptime: 7:23 (7 hrs 23 min)
# date; hwclock ; date
Thu Feb  7 03:23:03 MSK 2008
Thu Feb  7 03:23:01 2008  -0.000387 seconds MSK
Thu Feb  7 03:23:04 MSK 2008
# 

(So, on this kernel the system clock is a tiny bit too fast, not slow.)
Comment 18 Ivan Zakharyaschev 2008-02-07 04:51:56 MSK
Out of curiosity, I tested also 2.6.24-std-def-alt2 with clocksource=tsc. And
the effect is present, even in a stronger form: uptime: 1:20
# date; hwclock ; date
Thu Feb  7 04:48:39 MSK 2008
Thu Feb  7 01:49:44 2008  -0.000381 seconds MSK
Thu Feb  7 04:48:39 MSK 2008
#

So, the drift is about -1 min per 1 hour. 

(But of course I don't consider this as a serious bug because this is present
not under the default kernel parameters.)
Comment 19 Konstantin A Lepikhov (L.A. Kostis) 2008-02-07 11:35:40 MSK
(In reply to comment #17)
> This effect is not observed on 2.6.24-std-def-alt2: uptime: 7:23 (7 hrs 23 min)
> # date; hwclock ; date
> Thu Feb  7 03:23:03 MSK 2008
> Thu Feb  7 03:23:01 2008  -0.000387 seconds MSK
> Thu Feb  7 03:23:04 MSK 2008
> # 
> 
> (So, on this kernel the system clock is a tiny bit too fast, not slow.)

It's a good sign :) Because current wks-smp based on 2.6.24-rc8 we have all
chances that new release will doesn't have this bug (std-def based on vanilla
2.6.24). Please, test this behavior when new wks-smp appeared in Sisyphus.

 
Comment 20 Ivan Zakharyaschev 2008-02-23 18:50:04 MSK
(In reply to comment #19)
> 2.6.24). Please, test this behavior when new wks-smp appeared in Sisyphus.

Please let me know when there is a version to test.
Comment 21 Konstantin A Lepikhov (L.A. Kostis) 2008-08-21 11:16:07 MSD
(In reply to comment #20)
> (In reply to comment #19)
> > 2.6.24). Please, test this behavior when new wks-smp appeared in Sisyphus.
> 
> Please let me know when there is a version to test.

You can try new version of wks kernel from http://www.unsafe.ru/lakostis/RPMS/ALTLinux/kernel-2.6.26 and report about new behavior.
Comment 22 Konstantin A Lepikhov (L.A. Kostis) 2009-04-05 01:41:38 MSD
Reassing to actual kernel in Sisyphus. Feel free to check this issue on std-def kernel.
Comment 23 Michail Yakushin 2010-06-22 16:31:26 MSD
Проблема не наблюдается.