From owner-freebsd-current Fri Oct 6 14:17:22 2000 Delivered-To: freebsd-current@freebsd.org Received: from segfault.kiev.ua (segfault.kiev.ua [193.193.193.4]) by hub.freebsd.org (Postfix) with ESMTP id 02AF837B502; Fri, 6 Oct 2000 14:17:10 -0700 (PDT) Received: (from netch@localhost) by segfault.kiev.ua (8) id AGO13145; Sat, 7 Oct 2000 00:17:05 +0300 (EEST) (envelope-from netch) Date: Sat, 7 Oct 2000 00:13:36 +0300 From: Valentin Nechayev To: freebsd-current@freebsd.org, phk@freebsd.org Subject: microuptime() went backwards: possible diagnosis Message-ID: <20001007001336.A346@nn.kiev.ua> Reply-To: netch@netch.kiev.ua Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Mailer: Mutt 0.95.3i Organization: Lucky Netch Incorporated X-42: On Sender: owner-freebsd-current@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.ORG Following is partial dmesg output from 5.0(13)-CURRENT-20001002 kernel with advanced debugging prints: ==={{{ mi_startup(): call subsystem 0x8800000(142606336), microuptime is 1.4027506 mi_startup(): call subsystem 0x8800000(142606336), microuptime is 1.4027897 mi_startup(): call subsystem 0xa000000(167772160), microuptime is 1.4028290 mi_startup(): call subsystem 0xa800000(176160768), microuptime is 1.4028701 mi_switch(): microuptime() went backwards (1.4029032 -> 0.734106) mi_switch(): microuptime() went backwards (1.4029032 -> 0.734590) mi_switch(): microuptime() went backwards (1.4029032 -> 0.735077) mi_switch(): microuptime() went backwards (1.4029032 -> 0.735555) [...] mi_switch(): microuptime() went backwards (1.4029032 -> 1.053263) mi_switch(): microuptime() went backwards (1.4029032 -> 1.053756) mi_startup(): call subsystem 0xd000000(218103808), microuptime is 1.054550 proc0_post(): switchtime initialized to 1.54864 mi_startup(): call subsystem 0xe000000(234881024), microuptime is 1.055501 mi_startup(): call subsystem 0xe400000(239075328), microuptime is 1.056012 ===}}} mi_switch() uses static variable 'switchtime' which keeps microuptime data when previous switching occured. For non-MP systems, proc0_post() sets it up. But first mi_switch() call occures when SI_SUB_INT_CONFIG_HOOKS (or SI_SUB_KICK_SCHEDULER?) subsystem called - why? IMHO it is too early for mi_switch(), it should be enabled on SI_SUB_RUN_SCHEDULER. - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - This was first question. Another one is strange value returned by microuptime() (3-5 millions of microseconds). This value becomes strange on my system during third SI_SUB_CONFIGURE instance, which is configure() in i386/i386/autoconf.c: [...] isa_probe_children: before probing non-PNP device: microuptime=0.349777, x=0 fdc0: at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0 fdc0: FIFO enabled, 8 bytes threshold fd.c: fd_probe(): before set_motor(): microuptime=0.291463, x=0 fdc0: FIFO enabled, 8 bytes threshold fd.c: fd_probe(): before NE7CMD_SENSED(): microuptime=1.292409, x=0 fd0: <1440-KB 3.5" drive> on fdc0 drive 0 isa_probe_children: after probing non-PNP device: microuptime=1.1653283, x=0 isa_probe_children: before probing non-PNP device: microuptime=1.1604514, x=7 atkbdc0: at port 0x60,0x64 on isa0 atkbd0: flags 0x1 irq 1 on atkbdc0 kbd0 at atkbd0 isa_probe_children: after probing non-PNP device: microuptime=1.3138749, x=7 [...] it isn't possible to normalize value during this subsystem startup, is it? /netch To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-current" in the body of the message