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

Document created by Aaronwu Employee on Sep 4, 2013
Version 1Show Document
  • View in full screen mode

[#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 

5

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

97

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 

5

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

97

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

register early platform devices

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

Blackfin support (C) 2004-2009 Analog Devices, Inc.

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

 

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)

p

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

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

 

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

 

Case 3 ...PASS

mount /dev/sda1 /mnt

root:/>

Case 4 ...PASS

 

Case 4 ...PASS

cp /bin/pwd /mnt

root:/>

Case 5 ...PASS

 

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

 

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

 

Case 7 ...PASS

df

Filesystem           1K-blocks      Used Available Use% Mounted on

/dev/sda1               497829      2755    469372   1% /mnt

root:/>

Case 8 ...PASS

 

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

 

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

 

Case 10 ...PASS

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

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

4a1f033372e1f41f8f0c2c09e8187d1f  /mnt/pwd

^C

 

root:/>

Case 11 ...PASS

 

Case 11 ...PASS

umount /mnt

root:/> umount done, test pass

 

Case 12 ...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

 

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

 

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

    Tags

 

File Name     File Type     File Size     Posted By

No Files Were Found

Attachments

    Outcomes