Re: [PATCH RFC] x86, tsc: Allow for high latency in quick_pit_calibrate()

["George Spelvin" <linux@horizon.com>]

> I'll run your code as well, to make sure it's not something bad in my code.

Here's a modified version that uses less stack space (no need to store
all 64 bits of a timestamp), and captures a window around an RTC periodic
flag edge to explore WTF is going on there.

commit 769eba0b589141edca3541cfb1e30e01b806e5cb
Author: George Spelvin <linux@horizon.com>
Date:   Thu Jun 4 22:04:19 2015 -0400

    x86, tsc: Add test code.

diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index a00f35be..00ff0359 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -22,6 +22,8 @@
 #include <asm/nmi.h>
 #include <asm/x86_init.h>
 
+#include <asm/mc146818rtc.h>
+
 unsigned int __read_mostly cpu_khz;	/* TSC clocks / usec, not used here */
 EXPORT_SYMBOL(cpu_khz);
 
@@ -533,15 +535,15 @@ static inline int pit_verify_msb(unsigned char val)
 
 static inline int pit_expect_msb(unsigned char val, u64 *tscp, unsigned long *deltap)
 {
-	int count;
-	u64 tsc = 0, prev_tsc = 0;
+	int count = 0;
+	u64 prev_tsc, tsc = 0;
 
-	for (count = 0; count < 50000; count++) {
-		if (!pit_verify_msb(val))
-			break;
+	do {
+		if (++count > 50000)
+			return 0;
 		prev_tsc = tsc;
 		tsc = get_cycles();
-	}
+	} while (pit_verify_msb(val));
 	*deltap = get_cycles() - prev_tsc;
 	*tscp = tsc;
 
@@ -552,6 +554,177 @@ static inline int pit_expect_msb(unsigned char val, u64 *tscp, unsigned long *de
 	return count > 5;
 }
 
+/* Similar, but only a single read.  And returns the number of reads. */
+static inline unsigned
+pit_expect_msb1(unsigned char val, unsigned *tscp, unsigned *deltap)
+{
+	int count = 0;
+	unsigned prev_tsc, tsc = 0;
+
+	do {
+		if (++count > 50000)
+			return 0;
+		prev_tsc = tsc;
+		tsc = (unsigned)get_cycles();
+	} while (inb(0x42) == val);
+	*deltap = (unsigned)get_cycles() - prev_tsc;
+	*tscp = tsc;
+
+	return count;
+}
+
+static inline unsigned
+rtc_wait_bit(unsigned *tscp, unsigned *deltap)
+{
+	int count = 0;
+	unsigned prev_tsc, tsc = 0;
+
+	do {
+		if (++count > 5000)
+			return 0;
+		prev_tsc = tsc;
+		tsc = (unsigned)get_cycles();
+	} while (~inb(RTC_PORT(1)) & RTC_PF);	/* Wait for bit 6 to be set */
+	*deltap = (unsigned)get_cycles() - prev_tsc;
+	*tscp = tsc;
+
+	/*
+	 * We require _some_ success, but the quality control
+	 * will be based on the error terms on the TSC values.
+	 */
+	return count;
+}
+
+#define SAMPLES 64
+
+static void noinline_for_stack
+pit_test(void)
+{
+	unsigned tsc[SAMPLES+1];	/* How long since rpevious edge */
+	unsigned range[SAMPLES+1];	/* Range of uncertainty */
+	unsigned iter[SAMPLES];	/*& Number of iterations for capture */
+	int i, j;
+	unsigned char saved_a, saved_b;
+	unsigned long flags;
+	extern spinlock_t rtc_lock;
+
+	outb(0xb0, 0x43);
+
+	/* Start at 0xffff */
+	outb(0xff, 0x42);
+	outb(0xff, 0x42);
+
+	pit_verify_msb(0);
+
+	/*
+	 * Among the evil non-portable hacks this code does, it exploits
+	 * the fact that x86 is little-endian and allows unaligned stores
+	 * to store 64-bit values into an array of 32-bit values, where
+	 * each one overwrites the high half of the one before.
+	 */
+	if (pit_expect_msb(0xff, (u64 *)tsc, (unsigned long *)range)) {
+		for (i = 1; i < SAMPLES; i++) {
+			if (!pit_expect_msb(0xff - i, (u64 *)(tsc+i), (unsigned long *)(range+i)))
+				break;
+			if (!pit_verify_msb(0xfe - i))
+				break;
+		}
+		printk("** 2-byte PIT timing\n");
+		for (j = 1; j < i; j++)
+			printk("PIT edge delta %7u, range %6u\n",
+				tsc[j] - tsc[j-1], range[j]);
+	}
+
+	/* Try again, with one-byte reads */
+	outb(0xa0, 0x43);
+	outb(0xff, 0x42);	/* Start at 0xff00 */
+
+	/* Wait until we reach 0xfe (should be very fast) */
+	pit_verify_msb(0);
+	for (i = 0; i < 1000; i++)
+		if (inb(0x42) == 0xfe)
+			break;
+
+	if (i < 1000) {
+		for (i = 0; i < SAMPLES; i++) {
+			iter[i] = pit_expect_msb1(0xfe - i, tsc+i, range+i);
+			if (iter[i] <= 5)
+				break;
+			if (inb(0x42) != 0xfd - i)
+				break;
+		}
+		printk("** 1-byte PIT timing\n");
+		for (j = 1; j < i; j++)
+			printk("PIT edge delta %7u, range %6u, iter %u\n",
+				tsc[j] - tsc[j-1], range[j], iter[j]);
+	}
+
+	/* Once more, with the RTC */
+	spin_lock_irqsave(&rtc_lock, flags);
+
+	lock_cmos_prefix(RTC_REG_C);
+/* This is skanky stuff that requries rewritten RTC locking to do properly */
+	outb(RTC_REG_B, RTC_PORT(0));
+	saved_b = inb(RTC_PORT(1));
+	outb(saved_b & 7, RTC_PORT(1));	/* Clear interrupt enables */
+
+	outb(RTC_REG_A, RTC_PORT(0));
+	saved_a = inb(RTC_PORT(1));
+	outb((saved_a & 0xf0) | 3, RTC_PORT(1));	/* Set 8 kHz rate */
+/* End of skanky stuff */
+
+	outb(RTC_REG_C, RTC_PORT(0));
+	inb(RTC_PORT(1));	/* Clear any pending */
+
+	for (i = 0; i < SAMPLES; i++) {
+		iter[i] = rtc_wait_bit(tsc+i, range+i);
+		if (iter[i] <= 3)
+			break;
+		if (inb(RTC_PORT(1)) & RTC_PF)
+			break;
+	}
+
+	lock_cmos_suffix(RTC_REG_C);
+	spin_unlock_irqrestore(&rtc_lock, flags);
+
+	printk("** RTC timing\n");
+	for (j = 1; j < i; j++) {
+		printk("RTC edge delta %7u, range %6u, iter %u\n",
+			tsc[j] - tsc[j-1],  range[j], iter[j]);
+	}
+
+	/* Collect different statistics: per-read timing */
+	spin_lock_irqsave(&rtc_lock, flags);
+	lock_cmos_prefix(RTC_REG_C);
+	outb(RTC_REG_C, RTC_PORT(0));
+	inb(RTC_PORT(1));	/* Clear any pending */
+
+	/* Capture a series of timestamps straddling a bit change */
+	j = 10000;
+	for (i = 0; i < j; i++) {
+		tsc[i % (unsigned)SAMPLES] = (unsigned)get_cycles();
+		if (inb(RTC_PORT(1)) & RTC_PF && i >= SAMPLES/2 && j < 10000)
+			j = i + SAMPLES/2;
+	}
+
+	/* Restore the RTC state */
+	outb(RTC_REG_A, RTC_PORT(0));
+	outb(saved_a, RTC_PORT(1));
+	outb(RTC_REG_B, RTC_PORT(0));
+	outb(saved_b, RTC_PORT(1));
+
+	lock_cmos_suffix(RTC_REG_C);
+	spin_unlock_irqrestore(&rtc_lock, flags);
+
+	printk("** RTC timing details\n");
+	for (j = 1; j < SAMPLES; j++) {
+		unsigned k = i + j - SAMPLES;
+		printk("RTC sample %3d: %7u%s\n", k,
+			tsc[k % SAMPLES] - tsc[(k-1) % SAMPLES],
+			j == SAMPLES/2 ? " *" : "");
+	}
+}
+
 /*
  * How many MSB values do we want to see? We aim for
  * a maximum error rate of 500ppm (in practice the
@@ -570,6 +743,8 @@ static unsigned long quick_pit_calibrate(void)
 	/* Set the Gate high, disable speaker */
 	outb((inb(0x61) & ~0x02) | 0x01, 0x61);
 
+pit_test();
+
 	/*
 	 * Counter 2, mode 0 (one-shot), binary count
 	 *