2.6.16-rc2 powerpc timestamp skew

2.6.16-rc2 powerpc timestamp skew

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 1067 bytes --]

Hi folks,

When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
Freescale 7447A):

$ date && touch f && ls -l f && rm -f f && date
Sun Feb 12 12:20:14 GMT 2006
-rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
Sun Feb 12 12:20:14 GMT 2006

Notice the timestamp is 3 minutes in the future compared with the
system time.  "make" is not a very happy bunny running on this kernel
due to every touched file being 3 minutes in the future.

When the same command is run on 2.6.15.3:

$ date && touch f && ls -l f && rm -f f && date
Sun Feb 12 14:27:27 GMT 2006
-rw-r--r-- 1 rleigh rleigh 0 2006-02-12 14:27
Sun Feb 12 14:27:27 GMT 2006

In this case the times are identical, as you would expect.

In both these cases, the chrony NTP daemon is running, if that might
be a problem.


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: Type: application/pgp-signature, Size: 188 bytes --]

Re: 2.6.16-rc2 powerpc timestamp skew

[Gabriel Paubert]

On Sun, Feb 12, 2006 at 05:13:50PM +0000, Roger Leigh wrote:
> Hi folks,
> 
> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
> Freescale 7447A):
> 
> $ date && touch f && ls -l f && rm -f f && date
> Sun Feb 12 12:20:14 GMT 2006
> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
> Sun Feb 12 12:20:14 GMT 2006
> 
> Notice the timestamp is 3 minutes in the future compared with the
> system time.  "make" is not a very happy bunny running on this kernel
> due to every touched file being 3 minutes in the future.
> 
> When the same command is run on 2.6.15.3:
> 
> $ date && touch f && ls -l f && rm -f f && date
> Sun Feb 12 14:27:27 GMT 2006
> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 14:27
> Sun Feb 12 14:27:27 GMT 2006
> 
> In this case the times are identical, as you would expect.
> 
> In both these cases, the chrony NTP daemon is running, if that might
> be a problem.

I don't know whether it is reloated, but since I installed
a 2.6.16-rc2 kernel on my G4/466, I have log messages
that claim that the clock error rate is too large for NTP
to correct (larger than 512ppm).

	Gabriel

Re: 2.6.16-rc2 powerpc timestamp skew

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 1086 bytes --]

Roger Leigh <rleigh@whinlatter.ukfsn.org> writes:

> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
> Freescale 7447A):
>
> $ date && touch f && ls -l f && rm -f f && date
> Sun Feb 12 12:20:14 GMT 2006
> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
> Sun Feb 12 12:20:14 GMT 2006
>
> Notice the timestamp is 3 minutes in the future compared with the
> system time.  "make" is not a very happy bunny running on this kernel
> due to every touched file being 3 minutes in the future.

> In both these cases, the chrony NTP daemon is running, if that might
> be a problem.

Some further information:
- this does not appear to affect i386 kernels
- I have
    CONFIG_HZ_250=y
    CONFIG_HZ=250
  in my .config; the full config is at
  http://people.debian.org/~rleigh/config-2.6.16-rc2


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: Type: application/pgp-signature, Size: 188 bytes --]

Re: 2.6.16-rc2 powerpc timestamp skew

[Bin Zhang]

On 2/12/06, Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
> Roger Leigh <rleigh@whinlatter.ukfsn.org> writes:
>
> > When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
> > Freescale 7447A):
> >
> > $ date && touch f && ls -l f && rm -f f && date
> > Sun Feb 12 12:20:14 GMT 2006
> > -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
> > Sun Feb 12 12:20:14 GMT 2006
> >
> > Notice the timestamp is 3 minutes in the future compared with the
> > system time.  "make" is not a very happy bunny running on this kernel
> > due to every touched file being 3 minutes in the future.
>
> > In both these cases, the chrony NTP daemon is running, if that might
> > be a problem.
>
> Some further information:
> - this does not appear to affect i386 kernels
> - I have
>     CONFIG_HZ_250=y
>     CONFIG_HZ=250
>   in my .config; the full config is at
>   http://people.debian.org/~rleigh/config-2.6.16-rc2
>

I have in my config-2.6.16-rc2 (G4 1.2Ghz, 7447A)
CONFIG_HZ_1000=y
CONFIG_HZ=1000
and have
$ date && touch f && ls -l f && rm -f f && date
Sun Feb 12 21:08:43 CET 2006
-rw-r--r-- 1 zhang zhang 0 2006-02-12 21:08 f
Sun Feb 12 21:08:43 CET 2006

I don't have ntp daemon running (ntpdate at boot).

Regards,
Bin

>
> Regards,
> Roger
>
> --
> Roger Leigh
>                 Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
>                 Debian GNU/Linux        http://www.debian.org/
>                 GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.
>
>
>

Re: 2.6.16-rc2 powerpc timestamp skew

[Olaf Hering]

 On Sun, Feb 12, Roger Leigh wrote:

> In both these cases, the chrony NTP daemon is running, if that might
> be a problem.

I dont run Debian, but:

My G4/466 has the hwclock at 1970 for some reason. The early bootscripts
call klogd, which calls nanosleep. This syscall takes 3 hours to complete.

A bit userland debugging shows that hwclock is 1970, system time is also
1970 when nanosleep starts. But when it returns, the time is correct.
Its already at the end of the /etc/init.d/boot.d/S* scripts, nothing
else runs there. Bug exists since at least 2.6.15-git12, 2.6.15 was ok.
Fatfingerd kernel debug patch and lost remote access...

Re: 2.6.16-rc2 powerpc timestamp skew

[Olaf Hering]

 On Sun, Feb 12, Olaf Hering wrote:

>  On Sun, Feb 12, Roger Leigh wrote:
> 
> > In both these cases, the chrony NTP daemon is running, if that might
> > be a problem.
> 
> I dont run Debian, but:
> 
> My G4/466 has the hwclock at 1970 for some reason. The early bootscripts
> call klogd, which calls nanosleep. This syscall takes 3 hours to complete.

Firmware says the date is in 2006, so its a kernel bug. Looking.

Re: 2.6.16-rc2 powerpc timestamp skew

[Olaf Hering]

 On Mon, Feb 13, Olaf Hering wrote:

>  On Sun, Feb 12, Olaf Hering wrote:
> 
> >  On Sun, Feb 12, Roger Leigh wrote:
> > 
> > > In both these cases, the chrony NTP daemon is running, if that might
> > > be a problem.
> > 
> > I dont run Debian, but:
> > 
> > My G4/466 has the hwclock at 1970 for some reason. The early bootscripts
> > call klogd, which calls nanosleep. This syscall takes 3 hours to complete.

nanosleep is usually called with *rqtp <something>, *rmtp NULL.
Only in the klogd case both pointers are equal.

Re: 2.6.16-rc2 powerpc timestamp skew

[Benjamin Herrenschmidt]

On Sun, 2006-02-12 at 17:13 +0000, Roger Leigh wrote:
> Hi folks,
> 
> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
> Freescale 7447A):
> 
> $ date && touch f && ls -l f && rm -f f && date
> Sun Feb 12 12:20:14 GMT 2006
> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
> Sun Feb 12 12:20:14 GMT 2006
> 
> Notice the timestamp is 3 minutes in the future compared with the
> system time.  "make" is not a very happy bunny running on this kernel
> due to every touched file being 3 minutes in the future.
> 
> When the same command is run on 2.6.15.3:
> 
> $ date && touch f && ls -l f && rm -f f && date
> Sun Feb 12 14:27:27 GMT 2006
> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 14:27
> Sun Feb 12 14:27:27 GMT 2006
> 
> In this case the times are identical, as you would expect.
> 
> In both these cases, the chrony NTP daemon is running, if that might
> be a problem.

Can you strace vs. ltrace and see if the gettimeofday or clock_gettime
syscalls are ever called ? I wonder if you have a glibc new enough to
use the vDSO to obtain the time or if it's using the syscall... The vDSO
on ppc32 is very new.

Also, are your kernels built with ARCH=ppc or ARCH=powerpc ?

Ben.

Re: 2.6.16-rc2 powerpc timestamp skew

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 2233 bytes --]

Benjamin Herrenschmidt <benh@kernel.crashing.org> writes:

> On Sun, 2006-02-12 at 17:13 +0000, Roger Leigh wrote:
>> Hi folks,
>> 
>> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
>> Freescale 7447A):
>> 
>> $ date && touch f && ls -l f && rm -f f && date
>> Sun Feb 12 12:20:14 GMT 2006
>> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
>> Sun Feb 12 12:20:14 GMT 2006
>> 
>> Notice the timestamp is 3 minutes in the future compared with the
>> system time.  "make" is not a very happy bunny running on this kernel
>> due to every touched file being 3 minutes in the future.
>> 
>> When the same command is run on 2.6.15.3:
>> 
>> $ date && touch f && ls -l f && rm -f f && date
>> Sun Feb 12 14:27:27 GMT 2006
>> -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 14:27
>> Sun Feb 12 14:27:27 GMT 2006
>> 
>> In this case the times are identical, as you would expect.
>> 
>> In both these cases, the chrony NTP daemon is running, if that might
>> be a problem.
>
> Can you strace vs. ltrace and see if the gettimeofday or clock_gettime
> syscalls are ever called ?

           | strace        | ltrace
-----------+---------------+------------------------------------
2.6.15     |               |
date       | clock_gettime | clock_gettime -> SYS_clock_gettime,
           |               |   localtime, strftime
touch      | utimes        | futimes -> SYS_utimes
           |               |
2.6.16-rc2 |               |
date       | clock_gettime | clock_gettime -> SYS_clock_gettime,
           |               |   localtime, strftime
touch      | utimes        | futimes -> SYS_utimes

[clock_gettime(CLOCK_REALTIME, {1139826613, 157402000}) = 0]

> I wonder if you have a glibc new enough to
> use the vDSO to obtain the time or if it's using the syscall... The vDSO
> on ppc32 is very new.

It's glibc 2.3.5 (Debian libc6 2.3.5-13).

> Also, are your kernels built with ARCH=ppc or ARCH=powerpc ?

ppc.


Thanks,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: Type: application/pgp-signature, Size: 188 bytes --]

Re: 2.6.16-rc2 powerpc timestamp skew

[Benjamin Herrenschmidt]

> > Can you strace vs. ltrace and see if the gettimeofday or clock_gettime
> > syscalls are ever called ?
> 
>            | strace        | ltrace
> -----------+---------------+------------------------------------
> 2.6.15     |               |
> date       | clock_gettime | clock_gettime -> SYS_clock_gettime,
>            |               |   localtime, strftime
> touch      | utimes        | futimes -> SYS_utimes
>            |               |
> 2.6.16-rc2 |               |
> date       | clock_gettime | clock_gettime -> SYS_clock_gettime,
>            |               |   localtime, strftime
> touch      | utimes        | futimes -> SYS_utimes
> 
> [clock_gettime(CLOCK_REALTIME, {1139826613, 157402000}) = 0]
> 
> > I wonder if you have a glibc new enough to
> > use the vDSO to obtain the time or if it's using the syscall... The vDSO
> > on ppc32 is very new.
> 
> It's glibc 2.3.5 (Debian libc6 2.3.5-13).

Ok, does not using NTP fixes it ?

Ben.

Re: 2.6.16-rc2 powerpc timestamp skew

[Paul Mackerras]

Benjamin Herrenschmidt writes:

> Ok, does not using NTP fixes it ?

Try this patch.  With this the values from gettimeofday() or the VDSO
should stay exactly in sync with xtime even if NTP is adjusting the
clock.

This patch still has quite a few debugging printks in it, so it's not
final by any means.  I'll be interested to hear how it goes, and in
particular whether or not you see any "oops, time got ahead" messages.

Paul.

diff -urN linux-2.6/arch/powerpc/kernel/sys_ppc32.c dynvsid/arch/powerpc/kernel/sys_ppc32.c
--- linux-2.6/arch/powerpc/kernel/sys_ppc32.c	2006-01-11 08:42:09.000000000 +1100
+++ dynvsid/arch/powerpc/kernel/sys_ppc32.c	2006-02-13 15:07:52.000000000 +1100
@@ -176,7 +176,6 @@
 };
 
 extern int do_adjtimex(struct timex *);
-extern void ppc_adjtimex(void);
 
 asmlinkage long compat_sys_adjtimex(struct timex32 __user *utp)
 {
@@ -209,9 +208,6 @@
 
 	ret = do_adjtimex(&txc);
 
-	/* adjust the conversion of TB to time of day to track adjtimex */
-	ppc_adjtimex();
-
 	if(put_user(txc.modes, &utp->modes) ||
 	   __put_user(txc.offset, &utp->offset) ||
 	   __put_user(txc.freq, &utp->freq) ||
diff -urN linux-2.6/arch/powerpc/kernel/time.c dynvsid/arch/powerpc/kernel/time.c
--- linux-2.6/arch/powerpc/kernel/time.c	2006-02-09 11:39:04.000000000 +1100
+++ dynvsid/arch/powerpc/kernel/time.c	2006-02-14 16:24:31.000000000 +1100
@@ -50,6 +50,7 @@
 #include <linux/security.h>
 #include <linux/percpu.h>
 #include <linux/rtc.h>
+#include <linux/jiffies.h>
 
 #include <asm/io.h>
 #include <asm/processor.h>
@@ -99,7 +100,15 @@
 unsigned long tb_ticks_per_sec;
 u64 tb_to_xs;
 unsigned tb_to_us;
-unsigned long processor_freq;
+
+#define TICKLEN_SCALE	(SHIFT_SCALE - 10)
+u64 last_tick_len;	/* units are ns / 2^TICKLEN_SCALE */
+u64 ticklen_to_xs;	/* 0.64 fraction */
+
+/* If last_tick_len corresponds to about 1/HZ seconds, then
+   last_tick_len << TICKLEN_SHIFT will be about 2^63. */
+#define TICKLEN_SHIFT	(63 - 30 - TICKLEN_SCALE + SHIFT_HZ)
+
 DEFINE_SPINLOCK(rtc_lock);
 EXPORT_SYMBOL_GPL(rtc_lock);
 
@@ -113,10 +122,6 @@
 extern struct timezone sys_tz;
 static long timezone_offset;
 
-void ppc_adjtimex(void);
-
-static unsigned adjusting_time = 0;
-
 unsigned long ppc_proc_freq;
 unsigned long ppc_tb_freq;
 
@@ -248,23 +253,6 @@
 
 EXPORT_SYMBOL(do_gettimeofday);
 
-/* Synchronize xtime with do_gettimeofday */ 
-
-static inline void timer_sync_xtime(unsigned long cur_tb)
-{
-#ifdef CONFIG_PPC64
-	/* why do we do this? */
-	struct timeval my_tv;
-
-	__do_gettimeofday(&my_tv, cur_tb);
-
-	if (xtime.tv_sec <= my_tv.tv_sec) {
-		xtime.tv_sec = my_tv.tv_sec;
-		xtime.tv_nsec = my_tv.tv_usec * 1000;
-	}
-#endif
-}
-
 /*
  * There are two copies of tb_to_xs and stamp_xsec so that no
  * lock is needed to access and use these values in
@@ -323,15 +311,49 @@
 {
 	unsigned long offset;
 	u64 new_stamp_xsec;
+	u64 tlen, t2x;
+	static struct timespec last_xtime;
+	static u64 last_tb;
 
 	if (__USE_RTC())
 		return;
+	tlen = current_tick_length();
 	offset = cur_tb - do_gtod.varp->tb_orig_stamp;
-	if ((offset & 0x80000000u) == 0)
-		return;
-	new_stamp_xsec = do_gtod.varp->stamp_xsec
-		+ mulhdu(offset, do_gtod.varp->tb_to_xs);
-	update_gtod(cur_tb, new_stamp_xsec, do_gtod.varp->tb_to_xs);
+	if (tlen == last_tick_len && offset < 0x80000000u) {
+		struct timeval tv;
+		__do_gettimeofday(&tv, cur_tb);
+		if (tv.tv_sec <= xtime.tv_sec &&
+		    (tv.tv_sec < xtime.tv_sec ||
+		     tv.tv_usec * 1000 <= xtime.tv_nsec)) {
+			last_xtime = xtime;
+			last_tb = cur_tb;
+			return;
+		}
+		printk("oops, time got ahead: %ld.%06ld > %ld.%09ld\n",
+		       tv.tv_sec, tv.tv_usec,
+		       xtime.tv_sec, xtime.tv_nsec);
+		printk("  xtime was %ld.%09ld tb was %lld tick %lld\n",
+		       last_xtime.tv_sec, last_xtime.tv_nsec,
+		       last_tb, cur_tb);
+		printk("  tlen 0x%llx tb now %lld tpj %ld\n", tlen, get_tb(),
+		       tb_ticks_per_jiffy);
+		printk("  gtod tbstamp %lld xsec 0x%llx t2x 0x%llx\n",
+		       do_gtod.varp->tb_orig_stamp, do_gtod.varp->stamp_xsec,
+		       do_gtod.varp->tb_to_xs);
+	}
+	if (tlen != last_tick_len) {
+		t2x = mulhdu(tlen << TICKLEN_SHIFT, ticklen_to_xs);
+		printk("tick len 0x%llx -> 0x%llx, t2x now 0x%llx\n",
+		       last_tick_len, tlen, t2x);
+		last_tick_len = tlen;
+	} else
+		t2x = do_gtod.varp->tb_to_xs;
+	new_stamp_xsec = (u64) xtime.tv_nsec * XSEC_PER_SEC;
+	do_div(new_stamp_xsec, 1000000000);
+	new_stamp_xsec += (u64) xtime.tv_sec * XSEC_PER_SEC;
+	update_gtod(cur_tb, new_stamp_xsec, t2x);
+	last_xtime = xtime;
+	last_tb = cur_tb;
 }
 
 #ifdef CONFIG_SMP
@@ -462,13 +484,10 @@
 		write_seqlock(&xtime_lock);
 		tb_last_jiffy += tb_ticks_per_jiffy;
 		tb_last_stamp = per_cpu(last_jiffy, cpu);
-		timer_recalc_offset(tb_last_jiffy);
 		do_timer(regs);
-		timer_sync_xtime(tb_last_jiffy);
+		timer_recalc_offset(tb_last_jiffy);
 		timer_check_rtc();
 		write_sequnlock(&xtime_lock);
-		if (adjusting_time && (time_adjust == 0))
-			ppc_adjtimex();
 	}
 	
 	next_dec = tb_ticks_per_jiffy - ticks;
@@ -492,16 +511,18 @@
 
 void wakeup_decrementer(void)
 {
-	int i;
+	unsigned long ticks;
 
-	set_dec(tb_ticks_per_jiffy);
 	/*
-	 * We don't expect this to be called on a machine with a 601,
-	 * so using get_tbl is fine.
+	 * The timebase gets saved on sleep and restored on wakeup,
+	 * so all we need to do is to reset the decrementer.
 	 */
-	tb_last_stamp = tb_last_jiffy = get_tb();
-	for_each_cpu(i)
-		per_cpu(last_jiffy, i) = tb_last_stamp;
+	ticks = tb_ticks_since(__get_cpu_var(last_jiffy));
+	if (ticks < tb_ticks_per_jiffy)
+		ticks = tb_ticks_per_jiffy - ticks;
+	else
+		ticks = 1;
+	set_dec(ticks);
 }
 
 #ifdef CONFIG_SMP
@@ -541,12 +562,13 @@
 	time_t wtm_sec, new_sec = tv->tv_sec;
 	long wtm_nsec, new_nsec = tv->tv_nsec;
 	unsigned long flags;
-	long int tb_delta;
-	u64 new_xsec, tb_delta_xs;
+	u64 new_xsec;
+	unsigned long tb_delta;
 
 	if ((unsigned long)tv->tv_nsec >= NSEC_PER_SEC)
 		return -EINVAL;
 
+	printk("do_settimeofday(%ld.%09ld)\n", new_sec, new_nsec);
 	write_seqlock_irqsave(&xtime_lock, flags);
 
 	/*
@@ -563,9 +585,15 @@
 		first_settimeofday = 0;
 	}
 #endif
+
+	/*
+	 * Subtract off the number of nanoseconds since the
+	 * beginning of the last tick.
+	 */
 	tb_delta = tb_ticks_since(tb_last_stamp);
 	tb_delta += (jiffies - wall_jiffies) * tb_ticks_per_jiffy;
-	tb_delta_xs = mulhdu(tb_delta, do_gtod.varp->tb_to_xs);
+	tb_delta = mulhdu(tb_delta, do_gtod.varp->tb_to_xs); /* in xsec */
+	new_nsec -= SCALE_XSEC(tb_delta, 1000000000);
 
 	wtm_sec  = wall_to_monotonic.tv_sec + (xtime.tv_sec - new_sec);
 	wtm_nsec = wall_to_monotonic.tv_nsec + (xtime.tv_nsec - new_nsec);
@@ -580,12 +608,12 @@
 
 	ntp_clear();
 
-	new_xsec = 0;
-	if (new_nsec != 0) {
-		new_xsec = (u64)new_nsec * XSEC_PER_SEC;
+	new_xsec = xtime.tv_nsec;
+	if (new_xsec != 0) {
+		new_xsec *= XSEC_PER_SEC;
 		do_div(new_xsec, NSEC_PER_SEC);
 	}
-	new_xsec += (u64)new_sec * XSEC_PER_SEC - tb_delta_xs;
+	new_xsec += (u64)xtime.tv_sec * XSEC_PER_SEC;
 	update_gtod(tb_last_jiffy, new_xsec, do_gtod.varp->tb_to_xs);
 
 	vdso_data->tz_minuteswest = sys_tz.tz_minuteswest;
@@ -671,7 +699,7 @@
 	unsigned long flags;
 	unsigned long tm = 0;
 	struct div_result res;
-	u64 scale;
+	u64 scale, x;
 	unsigned shift;
 
         if (ppc_md.time_init != NULL)
@@ -693,11 +721,45 @@
 	}
 
 	tb_ticks_per_jiffy = ppc_tb_freq / HZ;
-	tb_ticks_per_sec = tb_ticks_per_jiffy * HZ;
+	tb_ticks_per_sec = ppc_tb_freq;
 	tb_ticks_per_usec = ppc_tb_freq / 1000000;
 	tb_to_us = mulhwu_scale_factor(ppc_tb_freq, 1000000);
+
+	/*
+	 * Calculate the length of each tick in ns.  It will not be
+	 * exactly 1e9/HZ unless ppc_tb_freq is divisible by HZ.
+	 * We compute 1e9 * tb_ticks_per_jiffy / ppc_tb_freq,
+	 * rounded up.
+	 */
+	x = (u64) NSEC_PER_SEC * tb_ticks_per_jiffy + ppc_tb_freq - 1;
+	do_div(x, ppc_tb_freq);
+	tick_nsec = x;
+	last_tick_len = x << TICKLEN_SCALE;
+	printk("HZ = %d tb_freq = %lu tick_nsec = %ld\n", HZ, ppc_tb_freq,
+	       tick_nsec);
+
+	/* Compute tb_to_xs the old way, as 2^20 / tb_ticks_per_sec */
 	div128_by_32(1024*1024, 0, tb_ticks_per_sec, &res);
 	tb_to_xs = res.result_low;
+	printk("tb_to_xs = %llx (old way)\n", tb_to_xs);
+
+	/*
+	 * Compute ticklen_to_xs, which is a factor which gets multiplied
+	 * by (last_tick_len << TICKLEN_SHIFT) to get a tb_to_xs value.
+	 * It is computed as:
+	 * ticklen_to_xs = 2^N / (tb_ticks_per_jiffy * 1e9)
+	 * where N = 64 + 20 - TICKLEN_SCALE - TICKLEN_SHIFT
+	 * so as to give the result as a 0.64 fixed-point fraction.
+	 */
+	div128_by_32(1ULL << (64 + 20 - TICKLEN_SCALE - TICKLEN_SHIFT), 0,
+		     tb_ticks_per_jiffy, &res);
+	div128_by_32(res.result_high, res.result_low, NSEC_PER_SEC, &res);
+	printk("ticklen_to_xs = %llx %llx\n", res.result_high, res.result_low);
+	ticklen_to_xs = res.result_low;
+
+	/* Compute tb_to_xs from tick_nsec */
+	tb_to_xs = mulhdu(last_tick_len << TICKLEN_SHIFT, ticklen_to_xs);
+	printk("tb_to_xs = %llx (new way)\n", tb_to_xs);
 
 	/*
 	 * Compute scale factor for sched_clock.
@@ -759,126 +821,6 @@
 	set_dec(tb_ticks_per_jiffy);
 }
 
-/* 
- * After adjtimex is called, adjust the conversion of tb ticks
- * to microseconds to keep do_gettimeofday synchronized 
- * with ntpd.
- *
- * Use the time_adjust, time_freq and time_offset computed by adjtimex to 
- * adjust the frequency.
- */
-
-/* #define DEBUG_PPC_ADJTIMEX 1 */
-
-void ppc_adjtimex(void)
-{
-#ifdef CONFIG_PPC64
-	unsigned long den, new_tb_ticks_per_sec, tb_ticks, old_xsec,
-		new_tb_to_xs, new_xsec, new_stamp_xsec;
-	unsigned long tb_ticks_per_sec_delta;
-	long delta_freq, ltemp;
-	struct div_result divres; 
-	unsigned long flags;
-	long singleshot_ppm = 0;
-
-	/*
-	 * Compute parts per million frequency adjustment to
-	 * accomplish the time adjustment implied by time_offset to be
-	 * applied over the elapsed time indicated by time_constant.
-	 * Use SHIFT_USEC to get it into the same units as
-	 * time_freq.
-	 */
-	if ( time_offset < 0 ) {
-		ltemp = -time_offset;
-		ltemp <<= SHIFT_USEC - SHIFT_UPDATE;
-		ltemp >>= SHIFT_KG + time_constant;
-		ltemp = -ltemp;
-	} else {
-		ltemp = time_offset;
-		ltemp <<= SHIFT_USEC - SHIFT_UPDATE;
-		ltemp >>= SHIFT_KG + time_constant;
-	}
-	
-	/* If there is a single shot time adjustment in progress */
-	if ( time_adjust ) {
-#ifdef DEBUG_PPC_ADJTIMEX
-		printk("ppc_adjtimex: ");
-		if ( adjusting_time == 0 )
-			printk("starting ");
-		printk("single shot time_adjust = %ld\n", time_adjust);
-#endif	
-	
-		adjusting_time = 1;
-		
-		/*
-		 * Compute parts per million frequency adjustment
-		 * to match time_adjust
-		 */
-		singleshot_ppm = tickadj * HZ;	
-		/*
-		 * The adjustment should be tickadj*HZ to match the code in
-		 * linux/kernel/timer.c, but experiments show that this is too
-		 * large. 3/4 of tickadj*HZ seems about right
-		 */
-		singleshot_ppm -= singleshot_ppm / 4;
-		/* Use SHIFT_USEC to get it into the same units as time_freq */
-		singleshot_ppm <<= SHIFT_USEC;
-		if ( time_adjust < 0 )
-			singleshot_ppm = -singleshot_ppm;
-	}
-	else {
-#ifdef DEBUG_PPC_ADJTIMEX
-		if ( adjusting_time )
-			printk("ppc_adjtimex: ending single shot time_adjust\n");
-#endif
-		adjusting_time = 0;
-	}
-	
-	/* Add up all of the frequency adjustments */
-	delta_freq = time_freq + ltemp + singleshot_ppm;
-	
-	/*
-	 * Compute a new value for tb_ticks_per_sec based on
-	 * the frequency adjustment
-	 */
-	den = 1000000 * (1 << (SHIFT_USEC - 8));
-	if ( delta_freq < 0 ) {
-		tb_ticks_per_sec_delta = ( tb_ticks_per_sec * ( (-delta_freq) >> (SHIFT_USEC - 8))) / den;
-		new_tb_ticks_per_sec = tb_ticks_per_sec + tb_ticks_per_sec_delta;
-	}
-	else {
-		tb_ticks_per_sec_delta = ( tb_ticks_per_sec * ( delta_freq >> (SHIFT_USEC - 8))) / den;
-		new_tb_ticks_per_sec = tb_ticks_per_sec - tb_ticks_per_sec_delta;
-	}
-	
-#ifdef DEBUG_PPC_ADJTIMEX
-	printk("ppc_adjtimex: ltemp = %ld, time_freq = %ld, singleshot_ppm = %ld\n", ltemp, time_freq, singleshot_ppm);
-	printk("ppc_adjtimex: tb_ticks_per_sec - base = %ld  new = %ld\n", tb_ticks_per_sec, new_tb_ticks_per_sec);
-#endif
-
-	/*
-	 * Compute a new value of tb_to_xs (used to convert tb to
-	 * microseconds) and a new value of stamp_xsec which is the
-	 * time (in 1/2^20 second units) corresponding to
-	 * tb_orig_stamp.  This new value of stamp_xsec compensates
-	 * for the change in frequency (implied by the new tb_to_xs)
-	 * which guarantees that the current time remains the same.
-	 */
-	write_seqlock_irqsave( &xtime_lock, flags );
-	tb_ticks = get_tb() - do_gtod.varp->tb_orig_stamp;
-	div128_by_32(1024*1024, 0, new_tb_ticks_per_sec, &divres);
-	new_tb_to_xs = divres.result_low;
-	new_xsec = mulhdu(tb_ticks, new_tb_to_xs);
-
-	old_xsec = mulhdu(tb_ticks, do_gtod.varp->tb_to_xs);
-	new_stamp_xsec = do_gtod.varp->stamp_xsec + old_xsec - new_xsec;
-
-	update_gtod(do_gtod.varp->tb_orig_stamp, new_stamp_xsec, new_tb_to_xs);
-
-	write_sequnlock_irqrestore( &xtime_lock, flags );
-#endif /* CONFIG_PPC64 */
-}
-
 
 #define FEBRUARY	2
 #define	STARTOFTIME	1970
diff -urN linux-2.6/include/linux/timex.h dynvsid/include/linux/timex.h
--- linux-2.6/include/linux/timex.h	2005-10-31 13:10:39.000000000 +1100
+++ dynvsid/include/linux/timex.h	2006-02-13 15:07:52.000000000 +1100
@@ -345,6 +345,9 @@
 
 #endif /* !CONFIG_TIME_INTERPOLATION */
 
+/* Returns how long ticks are at present, in ns / 2^(SHIFT_SCALE-10). */
+extern u64 current_tick_length(void);
+
 #endif /* KERNEL */
 
 #endif /* LINUX_TIMEX_H */
diff -urN linux-2.6/kernel/timer.c dynvsid/kernel/timer.c
--- linux-2.6/kernel/timer.c	2006-02-09 11:39:05.000000000 +1100
+++ dynvsid/kernel/timer.c	2006-02-13 15:07:54.000000000 +1100
@@ -759,6 +759,30 @@
 }
 
 /*
+ * Return how long ticks are at the moment, that is, how much time
+ * update_wall_time_one_tick will add to xtime next time we call it
+ * (assuming no calls to do_adjtimex in the meantime).
+ * The return value is in fixed-point nanoseconds with SHIFT_SCALE-10
+ * bits to the right of the binary point.
+ * This function has no side-effects.
+ */
+u64 current_tick_length(void)
+{
+	long time_adjust_step, delta_nsec;
+
+	if ((time_adjust_step = time_adjust) != 0 ) {
+		/*
+		 * Limit the amount of the step to be in the range
+		 * -tickadj .. +tickadj
+		 */
+		time_adjust_step = min(time_adjust_step, (long)tickadj);
+		time_adjust_step = max(time_adjust_step, (long)-tickadj);
+	}
+	delta_nsec = tick_nsec + time_adjust_step * 1000;
+	return ((u64) delta_nsec << (SHIFT_SCALE - 10)) + time_adj;
+}
+
+/*
  * Using a loop looks inefficient, but "ticks" is
  * usually just one (we shouldn't be losing ticks,
  * we're doing this this way mainly for interrupt

Re: 2.6.16-rc2 powerpc timestamp skew

[Olaf Hering]

[-- Attachment #1: Type: text/plain, Size: 5047 bytes --]

 On Wed, Feb 15, Paul Mackeras wrote:

> Benjamin Herrenschmidt writes:
> 
> > Ok, does not using NTP fixes it ?
> 
> Try this patch.  With this the values from gettimeofday() or the VDSO
> should stay exactly in sync with xtime even if NTP is adjusting the
> clock.
> 
> This patch still has quite a few debugging printks in it, so it's not
> final by any means.  I'll be interested to hear how it goes, and in
> particular whether or not you see any "oops, time got ahead" messages.

This fixes my hang during boot.

--- bad.txt	2006-02-03 12:01:24.000000000 +0100
+++ good.txt	2006-02-03 11:47:59.000000000 +0100
@@ -34,12 +34,20 @@
 GMT Delta read from XPRAM: 120 minutes, DST: on
 time_init: decrementer frequency = 33.290001 MHz
 time_init: processor frequency   = 466.666665 MHz
+HZ = 250 tb_freq = 33290001 tick_nsec = 4000000
+tb_to_xs = 810448dc5c2ca70 (old way)
+ticklen_to_xs = 0 10e9155d07742ee3
+tb_to_xs = 8104491d617e483 (new way)
 Console: colour dummy device 80x25
 pmac_zilog: i2c-modem detected, id: 1
 Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
 Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
+oops, time got ahead: 1138967190.003999 > 1138959990.000000000
+  xtime was 0.000000000 tb was 0 tick 909725147
+  tlen 0x3d0900000 tb now 909726490 tpj 133160
+  gtod tbstamp 909591987 xsec 0x43e3429600000 t2x 0x8104491d617e483
 High memory: 0k
-Memory: 251768k/262144k available (3416k kernel code, 10064k reserved, 556k data, 467k bss, 196k init)
+Memory: 251768k/262144k available (3420k kernel code, 10072k reserved, 556k data, 467k bss, 196k init)
 Calibrating delay loop... 66.30 BogoMIPS (lpj=132608)
 Security Framework v1.0.0 initialized
 Mount-cache hash table entries: 512
@@ -71,7 +79,7 @@
 TC classifier action (bugs to netdev@vger.kernel.org cc hadi@cyberus.ca)
 Thermal assist unit using timers, shrink_timer: 500 jiffies
 audit: initializing netlink socket (disabled)
-audit(1138960784.708:1): initialized
+audit(1138959990.708:1): initialized
 VFS: Disk quotas dquot_6.5.1
 Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
 Initializing Cryptographic API
@@ -198,8 +206,8 @@
 ide-floppy driver 0.99.newide
 hdd: No disk in drive
 hdd: 0kB, 0/64/32 CHS, 4096 kBps, 512 sector size, 2941 rpm
-device-mapper: 4.5.0-ioctl (2005-10-04) initialised: dm-devel@redhat.com
-dm-netlink version 0.0.2 loaded
+hdc: ATAPI 32X CD-ROM CD-R/RW drive, 4096kB Cache, (U)DMA
+Uniform CD-ROM driver Revision: 3.20
 USB Universal Host Controller Interface driver v2.3
 PCI: Enabling device 0001:10:12.0 (0014 -> 0015)
 PCI: Via IRQ fixup for 0001:10:12.0, from 52 to 4
@@ -241,34 +249,36 @@
 usb usb5: configuration #1 chosen from 1 choice
 hub 5-0:1.0: USB hub found
 hub 5-0:1.0: 4 ports detected
-hdc: ATAPI 32X CD-ROM CD-R/RW drive, 4096kB Cache, (U)DMA
-Uniform CD-ROM driver Revision: 3.20
 8139too Fast Ethernet driver 0.9.27
+sungem.c:v0.98 8/24/03 David S. Miller (davem@redhat.com)
 PCI: Enabling device 0001:10:14.0 (0004 -> 0007)
-eth0: RealTek RTL8139 at 0xd106e000, 00:50:fc:76:65:12, IRQ 54
+eth0: RealTek RTL8139 at 0xd105a000, 00:50:fc:76:65:12, IRQ 54
 eth0:  Identified 8139 chip type 'RTL-8100B/8139D'
-8139cp: 10/100 PCI Ethernet driver v1.2 (Mar 22, 2004)
-sungem.c:v0.98 8/24/03 David S. Miller (davem@redhat.com)
 PHY ID: 206053, addr: 0
+eth1: Sun GEM (PCI) 10/100/1000BaseT Ethernet 00:30:65:f3:4c:ae 
+eth1: Found BCM5401 PHY
+8139cp: 10/100 PCI Ethernet driver v1.2 (Mar 22, 2004)
 ieee1394: Initialized config rom entry `ip1394'
+JBD: barrier-based sync failed on hda13 - disabling barriers
 PCI: Enabling device 0001:10:12.3 (0090 -> 0093)
 PCI: Via IRQ fixup for 0001:10:12.3, from 52 to 4
 ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[52]  MMIO=[80084000-800847ff]  Max Packet=[2048]  IR/IT contexts=[8/8]
-eth1: Sun GEM (PCI) 10/100/1000BaseT Ethernet 00:30:65:f3:4c:ae 
-eth1: Found BCM5401 PHY
 ohci1394: fw-host1: Unexpected PCI resource length of 1000!
 ohci1394: fw-host1: OHCI-1394 1.0 (PCI): IRQ=[40]  MMIO=[f5000000-f50007ff]  Max Packet=[2048]  IR/IT contexts=[8/8]
-JBD: barrier-based sync failed on hda13 - disabling barriers
 ieee1394: Host added: ID:BUS[0-00:1023]  GUID[0011060000006685]
-ieee1394: Host added: ID:BUS[1-00:1023]  GUID[003065fffef34cae]
 eth1: Link is up at 100 Mbps, full-duplex.
+ieee1394: Host added: ID:BUS[1-00:1023]  GUID[003065fffef34cae]
+device-mapper: 4.5.0-ioctl (2005-10-04) initialised: dm-devel@redhat.com
+dm-netlink version 0.0.2 loaded
+hdd: No disk in drive
 loop: loaded (max 8 devices)
 kjournald starting.  Commit interval 5 seconds
 EXT3 FS on hda14, internal journal
 EXT3-fs: mounted filesystem with ordered data mode.
 AppArmor: AppArmor (version 2.0-19.43r6152) initialized
-audit(1138960811.468:2): AppArmor (version 2.0-19.43r6152) initialized
+audit(1138960018.908:2): AppArmor (version 2.0-19.43r6152) initialized
 
+do_settimeofday(1138963619.000000000)
 eth1: Link is up at 100 Mbps, full-duplex.
 eth1: Pause is enabled (rxfifo: 10240 off: 7168 on: 5632)
 NET: Registered protocol family 10

[-- Attachment #2: good.txt --]
[-- Type: text/plain, Size: 13934 bytes --]

Total memory = 256MB; using 512kB for hash table (at cff80000)
Linux version 2.6.16-rc3-git3-20060215_bug149895-default (geeko@buildhost) (gcc version 4.1.0 20060210 (prerelease) (SUSE Linux)) #1 Wed Feb 15 00:20:20 UTC 2006
Found initrd at 0xc0a00000:0xc0c2a000
Found UniNorth memory controller & host bridge @ 0xf8000000 revision: 0x11
Mapped at 0xfdfc0000
Found a Keylargo mac-io controller, rev: 3, mapped at 0xfdf40000
Processor NAP mode on idle enabled.
PowerMac motherboard: PowerMac G4 Silver
Using native/NAP idle loop
Found UniNorth PCI host bridge at 0xf0000000. Firmware bus number: 0->0
Found UniNorth PCI host bridge at 0xf2000000. Firmware bus number: 0->0
Found UniNorth PCI host bridge at 0xf4000000. Firmware bus number: 0->0
via-pmu: Server Mode is disabled
PMU driver v2 initialized for Core99, firmware: 0c
nvram: Checking bank 0...
nvram: gen0=348, gen1=347
nvram: Active bank is: 0
nvram: OF partition at 0x210
nvram: XP partition at 0x1220
nvram: NR partition at 0x1320
Top of RAM: 0x10000000, Total RAM: 0x10000000
Memory hole size: 0MB
On node 0 totalpages: 65536
  DMA zone: 65536 pages, LIFO batch:15
  DMA32 zone: 0 pages, LIFO batch:0
  Normal zone: 0 pages, LIFO batch:0
  HighMem zone: 0 pages, LIFO batch:0
Built 1 zonelists
Kernel command line: root=/dev/hda13  quiet video=aty128fb:1024x768@85 sysrq=1 
mpic: Setting up MPIC " MPIC 1   " version 1.2 at 80040000, max 4 CPUs
mpic: ISU size: 64, shift: 6, mask: 3f
mpic: Initializing for 64 sources
PID hash table entries: 2048 (order: 11, 32768 bytes)
GMT Delta read from XPRAM: 120 minutes, DST: on
time_init: decrementer frequency = 33.290001 MHz
time_init: processor frequency   = 466.666665 MHz
HZ = 250 tb_freq = 33290001 tick_nsec = 4000000
tb_to_xs = 810448dc5c2ca70 (old way)
ticklen_to_xs = 0 10e9155d07742ee3
tb_to_xs = 8104491d617e483 (new way)
Console: colour dummy device 80x25
pmac_zilog: i2c-modem detected, id: 1
Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
oops, time got ahead: 1138967190.003999 > 1138959990.000000000
  xtime was 0.000000000 tb was 0 tick 909725147
  tlen 0x3d0900000 tb now 909726490 tpj 133160
  gtod tbstamp 909591987 xsec 0x43e3429600000 t2x 0x8104491d617e483
High memory: 0k
Memory: 251768k/262144k available (3420k kernel code, 10072k reserved, 556k data, 467k bss, 196k init)
Calibrating delay loop... 66.30 BogoMIPS (lpj=132608)
Security Framework v1.0.0 initialized
Mount-cache hash table entries: 512
device-tree: property "l2-cache" name conflicts with node in /cpus/PowerPC,G4@0
checking if image is initramfs... it is
Freeing initrd memory: 2216k freed
NET: Registered protocol family 16
KeyWest i2c @0xf8001003 irq 42 /uni-n@f8000000/i2c@f8001000
 channel 0 bus <multibus>
 channel 1 bus <multibus>
KeyWest i2c @0x80018000 irq 26 /pci@f2000000/mac-io@17/i2c@18000
 channel 0 bus <multibus>
PMU i2c /pci@f2000000/mac-io@17/via-pmu@16000
 channel 1 bus <multibus>
 channel 2 bus <multibus>
Installing base platform functions...
Installing MMIO functions for macio /pci@f2000000/mac-io@17
Installing GPIO functions for macio /pci@f2000000/mac-io@17
Calling initial GPIO functions for macio /pci@f2000000/mac-io@17
Installing functions for UniN /uni-n@f8000000
All base functions installed
PCI: Probing PCI hardware
PCI: Cannot allocate resource region 4 of device 0001:10:12.0
PCI: Cannot allocate resource region 4 of device 0001:10:12.1
PCI: Cannot allocate resource region 1 of device 0001:10:12.3
PCI: Cannot allocate resource region 0 of device 0001:10:14.0
usbcore: registered new driver usbfs
usbcore: registered new driver hub
TC classifier action (bugs to netdev@vger.kernel.org cc hadi@cyberus.ca)
Thermal assist unit using timers, shrink_timer: 500 jiffies
audit: initializing netlink socket (disabled)
audit(1138959990.708:1): initialized
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
Initializing Cryptographic API
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
PCI: Enabling device 0000:00:10.0 (0086 -> 0087)
aty128fb: Invalid ROM signature 1111 should  be 0xaa55
aty128fb: BIOS not located, guessing timings.
aty128fb: Rage128 PF PRO AGP [chip rev 0x1] 16M 128-bit SDR SGRAM (1:1)
Console: switching to colour frame buffer device 128x48
fb0: ATY Rage128 frame buffer device on Rage128 PF PRO AGP
Generic RTC Driver v1.07
Macintosh non-volatile memory driver v1.1
pmac_zilog: 0.6 (Benjamin Herrenschmidt <benh@kernel.crashing.org>)
ttyS0 at MMIO 0x80013020 (irq = 22) is a Z85c30 ESCC - Internal modem
ttyS1 at MMIO 0x80013000 (irq = 50) is a Z85c30 ESCC - Serial port
RAMDISK driver initialized: 16 RAM disks of 123456K size 1024 blocksize
MacIO PCI driver attached to Keylargo chipset
input: Macintosh mouse button emulation as /class/input/input0
apm_emu: APM Emulation 0.5 initialized.
adb: starting probe task...
adb: finished probe task...
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
ide0: Found Apple KeyLargo ATA-4 controller, bus ID 2, irq 19
Probing IDE interface ide0...
hda: Maxtor 33073H3 B, ATA DISK drive
hda: Enabling Ultra DMA 4
ide0 at 0xd1024000-0xd1024007,0xd1024160 on irq 19
ide1: Found Apple KeyLargo ATA-3 controller, bus ID 0, irq 20
Probing IDE interface ide1...
hdc: SONY CD-RW CRX140E, ATAPI CD/DVD-ROM drive
hdd: IOMEGA ZIP 250 ATAPI, ATAPI FLOPPY drive
hdc: Enabling MultiWord DMA 2
ide1 at 0xd1026000-0xd1026007,0xd1026160 on irq 20
ide2: Found Apple KeyLargo ATA-3 controller, bus ID 1, irq 21
Probing IDE interface ide2...
Probing IDE interface ide2...
hda: max request size: 128KiB
hda: 60032448 sectors (30736 MB) w/2048KiB Cache, CHS=59556/16/63, UDMA(66)
hda: cache flushes not supported
 hda: [mac] hda1 hda2 hda3 hda4 hda5 hda6 hda7 hda8 hda9 hda10 hda11 hda12 hda13 hda14 hda15
ohci_hcd: 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
PCI: Enabling device 0001:10:18.0 (0000 -> 0002)
ohci_hcd 0001:10:18.0: OHCI Host Controller
ohci_hcd 0001:10:18.0: new USB bus registered, assigned bus number 1
ohci_hcd 0001:10:18.0: irq 27, io mem 0x80083000
usb usb1: new device found, idVendor=0000, idProduct=0000
usb usb1: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: OHCI Host Controller
usb usb1: Manufacturer: Linux 2.6.16-rc3-git3-20060215_bug149895-default ohci_hcd
usb usb1: SerialNumber: 0001:10:18.0
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
PCI: Enabling device 0001:10:19.0 (0000 -> 0002)
ohci_hcd 0001:10:19.0: OHCI Host Controller
ohci_hcd 0001:10:19.0: new USB bus registered, assigned bus number 2
ohci_hcd 0001:10:19.0: irq 28, io mem 0x80082000
usb usb2: new device found, idVendor=0000, idProduct=0000
usb usb2: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb2: Product: OHCI Host Controller
usb usb2: Manufacturer: Linux 2.6.16-rc3-git3-20060215_bug149895-default ohci_hcd
usb usb2: SerialNumber: 0001:10:19.0
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
usb 1-1: new full speed USB device using ohci_hcd and address 2
usb 1-1: new device found, idVendor=05ac, idProduct=1001
usb 1-1: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 1-1: Product: Hub in Apple USB Keyboard
usb 1-1: Manufacturer: Alps Electric
usb 1-1: configuration #1 chosen from 1 choice
hub 1-1:1.0: USB hub found
hub 1-1:1.0: 3 ports detected
usb 1-1.1: new low speed USB device using ohci_hcd and address 3
usb 1-1.1: new device found, idVendor=05ac, idProduct=0202
usb 1-1.1: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 1-1.1: Product: Apple USB Keyboard
usb 1-1.1: Manufacturer: Alps Electric
usb 1-1.1: configuration #1 chosen from 1 choice
usb 1-1.3: new low speed USB device using ohci_hcd and address 4
usb 1-1.3: new device found, idVendor=05ac, idProduct=0307
usb 1-1.3: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 1-1.3: Product: Apple Optical USB Mouse
usb 1-1.3: Manufacturer: Logitech
usb 1-1.3: configuration #1 chosen from 1 choice
usbcore: registered new driver hiddev
input: Alps Electric Apple USB Keyboard as /class/input/input1
input: USB HID v1.00 Keyboard [Alps Electric Apple USB Keyboard] on usb-0001:10:18.0-1.1
input: Logitech Apple Optical USB Mouse as /class/input/input2
input: USB HID v1.10 Mouse [Logitech Apple Optical USB Mouse] on usb-0001:10:18.0-1.3
usbcore: registered new driver usbhid
drivers/usb/input/hid-core.c: v2.6:USB HID core driver
mice: PS/2 mouse device common for all mice
PowerMac i2c bus pmu 2 registered
PowerMac i2c bus pmu 1 registered
PowerMac i2c bus mac-io 0 registered
PowerMac i2c bus uni-n 1 registered
PowerMac i2c bus uni-n 0 registered
md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
md: bitmap version 4.39
NET: Registered protocol family 2
IP route cache hash table entries: 4096 (order: 2, 16384 bytes)
TCP established hash table entries: 16384 (order: 6, 262144 bytes)
TCP bind hash table entries: 16384 (order: 6, 327680 bytes)
TCP: Hash tables configured (established 16384 bind 16384)
TCP reno registered
TCP westwood registered
TCP htcp registered
NET: Registered protocol family 1
NET: Registered protocol family 17
Freeing unused kernel memory: 196k init
kjournald starting.  Commit interval 5 seconds
EXT3-fs: mounted filesystem with ordered data mode.
Adding 131064k swap on /dev/hda12.  Priority:-1 extents:1 across:131064k
EXT3 FS on hda13, internal journal
Linux agpgart interface v0.101 (c) Dave Jones
agpgart: Detected Apple UniNorth 1.5 chipset
agpgart: configuring for size idx: 4
agpgart: AGP aperture is 16M @ 0x0
ide-floppy driver 0.99.newide
hdd: No disk in drive
hdd: 0kB, 0/64/32 CHS, 4096 kBps, 512 sector size, 2941 rpm
hdc: ATAPI 32X CD-ROM CD-R/RW drive, 4096kB Cache, (U)DMA
Uniform CD-ROM driver Revision: 3.20
USB Universal Host Controller Interface driver v2.3
PCI: Enabling device 0001:10:12.0 (0014 -> 0015)
PCI: Via IRQ fixup for 0001:10:12.0, from 52 to 4
uhci_hcd 0001:10:12.0: UHCI Host Controller
uhci_hcd 0001:10:12.0: new USB bus registered, assigned bus number 3
uhci_hcd 0001:10:12.0: irq 52, io base 0x00010000
usb usb3: new device found, idVendor=0000, idProduct=0000
usb usb3: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb3: Product: UHCI Host Controller
usb usb3: Manufacturer: Linux 2.6.16-rc3-git3-20060215_bug149895-default uhci_hcd
usb usb3: SerialNumber: 0001:10:12.0
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
PCI: Enabling device 0001:10:12.1 (0014 -> 0015)
PCI: Via IRQ fixup for 0001:10:12.1, from 52 to 4
uhci_hcd 0001:10:12.1: UHCI Host Controller
uhci_hcd 0001:10:12.1: new USB bus registered, assigned bus number 4
uhci_hcd 0001:10:12.1: irq 52, io base 0x00010020
usb usb4: new device found, idVendor=0000, idProduct=0000
usb usb4: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb4: Product: UHCI Host Controller
usb usb4: Manufacturer: Linux 2.6.16-rc3-git3-20060215_bug149895-default uhci_hcd
usb usb4: SerialNumber: 0001:10:12.1
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
PCI: Enabling device 0001:10:12.2 (0014 -> 0016)
PCI: Via IRQ fixup for 0001:10:12.2, from 52 to 4
ehci_hcd 0001:10:12.2: EHCI Host Controller
ehci_hcd 0001:10:12.2: new USB bus registered, assigned bus number 5
ehci_hcd 0001:10:12.2: irq 52, io mem 0x80081000
ehci_hcd 0001:10:12.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb5: new device found, idVendor=0000, idProduct=0000
usb usb5: new device strings: Mfr=3, Product=2, SerialNumber=1
usb usb5: Product: EHCI Host Controller
usb usb5: Manufacturer: Linux 2.6.16-rc3-git3-20060215_bug149895-default ehci_hcd
usb usb5: SerialNumber: 0001:10:12.2
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 4 ports detected
8139too Fast Ethernet driver 0.9.27
sungem.c:v0.98 8/24/03 David S. Miller (davem@redhat.com)
PCI: Enabling device 0001:10:14.0 (0004 -> 0007)
eth0: RealTek RTL8139 at 0xd105a000, 00:50:fc:76:65:12, IRQ 54
eth0:  Identified 8139 chip type 'RTL-8100B/8139D'
PHY ID: 206053, addr: 0
eth1: Sun GEM (PCI) 10/100/1000BaseT Ethernet 00:30:65:f3:4c:ae 
eth1: Found BCM5401 PHY
8139cp: 10/100 PCI Ethernet driver v1.2 (Mar 22, 2004)
ieee1394: Initialized config rom entry `ip1394'
JBD: barrier-based sync failed on hda13 - disabling barriers
PCI: Enabling device 0001:10:12.3 (0090 -> 0093)
PCI: Via IRQ fixup for 0001:10:12.3, from 52 to 4
ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[52]  MMIO=[80084000-800847ff]  Max Packet=[2048]  IR/IT contexts=[8/8]
ohci1394: fw-host1: Unexpected PCI resource length of 1000!
ohci1394: fw-host1: OHCI-1394 1.0 (PCI): IRQ=[40]  MMIO=[f5000000-f50007ff]  Max Packet=[2048]  IR/IT contexts=[8/8]
ieee1394: Host added: ID:BUS[0-00:1023]  GUID[0011060000006685]
eth1: Link is up at 100 Mbps, full-duplex.
ieee1394: Host added: ID:BUS[1-00:1023]  GUID[003065fffef34cae]
device-mapper: 4.5.0-ioctl (2005-10-04) initialised: dm-devel@redhat.com
dm-netlink version 0.0.2 loaded
hdd: No disk in drive
loop: loaded (max 8 devices)
kjournald starting.  Commit interval 5 seconds
EXT3 FS on hda14, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
AppArmor: AppArmor (version 2.0-19.43r6152) initialized
audit(1138960018.908:2): AppArmor (version 2.0-19.43r6152) initialized

do_settimeofday(1138963619.000000000)
eth1: Link is up at 100 Mbps, full-duplex.
eth1: Pause is enabled (rxfifo: 10240 off: 7168 on: 5632)
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
IPv6 over IPv4 tunneling driver
JBD: barrier-based sync failed on hda13 - disabling barriers
JBD: barrier-based sync failed on hda13 - disabling barriers

Re: 2.6.16-rc2 powerpc timestamp skew

[Mikael Pettersson]

Paul Mackerras writes:
 > Benjamin Herrenschmidt writes:
 > 
 > > Ok, does not using NTP fixes it ?
 > 
 > Try this patch.  With this the values from gettimeofday() or the VDSO
 > should stay exactly in sync with xtime even if NTP is adjusting the
 > clock.
 > 
 > This patch still has quite a few debugging printks in it, so it's not
 > final by any means.  I'll be interested to hear how it goes, and in
 > particular whether or not you see any "oops, time got ahead" messages.

This patch fixed the clock skew issues (warnings from 'make' while
building new kernels) my G4 eMac has been having since about 2.6.15.
User-space is YDL4.0 and ntpd is used to maintain a correct clock.

/Mikael

Re: 2.6.16-rc2 powerpc timestamp skew

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 1100 bytes --]

Paul Mackerras <paulus@samba.org> writes:

> Benjamin Herrenschmidt writes:
>
>> Ok, does not using NTP fixes it ?
>
> Try this patch.  With this the values from gettimeofday() or the VDSO
> should stay exactly in sync with xtime even if NTP is adjusting the
> clock.
>
> This patch still has quite a few debugging printks in it, so it's not
> final by any means.  I'll be interested to hear how it goes, and in
> particular whether or not you see any "oops, time got ahead" messages.

Without your patch, the clock works perfectly when NTP is not in use,
but when NTP is in use I get a large amount of skew (3 min) after
about half an hour.

With your patch (tested against 2.6.16-rc3), there is no skew whether
NTP is running or not, and the system has been up 90 mins so far.
They two times appear to be the same.


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: Type: application/pgp-signature, Size: 188 bytes --]

Re: 2.6.16-rc2 powerpc timestamp skew

[Andrew Morton]

Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
>
> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
>  Freescale 7447A):
> 
>  $ date && touch f && ls -l f && rm -f f && date
>  Sun Feb 12 12:20:14 GMT 2006
>  -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
>  Sun Feb 12 12:20:14 GMT 2006
> 
>  Notice the timestamp is 3 minutes in the future compared with the
>  system time.  "make" is not a very happy bunny running on this kernel
>  due to every touched file being 3 minutes in the future.

I've had several spates of time-going-nuts on ppc64.  The most recent one
was because someone went and fiddled with Kconfig naming and I lost the RTC
driver.

What does `grep RTC .config' say?

Re: 2.6.16-rc2 powerpc timestamp skew

[Roger Leigh]

[-- Attachment #1: Type: text/plain, Size: 1194 bytes --]

Andrew Morton <akpm@osdl.org> writes:

> Roger Leigh <rleigh@whinlatter.ukfsn.org> wrote:
>>
>> When running a 2.6.16-rc2 kernel on a powerpc system (Mac Mini;
>>  Freescale 7447A):
>> 
>>  $ date && touch f && ls -l f && rm -f f && date
>>  Sun Feb 12 12:20:14 GMT 2006
>>  -rw-r--r-- 1 rleigh rleigh 0 2006-02-12 12:23
>>  Sun Feb 12 12:20:14 GMT 2006
>> 
>>  Notice the timestamp is 3 minutes in the future compared with the
>>  system time.  "make" is not a very happy bunny running on this kernel
>>  due to every touched file being 3 minutes in the future.
>
> I've had several spates of time-going-nuts on ppc64.  The most recent one
> was because someone went and fiddled with Kconfig naming and I lost the RTC
> driver.
>
> What does `grep RTC .config' say?

CONFIG_GEN_RTC=y
CONFIG_GEN_RTC_X=y
CONFIG_SENSORS_RTC8564=m
CONFIG_RTC_X1205_I2C=m

This is just ppc, not ppc64, BTW:
$ uname -m
ppc


Regards,
Roger

-- 
Roger Leigh
                Printing on GNU/Linux?  http://gutenprint.sourceforge.net/
                Debian GNU/Linux        http://www.debian.org/
                GPG Public Key: 0x25BFB848.  Please sign and encrypt your mail.

[-- Attachment #2: Type: application/pgp-signature, Size: 188 bytes --]

[PATCH] powerpc: dont allow old RTC to be selected

[Anton Blanchard]

> I've had several spates of time-going-nuts on ppc64.  The most recent one
> was because someone went and fiddled with Kconfig naming and I lost the RTC
> driver.

This might help a bit:


Now powerpc uses the generic RTC stuff we should not enable the old
RTC. Doing so will result in hangs at boot.

Signed-off-by: Anton Blanchard <anton@samba.org>
---

Index: build/drivers/char/Kconfig
===================================================================
--- build.orig/drivers/char/Kconfig	2006-02-09 11:35:15.000000000 +1100
+++ build/drivers/char/Kconfig	2006-02-13 14:55:22.000000000 +1100
@@ -695,7 +695,7 @@ config NVRAM
 
 config RTC
 	tristate "Enhanced Real Time Clock Support"
-	depends on !PPC32 && !PARISC && !IA64 && !M68K && (!SPARC || PCI) && !FRV
+	depends on !PPC && !PARISC && !IA64 && !M68K && (!SPARC || PCI) && !FRV
 	---help---
 	  If you say Y here and create a character special file /dev/rtc with
 	  major number 10 and minor number 135 using mknod ("man mknod"), you