Bug 190258 - lost ticks, time source instable, slow system time
Summary: lost ticks, time source instable, slow system time
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 5
Hardware: x86_64
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Brian Brock
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2006-04-29 13:28 UTC by Roberto Ragusa
Modified: 2007-11-30 22:11 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2006-06-02 13:52:49 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
dmesg (28.81 KB, text/plain)
2006-04-29 13:31 UTC, Roberto Ragusa
no flags Details
/proc/interrupts (588 bytes, text/plain)
2006-04-29 13:32 UTC, Roberto Ragusa
no flags Details
lsmod (2.47 KB, text/plain)
2006-04-29 13:33 UTC, Roberto Ragusa
no flags Details
lspci (1.78 KB, text/plain)
2006-04-29 13:34 UTC, Roberto Ragusa
no flags Details

Description Roberto Ragusa 2006-04-29 13:28:25 UTC
Description of problem:
  The following message appears as soon as the system boots up:
    warning: many lost ticks.
    Your time source seems to be instable or some driver is hogging interupts
    rip default_idle+0x2b/0x54
  The system clock is slow (about half speed) and not even ntpd is able to keep
  the clock in sync. The system stability doesn't seem to be affected.

Version-Release number of selected component (if applicable):
  kernel 2.6.16-1.2096_FC5 for x86_64

How reproducible:
  Boot the system, it happens with 100% probability

Steps to Reproduce:
1. boot the system
2. realize that the clock is falling behind
  
Actual results:
  The system time clock is too slow

Expected results:
  Correct system time

Additional info:
  The problem was observed after upgrading the machine from FC4 to FC5
  (the root filesystem was duplicated and one of the istances was upgraded
  to FC5).
  Booting the FC5 partition with kernel x86_64 2.6.16-1.2096_FC5,
  the problem is present.
  Booting the FC4 partition with kernel x86_64 2.6.16-1.2096_FC4smp,
  the problem is not present.

  The comparison of dmesg, lspci, /proc/interrupts, lsmod doesn't show
  anything immediately relevant.
  The kernel source is not too different in the two cases, but I think
  voluntary preemption is enabled on FC5.

  Info about the system: nvidia CK804, sata disks, lvm, RAID1,
  reiserfs. The system is not able to work without the noacpi
  parameter (apparently related to PATA disks). Some BIOS-related
  warnings are present in the logs.

Comment 1 Roberto Ragusa 2006-04-29 13:31:04 UTC
Created attachment 128390 [details]
dmesg

dmesg, note BIOS warnings (present with FC4 kernel too)

Comment 2 Roberto Ragusa 2006-04-29 13:32:27 UTC
Created attachment 128391 [details]
/proc/interrupts

/proc/interrupts

Comment 3 Roberto Ragusa 2006-04-29 13:33:16 UTC
Created attachment 128392 [details]
lsmod

lsmod

Comment 4 Roberto Ragusa 2006-04-29 13:34:23 UTC
Created attachment 128393 [details]
lspci

lspci

Comment 5 Roberto Ragusa 2006-04-29 13:39:47 UTC
(In reply to comment #0)

>   The system is not able to work without the noacpi
>   parameter (apparently related to PATA disks).

Sorry, I meant noapic, not noacpi.


Comment 6 Roberto Ragusa 2006-05-23 07:46:45 UTC
Recompiled kernel without preemption and without xen, tried playing
with clock= option, disabled cpuspeed daemon: problem persists.

Updated the motherboard to latest BIOS and tried kernel 2.6.16-1.2122_FC5;
the system is able to boot without noapic, but the clock problem is still
there (so, the machine is still not usable as a file server).


Comment 7 Bill Rugolsky, Jr. 2006-05-23 12:32:27 UTC
See http://lkml.org/lkml/2006/3/16/166 for the discussion on LKML. I spent some
time with Jeff Garzik, Andi Kleen, and others trying to track down the problem,
and we narrowed it down to a single status register read that was taking many
milliseconds.  There is a version of the sata_nv driver that supports ADMA in
Jeff's libata GIT tree; that driver may work around the latency issue, but it
wasn't stable last time that I tested.

I'm currently working around the timekeeping issue by using John Stultz's new
timekeeping code, slated for 2.6.18; the particular patchset is from Thomas
Gleixner's merge with the hrtimers code, as used in Ingo Molnar's RT patch:

  http://tglx.de/projects/hrtimers/

Comment 8 Roberto Ragusa 2006-05-23 14:48:01 UTC
I knew that thread but didn't understand where the discussion ended.
If I understand correctly, after a couple of months, there isn't a simple
fix or workaround yet; right?

I wonder why everything is OK on FC4; it is almost the same kernel.

Couldn't a deep comparison between the two help in finding the cause
of the slow read or perhaps a workaround?

(still trying to resist the temptation to just run the FC4 kernel on FC5...)


Comment 9 Bill Rugolsky, Jr. 2006-05-23 16:30:35 UTC
Are you in fact stressing them in the same way?  I don't see a problem except
when doing I/O simultaneously to multiple disks either via RAID1 or on the raw
drives.

In that thread I also raised a concern with MD perhaps iterating too much while
processing i/o completions in softirq context; Lee Revell suggesteed reducing
max_sectors_kb: http://lkml.org/lkml/2006/3/15/252 but that didn't do the trick
for me.

I agree that the only significant difference that I see between the FC4 and FC5
kernel build configs (aside from Xen) is:
--- fc4/kernel-2.6.16-x86_64-smp.config 2006-05-23 11:38:05.000000000 -0400
+++ fc5/kernel-2.6.16-x86_64.config     2006-05-23 11:41:45.000000000 -0400
@@ -37,10 +36,10 @@
 CONFIG_IOSCHED_CFQ=y
 CONFIG_DEFAULT_CFQ=y
 CONFIG_POSIX_MQUEUE=y
-CONFIG_PREEMPT_NONE=y 
-# CONFIG_PREEMPT_VOLUNTARY is not set
+# CONFIG_PREEMPT_NONE is not set
+CONFIG_PREEMPT_VOLUNTARY=y
 # CONFIG_PREEMPT is not set
-# CONFIG_PREEMPT_BKL is not set
+CONFIG_PREEMPT_BKL=y

I suppose that using preemption might increase concurrency, thereby putting
further stress on the SATA I/O path.

Have you considered rebuilding the FC5 kernel with CONFIG_PREEMPT_NONE?  In my
own testing with the 2.6.16-rc kernels, I still had clock problems with
CONFIG_PREEMPT_NONE, but YMMV.

Comment 10 Roberto Ragusa 2006-05-23 19:56:32 UTC
I have 4 300GB SATA disks on nv_sata.
The root filesystem is a 4-disk RAID1 (software RAID); the rest of the 4 disks
is managed through lvm.
With FC4 there never was a problem. I even tried 4 hdparm -t together and the
speed was impressive: 60MB/s from each of the disk.

Before upgrading to FC5, I splitted the 4-disk RAID1 in two different 2-disk
RAID1 and uppgraded on only one of the two. So I have FC4 and FC5 on two
different /dev/md* devices and can boot both of them. The lvm space is visible
by both and the workload is identical; FC4 *never* had problems, FC5 misses
ticks even in the booting phase. The error is rather consistent: about 1.5
minutes lost every 5 minutes.

Yes, I tried with preemption disabled (see comment #6). No difference.

I'm beginning to think that it could depend on the compiler (gcc 4.0 vs.
gcc 4.1).



Comment 11 Roberto Ragusa 2006-05-24 09:25:52 UTC
Tried compiling the FC5 kernel with gcc 4.0 (on FC4).

No luck, always losing ticks.


Comment 12 Bill Rugolsky, Jr. 2006-05-24 13:40:56 UTC
Odd, because I've been booting my Tyan 2895 FC4 boxes with report_lost_ticks,
and I can generate losts ticks on my LVM2 over RAID1 config in seconds with

  tar -cf /dev/zero /usr & tar -cf /dev/zero /extra_disk &
 
Linux ti93 2.6.16-1.2096_FC4smp #1 SMP Wed Apr 19 16:01:54 EDT 2006 x86_64
x86_64 x86_64 GNU/Linux
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 1 timer tick(s)! rip do_gettimeoffset_pm+0x8/0x2a)
time.c: Lost 1 timer tick(s)! rip do_gettimeoffset_pm+0x8/0x2a)
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 3 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)
time.c: Lost 1 timer tick(s)! rip __do_softirq+0x51/0xd4)

rugolsky@ti93: cat /proc/interrupts 
           CPU0       CPU1       
  0:      40954      47453    IO-APIC-edge  timer
  1:          8          0    IO-APIC-edge  i8042
  7:          2          0    IO-APIC-edge  parport0
  8:          0          0    IO-APIC-edge  rtc
  9:          0          0   IO-APIC-level  acpi
 14:       1116       1796    IO-APIC-edge  ide0
 16:          0          0   IO-APIC-level  libata, ehci_hcd:usb1
 17:       1558     173925   IO-APIC-level  libata, ohci_hcd:usb2
 18:     263261          0   IO-APIC-level  eth0
 20:          0          0   IO-APIC-level  NVidia CK804
 21:          3          0   IO-APIC-level  ohci1394
NMI:         69         61 
LOC:      88417      88336 
ERR:          0
MIS:          0


Comment 13 Roberto Ragusa 2006-05-24 14:07:53 UTC
I used to run FC4 on 2.6.16-1.2096_FC4 (no smp), but I tried the
2.6.16-1.2096_FC4smp kernel and it was ok.
My test was with "noapic", to avoid locking at boot time.

In the mean time I have upgraded the BIOS, so I may try again without the
"noapic". Unfortunately I can only access the machine remotely at the moment
so experimentation involving repeated booting is not easy for me.


Comment 14 Roberto Ragusa 2006-06-02 13:52:49 UTC
Finally discovered the real cause of the problem: kudzu.

If you run kudzu without the "-s" (safe) flag (controlled through
/etc/sysconfig/kudzu), the message

  Losing some ticks... checking if CPU frequency changed.

is immediately logged, the clock slows down and after a few
seconds you get

  warning: many lost ticks.
  Your time source seems to be instable or some driver is hogging interupts

The kudzu man page hints to DDC probe causing problems on "some older
graphic cards".
Maybe my card is old enough, it is PCI:

  01:07.0 VGA compatible controller: S3 Inc. ViRGE/DX or /GX (rev 01)

(The machine is a file server and doesn't need a gfx card at all.)

Comment 15 Dan Carpenter 2006-07-18 03:49:04 UTC
Actually the real the problem is that the 2895 BIOS doesn't set up
/proc/interrupts correctly.  Your /proc/interrupts is showing up as XT-PIC
because you are using noapic to boot.  If you weren't using that option then it
would show up as edge triggered.  

The 1.01 BIOS sets up the interrupts correctly but it has other issues where
some PCI devices don't show up in lspci.  :/  However if those issues don't
affect you then the 1.01 BIOS is the way to go.




Note You need to log in before you can comment on or make changes to this bug.