[jaunty] file transfer from/to usb mp3 player is very very slow

[kulight]

coping files to/from my usb dok/mp3 player is extremely slow
as asked here (https://bugs.launchpad.net/ubuntu/+source/gvfs/+bug/197762) im opening a separate bug for jaunty

see attached files

[kulight (kulight)]

my lspci

[Chris Coulson (chrisccoulson)]

Could you also please attach your /var/log/kern.log? Your dmesg got flooded with error messages that removed all of the other information.

Thanks

[Diaa Sami (diaa.sami)]

I've tried using Jaunty Alpha 4 and the bug is still there, as far as I can tell it only happens with automounting and only when writing, not when reading, I've performed some non-scientific experiments to help find the problem and its characteristics, you can find the results below and the log files requested attached.

Copying a 147 MB file from the PC(NTFS partition) to a 4GB USB drive(FAT32 partition):

Windows, copied using the GUI, stopwatch timing: 15s
Windows, copied using the cmdline(via copy), automatic timing(via wtime.exe): 13.8s

Jaunty Alpha 4, mounted automatically, copied using nautilus, stopwatch timing: 31s
Jaunty Alpha 4, mounted automatically, copied using terminal(cp), automatic timing(via time): 25.8s
Jaunty Alpha 4, mounted automatically, copied using terminal(dd), automatic timing(via dd): 26.1s, reported speed at end (5.9 MB/s)

Jaunty Alpha 4, mounted manually, copied using nautilus, stopwatch timing: 15s
Jaunty Alpha 4, mounted manually, copied using terminal(cp), automatic timing(via time): 16s
Jaunty Alpha 4, mounted manually, copied using terminal(dd), automatic timing(via dd): 16.1s, reported speed at end (9.5 MB/s)

Copying a 147 MB file from a USB drive(FAT32 partition) to the PC(NTFS partition):

Windows, copied using the GUI, stopwatch timing: 6.6s
Windows, copied using the cmdline(via copy), automatic timing(via wtime.exe): 6.8s

Jaunty Alpha 4, mounted automatically, copied using nautilus, stopwatch timing: 8s
Jaunty Alpha 4, mounted automatically, copied using terminal(cp), automatic timing(via time): 2.6s
Jaunty Alpha 4, mounted automatically, copied using terminal(dd), automatic timing(via dd): 18.8s, reported speed at end (8.2 MB/s)

Jaunty Alpha 4, mounted manually, copied using nautilus, stopwatch timing: 6.5s
Jaunty Alpha 4, mounted manually, copied using terminal(cp), automatic timing(via time): 2.5s
Jaunty Alpha 4, mounted manually, copied using terminal(dd), automatic timing(via dd): 17.9s, reported speed at end (8.6 MB/s)

[Leann Ogasawara (leannogasawara)]

Hi kulight,

The kernel.log.tar.gz you attached seems to also be flooded with the same messages. Care to maybe reboot, then immediately capture your dmesg output and attach it here. Then, try to copy to/from your usb dok/mp3 player and then look at dmesg output again to see if any additional information is logged. Can you also attach the output of "sudo lsusb -v > lsusb-v.log" .

@Diaa Sami - it would be best if you opened a new bug for now as you seem to be describing a slightly different issue. ie. @kulight experiences this both reading and writing from the device whereas you describe it's only a specific scenario of "it only happens with automounting and only when writing, not when reading". We can easily mark bugs as duplicates later on if necessary. Thanks.

[Leann Ogasawara (leannogasawara)]

@kulight, just fyi, the flood of messages currently in your logs is likely bug 269652. Seems like there might be a patch available for that. I'll notify the kernel team. Thanks.

[kulight (kulight)]

@ Leann Ogasawara

the log i attached here is just after rebooting... (i think the beginning of it is what you look for)
any way thanks for the direction to bug 269652 as i have opened a new one Bug #333874 (after searching) ill mark it as dupe

when the kernel bug would be fixed ill post a new log

thank you for your attention

[Diaa Sami (diaa.sami)]

@Leann
Thanks for the instructions, I've opened a new bug, bug 337830

[kulight (kulight)]

new attachments (without the error flood)

[kulight (kulight)]

the bug is still here on fully updated jaunty...

is there any progress? any testing needed?

[Simon Holm (odie-cs)]

kulight,

assuming that you still experience the slow transfer and the problem with the flood of messages in dmesg is solved, can you provide us with a dstat trace as described on https://help.ubuntu.com/community/DiskPerformance ?

[Simon Holm (odie-cs)]

BTW it seems like you have connected your USB stick to a USB 1.1 port, so that could certainly explain why performance might not be as expected. It would still be useful to get the dstat trace as mentioned before.

You can tell by a look at the output of just a simple lsusb that shows the flash disk is on a bus with a 1.1 root hub. Or, looking at your dmesg that says "new full speed USB device" you would know since full speed translates to 1.1, where as high speed translates to 2.0.

[alex123 (stry90dis)]

I have the same problem. Upgraded to Ubuntu 9.04 64-bit, upgraded with latest updates as of now (1-6-2009) Reading from USB 2.0 devices (Sandisk U3 4GB flashdrive & WD 1TB ext. HDD) is around 600kB/s - 700kB/s by observing reported speeds by Gnome/Nautilus. Same with newer kernel 2.6.28-12-generic & also tried 2.6.30-rc7.

Copying a 200MB .avi file from internal sata disk to the USB flashdrive goes fast, but nautilus copy hangs/stays for a long while at 100%. Selecting the then copied file on the USB drive and copy it to my desktop is almost instant. The 200MB is probably cached? ain't that a bit overdone? (just guessing, there is not a dev on this end).

Before I used 8.04 and 8.10 both 64 bit, speeds where reasonable but the flash drive and USB HDD where not automounted. I had to "sudo rmmod ehci_hcd" and "sudo modprobe ehci_hcd". Devices where then mounted correctly and functioning at USB 2.0 speeds.

Also when connecting my USB HDD on 9.04 it seems to be constantly busy reading/writing.

Following as attachment dstat output to my USB2.0 flash drive while using kernel:

alex@alex-desktop:~$ uname -r
2.6.28-11-generic

I used this command for a test write:

alex@alex-desktop:~$ sudo dd if=/dev/zero of=/media/sdc1/test-file bs=32
[sudo] password for alex:
^C12044320+0 records gelezen
12044320+0 records geschreven
385418240 bytes (385 MB) gekopieerd, 107,044 s, 3,6 MB/s

adding dmesg etc in following posts

[alex123 (stry90dis)]

the flooding enumerated messages were caused by USB BT2.0 dongle, after it was removed they stopped. USB stick was then still attached and not affected.

[alex123 (stry90dis)]

So when reviewing the logs, you'll see it is recognized as an high-speed usb (2.0) device and attached to a USB 2.0 hub/port, still speeds are slow. They are all with the Sandisk flash drive. I rather not use my USB HDD since it holds valuable data. I bought it as a backup for migrating from 8.10 to 9.04.

[alex123 (stry90dis)]

Well since I figured dstat doesn't do any harm I attached my USB HDD, right clicked on properties in /media/disk which is the USB HDD while running a dstat trace. The only thing it does is count files and the space they use.
On this disk there are 28329 items totalling 325,6 GB. Files are documents, mp3's, videos ranging from a few KB to a few GB. Guesstimated average read speed is 40kB/s

Results are in dstat_USB_HDD_count_files.log

Next I copied an ubuntu ISO to the disk 699,0 MB. The first 204,9 MB went blazingly fast (few seconds). dstat didn't record anything being written to the disk. Then nautilus progress window stopped at 204,9 MB for a few minutes and dstat shows data being written at around 1300kB. After a while the nautilus window started progressing blazingly fast again to ~424MB and stopped again for a few minutes, dstat output still running along at ~1300kB. After a while nautiles progresses again blazingly fast to the end and the progress indicator window is closed. After this dstat output indicates it is still running along at 1300kB for a few minutes.

In the log of dstat, after the first 3-5 lines or so I started writing the file to the disk. You'll see nothing is actually written first, but the nautilus windows indicates this is being done. Wild guess, it caches every ~205 MB first?

Log is called dstat_USB_HDD_copy large_file_to.log

Next I copied a 623,5MB avi file that is on the USB HDD to my desktop. Constant speed of ~670kB right from the beginning according to dstat, also according to the nautilus window. When the nautilus progress window closed, dstat also showed no reading from the USB disk was done anymore.

Log is called dstat_USB_HDD_copy large_file_from.log

Attached are the dstat logs, kernel logs etc. Nothing special, they are the added bits of the logs posted above because somehow the other entires were removed. at around 20:15 you'll see alot could not enumerate etc... this is when I had that USB bluetooth 2.0 dongle plugged in,unplugged it around that time. So it has no (direct) link to the USB HDD.

Added the logs to a .tar.gz to prevent clutter here.

[alex123 (stry90dis)]

lspci -vvnn and uname -a for completeness as I read it is preferred over "lspci -v" and "uname -r". Did I forget anyhting else?

[alex123 (stry90dis)]

I just updated the BIOS of my PC, and the USB flash drive now works at reasonable speeds! Write of Ubuntu ISO of 700MB @~10MB/s, Read 623MB avi @~13MB/s.

Updated BIOS from GA-MA790X-DS4 (rev. 1.x) version F3 to GA-MA790X-DS4 (rev. 1.x) version F7C. Checked that all settings in BIOS where the same before restarting OS.
Link of motherboard and BIOS:

http://www.gigabyte.com.tw/Support/Motherboard/BIOS_Model.aspx?ProductID=2695#anchor_os.

----------------------------------------------------------------------------------------
Attached dstat trace of read/write to USB flash drive in:

dstat_copy_large_file_from_flash_BIOSup.log
&
dstat_copy_large_file_to_flash_BIOSup.log

----------------------------------------------------------------------------------------
kern, syslog and messages logs with info before and after update. BIOS was updated at ~ June 2nd 11:59. In files:

kern_after_BIOSup_and_before.log
&
syslog_after_BIOSup_and_before.log
&
messages_after_BIOSup_and_before.log

----------------------------------------------------------------------------------------
dmesg after BIOS update in:

dmesg_after_BIOSup.log

----------------------------------------------------------------------------------------
lsusb and lsusb -v after BIOS update in:

lsusb_v_after_BIOSup.log

----------------------------------------------------------------------------------------
uname -a and lspci -vvnn after BIOS update in:

uname_a_and_lspci_vvnn_after_BIOSup.log

All files added to .tar.gz to prevent clutter

[alex123 (stry90dis)]

1TB USB HDD also at reasonable speeds now. Read Ubuntu ISO of 700MB @~23MB/s. Write avi file of 623MB @~30MB/s.

Right clicking properties in nautilus also has a resonable progress, counting files etc now @~1MB/s.

dstat traces included are

right clicking properties of the disk in nautilus:
dstat_properties_disk_USBHDD_BIOSup.log

Read 700MB ISO from USB HDD:
dstat_copy_large_file_from_USBHDD_BIOSup.log

Write 623MB avi to USB HDD:
dstat_copy_large_file_to_USBHDD_BIOSup.log

added bits of syslog,kern and messages to the previous logs of plugging in the WD 1TB USB HDD:
syslog_messages_kern_addedbits_USBHDD.log

lspci -vvnn, lsusb and lsusb -v after plugging in the USB HDD:
lspci_vvnn_lsusb_v.log

All files added to .tar.gz to...well you know by now ;)

[Simon Holm (odie-cs)]

alex123: Cool, anything in particular that made you suspect a BIOS bug? I guess everything is fine for your system then.

kulight: We'd still like to hear whether this is simply an issue of USB 1.1 being used.

[kulight (kulight)]

This is not an issue of using usb 1
My device and port are both usb 2

-----Original Message-----
From: <email address hidden> [mailto:<email address hidden>] On Behalf Of Simon Holm Th?gersen
Sent: Wednesday, June 10, 2009 2:41 AM
To: <email address hidden>
Subject: [Bug 334914] Re: [jaunty] usb file transfer is very very slow

alex123: Cool, anything in particular that made you suspect a BIOS bug?
I guess everything is fine for your system then.

kulight: We'd still like to hear whether this is simply an issue of USB
1.1 being used.

--
[jaunty] usb file transfer is very very slow
https://bugs.launchpad.net/bugs/334914
You received this bug notification because you are a direct subscriber
of the bug.

Status in “linux” source package in Ubuntu: Triaged

Bug description:
coping files to/from my usb dok/mp3 player is extremely slow
as asked here (https://bugs.launchpad.net/ubuntu/+source/gvfs/+bug/197762) im opening a separate bug for jaunty

see attached files

[alex123 (stry90dis)]

Simon Holm Thøgersen: No nothing in particular, only that it wasn't the newest version anymore and was the last thing I could try.

[Simon Holm (odie-cs)]

ons, 10 06 2009 kl. 09:26 +0000, skrev kulight:
> This is not an issue of using usb 1
> My device and port are both usb 2

But they are still used in USB 1.1 mode, see your dmesg that says "new
full speed USB device" and lsusb that shows the USB drive is on a bus
with a 1.1 device (this is very easy to see if you use lsusb without any
other options).

You might be able to force it into 2.0 mode by rmmod/modprobe -r all usb
related stuff and modprobing ehci_hcd. You'll have to umount all
partitions on your USB drive and disable everything else that uses USB
before you can do that.

This should bring very substantial performance improvements so please
try that.

[alex123 (stry90dis)]

Yeah that was also a solution to my USB troubles in Ubuntu 8.04/8.10. Problem is, you can't do that anymore in 9.04 since the modules are built into the kernel now, at least thats what I make up of the technobabble.

[Zach McCullough (nosrepa)]

I am also experiencing this (noticed it in 8.xx before).

[mercutio22 (macabro22)]

I am also experiencing this in karmic what info may I contribute?

[yeus (thomas-meschede-deactivatedaccount)]

this bug still occurs in karmic... any workaround? I would really appreciate someone fixing this bug. This has been arounf for almost two years now.. Two years and I can not copy big files under 30min to my usb stick...

[Przemek K. (azrael)]

Please be aware that some of the commenting users might be affected by bug #197762, not this one.