Arch Linux

USB-Devices langsam / unmount schlägt fehl

RhahkJin

Guten Abend zusammen,
ich habe heute zum ersten Mal versucht unter Arch Daten auf ein (später noch ein zweites zum überprüfen) USB-Gerät (Sandisk Memory Stick Micro in SE-Handy / Kingston DataTraveler USB-Stick) zu kopieren. Beide Geräte funktionierten auf diesem Rechner (USB-Controller: Mainboard Asus A7N8X Deluxe) unter Ubuntu.
Der kopiervorgang dauert sehr lang (ca. 200KB/s) und beim Versuch die Geräte zu entfernen bekomme ich einen Fehlermeldung ("Did not recieve a reply") und die Änderungen werden nicht auf das Gerät geschrieben.
Leider weiss ich nicht, wo ich anfangen soll zu suchen, hat jemand eine Idee?

Grüße, RhahkJin

Xukashi

das mit dem extrem langsamen usb hab ich auch. bislang dachte ich immer das liegt an meinem stick aber hatte heute ne externe platte da und da wars das gleiche

GerBra

@RhahkJin
Diese Fehlermeldung kommt von KDE, richtig? Also wenn du unter KDE kopierst.
Wie ist der Stick denn eingebunden?
cat /proc/mounts (die Mount-Points vom Stick)

Zur Geschwindigkeit von Stick und Platten kann ich nichts Negatives sehen (bei mir):

# IDE-Platte am IDE-Bus
hdparm -t /dev/sdb
/dev/sdb:
 Timing buffered disk reads:  168 MB in  3.03 seconds =  55.42 MB/sec
# USB-Platte
hdparm -t /dev/sdc
/dev/sdc:
 Timing buffered disk reads:   92 MB in  3.05 seconds =  30.19 MB/sec

# Kopieren auf der USB: Zero nach Datei
dd if=/dev/zero of=/data-big/tt bs=1024k count=500
524288000 Bytes (524 MB) kopiert, 14,6218 s, 35,9 MB/s
# Kopierern auf USB: Datei nach Datei
dd if=/data-big/tt of=/data-big/tt2
524288000 Bytes (524 MB) kopiert, 31,9915 s, 16,4 MB/s

Zum Vergleich obiges Kopieren auf meiner IDE-Platte:
Zero -> Datei: 524288000 Bytes (524 MB) kopiert, 13,598 s, 38,6 MB/s
Datei -> Datei: 524288000 Bytes (524 MB) kopiert, 27,8849 s, 18,8 MB/s

//Edit
Hier noch das vom USB-Stick (olles 512MB-Teil):

hdparm -t /dev/sdb
/dev/sdb:
 Timing buffered disk reads:   74 MB in  3.02 seconds =  24.49 MB/sec

# 200 MB kopieren
dd if=/dev/zero of=/media/disk/tt bs=1024k count=200
209715200 Bytes (210 MB) kopiert, 43,5915 s, 4,8 MB/s

Die Nutzung der USB-Platte (bei mir Datenlager und Backup) braucht halt eine
wesentlich höhere CPU-Nutzung bzw. Load (da die CPU auf den langsameren Bus
warten muß. Das kann man schön beim Kopieren etc. mit top sehen, der Anteil von %wa
ist dort extrem hoch. Ähnlich wie z.B. große Mengen über Netzwerk zu transportieren.)

Vielleicht könnt ihr diese Tests mal nachvollziehen?

FJO

Erfolgt der Zugriff vielleicht über "media:/"? In dem Fall sind bei mir die Transferraten auch geringer als bei einem direkten Zugriff.

falke

Besitze ebenfalls ein Mainboard Asus A7N8X Deluxe sowie ein USB-Stick Kingston DataTraveler 2GB, habe mal das Beispiel von GerBra angewandt:

hdparm -t /dev/sdf1
/dev/sdf1:
Timing buffered disk reads: 64 MB in 3.10 seconds = 20.66 MB/sec

dd if=/dev/zero of=/media/USB_2GB/big bs=1024k count=200
200+0 Datensätze ein
200+0 Datensätze aus
209715200 Bytes (210 MB) kopiert, 24,6517 s, 8,5 MB/s

Hatte eigentlich nie Schwierigkeiten mit der Transferrate von USB-Sticks oder USB-Platten.
Gibt es eventuell Hinweise in einer Log Datei /var/log/errors.log oder messages.log?

RhahkJin

So erstmal danke euch allen für die Antworten!

Ich kann die Tests jetzt leider nur mit der Mit dem Handy machen, da ich den USB-Stick heute zum Testen mit auf Arbeit genommen jetzt und dort vergessen hab... Unter MacOSX schreibt er einwandfrei mit ca. 10MB/s, ich denke also das Ich Probleme bei den Devices ausschließen kann.

@GerBra: Die Meldung kam von Thunar, nicht von KDE

cat /proc/mounts 
/dev/sdd1 /media/PHONE\040CARD vfat rw,nosuid,nodev,uid=1000,fmask=0022,dmask=0022,codepage=cp437,iocharset=iso8859-1,shortname=winnt 0 0

hdparm -t /dev/sdd1
/dev/sdd1:
Timing buffered disk reads:    2 MB in  3.55 seconds = 576.76 kB/sec

dd if=/dev/zero of=/media/PHONE\ CARD/big bs=1024k count=200
200+0 Datensätze ein
200+0 Datensätze aus
209715200 Bytes (210 MB) kopiert, 317,321 s, 661 kB/s

Bei einem manuelle umount gibt es Keine Fehler, er ist auch gleich fertig.
Das Umount/Kein Sync Problem scheint also nur bei Thunar aufzutreten.
Allerdings ist die Geschwindigkeit immer noch weit unter USB2.0-Niveau...

// edit: ich bin noch verwirrter: nach einem erneuten moun/umount _ohne änderungen_ ist die datei /media/PHONE CARD/big (die 200MB dd-Testdatei) verschwunden, dafür sind jetzt die 300 MB Nutzdaten die ich gestern kopiert habe da... D.h. Sie waren bereits geschrieben aber nicht korrekt indiziert? Aber wieso... und wo sind die 200MB Müll aus /dev/null hin? Ich steh auf dem Schlauch...

GerBra

Wenn dieses Device unter MaxOSX am gleichen Port die volle Transferleistung bringt,
dann ist das in der Tat zu langsam.
Evtl. ein USB 1.1/2.0 Problem?
Was für Module sind denn bei dir geladen?
lsmod | grep usbcore
Auch eine Vermutung wäre gewesen, daß das Device mt sync gemountet wäre.
Das ist ja aber nicht der Fall.

Zu den verschwundenen/wiederaufgetauchten Daten...Hmmm
In den Logs oder in dmesg ist nach solch einem Transfer nichts zu finden was nach
Schreibfehler o.ä. hindeudet?
Bitte auch nochmal schauen nach einem solchen Transfer/Geschwindigkeitstest:
cat /proc/interrupts, dort die ERR -Spalte ob der Wert größer 0 ist.
Und in der gleichen Ausgabe ob sich die USB-Devices mit anderen Geräten interrupts
teilen müssen.

RhahkJin

/proc/interrupts sieht gut aus:

  0:        306   IO-APIC-edge      timer
  1:       4341   IO-APIC-edge      i8042
  7:          0   IO-APIC-edge      parport0
  8:          0   IO-APIC-edge      rtc0
  9:          0   IO-APIC-fasteoi   acpi
 10:          0   IO-APIC-edge      MPU401 UART
 14:      32133   IO-APIC-edge      libata
 15:     104221   IO-APIC-edge      libata
 16:         73   IO-APIC-fasteoi   ohci_hcd:usb1, firewire_ohci
 17:     732443   IO-APIC-fasteoi   ohci_hcd:usb2, eth1
 18:         14   IO-APIC-fasteoi   ehci_hcd:usb3, NVidia nForce2
 19:     294994   IO-APIC-fasteoi   nvidia
NMI:          0 
LOC:     340807 
ERR:          0
MIS:          0

/var/log/messages.log

Jan 23 22:02:54 desktop usb 2-1: new full speed USB device using ohci_hcd and address 7
Jan 23 22:02:55 desktop usb 2-1: configuration #3 chosen from 1 choice
Jan 23 22:02:55 desktop cdc_acm 2-1:3.1: ttyACM0: USB ACM device
Jan 23 22:02:55 desktop cdc_acm 2-1:3.3: ttyACM1: USB ACM device
Jan 23 22:02:55 desktop usb0: register 'cdc_ether' at usb-0000:00:02.1-1, CDC Ethernet Device, 02:80:37:15:03:00
Jan 23 22:03:04 desktop usb 2-1: USB disconnect, address 7
Jan 23 22:03:04 desktop usb0: unregister 'cdc_ether' usb-0000:00:02.1-1, CDC Ethernet Device
Jan 23 22:03:07 desktop usb 2-1: new full speed USB device using ohci_hcd and address 8
Jan 23 22:03:07 desktop usb 2-1: configuration #2 chosen from 1 choice
Jan 23 22:03:07 desktop scsi6 : SCSI emulation for USB Mass Storage devices
Jan 23 22:03:07 desktop scsi7 : SCSI emulation for USB Mass Storage devices
Jan 23 22:03:12 desktop scsi 6:0:0:0: Direct-Access     Sony Eri Memory Stick     0000 PQ: 0 ANSI: 0
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] 168000 512-byte hardware sectors (86 MB)
Jan 23 22:03:12 desktop scsi 7:0:0:0: Direct-Access     Sony Eri Memory Stick     0000 PQ: 0 ANSI: 0
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] Test WP failed, assume Write Enabled
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] 3995273 512-byte hardware sectors (2046 MB)
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] 168000 512-byte hardware sectors (86 MB)
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] Test WP failed, assume Write Enabled
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] Test WP failed, assume Write Enabled
Jan 23 22:03:12 desktop sdc:<5>sd 7:0:0:0: [sdd] 3995273 512-byte hardware sectors (2046 MB)
Jan 23 22:03:12 desktop sdc1
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] Attached SCSI removable disk
Jan 23 22:03:12 desktop sd 6:0:0:0: Attached scsi generic sg4 type 0
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] Test WP failed, assume Write Enabled
Jan 23 22:03:12 desktop sdd: sdd1
Jan 23 22:03:12 desktop sdd: p1 exceeds device capacity
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] Attached SCSI removable disk
Jan 23 22:03:12 desktop sd 7:0:0:0: Attached scsi generic sg5 type 0
Jan 23 22:03:13 desktop attempt to access beyond end of device
Jan 23 22:03:13 desktop sdd: rw=0, want=3995512, limit=3995273
Jan 23 22:03:13 desktop printk: 132 messages suppressed.
Jan 23 22:03:13 desktop attempt to access beyond end of device
Jan 23 22:03:13 desktop sdd: rw=0, want=3995513, limit=3995273
Jan 23 22:03:13 desktop attempt to access beyond end of device
Jan 23 22:03:13 desktop sdd: rw=0, want=3995514, limit=3995273

Die letzten 2 Zeilen zählen hoch bis want=3995648

/var/log/errors.log:

Jan 23 20:57:14 desktop sd 2:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 20:57:14 desktop sd 3:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 20:57:14 desktop sd 2:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 20:57:14 desktop sd 3:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995136
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995137
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995138
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995139
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995140
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995141
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995142
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995143
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995136
Jan 23 20:57:15 desktop Buffer I/O error on device sdd1, logical block 3995137
Jan 23 21:17:28 desktop sd 4:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 21:17:28 desktop sd 5:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 21:17:28 desktop sd 4:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 21:17:28 desktop sd 5:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995136
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995137
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995138
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995139
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995140
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995141
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995142
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995143
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995136
Jan 23 21:17:29 desktop Buffer I/O error on device sdd1, logical block 3995137
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 22:03:12 desktop sd 6:0:0:0: [sdc] Assuming drive cache: write through
Jan 23 22:03:12 desktop sd 7:0:0:0: [sdd] Assuming drive cache: write through
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995136
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995137
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995138
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995139
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995140
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995141
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995142
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995143
Jan 23 22:03:13 desktop Buffer I/O error on device sdd1, logical block 3995136

dmesg | tail

Buffer I/O error on device sdd1, logical block 3995137

und

attempt to access beyond end of device
sdd: rw=0, want=3995514, limit=3995273

beides sehr oft mit verschiedenen Blockangaben

GerBra

Hmm, diese Meldung "p1 exceeds device capacity" wird ja bei Suchmaschine
massenhaft gefunden, u.a. auch im Zusammenhang mit deinem Sony:
http://www.ottaky.com/k800i.php

Die Ursache? Keine wirkliche Ahnung, ich vermute für Linux Unstimmigkeiten in der
Partitionstabelle, die so aussehen als würde "außerhalb der Zylinder/Sektoren"
geschrieben.
Nach einem Datentransfer solltest du auf jedenfall als root den Befehl: sync
ausführen, irgendwie würde ich mich nur auf umount verlassen.

Mein Vorschlag wäre: teste es morgen nochmal mit einem "richtigen" USB-Stick.
Dann können wir auch sehen, ob diese Meldungen auch bei einem solchen Gerät
zu finden sind.

Pierre

Das Gerät oder controller sind USB 1.1. Jedenfalls steht dort "new full speed USB device using ohci_hcd". Bei USB 2.0 wäre es "high speed" und "ehci".

GerBra

@Pierre
Du meinst, das gilt für das ganze "Handy"? Wäre natürlich möglich...
Ich dachte, das wür de nur zu diesem Gerät:
usb0: unregister 'cdc_ether' usb-0000:00:02.1-1, CDC Ethernet Device
usb 2-1: new full speed USB device using ohci_hcd and address 8
gehören, was immer das auch für ein Teil sein mag 😉

Von der Geschwindigkeit her würde sich das allerdings mit USB 1.1 decken.

Pierre

Sonst finde ich auch nichts in dem Log; oder es ist eben nicht vollständig.