Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
I also see these messages on my Dell 410 Workstation at work and a Dual
PIII Box I use at home to do builds with...they just seem to 'come and go'
with no particular pattern to them...I have just been ignoring them for the
most part...they don't really seem to cause any problems..
At 06:54 PM 2/17/2002 +1100, Bruce Evans wrote:
On Sat, 16 Feb 2002, Matthew Dillon wrote:
Testing with a 'make -j 10 buildworld' on a -current box I am getting
regular:
microuptime() went backwards (146.826785 - 146.156715)
microuptime() went backwards (146.826782 - 146.228636)
...
microuptime() went backwards (8945.938288 - 8945.251603)
microuptime() went backwards (8945.938306 - 8945.347173)
microuptime() went backwards (9142.847550 - 9142.847546)
This occurs both with and without the gettimeofday Giant-removal patch, so
I am fairly sure it has nothing to do with any of my current work. This is
running -current on a DELL2550 (2xCPUs), compiled with the SMP option.
The fact that the timecounter usually goes backwards by about 0.68 seconds
is probably significant, but I can't quite explain it.
Timecounter i8254 frequency 1193182 Hz
...
Timecounter ACPI frequency 3579545 Hz
acpi_timer0: 32-bit timer at 3.579545MHz port 0x808-0x80b on acpi0
acpi_cpu0: CPU on acpi0
acpi_cpu1: CPU on acpi0
acpi_pcib0: Host-PCI bridge on acpi0
...
Question: How can this be occuring at all? Isn't the ACPI counter a
32 bit counter that does not have the rollover problems that the 8254 timer
has?
Timecounters go backwards when the timecounter update or reference code is
called insufficiently often to prevent overflow. The rollover problems of
the i8254 timecounter actually reduce this problem. If an i8254 rollover
is missed, then it causes the the i8254 timecounter to go forward less
than it should.
I just wrote the following fix for some of the overflow problems.
%%%
Index: kern_tc.c
===
RCS file: /home/ncvs/src/sys/kern/kern_tc.c,v
retrieving revision 1.113
diff -c -2 -r1.113 kern_tc.c
*** kern_tc.c 7 Feb 2002 21:21:55 - 1.113
--- kern_tc.c 17 Feb 2002 06:25:14 -
***
*** 108,114
struct timecounter *tc;
! tc = timecounter;
! *bt = tc-tc_offset;
! bintime_addx(bt, tc-tc_scale * tco_delta(tc));
}
--- 95,129
struct timecounter *tc;
! /*
! * The loop is to handle changes of timecounter underneath us.
! * Such changes may even become normal for preemptive kernels.
! * It is quite reasonable for idle priority processes to not
! * run for many seconds, and if they are not running after
! * being preempted here, the timecounter may cycle many times
! * underneath them. An NTIMECOUNTER of 2 is neither necessary
! * or sufficient for fixing this problem, unless NTIMECOUNTER is
! * preposterously large. NTIMECOUNTER == 2 suffices for most
! * cases, and something more is required to fix the general case.
! *
! * I hope this also fixes problems with overflow of the
! * multiplication. We depend on tc not becoming stale by more
! * than 1 second. We will now normally see such staleness
! * because it will cause the timecounter to change many times
! * underneath us. There will only be problems if hardclock()
! * doesn't run for many seconds, but hardclock() is a very
! * high priority interrupt, so such problems can't happen.
! *
! * XXX should use a generation count.
! *
! * XXX problems with hardclock() can happen, e.g., at boot time
! * if you have fixed hardclock() to not be a broken fast interrupt
! * handler, or if you sit at the ddb prompt for several seconds.
! * Should do something to make them harmless.
! */
! do {
! tc = timecounter;
! *bt = tc-tc_offset;
! bintime_addx(bt, tc-tc_scale * tco_delta(tc));
! } while (tc != timecounter);
}
%%%
Bruce
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Glenn Gombert
[EMAIL PROTECTED]
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
In message [EMAIL PROTECTED], Bruce Evans writes: This occurs both with and without the gettimeofday Giant-removal patch, so I am fairly sure it has nothing to do with any of my current work. This is running -current on a DELL2550 (2xCPUs), compiled with the SMP option. The Gian removal doesn't come anywhere near this. The fact that the timecounter usually goes backwards by about 0.68 seconds is probably significant, but I can't quite explain it. acpi_timer0: 32-bit timer at 3.579545MHz port 0x808-0x80b on acpi0 Well: 2^32 / 3579545 = 1199.86 seconds. 2^24 / 3579545 =4.68 seconds. So even assuming that ACPI reported a wrong width, four seconds should still be enough to prevent a wraparound even though we cycle through the timecounter ring in one second. I just wrote the following fix for some of the overflow problems. It is true that if a process is not running for arbitrary long time the timecounter may be modified underneat it, and bruce's patch is actually a pretty elegant solution for that case. By all means try it. I have had one other report of a similar problem, with the added information that changing to the TSC or i8254 instead of PIXX made it go away so I am not entirely convinced this is really what we are looking for in this case. -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 [EMAIL PROTECTED] | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
In message [EMAIL PROTECTED], Matthew Dillon wri tes: :I just wrote the following fix for some of the overflow problems. I don't understand how this code is supposed to handle overflows. You seem only to be checking to see if the master timecounter has changed to a different type. Bruce's patch amounts to a retry if the current timecounter was updated while we were calculating time. It is a bit more defensive than it needs to be and generally pessimizes the timecounters elegant lockless design a fair bit, but it is still much better than slamming a mutex around the entire clock code. If this patch cures the PIIX problem, something I'm not at all convinced about, it should go in, if not only the comment should go in. Poul-Henning -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 [EMAIL PROTECTED] | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Success! Sorta! (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
:Bruce's patch amounts to a retry if the current timecounter was updated
:while we were calculating time. It is a bit more defensive than it
:needs to be and generally pessimizes the timecounters elegant lockless
:design a fair bit, but it is still much better than slamming a mutex
:around the entire clock code.
:
:If this patch cures the PIIX problem, something I'm not at all convinced
:about, it should go in, if not only the comment should go in.
:
:Poul-Henning
:
:--
:Poul-Henning Kamp | UNIX since Zilog Zeus 3.20
Ok, I've tested Bruce's patch and it appeaars to mostly solve the problem.
I no longer get 'microuptime ... backwards' errors on a -current SMP
box.
However, I think to be complete we need to make it even less elegant.
The TC module is only flip-flopping between two time counters, which
means that it can flip-flop twice and the test will not work. We need
a generation count on the timecounter as well:
do {
tc = timecounter;
gen = tc-tc_generation;
*bt = tc-tc_offset;
bintime_addx(bt, tc-tc_scale * tco_delta(tc));
} while (tc != timecounter || tc-tc_generation != gen);
There is also an issue on non-i386 machines. The timecounter swapping
code requires a memory synchronization point after updating the
contents of the new timecounter but before setting the 'timecounter' global
to the new timecounter. If this is not done, non-i386 machines running
SMP may see the new timecounter structure but access pre-updated values
from it.
(i386 boxes do not have this problem because writes are ordered so the
inherent synchronication point at the end of the timer interrupt is
enough).
Is there a memory synchronization point macro available?
-Matt
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Re: Success! Sorta! (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
Whoop! I take it back. I'm still getting the errors:
microuptime() went backwards (458.168990 - 458.168882)
microuptime() went backwards (578.609995 - 577.929801)
microuptime() went backwards (748.912755 - 748.237402)
microuptime() went backwards (775.159625 - 775.159612)
I also think this retry loop has to be done everywhere where the
timecounter structure is accessed directly.
-Matt
:Ok, I've tested Bruce's patch and it appeaars to mostly solve the problem.
:I no longer get 'microuptime ... backwards' errors on a -current SMP
:box.
:...
Index: kern/kern_tc.c
===
RCS file: /home/ncvs/src/sys/kern/kern_tc.c,v
retrieving revision 1.113
diff -u -r1.113 kern_tc.c
--- kern/kern_tc.c 7 Feb 2002 21:21:55 - 1.113
+++ kern/kern_tc.c 17 Feb 2002 20:41:47 -
@@ -107,9 +107,11 @@
{
struct timecounter *tc;
- tc = timecounter;
- *bt = tc-tc_offset;
- bintime_addx(bt, tc-tc_scale * tco_delta(tc));
+ do {
+ tc = timecounter;
+ *bt = tc-tc_offset;
+ bintime_addx(bt, tc-tc_scale * tco_delta(tc));
+ } while (tc != timecounter);
}
void
@@ -126,8 +128,10 @@
struct timecounter *tc;
ngetmicrotime++;
- tc = timecounter;
- *tvp = tc-tc_microtime;
+ do {
+ tc = timecounter;
+ *tvp = tc-tc_microtime;
+ } while (tc != timecounter);
}
void
@@ -136,8 +140,10 @@
struct timecounter *tc;
ngetnanotime++;
- tc = timecounter;
- *tsp = tc-tc_nanotime;
+ do {
+ tc = timecounter;
+ *tsp = tc-tc_nanotime;
+ } while (tc != timecounter);
}
void
@@ -166,8 +172,10 @@
struct timecounter *tc;
ngetmicrouptime++;
- tc = timecounter;
- bintime2timeval(tc-tc_offset, tvp);
+ do {
+ tc = timecounter;
+ bintime2timeval(tc-tc_offset, tvp);
+ } while (tc != timecounter);
}
void
@@ -176,8 +184,10 @@
struct timecounter *tc;
ngetnanouptime++;
- tc = timecounter;
- bintime2timespec(tc-tc_offset, tsp);
+ do {
+ tc = timecounter;
+ bintime2timespec(tc-tc_offset, tsp);
+ } while (tc != timecounter);
}
void
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Re: Success! Sorta! (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
In message [EMAIL PROTECTED], Matthew Dillon wri
tes:
However, I think to be complete we need to make it even less elegant.
The TC module is only flip-flopping between two time counters, which
means that it can flip-flop twice and the test will not work. We need
a generation count on the timecounter as well:
do {
tc = timecounter;
gen = tc-tc_generation;
*bt = tc-tc_offset;
bintime_addx(bt, tc-tc_scale * tco_delta(tc));
} while (tc != timecounter || tc-tc_generation != gen);
No, more like:
do {
tc = timecounter;
gen = tc-gen;
...
} while (gen != tc-gen);
--
Poul-Henning Kamp | UNIX since Zilog Zeus 3.20
[EMAIL PROTECTED] | TCP/IP since RFC 956
FreeBSD committer | BSD since 4.3-tahoe
Never attribute to malice what can adequately be explained by incompetence.
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Re: Success! Sorta! (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
In message [EMAIL PROTECTED], Matthew Dillon wri tes: Whoop! I take it back. I'm still getting the errors: microuptime() went backwards (458.168990 - 458.168882) microuptime() went backwards (578.609995 - 577.929801) microuptime() went backwards (748.912755 - 748.237402) microuptime() went backwards (775.159625 - 775.159612) I also think this retry loop has to be done everywhere where the timecounter structure is accessed directly. No, only where the timecounter hardware is read and the math done. As far as I know, this is the only place. As I said, I am far from convinced this is the solution to the problem we are looking at with the PIIX timecounter. Msmith has some magic code in sys/dev/acpi/acpi_timer.c which tries to identify if the PIIX counter is broken or OK and I notice that the mask seems to always be set to 24 bits even if the hardware is 32 bits. I am not sure I read his code right, but he seems to default to the unsafe method, can you try this copypasted patch ? Index: acpi_timer.c === RCS file: /home/ncvs/src/sys/dev/acpica/acpi_timer.c,v retrieving revision 1.11 diff -u -r1.11 acpi_timer.c --- acpi_timer.c8 Jan 2002 06:45:56 - 1.11 +++ acpi_timer.c17 Feb 2002 20:48:23 - @@ -138,7 +138,7 @@ if (getenv(debug.acpi.timer_test) != NULL) acpi_timer_test(); -acpi_timer_timecounter.tc_get_timecount = acpi_timer_get_timecount; +acpi_timer_timecounter.tc_get_timecount = acpi_timer_get_timecount_safe; acpi_timer_timecounter.tc_frequency = acpi_timer_frequency; tc_init(acpi_timer_timecounter); -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 [EMAIL PROTECTED] | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
Matt, Easy now, there is more depth to it than that... I have promised myself to get the timecounter paper written and I'll probably present it at BSDcon-euro-2002 in Amsterdam if they want to listen to me. For now, lets concentrate on the PIIX hardware because that's where the problem seems to be... Poul-Henning In message [EMAIL PROTECTED], Matthew Dillon wri tes: Ok, I've looked at the code more carefully and I understand how this works now. However, it is not enough in an SMP environment. You need a generation count in the timecounter structure and you also need a synchronization point when you switch time counters or a process running on a different cpu may wind up using a time counter that is being actively updated. I'm experimenting with your patch now. I'll send email when I have some test results. -Matt : :I just wrote the following fix for some of the overflow problems. : :%%% :Index: kern_tc.c :=== :RCS file: /home/ncvs/src/sys/kern/kern_tc.c,v :retrieving revision 1.113 :diff -c -2 -r1.113 kern_tc.c :... To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 [EMAIL PROTECTED] | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
If this patch cures the PIIX problem, something I'm not at all convinced about, it should go in, if not only the comment should go in. I would like to see the PIIX problem caught on camera, personally. We're aware of one errata for it already, and we work around it. If there's another problem, or ideally if someone has some relatively quick code to test it, that would be much better. -- To announce that there must be no criticism of the president, or that we are to stand by the president, right or wrong, is not only unpatriotic and servile, but is morally treasonable to the American public. - Theodore Roosevelt To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: ACPI timer is screwed... (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
:I would like to see the PIIX problem caught on camera, personally.
:We're aware of one errata for it already, and we work around it. If
:there's another problem, or ideally if someone has some relatively quick
:code to test it, that would be much better.
Holy shit. We are screwed. It's a free-running counter with NO
synchronization whatsoever. None. Zip. Zero.
Sounds like we need to smack whoever made your chipset as well. Intel
learned their lesson (finally) with later revisions of the PIIX4. I'm
guessing you're running this against a ServerWorks system.
It looks like the hardware is using an adder with fast carry
(basically a forward looking carry calculation), which can result in a
later bit being set before the earlier bits are updated. However, if
this is the case then it is almost certain that you can catch the ripple
as well, or even catch the counter while the bit states are changing.
Lame. Incredibly lame.
The only way to get a guarenteed accurate sample under these circumstances
is something like this, where you calculate a mask that results in
reasonable accurancy without causing the cpu to go into an infinite
loop and then read the timer until you get two samples that are the same:
u1 = TIMER_READ;
u2 = TIMER_READ;
while ((u1 ^ u2) 0xFFF0) { mask must be chosen
u1 = u2;
u2 = TIMER_READ;
}
return(u2 0xFFF0)same mask here
Here are some more from my debug output:
Interesting. This would be reasonably robust in the ripple-counter case
we have to deal with on the old PIIX4. Have you tried implementing the
above yet, or measuring how much it costs?
At any rate, please let me know for sure whether you're running on a
ServerWorks board, and I'll see if I can't find a Big Stick to hit them
with.
Thanks,
Mike
--
To announce that there must be no criticism of the president,
or that we are to stand by the president, right or wrong, is not
only unpatriotic and servile, but is morally treasonable to
the American public. - Theodore Roosevelt
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
Re: ACPI timer is screwed... (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
:Sounds like we need to smack whoever made your chipset as well. Intel :learned their lesson (finally) with later revisions of the PIIX4. I'm :guessing you're running this against a ServerWorks system. atapci0: ServerWorks ROSB4 ATA33 controller port 0x8b0-0x8bf at device 15.1 on pci0 Uh huh. It might be possible to detect the situation during init-time by explicitly looking for a reverse indexed time in a tight loop of maybe a thousand reads, but that would still leave us with a statistical chance of not guessing right. :Interesting. This would be reasonably robust in the ripple-counter case :we have to deal with on the old PIIX4. Have you tried implementing the :above yet, or measuring how much it costs? : :At any rate, please let me know for sure whether you're running on a :ServerWorks board, and I'll see if I can't find a Big Stick to hit them :with. : :Thanks, :Mike I haven't measured the cost (extra loops) but I expect it would stabilize in no more then one additional loop, which would be three counter reads total or roughly the same as your originaln _safe code in the worst case. I think we could default to the _safe version and then explicitly change it to use the fast version if we see specific chipsets which we know to be good. -Matt To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: ACPI timer is screwed... (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
In message [EMAIL PROTECTED], Matthew Dillon wri tes: :I would like to see the PIIX problem caught on camera, personally. :We're aware of one errata for it already, and we work around it. If :there's another problem, or ideally if someone has some relatively quick :code to test it, that would be much better. Holy shit. We are screwed. It's a free-running counter with NO synchronization whatsoever. None. Zip. Zero. Yes, there is an errata for just that on early chipsets. Does the ..._slow patch I sent work for you ? -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 [EMAIL PROTECTED] | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: ACPI timer is screwed... (was Re: 'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible? )
:I would like to see the PIIX problem caught on camera, personally. :We're aware of one errata for it already, and we work around it. If :there's another problem, or ideally if someone has some relatively quick :code to test it, that would be much better. Holy shit. We are screwed. It's a free-running counter with NO synchronization whatsoever. None. Zip. Zero. Yes, there is an errata for just that on early chipsets. Does the ..._slow patch I sent work for you ? Matt's problem (look-ahead carry) will break the three-read algorithm because it can generate a sequence of three reads that appear to be in succession, but which are all wrong. We need three different algorithms; works, ripple and look-ahead. Of those, works should be based exclusively off a list of known-good chipsets, look-ahead seems to be easily enough detected (but we should probably have a blacklist anyway) and ripple is hard to detect and should be the default case. I really, really hate hardware. -- To announce that there must be no criticism of the president, or that we are to stand by the president, right or wrong, is not only unpatriotic and servile, but is morally treasonable to the American public. - Theodore Roosevelt To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
Re: Success! Sorta! (was Re: 'microuptime() went backwards ...'using ACPI timer. Shouldn't that be impossible? )
On Sun, 17 Feb 2002, Matthew Dillon wrote:
Whoop! I take it back. I'm still getting the errors:
microuptime() went backwards (458.168990 - 458.168882)
microuptime() went backwards (578.609995 - 577.929801)
microuptime() went backwards (748.912755 - 748.237402)
microuptime() went backwards (775.159625 - 775.159612)
I also think this retry loop has to be done everywhere where the
timecounter structure is accessed directly.
Yes, since the reads of all the relevant timecounter variables are
non-atomic.
Index: kern/kern_tc.c
===
RCS file: /home/ncvs/src/sys/kern/kern_tc.c,v
retrieving revision 1.113
diff -u -r1.113 kern_tc.c
--- kern/kern_tc.c7 Feb 2002 21:21:55 - 1.113
+++ kern/kern_tc.c17 Feb 2002 20:41:47 -
@@ -126,8 +128,10 @@
struct timecounter *tc;
ngetmicrotime++;
- tc = timecounter;
- *tvp = tc-tc_microtime;
+ do {
+ tc = timecounter;
+ *tvp = tc-tc_microtime;
+ } while (tc != timecounter);
}
void
E.g., tc_mictrotime here is a timeval. It doesn't matter getting a stale
value (although getting a stale value increases the possible incoherency
of the get*() functions from 1/HZ to NTIMECOUNTER/HZ), but getting a
stale value that changed underneath the read would be bad.
Bruce
To Unsubscribe: send mail to [EMAIL PROTECTED]
with unsubscribe freebsd-current in the body of the message
'microuptime() went backwards ...' using ACPI timer. Shouldn't that be impossible?
Testing with a 'make -j 10 buildworld' on a -current box I am getting regular: microuptime() went backwards (146.826785 - 146.156715) microuptime() went backwards (146.826782 - 146.228636) ... microuptime() went backwards (8945.938288 - 8945.251603) microuptime() went backwards (8945.938306 - 8945.347173) microuptime() went backwards (9142.847550 - 9142.847546) This occurs both with and without the gettimeofday Giant-removal patch, so I am fairly sure it has nothing to do with any of my current work. This is running -current on a DELL2550 (2xCPUs), compiled with the SMP option. Timecounter i8254 frequency 1193182 Hz ... Timecounter ACPI frequency 3579545 Hz acpi_timer0: 32-bit timer at 3.579545MHz port 0x808-0x80b on acpi0 acpi_cpu0: CPU on acpi0 acpi_cpu1: CPU on acpi0 acpi_pcib0: Host-PCI bridge on acpi0 ... Question: How can this be occuring at all? Isn't the ACPI counter a 32 bit counter that does not have the rollover problems that the 8254 timer has? -Matt Matthew Dillon [EMAIL PROTECTED] To Unsubscribe: send mail to [EMAIL PROTECTED] with unsubscribe freebsd-current in the body of the message
