Re: gettimeofday non-monotonic on 2.2.7 SMP

Simon Kirby (sim@netnation.com)
Mon, 17 May 1999 18:09:58 -0700 (PDT)


On Sun, 16 May 1999, dave madden wrote:

> I know multiple processors are relatively rare, but hasn't *somebody*
> else noticed the ill effects of gettimeofday returning earlier times?
> On my 2xPIII-450 system, the following program does about 900K
> gettimeofday's per second when otherwise idle, and 5-10 of them are
> mis-ordered (usually by less than 10us, but if I start doing something
> that causes a lot of complex interrupts, I see multiple-millisecond
> clock hiccoughs). I've been tweeking arch/i386/kernel/time.c, but
> haven't fixed it yet. Has anybody else tried?

My dual celeron 300As @ 450 MHz (2.2.9) running your program gives:

Mon May 17 18:05:40 1999: fwd:774496/0:back max 0000000
Mon May 17 18:05:41 1999: fwd:913473/0:back max 0000000
Mon May 17 18:05:42 1999: fwd:916224/0:back max 0000000
Mon May 17 18:05:43 1999: fwd:916309/0:back max 0000000
Mon May 17 18:05:44 1999: fwd:916286/0:back max 0000000
Mon May 17 18:05:45 1999: fwd:916016/0:back max 0000000
Mon May 17 18:05:46 1999: fwd:916303/0:back max 0000000
Mon May 17 18:05:47 1999: fwd:916321/0:back max 0000000
Mon May 17 18:05:48 1999: fwd:916105/0:back max 0000000
Mon May 17 18:05:49 1999: fwd:916267/0:back max 0000000
Mon May 17 18:05:50 1999: fwd:916047/0:back max 0000000
Mon May 17 18:05:51 1999: fwd:916177/0:back max 0000000
Mon May 17 18:05:52 1999: fwd:916177/0:back max 0000000
Mon May 17 18:05:53 1999: fwd:916280/0:back max 0000000
Mon May 17 18:05:54 1999: fwd:916078/0:back max 0000000
Mon May 17 18:05:55 1999: fwd:916178/0:back max 0000000
Mon May 17 18:05:56 1999: fwd:916180/0:back max 0000000

With nothing much else running. With an MP3 playing:

Mon May 17 18:06:28 1999: fwd:413369/0:back max 0000000
Mon May 17 18:06:29 1999: fwd:901381/0:back max 0000000
Mon May 17 18:06:30 1999: fwd:898870/0:back max 0000000
Mon May 17 18:06:31 1999: fwd:897722/0:back max 0000000
Mon May 17 18:06:32 1999: fwd:900022/0:back max 0000000
Mon May 17 18:06:33 1999: fwd:895142/0:back max 0000000
Mon May 17 18:06:34 1999: fwd:899793/0:back max 0000000
Mon May 17 18:06:35 1999: fwd:896234/0:back max 0000000
Mon May 17 18:06:36 1999: fwd:897314/0:back max 0000000
Mon May 17 18:06:37 1999: fwd:900105/0:back max 0000000
Mon May 17 18:06:38 1999: fwd:898454/0:back max 0000000
Mon May 17 18:06:39 1999: fwd:898409/0:back max 0000000
Mon May 17 18:06:40 1999: fwd:897051/0:back max 0000000
Mon May 17 18:06:41 1999: fwd:895099/0:back max 0000000
Mon May 17 18:06:42 1999: fwd:899030/0:back max 0000000
Mon May 17 18:06:43 1999: fwd:895173/0:back max 0000000
Mon May 17 18:06:44 1999: fwd:899061/0:back max 0000000

(...which is in a way a bit odd...shouldn't it be using the other CPU?)
I tried running "du" and moving the mouse and such to generate interrupts,
but still didn't see anything going backwards at all.

I _do_ however see "btime" flickering back and forth in /proc/stat as the
process reading /proc/stat bounces between CPUs, which I think might be
what's causing "vmstat" to occasionally show negative/wrapped idle
numbers...

Simon-

| Simon Kirby | Systems Administration |
| mailto:sim@netnation.com | NetNation Communications |
| http://www.netnation.com/ | Tech: (604) 684-6892 |

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/