From owner-freebsd-current@FreeBSD.ORG Thu Jun 16 06:43:02 2011 Return-Path: Delivered-To: freebsd-current@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 7DFE9106566C; Thu, 16 Jun 2011 06:43:02 +0000 (UTC) (envelope-from ianf@clue.co.za) Received: from inbound01.jnb1.gp-online.net (inbound01.jnb1.gp-online.net [41.154.0.151]) by mx1.freebsd.org (Postfix) with ESMTP id 72BEB8FC14; Thu, 16 Jun 2011 06:43:01 +0000 (UTC) Received: from [41.154.88.19] (helo=clue.co.za) by inbound01.jnb1.gp-online.net with esmtpsa (TLS-1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.63) (envelope-from ) id 1QX6I7-0006nK-3C; Thu, 16 Jun 2011 08:42:59 +0200 Received: from localhost ([127.0.0.1] helo=clue.co.za) by clue.co.za with esmtp (Exim 4.72 (FreeBSD)) (envelope-from ) id 1QX6I4-0000dH-4b; Thu, 16 Jun 2011 08:42:56 +0200 Message-Id: To: Jung-uk Kim From: Ian FREISLICH In-Reply-To: <201106151639.30308.jkim@FreeBSD.org> References: <201106151639.30308.jkim@FreeBSD.org> X-Attribution: BOFH Date: Thu, 16 Jun 2011 08:42:56 +0200 Cc: freebsd-current@FreeBSD.org Subject: Re: Time keeping Issues with the low-resolution TSC timecounter X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 16 Jun 2011 06:43:02 -0000 Jung-uk Kim wrote: > On Wednesday 15 June 2011 03:27 pm, Ian FREISLICH wrote: > > > Can you please show me verbose boot messages *without* your > > > patch? Does "sysctl kern.timecounter.hardware=HPET" help > > > *without* touching eventtimers? > > > > I have the same issue with my system (Atom N270). The effect that > > I see is about 29 wall clock seconds are recorded as 1 system > > second. > > Can please you send me output from the following? > > sh -c 'count=10; while [ $count -gt 0 ]; do count=$((count - 1));\ > sysctl kern.timecounter; sleep 1; done' Interesting it doesn't seem to be constant. While there was lots going on (launching exmh and scanning my mail folders opening and reading 20k files) keyboard repeats work as normal and xclock ticks one a second. When the activity stops, xclock ticks every 6 seconds. While the system clock recorded 10 seconds of wall clock, stopwatch ran for 42 seconds. Script started on Thu Jun 16 08:23:51 2011 [mini] /usr/home/ianf $ time sh -c 'count=10; while [ $count -gt 0 ]; do count=$((cou nt - 1)); sysctl kern.timecounter; sleep 1; done' kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 12748229 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3380795670 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 9828 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1915282150 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 4005701 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3480043331 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 22926 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1927865521 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 5223570 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3552023679 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 57522 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1940447630 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 5712953 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3621090061 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 45866 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1953031506 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 5262197 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3686395330 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 48107 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1965606144 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 4740225 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3751416462 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 27234 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1978190005 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 2658298 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3810197474 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 10285 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 1990767555 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 2336065 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3876017411 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 55956 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 2003351574 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 838327 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 3937135944 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 37164 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 2015929369 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 kern.timecounter.tick: 1 kern.timecounter.choice: TSC-low(1000) i8254(0) HPET(950) ACPI-fast(900) dummy(-1000000) kern.timecounter.hardware: TSC-low kern.timecounter.stepwarnings: 0 kern.timecounter.tc.ACPI-fast.mask: 16777215 kern.timecounter.tc.ACPI-fast.counter: 2857839 kern.timecounter.tc.ACPI-fast.frequency: 3579545 kern.timecounter.tc.ACPI-fast.quality: 900 kern.timecounter.tc.HPET.mask: 4294967295 kern.timecounter.tc.HPET.counter: 4012322248 kern.timecounter.tc.HPET.frequency: 14318180 kern.timecounter.tc.HPET.quality: 950 kern.timecounter.tc.i8254.mask: 65535 kern.timecounter.tc.i8254.counter: 11432 kern.timecounter.tc.i8254.frequency: 1193182 kern.timecounter.tc.i8254.quality: 0 kern.timecounter.tc.TSC-low.mask: 4294967295 kern.timecounter.tc.TSC-low.counter: 2028502028 kern.timecounter.tc.TSC-low.frequency: 12469046 kern.timecounter.tc.TSC-low.quality: 1000 kern.timecounter.smp_tsc: 1 kern.timecounter.invariant_tsc: 1 real 0m10.084s user 0m0.030s sys 0m0.045s [mini] /usr/home/ianf $ exit Script done on Thu Jun 16 08:24:04 2011 > > I had do something similar to the OP to make my system useable since > > it doesn't seem possible to influence timecounter choice at boot > > time. > > You can just add the following line in /etc/sysctl.conf for now: I set the quality to 800 in x86/x86/tsc.c. It makes the system start too slow to wait for rc.d/sysctl to execute. -- Ian Freislich