Modify

Opened 7 years ago

Closed 7 years ago

Last modified 5 years ago

#7813 closed defect (worksforme)

Writing to usb memory stick is very slow.

Reported by: bogklug Owned by: developers
Priority: normal Milestone: Backfire 10.03.1
Component: kernel Version: Backfire 10.03
Keywords: usb write low speed Cc:

Description

I'm running Backfire (10.03, r20728) on an Asus WL-500W router with an ext3 formatted 16GB EMTEC usb memory stick.

If I boot the router with no ehci-hcd (kmod-usb2 package uninstalled) and then install and load this module (let's call it scenario 1) the speed is reasonable:

root@OpenWrt:~# cat /dev/zero >/mnt/storage/z & sleep 5; killall cat
root@OpenWrt:~# cat /dev/zero >/mnt/storage/a/z & sleep 5; killall cat
root@OpenWrt:~# ls -l /mnt/storage/z
-rw-r--r--    1 root     root     27066368 Aug 25 23:26 /mnt/storage/z
root@OpenWrt:~# ls -l /mnt/storage/a/z
-rw-r--r--    1 root     root     15171584 Aug 25 23:26 /mnt/storage/a/z

After that when I simply reboot (let's call it scenario 2) writing gets very slow:

root@OpenWrt:~# cat /dev/zero >/mnt/storage/z & sleep 5; killall cat
root@OpenWrt:~# cat /dev/zero >/mnt/storage/a/z & sleep 5; killall cat
root@OpenWrt:~# ls -l /mnt/storage/z
-rw-r--r--    1 root     root       466944 Aug 25 23:17 /mnt/storage/z
root@OpenWrt:~# ls -l /mnt/storage/a/z
-rw-r--r--    1 root     root        49152 Aug 25 23:17 /mnt/storage/a/z

Reading speed seems to be fine in both cases (checked with catting a file from the memory stick to /dev/null).

Here is opkg ouput:

root@OpenWrt:~# opkg list-installed | grep usb
kmod-usb-core - 2.4.37.9-1
kmod-usb-storage - 2.4.37.9-1
kmod-usb2 - 2.4.37.9-1

Here is lsmod and dmesg output from scenario 1:

root@OpenWrt:~# lsmod | grep usb
usb-storage            70144  0 
usbcore                71296  1 ehci-hcd usb-storage
scsi_mod               67152  2 usb-storage sd_mod

root@OpenWrt:~# dmesg
CPU revision is: 00029006
Primary instruction cache 16kB, physically tagged, 2-way, linesize 16 bytes.
Primary data cache 16kB, 2-way, linesize 16 bytes.
Linux version 2.4.37.9 (openwrt@wrt1.marcant.net) (gcc version 3.4.6 (OpenWrt-2.0)) #42 Tue Apr 6 15:59:04 CEST 2010
Setting the PFC to its default value
Determined physical RAM map:
 memory: 02000000 @ 00000000 (usable)
On node 0 totalpages: 8192
zone(0): 8192 pages.
zone(1): 0 pages.
zone(2): 0 pages.
Kernel command line: root=/dev/mtdblock2 rootfstype=squashfs,jffs2 init=/etc/preinit noinitrd console=ttyS0,115200
CPU: BCM4704 rev 9 at 264 MHz
Using 132.000 MHz high precision timer.
Calibrating delay loop... 263.78 BogoMIPS
Memory: 30448k/32768k available (1447k kernel code, 2320k reserved, 100k data, 84k init, 0k highmem)
Dentry cache hash table entries: 4096 (order: 3, 32768 bytes)
Inode cache hash table entries: 2048 (order: 2, 16384 bytes)
Mount cache hash table entries: 512 (order: 0, 4096 bytes)
Buffer cache hash table entries: 1024 (order: 0, 4096 bytes)
Page-cache hash table entries: 8192 (order: 3, 32768 bytes)
Checking for 'wait' instruction...  unavailable.
POSIX conformance testing by UNIFIX
PCI: Initializing host
PCI: Fixing up bus 0
PCI: Fixing up bridge
PCI: Setting latency timer of device 01:00.0 to 64
PCI: Fixing up bus 1
Linux NET4.0 for Linux 2.4
Based upon Swansea University Computer Society NET3.039
Initializing RT netlink socket
Starting kswapd
Registering mini_fo version $Id$
devfs: v1.12c (20020818) Richard Gooch (rgooch@atnf.csiro.au)
devfs: boot_options: 0x1
JFFS2 version 2.1. (C) 2001 Red Hat, Inc., designed by Axis Communications AB.
squashfs: version 3.0 (2006/03/15) Phillip Lougher
pty: 256 Unix98 ptys configured
Serial driver version 5.05c (2001-07-08) with MANY_PORTS SHARE_IRQ SERIAL_PCI enabled
ttyS00 at 0xb8000300 (irq = 3) is a 16550A
ttyS01 at 0xb8000400 (irq = 3) is a 16550A
b44.c:v0.93 (Mar, 2004)
PCI: Setting latency timer of device 00:01.0 to 64
eth0: Broadcom 47xx 10/100BaseT Ethernet 00:22:15:28:47:37
PCI: Setting latency timer of device 00:02.0 to 64
eth1: Broadcom 47xx 10/100BaseT Ethernet 00:22:15:28:47:37
Physically mapped flash: Found an alias at 0x800000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1000000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1800000 for the chip at 0x0
 Amd/Fujitsu Extended Query Table v1.3 at 0x0040
number of CFI chips: 1
cfi_cmdset_0002: Disabling fast programming due to code brokenness.
Flash device: 0x800000 at 0x1c000000
bootloader size: 262144
Physically mapped flash: Filesystem type: squashfs, size=0x1a68f2
Creating 5 MTD partitions on "Physically mapped flash":
0x00000000-0x00040000 : "cfe"
0x00040000-0x007f0000 : "linux"
0x000bc000-0x00270000 : "rootfs"
mtd: partition "rootfs" doesn't start on an erase block boundary -- force read-only
0x007f0000-0x00800000 : "nvram"
0x00270000-0x007f0000 : "rootfs_data"
sflash: found no supported devices
Initializing Cryptographic API
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP, IGMP
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP: Hash tables configured (established 2048 bind 4096)
Linux IP multicast router 0.06 plus PIM-SM
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
NET4: Ethernet Bridge 008 for NET4.0
802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
All bugs added by David S. Miller <davem@redhat.com>
VFS: Mounted root (squashfs filesystem) readonly.
Mounted devfs on /dev
Freeing unused kernel memory: 84k freed
diag: Detected 'ASUS WL-500W'
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
roboswitch: Probing device eth0: found a 5325! It's a 5350.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
mini_fo: using base directory: /
mini_fo: using storage directory: /overlay
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
jffs2.bbc: SIZE compression mode activated.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
device eth0 entered promiscuous mode
br-lan: port 1(eth0) entering learning state
br-lan: port 1(eth0) entering forwarding state
br-lan: topology change detected, propagating
b44: eth1: Link is up at 100 Mbps, full duplex.
b44: eth1: Flow control is off for TX and off for RX.
SCSI subsystem driver Revision: 1.00
usb.c: registered new driver usbdevfs
usb.c: registered new driver hub
PCI: Setting latency timer of device 01:02.0 to 64
PCI: Enabling device 01:02.0 (0004 -> 0006)
PCI/DMA
wl0: wlc_attach: chiprev 1 coreunit 0 corerev 11 cccap 0x864000d maccap 0x0 band 2.4G, phy_type 4 phy_rev 1 ana_rev 5
wl0: Broadcom BCM4329 802.11 Wireless Controller 4.150.10.5
CSLIP: code copyright 1989 Regents of the University of California
PPP generic driver version 2.4.2
Journalled Block Device driver loaded
ip_tables: (C) 2000-2002 Netfilter core team
ip_conntrack version 2.1 (5953 buckets, 5953 max) - 352 bytes per conntrack
ipt_recent v0.3.1: Stephen Frost <sfrost@snowman.net>.  http://snowman.net/projects/ipt_recent/
imq driver loaded.
Initializing USB Mass Storage driver...
usb.c: registered new driver usb-storage
USB Mass Storage support registered.
device wl0 entered promiscuous mode
wl0: attempt to add interface with same source address.
br-lan: port 2(wl0) entering learning state
br-lan: port 2(wl0) entering forwarding state
br-lan: topology change detected, propagating
PCI: Enabling device 01:03.2 (0000 -> 0002)
ehci_hcd 01:03.2: PCI device 1106:3104
ehci_hcd 01:03.2: irq 2, pci mem c01fb000
usb.c: new USB bus registered, assigned bus number 1
EHCI: Enabling VIA 6212 workarounds
ehci_hcd 01:03.2: USB 2.0 enabled, EHCI 1.00, driver 2003-Dec-29/2.4
hub.c: USB hub found
hub.c: 4 ports detected
hub.c: new USB device 01:03.2-2, assigned address 2
scsi0 : SCSI emulation for USB Mass Storage devices
  Vendor:           Model:                   Rev: 0.00
  Type:   Direct-Access                      ANSI SCSI revision: 02
Attached scsi removable disk sda at scsi0, channel 0, id 0, lun 0
SCSI device sda: 31588352 512-byte hdwr sectors (16173 MB)
sda: Write Protect is off
Partition check:
 /dev/scsi/host0/bus0/target0/lun0: p1
WARNING: USB Mass Storage data integrity not assured
USB Mass Storage device found at 2

Here is lsmod and dmesg output from scenario 2:

root@OpenWrt:~# lsmod | grep usb
usb-storage            70144  1 
usbcore                71296  1 usb-storage ehci-hcd
scsi_mod               67152  2 usb-storage sd_mod

root@OpenWrt:~# dmesg
CPU revision is: 00029006
Primary instruction cache 16kB, physically tagged, 2-way, linesize 16 bytes.
Primary data cache 16kB, 2-way, linesize 16 bytes.
Linux version 2.4.37.9 (openwrt@wrt1.marcant.net) (gcc version 3.4.6 (OpenWrt-2.0)) #42 Tue Apr 6 15:59:04 CEST 2010
Setting the PFC to its default value
Determined physical RAM map:
 memory: 02000000 @ 00000000 (usable)
On node 0 totalpages: 8192
zone(0): 8192 pages.
zone(1): 0 pages.
zone(2): 0 pages.
Kernel command line: root=/dev/mtdblock2 rootfstype=squashfs,jffs2 init=/etc/preinit noinitrd console=ttyS0,115200
CPU: BCM4704 rev 9 at 264 MHz
Using 132.000 MHz high precision timer.
Calibrating delay loop... 263.78 BogoMIPS
Memory: 30448k/32768k available (1447k kernel code, 2320k reserved, 100k data, 84k init, 0k highmem)
Dentry cache hash table entries: 4096 (order: 3, 32768 bytes)
Inode cache hash table entries: 2048 (order: 2, 16384 bytes)
Mount cache hash table entries: 512 (order: 0, 4096 bytes)
Buffer cache hash table entries: 1024 (order: 0, 4096 bytes)
Page-cache hash table entries: 8192 (order: 3, 32768 bytes)
Checking for 'wait' instruction...  unavailable.
POSIX conformance testing by UNIFIX
PCI: Initializing host
PCI: Fixing up bus 0
PCI: Fixing up bridge
PCI: Setting latency timer of device 01:00.0 to 64
PCI: Fixing up bus 1
Linux NET4.0 for Linux 2.4
Based upon Swansea University Computer Society NET3.039
Initializing RT netlink socket
Starting kswapd
Registering mini_fo version $Id$
devfs: v1.12c (20020818) Richard Gooch (rgooch@atnf.csiro.au)
devfs: boot_options: 0x1
JFFS2 version 2.1. (C) 2001 Red Hat, Inc., designed by Axis Communications AB.
squashfs: version 3.0 (2006/03/15) Phillip Lougher
pty: 256 Unix98 ptys configured
Serial driver version 5.05c (2001-07-08) with MANY_PORTS SHARE_IRQ SERIAL_PCI enabled
ttyS00 at 0xb8000300 (irq = 3) is a 16550A
ttyS01 at 0xb8000400 (irq = 3) is a 16550A
b44.c:v0.93 (Mar, 2004)
PCI: Setting latency timer of device 00:01.0 to 64
eth0: Broadcom 47xx 10/100BaseT Ethernet 00:22:15:28:47:37
PCI: Setting latency timer of device 00:02.0 to 64
eth1: Broadcom 47xx 10/100BaseT Ethernet 00:22:15:28:47:37
Physically mapped flash: Found an alias at 0x800000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1000000 for the chip at 0x0
Physically mapped flash: Found an alias at 0x1800000 for the chip at 0x0
 Amd/Fujitsu Extended Query Table v1.3 at 0x0040
number of CFI chips: 1
cfi_cmdset_0002: Disabling fast programming due to code brokenness.
Flash device: 0x800000 at 0x1c000000
bootloader size: 262144
Physically mapped flash: Filesystem type: squashfs, size=0x1a68f2
Creating 5 MTD partitions on "Physically mapped flash":
0x00000000-0x00040000 : "cfe"
0x00040000-0x007f0000 : "linux"
0x000bc000-0x00270000 : "rootfs"
mtd: partition "rootfs" doesn't start on an erase block boundary -- force read-only
0x007f0000-0x00800000 : "nvram"
0x00270000-0x007f0000 : "rootfs_data"
sflash: found no supported devices
Initializing Cryptographic API
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP, IGMP
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP: Hash tables configured (established 2048 bind 4096)
Linux IP multicast router 0.06 plus PIM-SM
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
NET4: Ethernet Bridge 008 for NET4.0
802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
All bugs added by David S. Miller <davem@redhat.com>
VFS: Mounted root (squashfs filesystem) readonly.
Mounted devfs on /dev
Freeing unused kernel memory: 84k freed
diag: Detected 'ASUS WL-500W'
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
roboswitch: Probing device eth0: found a 5325! It's a 5350.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
mini_fo: using base directory: /
mini_fo: using storage directory: /overlay
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
jffs2.bbc: SIZE compression mode activated.
b44: eth0: Link is up at 100 Mbps, full duplex.
b44: eth0: Flow control is off for TX and off for RX.
device eth0 entered promiscuous mode
br-lan: port 1(eth0) entering learning state
br-lan: port 1(eth0) entering forwarding state
br-lan: topology change detected, propagating
b44: eth1: Link is up at 100 Mbps, full duplex.
b44: eth1: Flow control is off for TX and off for RX.
SCSI subsystem driver Revision: 1.00
usb.c: registered new driver usbdevfs
usb.c: registered new driver hub
PCI: Setting latency timer of device 01:02.0 to 64
PCI: Enabling device 01:02.0 (0004 -> 0006)
PCI/DMA
wl0: wlc_attach: chiprev 1 coreunit 0 corerev 11 cccap 0x864000d maccap 0x0 band 2.4G, phy_type 4 phy_rev 1 ana_rev 5
wl0: Broadcom BCM4329 802.11 Wireless Controller 4.150.10.5
CSLIP: code copyright 1989 Regents of the University of California
PPP generic driver version 2.4.2
Journalled Block Device driver loaded
ip_tables: (C) 2000-2002 Netfilter core team
PCI: Enabling device 01:03.2 (0000 -> 0002)
ehci_hcd 01:03.2: PCI device 1106:3104
ehci_hcd 01:03.2: irq 2, pci mem c021b000
usb.c: new USB bus registered, assigned bus number 1
EHCI: Enabling VIA 6212 workarounds
ehci_hcd 01:03.2: USB 2.0 enabled, EHCI 1.00, driver 2003-Dec-29/2.4
hub.c: USB hub found
hub.c: 4 ports detected
ip_conntrack version 2.1 (5953 buckets, 5953 max) - 352 bytes per conntrack
hub.c: new USB device 01:03.2-2, assigned address 2
usb.c: USB device 2 (vend/prod 0x1307/0x165) is not claimed by any active driver.
ipt_recent v0.3.1: Stephen Frost <sfrost@snowman.net>.  http://snowman.net/projects/ipt_recent/
imq driver loaded.
Initializing USB Mass Storage driver...
usb.c: registered new driver usb-storage
scsi0 : SCSI emulation for USB Mass Storage devices
  Vendor:           Model:                   Rev: 0.00
  Type:   Direct-Access                      ANSI SCSI revision: 02
Attached scsi removable disk sda at scsi0, channel 0, id 0, lun 0
SCSI device sda: 31588352 512-byte hdwr sectors (16173 MB)
sda: Write Protect is off
Partition check:
 /dev/scsi/host0/bus0/target0/lun0: p1
WARNING: USB Mass Storage data integrity not assured
USB Mass Storage device found at 2
USB Mass Storage support registered.
kjournald starting.  Commit interval 5 seconds
EXT3-fs warning: mounting fs with errors, running e2fsck is recommended
EXT3 FS 2.4-0.9.19, 19 August 2002 on sd(8,1), internal journal
EXT3-fs: mounted filesystem with ordered data mode.
device wl0 entered promiscuous mode
wl0: attempt to add interface with same source address.
br-lan: port 2(wl0) entering learning state
br-lan: port 2(wl0) entering forwarding state
br-lan: topology change detected, propagating

Attachments (0)

Change History (9)

comment:1 follow-up: Changed 7 years ago by bogklug

It looks like the order the ehci-hcd and usb-storage modules are loaded for the first time is important.

comment:2 in reply to: ↑ 1 Changed 7 years ago by KanjiMonster

I can confirm this behaviour on ar71xx, routerstation pro, latest trunk with root on sdcard. Writing is painfully slow (~50 kB/s).

Replying to bogklug:

It looks like the order the ehci-hcd and usb-storage modules are loaded for the first time is important.

I tried modifying the module load order in /etc/module.d, but I didn't succeed in getting it to run at acceptable speed.

comment:3 follow-up: Changed 7 years ago by KanjiMonster

Some further testing shows this only affects the rootfs device itself, a different simultaneusly connected usb driver is fine.

I couldn't test whether this affects the whole device or only the rootfs partition since my sdcard has only one.

comment:4 in reply to: ↑ 3 ; follow-up: Changed 7 years ago by bogklug

In my case it's not the rootfs device and loading usb-storage before ehci-hcd while booting seems to fix the problem. I did get however some strange behaviour a few times, like /dev/scsi/host0/bus0/target0/lun0/part1 failing to show up (while /dev/scsi/host0/bus0/target0/lun0/disc showing up normally) or process freezing if doing anything on the usb stick (like ls /mnt/storage - the whole system works, but ls locks up). Unfortunately I don't know how to reproduce those.

Replying to KanjiMonster:

Some further testing shows this only affects the rootfs device itself, a different simultaneusly connected usb driver is fine.

I couldn't test whether this affects the whole device or only the rootfs partition since my sdcard has only one.

comment:5 in reply to: ↑ 4 Changed 7 years ago by KanjiMonster

Replying to bogklug:

In my case it's not the rootfs device and loading usb-storage before ehci-hcd while booting seems to fix the problem.

Yes, must have been my imagination that this topic has anything to do with block-rootfs. Sorry for the unreleated comments.

I'll better open an separate ticket, since this probably doesn't have anything to do with this problem.

comment:6 follow-up: Changed 7 years ago by bojo42 <bojo42@…>

Got the same here on a TP-Link 1043 ND (ar71xx) with 10.03.1 RC3. I use my EXT3 formated stick for /home and thought it might be due some mount options. So i tested them:

data=ordered vs data=writeback -> neglectable
barrier=1 vs barrier=0 -> neglectable
sync vs no sync option -> deep impact

my write performance went from ~145 kb/s to ~5800 kb/s. of course the writing is not in sync, so you can see (by it's LED) that the stick take some more seconds to really finish it, but the performance is really usable. it may be okay to use that for non system data stuff with mount options like "rw,noatime,nodiratime,errors=remount-ro,data=ordered,barrier=1" when one doesn't have much power outtakes, system crashes or other unplaned system downtakes.

can anybody confirm the impact of "sync" and has some clues why it is that big? or are only certain types of flash stick affected by this?

BTW i just installed kmod-usb-storage kmod-fs-ext3 block-mount block-hotplug and configure it via /etc/config/fstab

comment:7 in reply to: ↑ 6 Changed 7 years ago by KanjiMonster

Replying to bojo42 <bojo42@…>:

Got the same here on a TP-Link 1043 ND (ar71xx) with 10.03.1 RC3. I use my EXT3 formated stick for /home and thought it might be due some mount options. So i tested them:

data=ordered vs data=writeback -> neglectable
barrier=1 vs barrier=0 -> neglectable
sync vs no sync option -> deep impact

my write performance went from ~145 kb/s to ~5800 kb/s. of course the writing is not in sync, so you can see (by it's LED) that the stick take some more seconds to really finish it, but the performance is really usable. it may be okay to use that for non system data stuff with mount options like "rw,noatime,nodiratime,errors=remount-ro,data=ordered,barrier=1" when one doesn't have much power outtakes, system crashes or other unplaned system downtakes.

can anybody confirm the impact of "sync" and has some clues why it is that big? or are only certain types of flash stick affected by this?

(This has nothing to do anymore with the original ticket.)

The slowness comes from the fact that (all!) flash memory uses much bigger blocks that have to be deleted/written at once. E.g. if the erase block size is 64k, then writing 32k takes the same amount of time as writing 64k at once, so writing 2 * 32k needs twice as long resulting in half the seen speed. Disabling snyc allows linux to cache the first 32k to wait until full 64k are there to write. HDDs have a block size of 512 (some have 4k), so the impact there is much lower.

Try increasing your block size when doing your speed test, and you should see a speed increase until you reach the optimum block size. Then there should be next to no speed difference.

comment:8 Changed 7 years ago by jow

  • Resolution set to worksforme
  • Status changed from new to closed

Don't use sync if you want fast writes - it will bypass IO caches.

comment:9 Changed 5 years ago by anonymous

Works for me too :)

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.