Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 11 Apr 2001 19:28:55 +0300
From:      Valentin Nechayev <netch@netch.kiev.ua>
To:        freebsd-stable@freebsd.org
Subject:   fresh 4.3-RC: "microuptime went backwards", console lockup
Message-ID:  <20010411192854.A570@netch.kiev.ua>

next in thread | raw e-mail | index | archive | help
Today, 4.3-RC (RELENG_4, date=2001.04.11.00.00.00) was built and, when
new system started:
1) during boot and even before /sbin/init started, "microuptime went backwards"
occured too many times.
2) after startx, syscons switched to ttyv0 and stayed here; after
mutual swithing to ttyvb, console locked up totally.
No problems with previous system (RELENG_4, date=2001.03.05.00.00.00)
were seen. Xwindow is 3.3.6 from latest port.

Messages, messages diff and kernel config attached. What another information
should I provide?

/var/log/messages during bad kernel:

==={{{
Apr 11 18:41:38 grizzly /kernel: Copyright (c) 1992-2001 The FreeBSD Project.
Apr 11 18:41:38 grizzly /kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Apr 11 18:41:38 grizzly /kernel: The Regents of the University of California. All rights reserved.
Apr 11 18:41:38 grizzly /kernel: FreeBSD 4.3-RC #0: Wed Apr 11 18:29:42 EEST 2001
Apr 11 18:41:38 grizzly /kernel: root@grizzly.carrier.kiev.ua:/var/obj/var/src/sys/compile/griz
Apr 11 18:41:38 grizzly /kernel: Timecounter "i8254"  frequency 1193182 Hz
Apr 11 18:41:38 grizzly /kernel: CPU: Pentium II/Pentium II Xeon/Celeron (300.68-MHz 686-class CPU)
Apr 11 18:41:38 grizzly /kernel: Origin = "GenuineIntel"  Id = 0x660  Stepping = 0
Apr 11 18:41:38 grizzly /kernel: Features=0x183f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
Apr 11 18:41:38 grizzly /kernel: real memory  = 134217728 (131072K bytes)
Apr 11 18:41:38 grizzly /kernel: avail memory = 127016960 (124040K bytes)
Apr 11 18:41:38 grizzly /kernel: Preloaded elf kernel "kernel" at 0xc0357000.
Apr 11 18:41:38 grizzly /kernel: VESA: v2.0, 8192k memory, flags:0x0, mode table:0xc02f81a2 (1000022)
Apr 11 18:41:38 grizzly /kernel: VESA: ATI MACH64
Apr 11 18:41:38 grizzly /kernel: Pentium Pro MTRR support enabled
Apr 11 18:41:38 grizzly /kernel: apm0: <APM BIOS> on motherboard
Apr 11 18:41:38 grizzly /kernel: apm: found APM BIOS v1.2, connected at v1.2
Apr 11 18:41:38 grizzly /kernel: npx0: <math processor> on motherboard
Apr 11 18:41:38 grizzly /kernel: npx0: INT 16 interface
Apr 11 18:41:38 grizzly /kernel: pcib0: <Intel 82443LX (440 LX) host to PCI bridge> on motherboard
Apr 11 18:41:38 grizzly /kernel: pci0: <PCI bus> on pcib0
Apr 11 18:41:38 grizzly /kernel: pcib1: <Intel 82443LX (440 LX) PCI-PCI (AGP) bridge> at device 1.0 on pci0
Apr 11 18:41:38 grizzly /kernel: pci1: <PCI bus> on pcib1
Apr 11 18:41:38 grizzly /kernel: pci1: <ATI Mach64-GB graphics accelerator> at 0.0 irq 15
Apr 11 18:41:38 grizzly /kernel: isab0: <Intel 82371AB PCI to ISA bridge> at device 7.0 on pci0
Apr 11 18:41:38 grizzly /kernel: isa0: <ISA bus> on isab0
Apr 11 18:41:38 grizzly /kernel: pci0: <Intel PIIX4 ATA controller> at 7.1
Apr 11 18:41:38 grizzly /kernel: pci0: <Intel 82371AB/EB (PIIX4) USB controller> at 7.2
Apr 11 18:41:38 grizzly /kernel: chip1: <Intel 82371AB Power management controller> port 0x5000-0x500f at device 7.3 on pci0
Apr 11 18:41:38 grizzly /kernel: fxp0: <Intel Pro 10/100B/100+ Ethernet> port 0xe400-0xe41f mem 0xea000000-0xea0fffff,0xea101000-0xea101fff irq 11 at device 18.0 on pci0
Apr 11 18:41:38 grizzly /kernel: fxp0: Ethernet address 00:90:27:2d:41:d0
Apr 11 18:41:38 grizzly /kernel: ahc0: <Adaptec 2940 Ultra SCSI adapter> port 0xe800-0xe8ff mem 0xea100000-0xea100fff irq 10 at device 19.0 on pci0
Apr 11 18:41:38 grizzly /kernel: aic7880: Wide Channel A, SCSI Id=7, 16/255 SCBs
Apr 11 18:41:38 grizzly /kernel: fdc0: <NEC 72065B or clone> at port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on isa0
Apr 11 18:41:38 grizzly /kernel: fdc0: FIFO enabled, 8 bytes threshold
Apr 11 18:41:38 grizzly /kernel: fd0: <1440-KB 3.5" drive> on fdc0 drive 0
Apr 11 18:41:38 grizzly /kernel: atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
Apr 11 18:41:38 grizzly /kernel: atkbd0: <AT Keyboard> flags 0x1 irq 1 on atkbdc0
Apr 11 18:41:38 grizzly /kernel: kbd0 at atkbd0
Apr 11 18:41:38 grizzly /kernel: psm0: <PS/2 Mouse> irq 12 on atkbdc0
Apr 11 18:41:38 grizzly /kernel: psm0: model Generic PS/2 mouse, device ID 0
Apr 11 18:41:38 grizzly /kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Apr 11 18:41:38 grizzly /kernel: sc0: <System console> at flags 0x100 on isa0
Apr 11 18:41:38 grizzly /kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Apr 11 18:41:38 grizzly /kernel: sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
Apr 11 18:41:38 grizzly /kernel: sio0: type 16550A
Apr 11 18:41:38 grizzly /kernel: sio1 at port 0x2f8-0x2ff irq 3 on isa0
Apr 11 18:41:38 grizzly /kernel: sio1: type 16550A
Apr 11 18:41:38 grizzly /kernel: ppc0: <Parallel port> at port 0x378-0x37f irq 7 on isa0
Apr 11 18:41:38 grizzly /kernel: ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode
Apr 11 18:41:38 grizzly /kernel: ppc0: FIFO with 16/16/16 bytes threshold
Apr 11 18:41:38 grizzly /kernel: plip0: <PLIP network interface> on ppbus0
Apr 11 18:41:38 grizzly /kernel: lpt0: <Printer> on ppbus0
Apr 11 18:41:38 grizzly /kernel: lpt0: Interrupt-driven port
Apr 11 18:41:38 grizzly /kernel: ppi0: <Parallel I/O> on ppbus0
Apr 11 18:41:38 grizzly /kernel: sbc0: <Creative ViBRA16X> at port 0x220-0x22f,0x330-0x331,0x388-0x38b irq 5 drq 1,3 on isa0
Apr 11 18:41:38 grizzly /kernel: pcm0: <SB16 DSP 4.16 (ViBRA16X)> on sbc0
Apr 11 18:41:38 grizzly /kernel: IP packet filtering initialized, divert disabled, rule-based forwarding disabled, default to accept, unlimited logging
Apr 11 18:41:38 grizzly /kernel: Waiting 3 seconds for SCSI devices to settle
Apr 11 18:41:38 grizzly /kernel: Mounting root from ufs:/dev/da0s1a
Apr 11 18:41:38 grizzly /kernel: da1 at ahc0 bus 0 target 2 lun 0
Apr 11 18:41:38 grizzly /kernel: da1: <IBM DCAS-34330W S65A> Fixed Direct Access SCSI-2 device 
Apr 11 18:41:38 grizzly /kernel: da1: 40.000MB/s transfers (20.000MHz, offset 8, 16bit)
Apr 11 18:41:38 grizzly /kernel: da1: 4134MB (8467200 512 byte sectors: 255H 63S/T 527C)
Apr 11 18:41:38 grizzly /kernel: da0 at ahc0 bus 0 target 0 lun 0
Apr 11 18:41:38 grizzly /kernel: da0: <IBM DDRS-34560D DC1B> Fixed Direct Access SCSI-2 device 
Apr 11 18:41:38 grizzly /kernel: da0: 40.000MB/s transfers (20.000MHz, offset 8, 16bit), Tagged Queueing Enabled
Apr 11 18:41:38 grizzly /kernel: da0: 4357MB (8925000 512 byte sectors: 255H 63S/T 555C)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843816 -> 7.734809)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843816 -> 7.737171)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843573 -> 7.734732)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843573 -> 7.735340)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843573 -> 7.736912)
Apr 11 18:41:38 grizzly /kernel: cd0 at ahc0 bus 0 target 1 lun 0
Apr 11 18:41:38 grizzly /kernel: cd0: <TOSHIBA CD-ROM XM-3801TA 0207> Removable CD-ROM SCSI-2 device 
Apr 11 18:41:38 grizzly /kernel: cd0: 10.000MB/s transfers (10.000MHz, offset 8)
Apr 11 18:41:38 grizzly /kernel: cd0: cd present [327338 x 2048 byte records]
Apr 11 18:41:38 grizzly named[177]: starting (/etc/namedb/named.conf).  named 8.2.3-REL Wed Apr 11 16:59:40 EEST 2001 	root@grizzly.carrier.kiev.ua:/var/obj/var/src/usr.sbin/named
Apr 11 18:41:38 grizzly named[177]: limit files set to fdlimit (1024)
Apr 11 18:41:38 grizzly named[178]: Ready to answer queries.
Apr 11 18:41:38 grizzly ntpd[180]: ntpd 4.0.99b Wed Apr 11 16:58:45 EEST 2001 (1)
Apr 11 18:41:38 grizzly ntpd[180]: using kernel phase-lock loop 2040
Apr 11 18:41:38 grizzly ntpd[180]: getnetnum: "news.demos.su" invalid host number, line ignored
Apr 11 18:41:38 grizzly ntpd[180]: getnetnum: "news1.demos.su" invalid host number, line ignored
Apr 11 18:41:38 grizzly ntpd[180]: getnetnum: "news.gamma.ru" invalid host number, line ignored
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.834984 -> 7.737884)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842559 -> 7.735504)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843816 -> 7.738378)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839712 -> 7.734986)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839748 -> 7.743734)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.736175)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.739450)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.750258)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.751613)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.764301)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.764883)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.775410)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.776000)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.780731)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.787880)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.788925)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.791228)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.811999 -> 7.792100)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.742846)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.745269)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.746962)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.748818)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.749914)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.751635)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.753202)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839740 -> 7.756961)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.739800)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.740682)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.751453)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.752134)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.753513)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.754646)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.755632)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.757180)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.761039)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.765178)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.837073 -> 7.766163)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843178 -> 7.734621)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843178 -> 7.735361)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843178 -> 7.737016)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843178 -> 7.737564)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.830187 -> 7.734668)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.830187 -> 7.749899)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.838573 -> 7.734923)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843469 -> 7.734611)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.838522 -> 7.738094)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.838522 -> 7.745038)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.844055 -> 7.734420)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.735466)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.740883)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.755061)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.766780)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.783736)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.795306)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.810152)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842481 -> 7.826392)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843630 -> 7.735223)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.831660 -> 7.737727)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.831660 -> 7.759594)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842772 -> 7.734324)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.805040 -> 7.735190)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.805040 -> 7.735336)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.805040 -> 7.771539)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.843616 -> 7.734416)
Apr 11 18:41:38 grizzly login: ROOT LOGIN (root) ON ttyv1
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.774619 -> 7.740860)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839139 -> 7.735976)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839139 -> 7.736433)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839139 -> 7.736580)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839139 -> 7.736791)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.839139 -> 7.736964)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.820332 -> 7.744583)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.820332 -> 7.744793)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.820332 -> 7.750961)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.842030 -> 7.734805)
Apr 11 18:41:38 grizzly /kernel: microuptime() went backwards (7.831764 -> 7.737653)
===}}}

Different lines between bad kernel messages('-') and good old kernel
messages('+'):

-avail memory = 127016960 (124040K bytes)
+avail memory = 127021056 (124044K bytes)

-VESA: v2.0, 8192k memory, flags:0x0, mode table:0xc02f81a2 (1000022)
+VESA: v2.0, 8192k memory, flags:0x0, mode table:0xc02f7362 (1000022)

Kernel config (did not changed):

==={{{
machine		i386
#cpu		I386_CPU
#cpu		I486_CPU
#cpu		I586_CPU
cpu		I686_CPU
ident		griz
maxusers	64
options		MSGBUF_SIZE=81920
#makeoptions	DEBUG=-g		#Build kernel with gdb(1) debug symbols
#options 	MATH_EMULATE		#Support for x87 emulation
options 	INET			#InterNETworking
options         IPFIREWALL              #firewall
options         IPFIREWALL_VERBOSE      #print information about
options         IPFIREWALL_DEFAULT_TO_ACCEPT
options 	FFS			#Berkeley Fast Filesystem
options 	FFS_ROOT		#FFS usable as root device [keep this!]
options 	SOFTUPDATES		#Enable FFS soft updates support
options 	NFS			#Network Filesystem
options 	MSDOSFS			#MSDOS Filesystem
options 	CD9660			#ISO 9660 Filesystem
options 	PROCFS			#Process filesystem
options 	COMPAT_43		#Compatible with BSD 4.3 [KEEP THIS!]
options 	SCSI_DELAY=3000		#Delay (in ms) before probing SCSI
options 	INCLUDE_CONFIG_FILE
options 	USERCONFIG		#boot -c editor
options 	VISUAL_USERCONFIG	#visual boot -c editor
options 	KTRACE			#ktrace(1) support
options 	SYSVSHM			#SYSV-style shared memory
options 	SYSVMSG			#SYSV-style message queues
options 	SYSVSEM			#SYSV-style semaphores
options 	P1003_1B		#Posix P1003_1B real-time extensions
options 	_KPOSIX_PRIORITY_SCHEDULING
options		ICMP_BANDLIM		#Rate limit bad replies
options 	KBD_INSTALL_CDEV	# install a CDEV entry in /dev
options		VESA
options         EXT2FS
options		USER_LDT
device		isa
device		pci
# Floppy drives
device		fdc0	at isa? port IO_FD1 irq 6 drq 2
device		fd0	at fdc0 drive 0
# SCSI peripherals
device		ahc		# AHA2940 and onboard AIC7xxx devices
device		scbus		# SCSI bus (required)
device		da		# Direct Access (disks)
device		cd		# CD
device		pass		# Passthrough device (direct SCSI access)
# atkbdc0 controls both the keyboard and the PS/2 mouse
device		atkbdc0	at isa? port IO_KBD
device		atkbd0	at atkbdc? irq 1 flags 0x1
device		psm0	at atkbdc? irq 12
device		vga0	at isa?
# splash screen/screen saver
pseudo-device	splash
# syscons is the default console driver, resembling an SCO console
device		sc0	at isa? flags 0x100
options		SC_HISTORY_SIZE=1200
options		SC_MOUSE_CHAR=0x03
# Floating point support - do not disable.
device		npx0	at nexus? port IO_NPX irq 13
# Power management support (see LINT for more options)
device		apm0    at nexus? flags 0x20 # Advanced Power Management
# Serial (COM) ports
device		sio0	at isa? port IO_COM1 flags 0x10 irq 4
device		sio1	at isa? port IO_COM2 irq 3
# Parallel port
device		ppc0	at isa? irq 7
device		ppbus		# Parallel port bus (required)
device		lpt		# Printer
device		plip		# TCP/IP over parallel
device		ppi		# Parallel port interface device
#device		vpo		# Requires scbus and da
# PCI Ethernet NICs.
device		fxp		# Intel EtherExpress PRO/100B (82557, 82558)
## sound
device		pcm
device		sbc
# Pseudo devices - the number indicates how many units to allocated.
pseudo-device	loop		# Network loopback
pseudo-device	ether		# Ethernet support
pseudo-device	sl	1	# Kernel SLIP
pseudo-device	ppp	1	# Kernel PPP
pseudo-device	tun		# Packet tunnel.
pseudo-device	pty	64	# Pseudo-ttys (telnet etc)
pseudo-device   vn	3
pseudo-device	bpf	3
pseudo-device	speaker

options 	NETGRAPH		#netgraph(4) system
options 	TCP_DROP_SYNFIN		#drop TCP packets with SYN+FIN
options 	TCP_RESTRICT_RST	#restrict emission of TCP RST
options 	ICMP_BANDLIM
options 	QUOTA			#enable disk quotas
options 	NTIMECOUNTER=20
options 	VESA
===}}}

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-stable" in the body of the message




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20010411192854.A570>