openbsd hangs momentarily at boot

[bogd]

it lasts ~60 seconds and I highlighted the last displayed line in red

OpenBSD 4.4 (GENERIC.MP) #1812: Tue Aug 12 17:22:53 MDT 2008
    deraadt@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 3341381632 (3186MB)
avail mem = 3241144320 (3090MB)
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.4 @ 0xdc010 (27 entries)
bios0: vendor Hewlett-Packard version "F.21" date 02/28/2008
bios0: Hewlett-Packard HP Pavilion dv2700 Notebook PC
acpi0 at bios0: rev 3
acpi0: tables DSDT FACP SLIC WDAT SRAT MCFG HPET APIC BOOT SSDT
acpi0: wakeup devices LID0(S3) SLPB(S3) MAC0(S5) P2P0(S5) MCEB(S4) DVDB(S4) QPWB
(S4) PICB(S4) VDOB(S4) LTVB(S4) MUSB(S4) KBD0(S3) PS2M(S3)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpihpet0 at acpi0: 25000000 Hz
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: AMD Turion(tm) 64 X2 TL-60, 2000.53 MHz
cpu0: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CF
LUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,CX16,NXE,MMXX,FFXSR,LONG,3DNOW2,3DNOW
cpu0: 64KB 64b/line 2-way I-cache, 64KB 64b/line 2-way D-cache, 512KB 64b/line 1
6-way L2 cache
cpu0: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu0: DTLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu0: apic clock running at 200MHz
cpu1 at mainbus0: apid 1 (application processor)
cpu1: AMD Turion(tm) 64 X2 TL-60, 2000.19 MHz
cpu1: FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CF
LUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,CX16,NXE,MMXX,FFXSR,LONG,3DNOW2,3DNOW
cpu1: 64KB 64b/line 2-way I-cache, 64KB 64b/line 2-way D-cache, 512KB 64b/line 1
6-way L2 cache
cpu1: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative
cpu1: DTLB 32 4KB entries fully associative, 8 4MB entries fully associative
ioapic0 at mainbus0 apid 2 pa 0xfec00000, version 11, 24 pins
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus 1 (P2P0)
acpiprt2 at acpi0: bus 255 (XVR0)
acpiprt3 at acpi0: bus 6 (XVR1)
acpiprt4 at acpi0: bus 4 (XVR2)
acpiec0 at acpi0
acpitz0 at acpi0: critical temperature 120 degC
acpitz1 at acpi0: critical temperature 120 degC
acpicpu0 at acpi0: PSS
acpicpu1 at acpi0: PSS
acpibtn0 at acpi0: LID0
acpibtn1 at acpi0: SLPB
acpibtn2 at acpi0: PWRB
acpibat0 at acpi0: BAT0 not present
acpiac0 at acpi0: AC unit online
acpivideo at acpi0 not configured
cpu0: PowerNow! K8 2000 MHz: speeds: 2000 1800 1600 800 MHz
pci0 at mainbus0 bus 0: configuration mode 1
"NVIDIA MCP67 Memory" rev 0xa2 at pci0 dev 0 function 0 not configured
pcib0 at pci0 dev 1 function 0 "NVIDIA MCP67 Host" rev 0xa2
nviic0 at pci0 dev 1 function 1 "NVIDIA MCP67 SMBus" rev 0xa2
iic0 at nviic0
iic1 at nviic0
spdmem0 at iic1 addr 0x50: 2GB DDR2 SDRAM non-parity PC2-5300CL5 SO-DIMM
spdmem1 at iic1 addr 0x51: 2GB DDR2 SDRAM non-parity PC2-5300CL5 SO-DIMM
"NVIDIA MCP67 Memory" rev 0xa2 at pci0 dev 1 function 2 not configured
vendor "NVIDIA", unknown product 0x0543 (class processor subclass Co-processor, 
rev 0xa2) at pci0 dev 1 function 3 not configured
ohci0 at pci0 dev 2 function 0 "NVIDIA MCP67 USB" rev 0xa2: apic 2 int 11 (irq 1
1), version 1.0, legacy support
ehci0 at pci0 dev 2 function 1 "NVIDIA MCP67 USB" rev 0xa2: apic 2 int 7 (irq 7)
usb0 at ehci0: USB revision 2.0
uhub0 at usb0 "NVIDIA EHCI root hub" rev 2.00/1.00 addr 1
ohci1 at pci0 dev 4 function 0 "NVIDIA MCP67 USB" rev 0xa2: apic 2 int 10 (irq 1
0), version 1.0, legacy support
ehci1 at pci0 dev 4 function 1 "NVIDIA MCP67 USB" rev 0xa2: apic 2 int 11 (irq 1
1)
usb1 at ehci1: USB revision 2.0
uhub1 at usb1 "NVIDIA EHCI root hub" rev 2.00/1.00 addr 1
pciide0 at pci0 dev 6 function 0 "NVIDIA MCP67 IDE" rev 0xa1: DMA, channel 0 con
figured to compatibility, channel 1 configured to compatibility
atapiscsi0 at pciide0 channel 0 drive 0
scsibus0 at atapiscsi0: 2 targets, initiator 7
cd0 at scsibus0 targ 0 lun 0: <Slimtype, DVD A DS8A1H, WH66> ATAPI 5/cdrom remov
able
cd0(pciide0:0:0): using PIO mode 4, DMA mode 2
pciide0: channel 1 ignored (disabled)
azalia0 at pci0 dev 7 function 0 "NVIDIA MCP67 HD Audio" rev 0xa1: apic 2 int 10
 (irq 10)
azalia0: codec[s]: Conexant/0x5051
audio0 at azalia0
ppb0 at pci0 dev 8 function 0 "NVIDIA MCP67 PCI" rev 0xa2
pci1 at ppb0 bus 1
"Ricoh 5C832 Firewire" rev 0x05 at pci1 dev 9 function 0 not configured
sdhc0 at pci1 dev 9 function 1 "Ricoh 5C822 SD/MMC" rev 0x22: apic 2 int 10 (irq
 11)
sdmmc0 at sdhc0
"Ricoh 5C843 MMC" rev 0x12 at pci1 dev 9 function 2 not configured
"Ricoh 5C592 Memory Stick" rev 0x12 at pci1 dev 9 function 3 not configured
"Ricoh 5C852 xD" rev 0x12 at pci1 dev 9 function 4 not configured
pciide1 at pci0 dev 9 function 0 "NVIDIA MCP67 SATA" rev 0xa2: DMA
pciide1: using apic 2 int 5 (irq 5) for native-PCI interrupt
wd0 at pciide1 channel 0 drive 0: <FUJITSU MHY2250BH>
wd0: 16-sector PIO, LBA48, 238475MB, 488397168 sectors
wd0(pciide1:0:0): using PIO mode 4, Ultra-DMA mode 5
nfe0 at pci0 dev 10 function 0 "NVIDIA MCP67 LAN" rev 0xa2: apic 2 int 11 (irq 1
1), address 00:1d:72:56:d4:09
eephy0 at nfe0 phy 1: Marvell 88E1118 Gigabit PHY, rev. 0
ppb1 at pci0 dev 12 function 0 "NVIDIA MCP67 PCIE" rev 0xa2
pci2 at ppb1 bus 6
ppb2 at pci0 dev 13 function 0 "NVIDIA MCP67 PCIE" rev 0xa2
pci3 at ppb2 bus 4
"Broadcom BCM4328" rev 0x03 at pci3 dev 0 function 0 not configured
vga1 at pci0 dev 18 function 0 vendor "NVIDIA", unknown product 0x0531 rev 0xa2
wsdisplay0 at vga1 mux 1: console (80x25, vt100 emulation)
wsdisplay0: screen 1-5 added (80x25, vt100 emulation)
drm at vga1 unsupported
pchb0 at pci0 dev 24 function 0 "AMD AMD64 0Fh HyperTransport" rev 0x00
pchb1 at pci0 dev 24 function 1 "AMD AMD64 0Fh Address Map" rev 0x00
pchb2 at pci0 dev 24 function 2 "AMD AMD64 0Fh DRAM Cfg" rev 0x00
kate0 at pci0 dev 24 function 3 "AMD AMD64 0Fh Misc Cfg" rev 0x00: core rev BH-G
2
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5
pckbd0 at pckbc0 (kbd slot)
pckbc0: using irq 1 for kbd slot
wskbd0 at pckbd0: console keyboard, using wsdisplay0
pms0 at pckbc0 (aux slot)
pckbc0: using irq 12 for aux slot
wsmouse0 at pms0 mux 0
pcppi0 at isa0 port 0x61
midi0 at pcppi0: <PC speaker>
spkr0 at pcppi0
usb2 at ohci0: USB revision 1.0
uhub2 at usb2 "NVIDIA OHCI root hub" rev 1.00/1.00 addr 1
usb3 at ohci1: USB revision 1.0
uhub3 at usb3 "NVIDIA OHCI root hub" rev 1.00/1.00 addr 1
mtrr: Pentium Pro MTRR support
uhidev0 at uhub2 port 1 configuration 1 interface 0 "Logitech Optical USB Mouse"
 rev 2.00/3.40 addr 2
uhidev0: iclass 3/1
ums0 at uhidev0: 3 buttons, Z dir
wsmouse1 at ums0 mux 0
uvideo0 at uhub2 port 4 configuration 1 interface 0 "Chicony Electronics Co., Lt
d. HP Webcam" rev 2.00/6.04 addr 3
video0 at uvideo0
softraid0 at root
root on wd0a swap on wd0b dump on wd0b

is this a bug?

[jggimi]

It's possibly a bug. Based on your description, it is more likely a hardware problem. The delay occurs between the probe of your second pciide bus (pciide1) and finding the hard drive (wd0) on that bus.

Question: Was this delay present when you booted the GENERIC kernel, or does it appear only when use use the GENERIC.MP kernel?

Question: Did this delay happen with the RAMDISK (/bsd.rd) kernel, too?

If it always happens, then it is most likely indicative of some problem communicating with the hard drive's electronics.

It is possible that you might obtain additional information on your console (and dmesg) during the hardware probes by booting in verbose mode. To do that:

At the boot> prompt, use the -c option. e.g.:

boot> boot bsd.mp -c

Then, at the UKC> prompt, set verbose mode:

UKC> verbose
UKC> quit

For more information, see boot(8) and boot_config(8).

[bogd]

Originally Posted by jggimi

Question: Was this delay present when you booted the GENERIC kernel, or does it appear only when use use the GENERIC.MP kernel?

Yes. But that's another problem. When I booted the GENERIC kernel, the whole system would go unresponsive a few seconds after starting Xmms (that I got with pkg_add). The only thing I could do was to forcibly shut it down. Then I ended up with an unusable pkg_add.

This guy seemed to have the same problem I did: http://fixunix.com/bsd/87339-screwed-up-pkg_add.html

Wiping out /usr/local and /var/db/pkg did not help solving the pkg_add problem and starting Xmms would freeze everything again. None of this occurred under GENERIC.MP

Originally Posted by jggimi

Question: Did this delay happen with the RAMDISK (/bsd.rd) kernel, too?

Yes.

Originally Posted by jggimi

It is possible that you might obtain additional information on your console (and dmesg) during the hardware probes by booting in verbose mode.

dmesg | more gives:

i probe returned 0
>>> probing for ehci*
>>> ehci probe returned 0
>>> probing for cbb*
>>> cbb probe returned 0
>>> probing for skc*
>>> skc probe returned 0
>>> probing for mskc*
>>> mskc probe returned 0
>>> probing for puc*
>>> puc probe returned 0
>>> probing for wi*
>>> wi probe returned 0
>>> probing for an*
>>> an probe returned 0
>>> probing for iwi*
>>> iwi probe returned 0
>>> probing for wpi*
>>> wpi probe returned 0
>>> probing for iwn*
>>> iwn probe returned 0
>>> probing for cmpci*
>>> cmpci probe returned 0
byte 529

The beginning seems to be missing if not other portions as well. Is there a way to view it fully?

Thanks for your help.

[jggimi]

Unfortunately, there is only a limited amount of space for kernel messages in the in-core dmesg.

You might find useful information in /var/run/dmesg.boot or /var/log/messages.

----

I believe this particular problem - delays during kernel-probe at boot time -- has little or nothing to do with your system hang when running a multimedia application under GENERIC. Let's solve one problem at a time.

[bogd]

Originally Posted by jggimi

Unfortunately, there is only a limited amount of space for kernel messages in the in-core dmesg.

You might find useful information in /var/run/dmesg.boot or /var/log/messages.

I looked into those two places and the output is no different from dmesg, still missing portions (especially the one concerning pciide1 and wd0).

Would pcidump provide hints? I'm no hardware expert...

[jggimi]

Not really; if you look at the output it only shows pci bus configuration.

Perhaps SMART data from the drive electronics might indicate if there have been any communications problems; this may indicate if you have cable or device connection problems.

You may be able to use atactl to obtain SMART data; I prefer the smartmontools package. After installing it, you may review the output from:

# smartctl -a /dev/wd0c

[bogd]

Hi jggimi

Here is the result from running smartctl -a /dev/wd0c

smartctl version 5.38 [x86_64-unknown-openbsd4.4] Copyright (C) 2002-8 Bruce All
en
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     FUJITSU MHY2250BH
Serial Number:    K413T842NJ4R
Firmware Version: 890B
User Capacity:    250,059,350,016 bytes
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   8
ATA Standard is:  ATA-8-ACS revision 3f
Local Time is:    Fri Jan  2 16:56:41 2009 EST
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x00) Offline data collection activity
                                        was never started.
                                        Auto Offline Data Collection: Disabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever 
                                        been run.
Total time to complete Offline 
data collection:                 (1009) seconds.
Offline data collection
capabilities:                    (0x51) SMART execute Offline immediate.
                                        No Auto Offline data collection support.
                                        Suspend Offline collection upon new
                                        command.
                                        No Offline surface scan supported.
                                        Self-test supported.
                                        No Conveyance Self-test supported.
                                        Selective Self-test supported.
SMART capabilities:            (0x0003) Saves SMART data before entering
                                        power-saving mode.
                                        Supports SMART auto save timer.
Error logging capability:        (0x01) Error logging supported.
                                        General Purpose Logging supported.
Short self-test routine 
recommended polling time:        (   2) minutes.
Extended self-test routine
recommended polling time:        ( 143) minutes.
SCT capabilities:              (0x003f) SCT Status supported.
                                        SCT Feature Control supported.
                                        SCT Data Table supported.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_
FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000f   100   100   046    Pre-fail  Always       -
       60550
  2 Throughput_Performance  0x0005   100   100   030    Pre-fail  Offline      -
       53411840
  3 Spin_Up_Time            0x0003   100   100   025    Pre-fail  Always       -
       1
  4 Start_Stop_Count        0x0032   099   099   000    Old_age   Always       -
       394
  5 Reallocated_Sector_Ct   0x0033   100   100   024    Pre-fail  Always       -
       8589934592000
  7 Seek_Error_Rate         0x000f   100   100   047    Pre-fail  Always       -
       1538
  8 Seek_Time_Performance   0x0005   100   100   019    Pre-fail  Offline      -
       0
  9 Power_On_Hours          0x0032   097   097   000    Old_age   Always       -
       1871
 10 Spin_Retry_Count        0x0013   100   100   020    Pre-fail  Always       -
       0
 11 Calibration_Retry_Count 0x0032   253   253   000    Old_age   Always       -
       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -
       378
182 Unknown_Attribute       0x0032   100   100   000    Old_age   Always       -
       0
184 Unknown_Attribute       0x0033   253   253   097    Pre-fail  Always       -
       0
185 Unknown_Attribute       0x0010   253   253   000    Old_age   Offline      -
       0
186 Unknown_Attribute       0x0032   253   253   000    Old_age   Always       -
       0
187 Reported_Uncorrect      0x0032   100   100   000    Old_age   Always       -
       42949672960
188 Unknown_Attribute       0x0032   100   100   000    Old_age   Always       -
       0
189 High_Fly_Writes         0x003a   100   100   000    Old_age   Always       -
       0
190 Airflow_Temperature_Cel 0x0022   057   045   000    Old_age   Always       -
       43 (Lifetime Min/Max 20/45)
191 G-Sense_Error_Rate      0x0032   253   253   000    Old_age   Always       -
       16580608
192 Power-Off_Retract_Count 0x0032   100   100   000    Old_age   Always       -
       2031647
193 Load_Cycle_Count        0x0032   099   099   000    Old_age   Always       -
       35569
195 Hardware_ECC_Recovered  0x001a   100   100   000    Old_age   Always       -
       16
196 Reallocated_Event_Count 0x0032   100   100   000    Old_age   Always       -
       445448192
197 Current_Pending_Sector  0x0012   100   100   000    Old_age   Always       -
       0
198 Offline_Uncorrectable   0x0010   100   100   000    Old_age   Offline      -
       0
199 UDMA_CRC_Error_Count    0x003e   200   253   000    Old_age   Always       -
       0
200 Multi_Zone_Error_Rate   0x000f   100   100   060    Pre-fail  Always       -
       6691
203 Run_Out_Cancel          0x0002   100   100   000    Old_age   Always       -
       3732259668357
240 Head_Flying_Hours       0x003e   200   200   000    Old_age   Always       -
       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


SMART Selective self-test log data structure revision number 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.

[jggimi]

No errors were logged; if there had been any communication problems (cable,connector) we would have seen them here.

Attributes are a little confusing. While none of them should have anything to do with a delay during probe, some indicate disk-drive trouble, if they are at all accurate. It is unclear how accurate they are, the vendors all use different raw and normalized values.

You have a high read error rate (Attribute 1). http://en.wikipedia.org/wiki/S.M.A.R.T. says:

Indicates the rate of hardware read errors that occurred when reading data from a disk surface. A non-zero value indicates a problem with either the disk surface or read/write heads. Note that Seagate drives often report a raw value that is very high even on new drives, and does not thereby indicate a failure.

Your drive was manufactured by FJ, not Seagate.

Your reallocated sector count (#5) and reallocation (#196) raw values are so large I believe they are meaningless. As is your run out cancel (#203). I'm guessing the vendor doesn't use these fields as intended.

A short offline test (#smartctl -t short /dev/wd0c) will test drive electronics, and basic seek and read operations. Wait two minutes, then run #smartctl -a /dev/wd0c, look near the bottom to see if the test is successful. The long offline test will read every addressable sector on the drive.

I'm going to guess that the electronics will test without error.

[bogd]

completed without error

out of curiosity, is it possible to disable apic?

[jggimi]

If you meant ACPI, then yes, ACPI can be disabled via boot -c. I don't know if disabling ioapic would result in a working kernel.

[h5n1]

@jggimi

Tell me,how can I exactly disable ACPI.

[jggimi]

To test:

boot> boot -c
UKC> disable acpi
UKC> quit

To make permanent, while still running a reconfigured kernel:

# config -euf /bsd