I'm experiencing time-related issues that seem to be caused by the low-resolution TSC timecounter (r222866). The problem I noticed first is that it takes unusually long until a key press is repeated. With the default eventtimer (HPET) it seems to take about 4s, which can be slightly improved by switching to i8254. The "error beep" seems to take longer than usual, too, and the system "feels sluggish" in general. An effect that is easier to measure is that the system is unable to properly keep the time. Again the problem is less severe when using i8254 instead of HPET: fk_at_r500 ~ $sudo sysctl kern.eventtimer.timer=HPET kern.eventtimer.timer: i8254 -> HPET fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Setting date via ntp. 13 Jun 14:30:34 ntpdate[4161]: step time server 72.14.179.211 offset 47.463608 sec Setting date via ntp. 13 Jun 14:30:52 ntpdate[4172]: step time server 178.26.114.66 offset 14.867148 sec Setting date via ntp. 13 Jun 14:31:12 ntpdate[4183]: step time server 178.26.114.66 offset 17.472867 sec Setting date via ntp. 13 Jun 14:31:37 ntpdate[4194]: step time server 72.14.179.211 offset 22.477665 sec Setting date via ntp. 13 Jun 14:31:51 ntpdate[4205]: step time server 178.26.114.66 offset 10.956637 sec Setting date via ntp. 13 Jun 14:32:11 ntpdate[4216]: step time server 178.26.114.66 offset 16.548800 sec ^C fk_at_r500 ~ $sudo sysctl kern.eventtimer.timer=i8254 kern.eventtimer.timer: HPET -> i8254 fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Setting date via ntp. 13 Jun 14:32:23 ntpdate[4240]: step time server 178.26.114.66 offset 8.713638 sec Setting date via ntp. 13 Jun 14:32:28 ntpdate[4251]: step time server 178.26.114.66 offset 1.630654 sec Setting date via ntp. 13 Jun 14:32:33 ntpdate[4262]: step time server 178.26.114.66 offset 2.317175 sec Setting date via ntp. 13 Jun 14:32:38 ntpdate[4273]: step time server 178.26.114.66 offset 2.174220 sec Setting date via ntp. 13 Jun 14:32:43 ntpdate[4284]: step time server 178.26.114.66 offset 1.775281 sec Setting date via ntp. 13 Jun 14:32:49 ntpdate[4295]: step time server 178.26.114.66 offset 2.223660 sec Setting date via ntp. 13 Jun 14:32:54 ntpdate[4306]: step time server 208.52.173.46 offset 1.900942 sec ^C fk_at_r500 ~ $sudo sysctl kern.eventtimer.timer=HPET kern.eventtimer.timer: i8254 -> HPET fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Setting date via ntp. 13 Jun 14:33:08 ntpdate[4319]: step time server 108.71.253.20 offset 9.740812 sec Setting date via ntp. 13 Jun 14:33:30 ntpdate[4330]: step time server 108.71.253.20 offset 19.046164 sec Setting date via ntp. 13 Jun 14:33:51 ntpdate[4341]: step time server 108.71.253.20 offset 18.489062 sec Setting date via ntp. 13 Jun 14:34:03 ntpdate[4352]: step time server 69.65.40.29 offset 8.659389 sec Setting date via ntp. 13 Jun 14:34:09 ntpdate[4363]: step time server 108.71.253.20 offset 2.868611 sec Setting date via ntp. 13 Jun 14:34:23 ntpdate[4374]: step time server 108.71.253.20 offset 10.798129 sec Setting date via ntp. 13 Jun 14:34:33 ntpdate[4407]: step time server 108.71.253.20 offset 6.919764 sec Setting date via ntp. 13 Jun 14:34:43 ntpdate[4422]: step time server 108.71.253.20 offset 7.135878 sec ^C fk_at_r500 ~ $sudo sysctl kern.eventtimer.timer=i8254 kern.eventtimer.timer: HPET -> i8254 fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Setting date via ntp. 13 Jun 14:34:56 ntpdate[4435]: step time server 108.71.253.20 offset 9.596463 sec Setting date via ntp. 13 Jun 14:35:02 ntpdate[4446]: step time server 108.71.253.20 offset 2.137592 sec Setting date via ntp. 13 Jun 14:35:07 ntpdate[4457]: step time server 108.71.253.20 offset 2.435011 sec Setting date via ntp. 13 Jun 14:35:13 ntpdate[4468]: step time server 108.71.253.20 offset 2.631290 sec Setting date via ntp. 13 Jun 14:35:18 ntpdate[4479]: step time server 108.71.253.20 offset 1.909570 sec Setting date via ntp. 13 Jun 14:35:24 ntpdate[4490]: step time server 108.71.253.20 offset 2.398583 sec Setting date via ntp. 13 Jun 14:35:29 ntpdate[4501]: step time server 108.71.253.20 offset 2.264760 sec Setting date via ntp. 13 Jun 14:35:34 ntpdate[4512]: step time server 108.71.253.20 offset 1.808083 sec Setting date via ntp. HPET1 to HPET3 seem to behave similar to HPET or at least the difference isn't significant enough to be obvious without running proper benchmarks. The cpu is: Calibrating TSC clock ... TSC clock: 1995043420 Hz CPU: Intel(R) Core(TM)2 Duo CPU T5870 _at_ 2.00GHz (1995.04-MHz K8-class CPU) Origin = "GenuineIntel" Id = 0x6fd Family = 6 Model = f Stepping = 13 Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE> Features2=0xe39d<SSE3,DTES64,MON,DS_CPL,EST,TM2,SSSE3,CX16,xTPR,PDCM> AMD Features=0x20100800<SYSCALL,NX,LM> AMD Features2=0x1<LAHF> TSC: P-state invariant, performance statistics With r222866, I get the message: "TSC timecounter discards lower 7 bit(s)" I'm using powerd, but killing it doesn't solve the issue. fk_at_r500 ~ $sysctl kern.eventtimer kern.eventtimer.choice: HPET(450) HPET1(440) HPET2(440) HPET3(440) i8254(100) kern.eventtimer.et.i8254.flags: 1 kern.eventtimer.et.i8254.frequency: 1193182 kern.eventtimer.et.i8254.quality: 100 kern.eventtimer.et.HPET.flags: 3 kern.eventtimer.et.HPET.frequency: 14318180 kern.eventtimer.et.HPET.quality: 450 kern.eventtimer.et.HPET1.flags: 3 kern.eventtimer.et.HPET1.frequency: 14318180 kern.eventtimer.et.HPET1.quality: 440 kern.eventtimer.et.HPET2.flags: 3 kern.eventtimer.et.HPET2.frequency: 14318180 kern.eventtimer.et.HPET2.quality: 440 kern.eventtimer.et.HPET3.flags: 3 kern.eventtimer.et.HPET3.frequency: 14318180 kern.eventtimer.et.HPET3.quality: 440 kern.eventtimer.periodic: 0 kern.eventtimer.timer: HPET kern.eventtimer.idletick: 0 kern.eventtimer.singlemul: 2 Things improve quite a bit with this patch: commit 4e7d41a5438a502f754d0e4b02c8eba5d0ae15a2 Author: Fabian Keil <fk_at_fabiankeil.de> Date: Mon Jun 13 17:07:46 2011 +0200 Do not mess with smp_tsc in test_smp_tsc() diff --git a/sys/x86/x86/tsc.c b/sys/x86/x86/tsc.c index 83eab4d..7a70484 100644 --- a/sys/x86/x86/tsc.c +++ b/sys/x86/x86/tsc.c _at__at_ -376,7 +376,8 _at__at_ test_smp_tsc(void) data = malloc(sizeof(*data) * size * N, M_TEMP, M_WAITOK); for (i = 0, tsc = data; i < N; i++, tsc += size) smp_rendezvous(tsc_read_0, tsc_read_1, tsc_read_2, tsc); - smp_tsc = 1; /* XXX */ + if (bootverbose) + printf("SMP: Keeping smp_tsc at %d\n", smp_tsc); smp_rendezvous(smp_no_rendevous_barrier, comp_smp_tsc, smp_no_rendevous_barrier, data); free(data, M_TEMP); fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Password: Setting date via ntp. 13 Jun 17:29:56 ntpdate[3464]: step time server 131.234.137.23 offset 1.748995 sec Setting date via ntp. 13 Jun 17:29:59 ntpdate[3475]: step time server 131.234.137.23 offset 0.001936 sec Setting date via ntp. 13 Jun 17:30:02 ntpdate[3486]: step time server 80.153.14.198 offset 0.023167 sec Setting date via ntp. 13 Jun 17:30:07 ntpdate[3508]: step time server 80.153.14.198 offset -0.002901 sec Setting date via ntp. 13 Jun 17:30:10 ntpdate[3519]: step time server 131.234.137.23 offset -0.022134 sec Setting date via ntp. 13 Jun 17:30:14 ntpdate[3530]: step time server 80.153.14.198 offset 0.014018 sec Setting date via ntp. 13 Jun 17:30:17 ntpdate[3541]: step time server 131.234.137.23 offset -0.014088 sec Setting date via ntp. 13 Jun 17:30:20 ntpdate[3552]: step time server 131.234.137.23 offset 0.000335 sec Setting date via ntp. 13 Jun 17:30:24 ntpdate[3563]: step time server 131.234.137.23 offset 0.001874 sec Setting date via ntp. 13 Jun 17:30:27 ntpdate[3574]: step time server 131.234.137.23 offset -0.002200 sec Setting date via ntp. 13 Jun 17:30:31 ntpdate[3585]: step time server 131.234.137.23 offset 0.000883 sec Setting date via ntp. 13 Jun 17:30:34 ntpdate[3596]: step time server 131.234.137.23 offset 0.000910 sec Setting date via ntp. 13 Jun 17:30:38 ntpdate[3607]: step time server 131.234.137.23 offset -0.001278 sec Setting date via ntp. 13 Jun 17:30:41 ntpdate[3618]: step time server 131.234.137.23 offset 0.001204 sec Setting date via ntp. 13 Jun 17:30:45 ntpdate[3629]: step time server 131.234.137.23 offset -0.001360 sec Setting date via ntp. 13 Jun 17:30:49 ntpdate[3640]: step time server 131.234.137.23 offset -0.000312 sec Setting date via ntp. 13 Jun 17:30:52 ntpdate[3651]: step time server 131.234.137.23 offset 0.000123 sec Setting date via ntp. 13 Jun 17:30:56 ntpdate[3662]: step time server 131.234.137.23 offset -0.000025 sec Setting date via ntp. 13 Jun 17:30:59 ntpdate[3673]: step time server 80.153.14.198 offset 0.020460 sec Setting date via ntp. 13 Jun 17:31:02 ntpdate[3684]: step time server 80.153.14.198 offset -0.009112 sec Setting date via ntp. 13 Jun 17:31:06 ntpdate[3695]: step time server 131.234.137.23 offset -0.009259 sec Setting date via ntp. 13 Jun 17:31:09 ntpdate[3706]: step time server 80.153.14.198 offset 0.026002 sec ^C I get the impression that the offsets are still a bit larger on average than with a kernel with sys/x86/x86/tsc.c from r222864, but haven't done enough tests to be sure: fk_at_r500 ~ $while sudo /etc/rc.d/ntpdate onestart; do sleep 1; done Setting date via ntp. 13 Jun 18:37:56 ntpdate[4404]: step time server 212.112.228.242 offset -0.003875 sec Setting date via ntp. 13 Jun 18:37:59 ntpdate[4415]: step time server 79.143.177.46 offset 0.003266 sec Setting date via ntp. 13 Jun 18:38:03 ntpdate[4426]: step time server 212.112.228.242 offset -0.003565 sec Setting date via ntp. 13 Jun 18:38:06 ntpdate[4437]: step time server 212.112.228.242 offset -0.000430 sec Setting date via ntp. 13 Jun 18:38:10 ntpdate[4448]: step time server 79.143.177.46 offset 0.004059 sec Setting date via ntp. 13 Jun 18:38:13 ntpdate[4459]: step time server 79.143.177.46 offset 0.000609 sec Setting date via ntp. 13 Jun 18:38:17 ntpdate[4470]: step time server 212.112.228.242 offset -0.003540 sec Setting date via ntp. 13 Jun 18:38:20 ntpdate[4481]: step time server 79.143.177.46 offset 0.003722 sec Setting date via ntp. 13 Jun 18:38:23 ntpdate[4492]: step time server 79.143.177.46 offset -0.000707 sec Setting date via ntp. 13 Jun 18:38:27 ntpdate[4503]: step time server 79.143.177.46 offset -0.000125 sec Setting date via ntp. 13 Jun 18:38:30 ntpdate[4514]: step time server 212.112.228.242 offset -0.003536 sec Setting date via ntp. Fabian
This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:14 UTC