IDE + CPU Scaling problem on Via EPIA systems

From: gboyce
Date: Mon Nov 28 2005 - 00:02:11 EST


Folks,

While attempting to setup a new server using a Via EPIA-M motherboard (Nehemiah processor), I encountered a problem when I enabled CPU Frequency scaling via the powernowd daemon.

The system is using software RAID 1 on a pair of IDE drives. Everything goes fine until powernowd is enabled. At that point I get the following errors:

[4294871.703000] hda: dma_timer_expiry: dma status == 0x20
[4294871.703000] hda: DMA timeout retry
[4294871.703000] hda: timeout waiting for DMA
[4294871.703000] hda: status error: status=0x58 { DriveReady SeekComplete DataRequest }
[4294871.703000]
[4294871.703000] ide: failed opcode was: unknown
[4294871.703000] hda: drive not ready for command
[4294958.589000] hda: dma_timer_expiry: dma status == 0x20
[4294958.589000] hda: DMA timeout retry
[4294958.589000] hda: timeout waiting for DMA
[4294958.589000] hda: status error: status=0x58 { DriveReady SeekComplete DataRequest }
[4294958.589000]
[4294958.589000] ide: failed opcode was: unknown
[4294958.589000] hda: drive not ready for command

I ran the system for an extended time previously with no problem, but at this point I did not use powernowd, and I was not using RAID.

The system is running Ubuntu, but I also encountered someone else with the same problem on an older Via EPIA system and SuSE. The ubuntu kernel I'm using is 2.6.12-10-386.

I've attached the full dmesg output as well.

For now I'm just going to turn off cpu scaling. Someday I'd like to use it though. Any suggestions for things I can try? Or is this perhaps a known issue of some sort?

--
Gregsor.
[4294667.296000] Using pmtmr for high-res timesource
[4294667.296000] Console: colour VGA+ 80x25
[4294671.344000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
[4294671.345000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
[4294671.377000] Memory: 218888k/229312k available (1416k kernel code, 9816k reserved, 762k data, 224k init, 0k highmem)
[4294671.377000] Checking if this processor honours the WP bit even in supervisor mode... Ok.
[4294671.377000] Calibrating delay loop... 1982.46 BogoMIPS (lpj=991232)
[4294671.398000] Security Framework v1.0.0 initialized
[4294671.398000] SELinux: Disabled at boot.
[4294671.398000] Mount-cache hash table entries: 512
[4294671.398000] CPU: After generic identify, caps: 0380b03d 00000000 00000000 00000000 00000000 00000000 00000000
[4294671.398000] CPU: L1 I Cache: 64K (32 bytes/line), D cache 64K (32 bytes/line)
[4294671.398000] CPU: L2 Cache: 64K (32 bytes/line)
[4294671.398000] CPU: After all inits, caps: 0380b13d 00000000 00000000 00000000 00000000 0000003d 00000000
[4294671.398000] CPU: Centaur VIA Nehemiah stepping 05
[4294671.398000] Enabling fast FPU save and restore... done.
[4294671.398000] Enabling unmasked SIMD FPU exception support... done.
[4294671.398000] Checking 'hlt' instruction... OK.
[4294671.402000] Checking for popad bug... OK.
[4294671.402000] checking if image is initramfs... it is
[4294672.851000] Freeing initrd memory: 5141k freed
[4294672.857000] ACPI: Looking for DSDT in initrd... not found!
[4294673.050000] not found!
[4294673.066000] ACPI: setting ELCR to 0200 (from 1e20)
[4294673.126000] NET: Registered protocol family 16
[4294673.126000] EISA bus registered
[4294673.126000] ACPI: bus type pci registered
[4294673.135000] PCI: PCI BIOS revision 2.10 entry at 0xfb260, last bus=1
[4294673.135000] PCI: Using configuration type 1
[4294673.135000] mtrr: v2.0 (20020519)
[4294673.136000] ACPI: Subsystem revision 20050729
[4294673.153000] ACPI: Interpreter enabled
[4294673.153000] ACPI: Using PIC for interrupt routing
[4294673.154000] ACPI: PCI Root Bridge [PCI0] (0000:00)
[4294673.154000] PCI: Probing PCI hardware (bus 00)
[4294673.154000] ACPI: Assume root bridge [\_SB_.PCI0] segment is 0
[4294673.159000] Boot video device is 0000:01:00.0
[4294673.203000] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[4294673.206000] ACPI: PCI Interrupt Link [LNKA] (IRQs 1 3 4 5 6 7 10 *11 12 14 15)
[4294673.207000] ACPI: PCI Interrupt Link [LNKB] (IRQs 1 3 4 5 6 7 10 11 *12 14 15)
[4294673.208000] ACPI: PCI Interrupt Link [LNKC] (IRQs 1 3 4 5 6 7 *10 11 12 14 15)
[4294673.209000] ACPI: PCI Interrupt Link [LNKD] (IRQs 1 3 4 *5 6 7 10 11 12 14 15)
[4294673.215000] Linux Plug and Play Support v0.97 (c) Adam Belay
[4294673.215000] pnp: PnP ACPI init
[4294673.223000] pnp: PnP ACPI: found 12 devices
[4294673.223000] PnPBIOS: Disabled by ACPI PNP
[4294673.223000] PCI: Using ACPI for IRQ routing
[4294673.223000] PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
[4294673.280000] pnp: 00:01: ioport range 0x400-0x47f could not be reserved
[4294673.280000] pnp: 00:01: ioport range 0x500-0x50f has been reserved
[4294673.281000] audit: initializing netlink socket (disabled)
[4294673.281000] audit: initialized
[4294673.281000] VFS: Disk quotas dquot_6.5.1
[4294673.281000] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[4294673.281000] devfs: 2004-01-31 Richard Gooch (rgooch@xxxxxxxxxxxxx)
[4294673.281000] devfs: boot_options: 0x0
[4294673.281000] Initializing Cryptographic API
[4294673.282000] isapnp: Scanning for PnP cards...
[4294673.635000] isapnp: No Plug & Play device found
[4294673.681000] PNP: PS/2 controller doesn't have AUX irq; using default 0xc
[4294673.681000] PNP: PS/2 Controller [PNP0303:PS2K] at 0x60,0x64 irq 112
[4294673.681000] serio: i8042 AUX port at 0x60,0x64 irq 12
[4294673.681000] serio: i8042 KBD port at 0x60,0x64 irq 1
[4294673.681000] Serial: 8250/16550 driver $Revision: 1.90 $ 54 ports, IRQ sharing enabled
[4294673.681000] ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[4294673.681000] ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[4294673.686000] ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[4294673.687000] ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[4294673.687000] io scheduler noop registered
[4294673.687000] io scheduler anticipatory registered
[4294673.687000] io scheduler deadline registered
[4294673.687000] io scheduler cfq registered
[4294673.688000] RAMDISK driver initialized: 16 RAM disks of 65536K size 1024 blocksize
[4294673.688000] EISA: Probing bus 0 at eisa.0
[4294673.688000] EISA: Detected 0 cards.
[4294673.688000] NET: Registered protocol family 2
[4294673.697000] IP: routing cache hash table of 2048 buckets, 16Kbytes
[4294673.697000] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
[4294673.697000] TCP bind hash table entries: 8192 (order: 3, 32768 bytes)
[4294673.697000] TCP: Hash tables configured (established 8192 bind 8192)
[4294673.698000] NET: Registered protocol family 8
[4294673.698000] NET: Registered protocol family 20
[4294673.698000] ACPI wakeup devices:
[4294673.698000] PCI0 USB0 USB1 USB2 USB3 USB4 USB5 USB6 LAN0 AC97 MC97 UAR1
[4294673.698000] ACPI: (supports S0 S1 S4 S5)
[4294673.699000] Freeing unused kernel memory: 224k freed
[4294673.809000] Capability LSM initialized
[4294673.812000] input: AT Translated Set 2 keyboard on isa0060/serio0
[4294673.847000] NET: Registered protocol family 1
[4294673.895000] Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
[4294673.895000] ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
[4294673.895000] ACPI: bus type ide registered
[4294673.907000] VP_IDE: IDE controller at PCI slot 0000:00:11.1
[4294673.909000] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 11
[4294673.909000] PCI: setting IRQ 11 as level-triggered
[4294673.909000] ACPI: PCI Interrupt 0000:00:11.1[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[4294673.909000] PCI: Via IRQ fixup for 0000:00:11.1, from 255 to 11
[4294673.909000] VP_IDE: chipset revision 6
[4294673.909000] VP_IDE: not 100% native mode: will probe irqs later
[4294673.909000] VP_IDE: VIA vt8235 (rev 00) IDE UDMA133 controller on pci0000:00:11.1
[4294673.909000] ide0: BM-DMA at 0xe000-0xe007, BIOS settings: hda:DMA, hdb:pio
[4294673.909000] ide1: BM-DMA at 0xe008-0xe00f, BIOS settings: hdc:DMA, hdd:DMA
[4294673.909000] Probing IDE interface ide0...
[4294674.293000] hda: Maxtor 6Y160P0, ATA DISK drive
[4294674.905000] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[4294674.905000] Probing IDE interface ide1...
[4294675.697000] hdc: MATSHITACD-RW CW-8123, ATAPI CD/DVD-ROM drive
[4294675.952000] hdd: ST3120026A, ATA DISK drive
[4294676.003000] ide1 at 0x170-0x177,0x376 on irq 15
[4294676.004000] Probing IDE interface ide2...
[4294676.517000] Probing IDE interface ide3...
[4294677.030000] Probing IDE interface ide4...
[4294677.543000] Probing IDE interface ide5...
[4294678.066000] hda: max request size: 1024KiB
[4294678.082000] hda: 320173056 sectors (163928 MB) w/7936KiB Cache, CHS=19929/255/63, UDMA(133)
[4294678.082000] hda: cache flushes supported
[4294678.083000] /dev/ide/host0/bus0/target0/lun0: p1 p2 p4
[4294678.092000] hdd: max request size: 1024KiB
[4294678.092000] hdd: 234441648 sectors (120034 MB) w/8192KiB Cache, CHS=16383/255/63, UDMA(100)
[4294678.093000] hdd: cache flushes supported
[4294678.093000] /dev/ide/host0/bus1/target1/lun0: p1
[4294678.106000] hdc: ATAPI 24X DVD-ROM CD-R/RW drive, 2048kB Cache
[4294678.106000] Uniform CD-ROM driver Revision: 3.20
[4294679.003000] Attempting manual resume
[4294679.003000] swsusp: Suspend partition has wrong signature?
[4294679.102000] usbcore: registered new driver usbfs
[4294679.102000] usbcore: registered new driver hub
[4294679.104000] USB Universal Host Controller Interface driver v2.2
[4294679.105000] ACPI: PCI Interrupt 0000:00:10.0[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[4294679.105000] uhci_hcd 0000:00:10.0: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
[4294679.167000] uhci_hcd 0000:00:10.0: new USB bus registered, assigned bus number 1
[4294679.167000] uhci_hcd 0000:00:10.0: irq 11, io base 0x0000d400
[4294679.167000] hub 1-0:1.0: USB hub found
[4294679.167000] hub 1-0:1.0: 2 ports detected
[4294679.171000] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 12
[4294679.171000] PCI: setting IRQ 12 as level-triggered
[4294679.171000] ACPI: PCI Interrupt 0000:00:10.1[B] -> Link [LNKB] -> GSI 12 (level, low) -> IRQ 12
[4294679.171000] uhci_hcd 0000:00:10.1: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#2)
[4294679.233000] uhci_hcd 0000:00:10.1: new USB bus registered, assigned bus number 2
[4294679.233000] uhci_hcd 0000:00:10.1: irq 12, io base 0x0000d800
[4294679.233000] hub 2-0:1.0: USB hub found
[4294679.233000] hub 2-0:1.0: 2 ports detected
[4294679.237000] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
[4294679.237000] PCI: setting IRQ 10 as level-triggered
[4294679.237000] ACPI: PCI Interrupt 0000:00:10.2[C] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
[4294679.237000] uhci_hcd 0000:00:10.2: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller (#3)
[4294679.299000] uhci_hcd 0000:00:10.2: new USB bus registered, assigned bus number 3
[4294679.299000] uhci_hcd 0000:00:10.2: irq 10, io base 0x0000dc00
[4294679.299000] hub 3-0:1.0: USB hub found
[4294679.299000] hub 3-0:1.0: 2 ports detected
[4294679.376000] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 5
[4294679.376000] PCI: setting IRQ 5 as level-triggered
[4294679.376000] ACPI: PCI Interrupt 0000:00:10.3[D] -> Link [LNKD] -> GSI 5 (level, low) -> IRQ 5
[4294679.376000] ehci_hcd 0000:00:10.3: VIA Technologies, Inc. USB 2.0
[4294679.376000] ehci_hcd 0000:00:10.3: new USB bus registered, assigned bus number 4
[4294679.376000] ehci_hcd 0000:00:10.3: irq 5, io mem 0xde001000
[4294679.376000] ehci_hcd 0000:00:10.3: USB 2.0 initialized, EHCI 1.00, driver 10 Dec 2004
[4294679.376000] hub 4-0:1.0: USB hub found
[4294679.376000] hub 4-0:1.0: 6 ports detected
[4294679.496000] via-rhine.c:v1.10-LK1.2.0-2.6 June-10-2004 Written by Donald Becker
[4294679.496000] ACPI: PCI Interrupt 0000:00:12.0[A] -> Link [LNKA] -> GSI 11 (level, low) -> IRQ 11
[4294679.500000] eth0: VIA Rhine II at 0x1ec00, 00:40:63:d7:a9:0f, IRQ 11.
[4294679.501000] eth0: MII PHY found at address 1, status 0x786d advertising 05e1 Link 45e1.
[4294680.241000] usb 1-2: new full speed USB device using uhci_hcd and address 2
[4294680.332000] hub 1-2:1.0: USB hub found
[4294680.334000] hub 1-2:1.0: 3 ports detected
[4294680.515000] usb 1-2.1: new full speed USB device using uhci_hcd and address 3
[4294681.577000] usbcore: registered new driver hiddev
[4294681.581000] input: USB HID v1.00 Keyboard [Silitek IBM USB HUB KEYBOARD] on usb-0000:00:10.0-2.1
[4294681.585000] input: USB HID v1.00 Device [Silitek IBM USB HUB KEYBOARD] on usb-0000:00:10.0-2.1
[4294681.585000] usbcore: registered new driver usbhid
[4294681.585000] drivers/usb/input/hid-core.c: v2.01:USB HID core driver
[4294682.633000] ACPI: CPU0 (power states: C1[C1] C2[C2])
[4294682.633000] ACPI: Processor [CPU0] (supports 2 throttling states)
[4294682.745000] md: md driver 0.90.1 MAX_MD_DEVS=256, MD_SB_DISKS=27
[4294682.753000] md: raid1 personality registered as nr 3
[4294682.973000] devfs_mk_dev: could not append to parent for md/0
[4294682.981000] md: md0 stopped.
[4294682.982000] md: bind<hdd1>
[4294682.982000] md: bind<hda2>
[4294682.982000] md: md0: raid array is not clean -- starting background reconstruction
[4294682.983000] raid1: raid set md0 active with 2 out of 2 mirrors
[4294682.985000] .<6>md: syncing RAID array md0
[4294682.985000] md: minimum _guaranteed_ reconstruction speed: 1000 KB/sec/disc.
[4294682.985000] md: using maximum available idle IO bandwith (but not more than 200000 KB/sec) for reconstruction.
[4294682.985000] md: using 128k window, over a total of 117186048 blocks.
[4294682.985000] md: resuming recovery of md0 from checkpoint.
[4294683.098000] Attempting manual resume
[4294683.098000] swsusp: Suspend partition has wrong signature?
[4294683.124000] kjournald starting. Commit interval 5 seconds
[4294683.124000] EXT3-fs: mounted filesystem with ordered data mode.
[4294688.371000] Adding 979924k swap on /dev/hda1. Priority:-1 extents:1
[4294688.473000] EXT3 FS on hda4, internal journal
[4294694.670000] parport: PnPBIOS parport detected.
[4294694.670000] parport0: PC-style at 0x378, irq 7 [PCSPP,TRISTATE,EPP]
[4294694.766000] lp0: using parport0 (interrupt-driven).
[4294694.873000] mice: PS/2 mouse device common for all mice
[4294695.048000] ieee1394: Initialized config rom entry `ip1394'
[4294695.060000] SCSI subsystem initialized
[4294695.084000] sbp2: $Rev: 1219 $ Ben Collins <bcollins@xxxxxxxxxx>
[4294698.654000] device-mapper: 4.4.0-ioctl (2005-01-12) initialised: dm-devel@xxxxxxxxxx
[4294699.525000] cdrom: open failed.
[4294700.168000] kjournald starting. Commit interval 5 seconds
[4294700.168000] EXT3 FS on md0, internal journal
[4294700.168000] EXT3-fs: mounted filesystem with ordered data mode.
[4294701.226000] Linux agpgart interface v0.101 (c) Dave Jones
[4294701.247000] agpgart: Detected VIA CLE266 chipset
[4294701.260000] agpgart: AGP aperture is 128M @ 0xd0000000
[4294701.601000] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[4294701.634000] shpchp: shpc_init : shpc_cap_offset == 0
[4294701.634000] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
[4294701.993000] ohci1394: $Rev: 1250 $ Ben Collins <bcollins@xxxxxxxxxx>
[4294701.993000] ACPI: PCI Interrupt 0000:00:0d.0[A] -> Link [LNKB] -> GSI 12 (level, low) -> IRQ 12
[4294702.061000] ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[12] MMIO=[de000000-de0007ff] Max Packet=[2048]
[4294703.139000] irda_init()
[4294703.139000] NET: Registered protocol family 23
[4294703.330000] ieee1394: Host added: ID:BUS[0-00:1023] GUID[004063500001b247]
[4294704.570000] ACPI: PCI Interrupt 0000:00:11.5[C] -> Link [LNKC] -> GSI 10 (level, low) -> IRQ 10
[4294704.570000] PCI: Setting latency timer of device 0000:00:11.5 to 64
[4294709.120000] Real Time Clock Driver v1.12
[4294709.269000] input: PC Speaker
[4294709.806000] Floppy drive(s): fd0 is 1.44M
[4294709.820000] FDC 0 is a post-1991 82077
[4294712.466000] eth0: link up, 100Mbps, full-duplex, lpa 0x45E1
[4294712.500000] NET: Registered protocol family 17
[4294715.559000] NET: Registered protocol family 10
[4294715.559000] Disabled Privacy Extensions on device c02eb280(lo)
[4294715.559000] IPv6 over IPv4 tunneling driver
[4294718.087000] ACPI: Power Button (FF) [PWRF]
[4294718.087000] ACPI: Power Button (CM) [PWRB]
[4294718.483000] ibm_acpi: ec object not found
[4294725.851000] eth0: no IPv6 routers present
[4294788.304000] cdrom: open failed.
[4294788.540000] cdrom: open failed.
[4294850.638000] longhaul: VIA C3 'Nehemiah C' [C5N] CPU detected. Powersaver supported.
[4294871.703000] hda: dma_timer_expiry: dma status == 0x20
[4294871.703000] hda: DMA timeout retry
[4294871.703000] hda: timeout waiting for DMA
[4294871.703000] hda: status error: status=0x58 { DriveReady SeekComplete DataRequest }
[4294871.703000]
[4294871.703000] ide: failed opcode was: unknown
[4294871.703000] hda: drive not ready for command
[4294958.589000] hda: dma_timer_expiry: dma status == 0x20
[4294958.589000] hda: DMA timeout retry
[4294958.589000] hda: timeout waiting for DMA
[4294958.589000] hda: status error: status=0x58 { DriveReady SeekComplete DataRequest }
[4294958.589000]
[4294958.589000] ide: failed opcode was: unknown
[4294958.589000] hda: drive not ready for command