[#5557] run bonnie++ on ide harddisk has timeout

Submitted By: Mingquan Pan

Open Date

2009-09-26 22:38:43

Priority:

Medium Assignee:

Barry Song

Status:

Open Fixed In Release:

N/A

Found In Release:

2010R1 Release:

Category:

N/A Board:

N/A

Processor:

BF537 Silicon Revision:

Is this bug repeatable?:

Yes Resolution:

Upstream

Uboot version or rev.:

Toolchain version or rev.:

09r1-rc9

App binary format:

N/A

Summary: run bonnie++ on ide harddisk has timeout

Details:

run bonnie++ on ide harddisk has timeout now.

root:/> vePHY: 0:01 - Link is Up - 100/Full^M

rsion^M

kernel: Linux release 2.6.31-ADI-2010R1-pre-svn7448, build #4 Fri Sep 25 12:07:28 MDT 2009^M

toolchain: bfin-uclinux-gcc release gcc version 4.1.2 (ADI svn)^M

user-dist: release svn-8884, build #46 Fri Sep 25 12:06:31 MDT 2009^M

....

mount /dev/sda1 /mnt^M

bonnie++ -u root -d /mnt^M

root:/> bonnie++ -u root -d /mnt^M

Using uid:0, gid:0.^M

Writing a byte at a time...done^M

Writing intelligently...done^M

Rewriting...done^M

Reading a byte at a time...done^M

Reading intelligently...bonnie++ timeout

Last passed time: 2009_Sep_09_18_56, ucdist ver: 8834, kernel ver: 7275

Follow-ups

--- Barry Song 2009-10-09 03:55:42

Yes. The upgraded kernel causes some chances that interrupts will lose:

root:/> bonnie\+\+ -u root -d /mnt/

Using uid:0, gid:0.

Writing a byte at a time...done

Writing intelligently...done

Rewriting...ata1: lost interrupt (Status 0x58)

ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen

ata1.00: cmd 20/00:00:67:d3:e8/00:00:00:00:00/e2 tag 0 pio 131072 in

res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata1.00: status: { DRDY }

ata1: soft resetting link

ata1.00: configured for PIO

ata1.00: device reported invalid CHS sector 0

ata1: EH complete

ata1.00: limiting speed to UDMA7:PIO5

ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen

ata1.00: ST-ATA: BUSY|DRQ persists on ERR|DF, dev_stat 0x7E

ata1.00: cmd 34/00:00:5f:b7:e9/00:04:02:00:00/e0 tag 0 pio 524288 out

res 58/00:07:58:bb:e9/00:00:02:00:00/e0 Emask 0x3 (HSM violation)

ata1.00: status: { DRDY DRQ }

ata1: soft resetting link

ata1.00: configured for PIO

ata1: EH complete

ata1: lost interrupt (Status 0x58)

ata1.00: limiting speed to PIO0

ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen

ata1.00: cmd 20/00:00:6f:2d:ec/00:00:00:00:00/e2 tag 0 pio 131072 in

res 40/00:07:58:bb:e9/00:00:02:00:00/e0 Emask 0x4 (timeout)

ata1.00: status: { DRDY }

ata1: soft resetting link

ata1.00: configured for PIO

ata1: EH complete

ata1: lost interrupt (Status 0x58)

ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen

ata1.00: cmd 34/00:00:17:73:ec/00:04:02:00:00/e0 tag 0 pio 524288 out

res 40/00:07:58:bb:e9/00:00:02:00:00/e0 Emask 0x4 (timeout)

ata1.00: status: { DRDY }

ata1: soft resetting link

ata1.00: configured for PIO

ata1: EH complete

done

Reading a byte at a time...done

Reading intelligently...

Let me figure out what driver change causes this problem or whether our

hardware still has other interrupt issue even after adding that res Michael

pointed out.

--- Barry Song 2009-10-25 22:05:59

I find my HP laptop has also same "lost interrupt" problems after

upgrading kernel to 2.6.31. After lost interrupts, it begins to reset, and

accessing to the disk will be blocked for several seconds.

It seems some changes in the mainline ATA driver makes some

hard-disks/controller can't always work normally now.

--- Barry Song 2009-10-26 03:24:08

This problem disappear in the svn trunk head now:

root:/> uname -a

Linux blackfin 2.6.31.4-ADI-2010R1-pre-svn7704 #1595 Mon Oct 26 14:59:20 CST

2009 blackfin GNU/Linux

root:/> mount /dev/sda5 /mnt

EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended

root:/> bonnie++ -u root -d /mnt

Using uid:0, gid:0.

Writing a byte at a time...done

Writing intelligently...done

Rewriting...done

Reading a byte at a time...done

Reading intelligently...done

start 'em...done...done...done...done...done...

Create files in sequential order...done.

Stat files in sequential order...done.

Delete files in sequential order...done.

Create files in random order...done.

Stat files in random order...done.

Delete files in random order...done.

Version 1.94 ------Sequential Output------ --Sequential Input-

--Random-

Concurrency 1 -Per Chr- --Block-- -Rewrite- -Per Chr- --Block--

--Seeks--

Machine Size K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP /sec

%CP

blackfin 300M 57 99 6772 65 3454 79 165 99 6663 59 129.0

Latency 335ms 608ms 435ms 68000us 184ms 283ms

Version 1.94 ------Sequential Create------ --------Random

Create--------

blackfin -Create-- --Read--- -Delete-- -Create-- --Read---

-Delete--

files /sec %CP /sec %CP /sec %CP /sec %CP /sec %CP /sec

%CP

16 277 99 8827 100 4471 89 279 99 9372 100 989

Latency 92000us 4000us 4000us 72000us 4000us 4000us

1.93c,1.94,blackfin,1,1428964113,300M,,57,99,6772,65,3454,79,165,99,6663,59,129.0,5,16,,,,,277,99,8827,100,4471,89,279,99,9372,100,989,97,335ms,608ms,435ms,68000us,184ms,283ms,92000us,4000us,4000us,72000us,4000us,4000us

root:/> bonnie++ -u root -d /mnt

Using uid:0, gid:0.

Writing a byte at a time...done

Writing intelligently...done

Rewriting...done

Reading a byte at a time...done

Reading intelligently...done

start 'em...done...done...done...done...done...

Create files in sequential order...done.

Stat files in sequential order...done.

Delete files in sequential order...done.

Create files in random order...done.

Stat files in random order...done.

Delete files in random order...done.

Version 1.94 ------Sequential Output------ --Sequential Input-

--Random-

Concurrency 1 -Per Chr- --Block-- -Rewrite- -Per Chr- --Block--

--Seeks--

Machine Size K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP /sec

%CP

blackfin 300M 57 99 6767 64 3455 80 160 99 6657 61 128.7

Latency 332ms 552ms 447ms 68000us 164ms 296ms

Version 1.94 ------Sequential Create------ --------Random

Create--------

blackfin -Create-- --Read--- -Delete-- -Create-- --Read---

-Delete--

files /sec %CP /sec %CP /sec %CP /sec %CP /sec %CP /sec

%CP

16 276 99 8865 99 4566 93 279 99 9437 99 980

Latency 139ms 4000us 4000us 115ms 4000us 4000us

1.93c,1.94,blackfin,1,1428964927,300M,,57,99,6767,64,3455,80,160,99,6657,61,128.7,5,16,,,,,276,99,8865,99,4566,93,279,99,9437,99,980,97,332ms,552ms,447ms,68000us,164ms,296ms,139ms,4000us,4000us,115ms,4000us,4000us

And I make my HP laptop work by disabling ATA_ACPI feature.

--- Mingquan Pan 2009-11-02 03:46:26

Yeah, it is not seen these days. So close.

--- Barry Song 2009-11-03 21:33:17

The bug maybe is still active in mainline, check "Bug 14515 - ATA

controller losing interrupt, system stall":

http://bugzilla.kernel.org/show_bug.cgi?id=14515

--- Mingquan Pan 2010-01-15 03:22:29

It shows up again on trunk head testing. So reopen this.

Linux version 2.6.32.3-ADI-2010R1-pre-svn8131 (test@uclinux55-bf537-cf) (gcc

version 4.3.4 (ADI-trunk/svn-3771) ) #12 Fri Jan 8 13:37:02 CST 2010

bootconsole [early_shadow0] enabled

bootconsole [early_BFuart0] enabled

early printk enabled on early_BFuart0

Limiting kernel memory to 56MB due to anomaly 05000263

Board Memory: 64MB

Kernel Managed Memory: 64MB

Memory map:

fixedcode = 0x00000400-0x00000490

text = 0x00001000-0x0013e5c0

rodata = 0x0013e5c0-0x001ad808

bss = 0x001ae000-0x001bfe2c

data = 0x001bfe2c-0x001d2000

stack = 0x001d0000-0x001d2000

init = 0x001d2000-0x008ff000

available = 0x008ff000-0x03800000

DMA Zone = 0x03f00000-0x04000000

Hardware Trace Active and Enabled

Boot Mode: 0

Reset caused by Software reset

Compiled for ADSP-BF537 Rev 0.2

Blackfin Linux support by http://blackfin.uclinux.org/

Processor Speed: 350 MHz core clock and 70 MHz System Clock

boot memmap: 00000000008ff000 - 0000000003800000 (usable)

On node 0 totalpages: 14336

free_area_init_node: node 0, pgdat 001cece8, node_mem_map 00901000

DMA zone: 112 pages used for memmap

DMA zone: 0 pages reserved

DMA zone: 14224 pages, LIFO batch:0

NOMPU: setting up cplb tables

Instruction Cache Enabled for CPU0

External memory: cacheable in instruction cache

Data Cache Enabled for CPU0

External memory: cacheable (write-back) in data cache

Built 1 zonelists in Zone order, mobility grouping off. Total pages: 14224

Kernel command line: root=/dev/mtdblock0 rw ip=10.100.4.50

earlyprintk=serial,uart0,57600 console=ttyBF0,57600

ip=10.100.4.50:10.100.4.174:10.100.4.174:255.255.255.0:bf537-stamp:eth0:off

PID hash table entries: 256 (order: -2, 1024 bytes)

Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)

Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)

Kernel managed physical pages: 14336

Memory available: 47564k/65536k RAM, (7348k init code, 1269k kernel code, 591k

data, 1024k dma, 7740k reserved)

Hierarchical RCU implementation.

NR_IRQS:98

Configuring Blackfin Priority Driven Interrupts

console [ttyBF0] enabled, bootconsole disabled

Calibrating delay loop... 696.32 BogoMIPS (lpj=1392640)

Security Framework initialized

Mount-cache hash table entries: 512

Blackfin Scratchpad data SRAM: 4 KB

Blackfin L1 Data A SRAM: 16 KB (16 KB free)

Blackfin L1 Data B SRAM: 16 KB (16 KB free)

Blackfin L1 Instruction SRAM: 48 KB (36 KB free)

NET: Registered protocol family 16

Blackfin DMA Controller

stamp_init(): registering device resources

bio: create slab <bio-0> at 0

SCSI subsystem initialized

libata version 3.00 loaded.

Switching to clocksource bfin_cs_cycles

NET: Registered protocol family 2

IP route cache hash table entries: 1024 (order: 0, 4096 bytes)

TCP established hash table entries: 2048 (order: 2, 16384 bytes)

TCP bind hash table entries: 2048 (order: 1, 8192 bytes)

TCP: Hash tables configured (established 2048 bind 2048)

TCP reno registered

NET: Registered protocol family 1

Setting up Blackfin MMR debugfs

msgmni has been set to 92

io scheduler noop registered

io scheduler anticipatory registered (default)

io scheduler cfq registered

bfin-uart: Blackfin serial driver

bfin-uart.0: ttyBF0 at MMIO 0xffc00400 (irq = 18) is a BFIN-UART

brd: module loaded

scsi0 : pata_platform

ata1: PATA max PIO0 mmio cmd 0x20314020 ctl 0x2031401c irq 55

bfin-spi bfin-spi.0: Blackfin on-chip SPI Controller Driver, Version 1.0,

regs_base@ffc00500, dma channel@7

bfin_mii_bus: probed

bfin_mac: attached PHY driver [SMSC LAN83C185] (mii_bus:phy_addr=0:01, irq=-1,

mdc_clk=2500000Hz(mdc_div=13)@sclk=70MHz)

bfin_mac bfin_mac.0: Blackfin on-chip Ethernet MAC driver, Version 1.1

rtc-bfin rtc-bfin: rtc core: registered rtc-bfin as rtc0

bfin-wdt: initialized: timeout=20 sec (nowayout=0)

TCP cubic registered

NET: Registered protocol family 17

rtc-bfin rtc-bfin: setting system clock to 1970-11-21 13:42:05 UTC (28042925)

ata1.00: ATA-6: WDC WD800BB-00JHC0, 05.01C05, max UDMA/100

ata1.00: 156301488 sectors, multi 0: LBA

ata1.01: ATAPI: TSSTcorpDVD-ROM TS-H352C, CH01, max UDMA/33

ata1.00: configured for PIO

ata1.01: configured for PIO

scsi 0:0:0:0: Direct-Access ATA WDC WD800BB-00JH 05.0 PQ: 0 ANSI: 5

scsi 0:0:1:0: CD-ROM TSSTcorp DVD-ROM TS-H352C CH01 PQ: 0 ANSI: 5

sd 0:0:0:0: [sda] 156301488 512-byte logical blocks: (80.0 GB/74.5 GiB)

sd 0:0:0:0: [sda] Write Protect is off

sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00

sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support

DPO or FUA

sda: sda1

sd 0:0:0:0: [sda] Attached SCSI disk

IP-Config: Complete:

device=eth0, addr=10.100.4.50, mask=255.255.255.0, gw=10.100.4.174,

host=bf537-stamp, domain=, nis-domain=(none),

bootserver=10.100.4.174, rootserver=10.100.4.174, rootpath=

Freeing unused kernel memory: 7348k freed

dma_alloc_init: dma_page @ 0x0291c000 - 256 pages at 0x03f00000

PHY: 0:01 - Link is Up - 100/Full

root:/>

Case 1 ...PASS

fdisk /dev/sda

The number of cylinders for this disk is set to 9729.

There is nothing wrong with that, but this is larger than 1024,

and could in certain setups cause problems with:

1) software that runs at boot time (e.g., old versions of LILO)

2) booting and partitioning software from other OSs

(e.g., DOS FDISK, OS/2 FDISK)

Command (m for help): p

Disk /dev/sda: 255 heads, 63 sectors, 9729 cylinders

Units = cylinders of 16065 * 512 bytes

Device Boot Start End Blocks Id System

/dev/sda1 1 64 514048+ 83 Linux

Command (m for help): d

Partition number (1-4): 1

Command (m for help): n

Command action

e extended

p primary partition (1-4)

Partition number (1-4): 1

First cylinder (1-9729, default 1):

Using default value 1

Last cylinder or +size or +sizeM or +sizeK (1-9729, default 9729): +500M

Command (m for help): w

The partition table has been altered!

Calling ioctl() to re-read partition table.

sda: sda1

WARNING: If you have created or modified any DOS 6.x

partitions, please see the fdisk manual page for additional

information.

Syncing disks.

Case 2 ...PASS

mke2fs /dev/sda1

root:/> mke2fs /dev/sda1

mke2fs 1.41.9 (22-Aug-2009)

ext2fs_check_if_mount: Can't check if filesystem is mounted due to missing mtab

file while determining whether /dev/sda1 is mounted.

Filesystem label=

OS type: Linux

Block size=1024 (log=0)

Fragment size=1024 (log=0)

128520 inodes, 514048 blocks

25702 blocks (5.00%) reserved for the super user

First data block=1

Maximum filesystem blocks=67633152

63 block groups

8192 blocks per group, 8192 fragments per group

2040 inodes per group

Superblock backups stored on blocks:

8193, 24577, 40961, 57345, 73729, 204801, 221185, 401409

Writing inode tables: done

Writing superblocks and filesystem accounting information: done

This filesystem will be automatically checked every 39 mounts or

180 days, whichever comes first. Use tune2fs -c or -i to override.

root:/>

Case 3 ...PASS

mount /dev/sda1 /mnt

root:/>

Case 4 ...PASS

cp /bin/pwd /mnt

root:/>

Case 5 ...PASS

ls -al /mnt

drwxr-xr-x 3 root root 1024 Nov 21 13:42 .

drwxr-xr-x 14 root root 0 Jan 1 2007 ..

drwx------ 2 root root 12288 Nov 21 13:42 lost+found

-rwxr-xr-x 1 root root 444052 Nov 21 13:42 pwd

root:/>

Case 6 ...PASS

cat /proc/filesystems

nodev sysfs

nodev rootfs

nodev bdev

nodev proc

nodev tmpfs

nodev debugfs

nodev sockfs

nodev pipefs

nodev anon_inodefs

nodev inotifyfs

nodev devpts

ext2

nodev ramfs

vfat

msdos

iso9660

root:/> The two fs -- vfat and msdos are found!

Case 7 ...PASS

Filesystem 1K-blocks Used Available Use% Mounted on

/dev/sda1 497829 2755 469372 1% /mnt

root:/>

Case 8 ...PASS

time dd conv=fsync if=/dev/zero of=/mnt/test.bin bs=1M count=100

100+0 records in

100+0 records out

real 0m 24.34s

user 0m 0.00s

sys 0m 8.88s

root:/> Generate file done, test pass

Case 9 ...PASS

time cat /mnt/test.bin > /dev/null

real 0m 21.35s

user 0m 0.38s

sys 0m 13.97s

root:/> Read file done, test pass

Case 10 ...PASS

while [ 1 ]; do md5sum /mnt/pwd ; done

4a1f033372e1f41f8f0c2c09e8187d1f /mnt/pwd

root:/>

Case 11 ...PASS

umount /mnt

root:/> umount done, test pass

Case 12 ...PASS

************** STEP 3: Start bonnie++ test

mke2fs /dev/sda1

mke2fs 1.41.9 (22-Aug-2009)

ext2fs_check_if_mount: Can't check if filesystem is mounted due to missing mtab

file while determining whether /dev/sda1 is mounted.

Filesystem label=

OS type: Linux

Block size=1024 (log=0)

Fragment size=1024 (log=0)

128520 inodes, 514048 blocks

25702 blocks (5.00%) reserved for the super user

First data block=1

Maximum filesystem blocks=67633152

63 block groups

8192 blocks per group, 8192 fragments per group

2040 inodes per group

Superblock backups stored on blocks:

8193, 24577, 40961, 57345, 73729, 204801, 221185, 401409

Writing inode tables: done

Writing superblocks and filesystem accounting information: done

This filesystem

Case 13 ...PASS

will be automatically checked every 24 mounts or

180 days, whichever comes first. Use tune2fs -c or -i to override.

mount /dev/sda1 /mnt

root:/>

Case 14 ...PASS

mount /dev/sda1 /mnt

bonnie++ -u root -d /mnt

root:/> bonnie++ -u root -d /mnt

Using uid:0, gid:0.

Writing a byte at a time...done

Writing intelligently...done

Rewriting...done

Reading a byte at a time...done

Reading intelligently...bonnie++ timeout

Last passed time: 2010_Jan_06_08_46, ucdist ver: 9346, kernel ver: 8121

Case 15 ...FAIL

--- Barry Song 2010-01-15 04:02:53

No information shows http://bugzilla.kernel.org/show_bug.cgi?id=14515 has been

fixed. There are still many complains

in:https://bugs.launchpad.net/ubuntu/+source/libatasmart/+bug/445852.

It should be a reproduction of this bug on our platform.

Files

Changes

Commits

Dependencies

Duplicates

Associations

Partner Forums

Partner Libraries

[#5557] run bonnie++ on ide harddisk has timeout