Disconnecting kernal: reset high-speed USB device

flyer2000

Hallo zusammen,

Sporadische disconnects verunmöglichen drucken aub Repertier Server.

Konfiguration:

Raspberry PI  3 mit Repetier Server 93.1

Verbindung via USB zu Arduino Due (Native USB Port) und RADDS

Firmware Marlin 2.0.5.1

Repetier-Server LOG:
2020-03-25 13:23:19: Job created: /var/lib/Repetier-Server/printer/FireXX/jobs/00000003_KettenradAntrieb.u
2020-03-25 13:23:19: finish job creation /var/lib/Repetier-Server/printer/FireXX/jobs/00000003_KettenradAntrieb.u
2020-03-25 13:23:23: Job created: /var/lib/Repetier-Server/printer/FireXX/jobs/00000004_KettenradAntrieb.u
2020-03-25 13:23:24: finish job creation /var/lib/Repetier-Server/printer/FireXX/jobs/00000004_KettenradAntrieb.u
2020-03-25 13:23:24: start printjob KettenradAntrieb on printer FireXX

SYSLOG:
Mar 25 13:50:35 Repetier-Server systemd[1]: Starting Time & Date Service...
Mar 25 13:50:35 Repetier-Server dbus-daemon[297]: [system] Successfully activated service 'org.freedesktop.timedate1'
Mar 25 13:50:35 Repetier-Server systemd[1]: Started Time & Date Service.
Mar 25 13:50:53 Repetier-Server kernel: [ 3502.661922] usb 1-1.5: reset high-speed USB device number 5 using dwc_otg
Mar 25 13:50:53 Repetier-Server kernel: [ 3502.796971] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
Mar 25 13:50:53 Repetier-Server ModemManager[286]: <info>  (tty/ttyACM0): released by device '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5'
Mar 25 13:50:53 Repetier-Server ModemManager[286]: <info>  Couldn't check support for device '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5': Operation was cancelled
Mar 25 13:50:53 Repetier-Server kernel: [ 3502.931900] usb 1-1.5: reset high-speed USB device number 5 using dwc_otg
Mar 25 13:50:54 Repetier-Server kernel: [ 3503.063178] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
Mar 25 13:51:05 Repetier-Server systemd[1]: systemd-timedated.service: Succeeded.
Mar 25 13:51:11 Repetier-Server ModemManager[286]: <info>  [device /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5] creating modem with plugin 'Generic' and '1' ports
Mar 25 13:51:11 Repetier-Server ModemManager[286]: <warn>  Could not grab port (tty/ttyACM0): 'Cannot add port 'tty/ttyACM0', unhandled serial type'
Mar 25 13:51:11 Repetier-Server ModemManager[286]: <warn>  Couldn't create modem for device '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5': Failed to find primary AT port
Mar 25 13:51:38 Repetier-Server dbus-daemon[297]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.463' (uid=0 pid=6683 comm="timedatectl ")

Der ModemManager funkt irgenwie dazwischen. Was kann ich tun dagegen?

Danke für jeden Hinweis.

Thomas

flyer2000

Das Repetier-Server Log ist der interessante Abschnitt nicht kopiert worden. Sorry.

Hier der Nachtrag:

Repetier-Server LOG:
2020-03-25 13:23:19: Job created: /var/lib/Repetier-Server/printer/FireXX/jobs/00000003_KettenradAntrieb.u
2020-03-25 13:23:19: finish job creation /var/lib/Repetier-Server/printer/FireXX/jobs/00000003_KettenradAntrieb.u
2020-03-25 13:23:23: Job created: /var/lib/Repetier-Server/printer/FireXX/jobs/00000004_KettenradAntrieb.u
2020-03-25 13:23:24: finish job creation /var/lib/Repetier-Server/printer/FireXX/jobs/00000004_KettenradAntrieb.u
2020-03-25 13:23:24: start printjob KettenradAntrieb on printer FireXX
2020-03-25 13:50:53: error: Reading serial conection failed: End of file. Closing connection.
2020-03-25 13:50:53: Port closed for FireXX
2020-03-25 13:50:53: Connection closed: FireXX
2020-03-25 13:51:23: Connection started: FireXX
2020-03-25 13:51:23: Reset printer FireXX

Über die Stromversorgung wurde auch schon viel diskutiert. Ich habe mit verschiedenen Netzteilen schon probiert. Fehler tritt immer gleich auf. Aktuell ist ein MEAN WELL RS-15-5 zur Stromversorung eingebaut.

Gruss Thomas

Repetier

Stromversorgung läst sich leicht ausschließen. Gib nach winer weile wenn das wieder passiert mal
dmesg
an. Wenn du Probleme hast steht da undervoltage detected.
Eigentlich kenne ich das so das dann usb disconnected oder so im log stand, reset kommt mir auch komisch vor.

Du könntest den modemmanager deinstallieren

sudo apt-get purge modemmanager

der ist eh nur für mobilfunk zuständig. Bisher hatte ich das Problem damit, aber wüsste auch nicht warum ich ihn brauchen sollte.

flyer2000

Danke für den Tip.

stand tatsächlich:

flyer2000

Danke für den Tipp.

stand tatsächlich:

[    6.871955] Under-voltage detected! (0x00050000)

im Log

Habe den modemmanager deinstalliert.

Zusätzlich die Spannung am Netzgerät von 5.05 auf 5.25 Volt erhöht.

Schon vor einiger Zeit habe ich ein "vernünftiges" kurzes (8cm) Kabel vom Netzgerät zum Raspi verlegt. Das Kabel ist auf der PCB Rückseite auf die USB Buchse verlötet.  Habe gedacht, dass das Thema für alle Zeiten erledigt ist.

Eigentlich hätten die 5.05 Volt auch ausreichen sollen. Kommt vermutlich darauf an, wo Under-voltage detektiert wird.

An den USB A Buchsen kommen nur noch 5.09 Volt an. Mit dem Oszi über längere Zeit gemessen ist das min 5.04 das maximum 5.20 Volt.

Gemessen mit einem kalibrierten Messgerät.

Kaum zu glauben das der Raspi so zikig ist

Danke nochmal für die Unterstützung

flyer2000

Hallo zusammen,

Das Problem tritt immer noch auf.

dmesg:

[Sat Mar 28 12:01:22 2020] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[Sat Mar 28 12:01:22 2020] sd 0:0:0:0: [sda] tag#0 Sense Key : 0x4 [current]
[Sat Mar 28 12:01:22 2020] sd 0:0:0:0: [sda] tag#0 ASC=0x0 ASCQ=0x0
[Sat Mar 28 12:01:22 2020] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 1e 45 80 00 00 08 00
[Sat Mar 28 12:01:22 2020] print_req_error: I/O error, dev sda, sector 1983872
[Sat Mar 28 12:01:22 2020] Buffer I/O error on dev sda, logical block 247984, async page read
[Sat Mar 28 12:04:05 2020] WARN::dwc_otg_hcd_urb_dequeue:639: Timed out waiting for FSM NP transfer to complete on 0
[Sat Mar 28 12:04:06 2020] usb 1-1.4: reset high-speed USB device number 7 using dwc_otg
[Sat Mar 28 12:04:06 2020] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device
[Sat Mar 28 12:04:06 2020] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x03 driverbyte=0x00
[Sat Mar 28 12:04:06 2020] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 1e 45 80 00 00 08 00
[Sat Mar 28 12:04:06 2020] print_req_error: I/O error, dev sda, sector 1983872
[Sat Mar 28 12:04:06 2020] dwc_otg: DEVICE:007 : update_urb_state_xfer_comp:751:trimming xfer length
[Sat Mar 28 12:04:06 2020] usb 1-1.4: reset high-speed USB device number 7 using dwc_otg
[Sat Mar 28 12:04:06 2020] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device

Repetier Server.log:

2020-03-28 11:56:49: start printjob BettAbdeckung (Meshed) on printer FireXX
2020-03-28 12:04:06: error: Reading serial conection failed: End of file. Closing connection.
2020-03-28 12:04:06: Port closed for FireXX
2020-03-28 12:04:06: Connection closed: FireXX
2020-03-28 12:04:36: Connection started: FireXX
2020-03-28 12:04:36: Reset printer FireXX

Um ein HW Problem auszuschliessen habe ich schon folgendes gemacht:

-mit verschiedenen hochwertigen USB Kabeln versucht (Verbindung PI -- Arduino Due)

-Arduino Due ersetzt

-Raspi ersetzt mit neu erstellter SD. auch Test mit PI 4

-Hochwertiges Netzteil verbaut dmesg hat keine Hinweise auf Under-voltage

alle diese Versuche brachten leider nichts. Immer wieder das Gleiche Problem.

Was mir auch nicht so gefällt sind:

[Sat Mar 28 12:07:06 2020] print_req_error: critical target error, dev sda, sector 0
[Sat Mar 28 12:07:06 2020] Buffer I/O error on dev sda, logical block 0, async page read

da habe ich mit zwei verschiedenen SD Herstellern versucht. Bei beiden kommen die gleichen Meldungen.

Ein sudo badblocks -n -v /dev/sdb ergibt: keine Fehler gefunden.

Habt ihr noch Ideen?

Bin um jeden Hinweis froh.

Gruss Thomas

Repetier

Wenn man 
usb 1-1.4: reset high-speed USB device number 7 using dwc_otg
googelt findet man viele die Probleme mit unterschiedlicher Hardware haben. Oft wird vermutet das dass Gerät am usb port zu viel Strom zieht. Hast du mal versucht ein USB Kabel ohne 5V kabel zu verwenden, damit das Board keinen Strom vom pi ziehen kann. Ich hab das für ein eins gemacht indem ich das Rote Kabel durchtrennt habe. Aber du scheinst ja eh mehr Ahnung von Elektronik zu haben als ich. Damit zieht der Drucker 0 strom über usb und muss sich selber versorgen. Entlastet den pi und sollte dann hoffentlich nicht mehr stören.

flyer2000

Danke für die Antwort.

Ja, als ich diesen Drucker gebaut habe, habe ich das gleich so gemacht. Die 5V sind getrennt zwischen Pi und Arduino Due.

Es ist schon seltsam. Der Drucker ist 1.5 Jahre einwandfrei gelaufen. Plötzlich hat es sporadisch angefangen mit den disconnects. Zuerst ganz selten. Heute bringe ich kaum einen Druckjob mehr raus. Manchmal läuft er auch wieder 4 Stunden ohne Probleme.

Ich habe zuerst geglaubt, dass ein Masseproblem vorliegt da ich drei Netzteile verwende. Ich habe das alles überprüft und die 0 Volt der Netzteile mit direkten dicken Leitungen verbunden. Hat alles nichts gebracht.

Im Moment habe keine Ideen mehr.

Zuverlässig drucken geht nur via SD Card.

Gruss Thomas

Repetier

Da die Trennung im Linux Kernel erzeugt ist kann ich nicht wirklich viel dazu sagen außer meinen Erfahrungen damit bisher. Wenn man nach "raspebrry dwc_otg" sucht findet man viel dazu und viele Optionen die Versuchen USB Probleme zu lösen. Also leider kein unbekanntes Problem beim pi. Ein hub dazwischen kann vielleicht noch helfen, aber das ist schwer zu sagen.

mhas

Grüß euch,

hatte heute Nacht leider auch einen "absteller". Absteller aber in der Form, dass alles zu 100% weiterlief nur der Druckkopf blieb stehen und tat nichts mehr ...
Vorhin das gleiche nochmal - der Druckkopf fuhr nur noch vor und zurück ...

Gibts da Erfahrungen??

Danke euch, VG
Manuel

Repetier

Der Kopf bewegte sich noch weiter? Dann müsste die Kommuniaktion noch funktionieren. In dem Fall gab es vermutlich nur ein Problem mit dem Extruder und er hat den eingestellt. Wichtig zur Analyse - logging einschalten und dann am Zeitpunkt nachsehen was da im log steht. Auch im server.log nachsehen ob der Drucker getrennt wurde und dann in /var/log/syslog nachsehen ob linux die usb Verbindung getrennt hat. Aber wenn er sich weiter bewegt ist es eher ein Problem am drucker das ihn extrudieren stoppen lässt. Heater decoupled beispielsweise führt gerne zu dem Muster.

mhas

Die Kommunikation funktionierte auch - als er stehen blieb und die vollen Temp. vorhanden waren ...

Ich konnte den Drucker auch ganz normal via Z-Achse hochfahren!

Repetier

Hat der server den Druck denn für beendet erklärt? Könnte sein das Linux die Verbindung getrennt hat - daher in server.log nachsehen ob das passiert ist! In dem Fall stoppt der Druck natürlich. Wenn der Drucker beim verbinden nicht resetet (manche tun das nicht) würde die Heizung weiter laufen und neue Befehle klappen.

flyer2000

Hallo zusammen,

es lag tatsächlich am verwendeten Port auf dem Arduino Due. Ich hatte ja geschrieben, dass ich den native USB Port verwende um den Repetier Server zu verbinden. Der Grund lag vor allem daran, dass mich der Reset (mehrmalig) beim Verbinden von Repetier Server mit dem Arduino Programming Port störte. Das Verbinden mit dem native USB Port löst kein Reset aus. Auch bricht kein Druck ab der ab SD läuft.

Der Drucker lief vorher ca. 1.5 Jahre ohne Problem mit dem native USB Port.

Und jetzt kommts: Mit der Repetier Firmware. Das Problem trat erst auf als ich auf Marlin wegen UBL gewechselt habe. So ganz allmählich. Warum das so war, keine Ahnung.

Und warum  $dmesg

Buffer I/O error on dev sda, logical block 247984, async page read

aus gibt, wenn der native USB Port verwendet wird, weiss ich auch nicht. Dazu könnte eventuell Repetier etwas sagen. Logischer wäre ein I/O error on usb 1-1.4 oder so.

Eventuell weiss das jemand, warum das so ist.

Was jetzt noch ist:

Der Reset beim Verbinden ist sehr unschön. Ich verwende die RAPS128 Stepper Driver. Bei denen ist der Motor Strom On/OFF  Invertiert. Also 0 ist Strom eingeschaltet. Bis dann der Arduino Due gebootet hat liegt der volle Motorstrom an allen Motoren an. Weil nun Repetier Server kurz hintereinander 3! Resets sendet, rumpelt der Drucker ganz schön. Zudem ist nach diesen 3 Resets die Firmware blockiert. Den genauen Wortlaut der Meldung habe ich jetzt nicht zur Hand. Kann ich aber nachliefern. Ein zusätzlicher Reset am Drucker bringt dann den Drucker online.

Habe schon gegoogelt und gelesen, dass der Reset nicht unterdrückt werden kann. Jedoch gleich 3 mal ist schon heftig.

Gruss Thomas

Repetier

Der Reset hängt am DTR pin. In den Verbindungseinstellungen steht drin wie er sich ändert. Default ist LOW/HIGH glaube ich. Wenn er sich bei jedem wechsel ändert sind das 2 wechsel und resets. Kann man aber auch auf immer high setzen, aber dann macht er reset eher selten. Und am native port ohnehin nicht. Damit kann man aber immerhin die Anzahl ändern. Wenn es beim ersten verbindungsversuch nicht klappt (warum auch immer) versucht er es noch mal. 

Buffer I/O error on dev sda, logical block 247984, async page read
sda ist die sd karte im pi. Da gab es also einen lesefehler. Ob er behoben wurde oder nicht kann ich nicht sagen. Hab Linux ja nicht geschrieben:-)

flyer2000

@Repetier

danke für das Feedback!!

Wegen dem Lesefehler etwas kalarer ausgedrückt:

Wenn am native USB gedruckt wird                = Lesefehler auf der SD-Karte.

Wenn am Programming Port gedruckt wird = kein Lesefehler auf der SD-Karte.

Ist doch komisch oder?

Reset:

Wenn der Drucker eingeschaltet wird, kommt immer in der Repetier-Server Konsole:

Firmware stopped! You can only send host and shell commands until you hit emergency stop or restart the printer

Dann muss immer nochmals der Reset-Taster gedrückt werden.

Hatte bisher kein Erfolg mit den LOW/HIGH Einstellungen.

Gruss Thomas

Repetier

Firmware stopped kommt wenn firmware
!!
sendet. Das ist die offizielle anfrage der Firmware nichts mehr zu machen. Frage ist also warum kommt die Aufforderung? Dazu müsste man das log komplett sehen dann macht es vielleicht sinn.

Lesefehler bei nativeport hört sich unlogisch an. Die haben ja erst mal nichts gemeinsam, außer das beide am USB system hängen denke ich. Elektrisch ist das natürlich etwas anders aber deswegen lesefehler rauszugeben ist trotzdem nicht logisch. Kann ich also nichts zu sagen.

flyer2000

Danke!

!! das war ein sehr nützlicher Hinweis.

Startet der Arduino Due (überigens kein Klon sondern Original Arduino), kommt ein völliger wirrwarr beim Repetier-Server an. Zufällig in 90% aller Fälle auch ein "!!"

Scheinbar bekannter Bug:

https://github.com/arduino/Arduino/pull/1267

Und die Lösung:

https://www.arduino.cc/en/Hacking/Upgrading16U2Due

Das beste:

Es funktioniert auch. Keine Firmware stopped. Kein zusätzlicher Reset mehr erforderlich.

Somit:

Repetier

Den Bug im Arduino kannte ich noch nicht. Vielleicht geht dann auch die Kommunikation besser. Hab den 16u2 immer schon im Verdacht gehabt bei hoher last mist zu bauen. Aber das er es schon beim einschalten macht hatte ich noch nicht.