staging.inyokaproject.org

Hallo,

ich habe gerade festgestellt, dass ich auf meinen "Arduino UNO" kein sketch mehr (über den USB Port) laden kann. Es tritt der Fehler "can't open device "/dev/ttyACM3": Input/output error" auf. Dieses Verhalten habe ich allerdings erst nach dem Einspielen der letzten Updates für mein Ubuntu 20.04-2 LTS ("5.4.0-74-generic") festgestellt.

Mit einem anderen Rechner, der auch unter "5.4.0-74-generic" läuft, klappt der Zugriff auf die serielle Schnittstelle /dev/ttyACM0 aber. Dort sind allerdings die letzten Patches noch nicht eingespielt.

Im syslog erhalte ich die Fehlermeldung "cdc_acm 2-1.2:1.0: acm_port_activate - usb_submit_urb(ctrl irq) failed", die ich dem festgestellten Fehlverhalten zeitlich zuordnen kann. Im Internet gibt es eine Person, die das gleiche Problem allerdings unter MANJARO-ARM auch hatte und mit Einspielen eines anderen Kernels das Problem lösen konnte.

Meine Frage an die Community ist daher:

• Wie kann ich analysieren, weshalb das Problem auftritt?

• Mit der gleichen Arduino snap Installation ist auf dem 2. Rechner ja das Problem nicht vorhanden.

• Die "üblichen" Probleme mit Gruppenzugehörigkeit "dialout" oder einem dazwichen funkenden "ModemManager" möchte ich ausschließen (da auf beiden Systemen gleich).

Hier der relevante Auszug aus dem Syslog:

testuser@XFCE-TLS2004:~$ arduino --upload  /snap/arduino/current/examples/01.Basics/Blink/Blink.ino 
...
Der Sketch verwendet 924 Bytes (2%) des Programmspeicherplatzes. Das Maximum sind 32256 Bytes.
Globale Variablen verwenden 9 Bytes (0%) des dynamischen Speichers, 2039 Bytes für lokale Variablen verbleiben. Das Maximum sind 2048 Bytes.
Hochladen...
Beim Hochladen des Sketches ist ein Fehler aufgetreten
avrdude: ser_open(): can't open device "/dev/ttyACM3": Input/output error
testuser@XFCE-TLS2004:~$ grep -a -A 32 -B 5 ttyACM3 /var/log/syslog | grep "11 17"
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.809217] usb 2-1.2: new full-speed USB device number 6 using ehci-pci
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.926189] usb 2-1.2: New USB device found, idVendor=2341, idProduct=0043, bcdDevice= 0.01
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.926197] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=220
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.926201] usb 2-1.2: Manufacturer: Arduino (www.arduino.cc)
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.926204] usb 2-1.2: SerialNumber: 85xxxxxxxxxxxxxxx21
Jun 11 17:43:15 XFCE-TLS2004 kernel: [ 7474.926905] cdc_acm 2-1.2:1.0: ttyACM3: USB ACM device
Jun 11 17:43:15 XFCE-TLS2004 mtp-probe: checking bus 2, device 6: "/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2"
Jun 11 17:43:15 XFCE-TLS2004 mtp-probe: bus: 2, device: 6 was not an MTP device
Jun 11 17:43:16 XFCE-TLS2004 snapd[1400]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Jun 11 17:43:16 XFCE-TLS2004 mtp-probe: checking bus 2, device 6: "/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2"
Jun 11 17:43:16 XFCE-TLS2004 mtp-probe: bus: 2, device: 6 was not an MTP device
Jun 11 17:43:27 XFCE-TLS2004 systemd[1980]: Started snap.arduino.arduino.dbac8ee8-34a7-48b1-8b5d-01b3de3b79fb.scope.
Jun 11 17:43:27 XFCE-TLS2004 systemd[1980]: tmp-snap.rootfs_1SQGhR.mount: Succeeded.
Jun 11 17:43:27 XFCE-TLS2004 kernel: [ 7487.093925] audit: type=1400 audit(1623426207.816:73): apparmor="DENIED" operation="capable" profile="/snap/snapd/12057/usr/lib/snapd/snap-confine" pid=11633 comm="snap-confine" capability=4  capname="fsetid"
Jun 11 17:43:27 XFCE-TLS2004 systemd[1]: tmp-snap.rootfs_1SQGhR.mount: Succeeded.
Jun 11 17:43:28 XFCE-TLS2004 kernel: [ 7488.196347] audit: type=1326 audit(1623426208.920:74): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11715 comm="sed" exe="/bin/sed" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7fb19d0024e7 code=0x50000
Jun 11 17:43:28 XFCE-TLS2004 kernel: [ 7488.196351] audit: type=1326 audit(1623426208.920:75): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11715 comm="sed" exe="/bin/sed" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7fb19d0024e7 code=0x50000
Jun 11 17:43:29 XFCE-TLS2004 kernel: [ 7488.650314] audit: type=1400 audit(1623426209.376:76): apparmor="DENIED" operation="open" profile="snap.arduino.arduino" name="/proc/11722/mountinfo" pid=11722 comm="java" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
Jun 11 17:43:29 XFCE-TLS2004 kernel: [ 7488.654565] audit: type=1400 audit(1623426209.380:77): apparmor="DENIED" operation="open" profile="snap.arduino.arduino" name="/proc/11722/coredump_filter" pid=11722 comm="java" requested_mask="wr" denied_mask="wr" fsuid=1000 ouid=1000
Jun 11 17:43:29 XFCE-TLS2004 kernel: [ 7488.654571] audit: type=1400 audit(1623426209.380:78): apparmor="DENIED" operation="open" profile="snap.arduino.arduino" name="/proc/11722/coredump_filter" pid=11722 comm="java" requested_mask="wr" denied_mask="wr" fsuid=1000 ouid=1000
Jun 11 17:43:34 XFCE-TLS2004 kernel: [ 7493.360318] audit: type=1400 audit(1623426214.084:79): apparmor="DENIED" operation="open" profile="snap.arduino.arduino" name="/proc/11722/mountinfo" pid=11722 comm="java" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.419284] audit: type=1326 audit(1623426224.144:80): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11888 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fcb7a8304b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.424984] audit: type=1326 audit(1623426224.152:81): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11890 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7f7f48ccb4b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.430192] audit: type=1326 audit(1623426224.156:82): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11892 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7f15ca72c4b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.435447] audit: type=1326 audit(1623426224.160:83): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11894 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7f59a2b544b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.441027] audit: type=1326 audit(1623426224.168:84): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11896 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fc613c624b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.446547] audit: type=1326 audit(1623426224.172:85): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11898 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7ff3efc384b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.451929] audit: type=1326 audit(1623426224.176:86): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11900 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7f19490f04b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.457321] audit: type=1326 audit(1623426224.184:87): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11902 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fec34e554b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.465314] audit: type=1326 audit(1623426224.192:88): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11904 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fdba55f94b7 code=0x50000
Jun 11 17:43:44 XFCE-TLS2004 kernel: [ 7503.471983] audit: type=1326 audit(1623426224.196:89): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11906 comm="ar" exe="/snap/arduino/56/hardware/tools/avr/avr/bin/ar" sig=0 arch=c000003e syscall=92 compat=0 ip=0x7fd01c5bf4b7 code=0x50000
Jun 11 17:44:01 XFCE-TLS2004 kernel: [ 7520.317220] cdc_acm 2-1.2:1.0: acm_port_activate - usb_submit_urb(ctrl irq) failed
Jun 11 17:44:37 XFCE-TLS2004 kernel: [ 7556.857905] kauditd_printk_skb: 15 callbacks suppressed
Jun 11 17:44:37 XFCE-TLS2004 kernel: [ 7556.857907] audit: type=1326 audit(1623426277.584:105): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11722 comm="Timer-0" exe="/snap/arduino/56/usr/lib/jvm/java-11-openjdk-amd64/bin/java" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7f0033e6b4e7 code=0x50000
Jun 11 17:44:38 XFCE-TLS2004 kernel: [ 7557.614239] audit: type=1326 audit(1623426278.340:106): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11722 comm="Timer-0" exe="/snap/arduino/56/usr/lib/jvm/java-11-openjdk-amd64/bin/java" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7f0033e6b4e7 code=0x50000
Jun 11 17:44:38 XFCE-TLS2004 kernel: [ 7557.615109] audit: type=1326 audit(1623426278.340:107): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11722 comm="Timer-0" exe="/snap/arduino/56/usr/lib/jvm/java-11-openjdk-amd64/bin/java" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7f0033e6b4e7 code=0x50000
Jun 11 17:44:39 XFCE-TLS2004 kernel: [ 7558.701237] audit: type=1326 audit(1623426279.428:108): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11722 comm="Timer-0" exe="/snap/arduino/56/usr/lib/jvm/java-11-openjdk-amd64/bin/java" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7f0033e6b4e7 code=0x50000
Jun 11 17:44:39 XFCE-TLS2004 kernel: [ 7558.734038] audit: type=1326 audit(1623426279.460:109): auid=4294967295 uid=1000 gid=1000 ses=4294967295 pid=11722 comm="Timer-0" exe="/snap/arduino/56/usr/lib/jvm/java-11-openjdk-amd64/bin/java" sig=0 arch=c000003e syscall=93 compat=0 ip=0x7f0033e6b4e7 code=0x50000
testuser@XFCE-TLS2004:~$ ls -l /dev/ttyA*
crw-rw---- 1 root dialout 166, 0 Jun 11 16:14 /dev/ttyACM0
crw-rw---- 1 root dialout 166, 1 Jun 11 16:14 /dev/ttyACM1
crw-rw---- 1 root dialout 166, 2 Jun 11 16:14 /dev/ttyACM2
crw-rw---- 1 root dialout 166, 3 Jun 11 17:43 /dev/ttyACM3
testuser@XFCE-TLS2004:~$ groups
testuser adm dialout cdrom sudo dip plugdev lpadmin scanner sambashare davfs2
testuser@XFCE-TLS2004:~$ uname -r
5.4.0-74-generic
testuser@XFCE-TLS2004:~$ stty -F /dev/ttyACM3
stty: /dev/ttyACM3: Eingabe-/Ausgabefehler
testuser@XFCE-TLS2004:~$ lsusb
Bus 002 Device 005: ID 0bdb:1911 Ericsson Business Mobile Networks BV 
Bus 002 Device 008: ID 2341:0043 Arduino SA Uno R3 (CDC ACM)
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 005: ID 04f2:b221 Chicony Electronics Co., Ltd integrated camera
Bus 001 Device 003: ID 147e:2016 Upek Biometric Touchchip/Touchstrip Fingerprint Sensor
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
testuser@XFCE-TLS2004:~$ lsusb -v -d 2341:0043

Bus 002 Device 008: ID 2341:0043 Arduino SA Uno R3 (CDC ACM)
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               1.10
  bDeviceClass            2 Communications
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         8
  idVendor           0x2341 Arduino SA
  idProduct          0x0043 Uno R3 (CDC ACM)
  bcdDevice            0.01
  iManufacturer           1 Arduino (www.arduino.cc)
  iProduct                2 (error)
  iSerial               220 85937313537351408121
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x003e
    bNumInterfaces          2
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0xc0
      Self Powered
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         2 Communications
      bInterfaceSubClass      2 Abstract (modem)
      bInterfaceProtocol      1 AT-commands (v.25ter)
      iInterface              0 
      CDC Header:
        bcdCDC               10.01
      CDC ACM:
        bmCapabilities       0x06
          sends break
          line coding and serial state
      CDC Union:
        bMasterInterface        0
        bSlaveInterface         1 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0008  1x 8 bytes
        bInterval             255
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        1
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass        10 CDC Data
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 
      iInterface              0 
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x04  EP 4 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0040  1x 64 bytes
        bInterval               1
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0000
  (Bus Powered)
testuser@XFCE-TLS2004:~$ 

Ein "dmesg -wH" liefert die gleichen Informationen wie die im syslog aufgeführten.

Weitere Informationen zu dem oben geschilderten Fehler:

• Wird über Grub die Vorgänger-Version "5.4.0-73-generic" gebootet, funktioniert alles einwandfrei

• Wird über Grub die default oder Version "5.4.0-74-generic" gebootet, tritt der Fehler auf.

Fazit: Der Fehler ist mit dem Upgrade auf Kernel 74 gekommen.

Bei näherer Untersuchung von /var/log/apt/term.log* und history.log* ist nach dem Update auf Kernel 74 bei dem betroffenen Rechner auch noch ein Update der "linux-firmware" und "intel-microcode" eingespielt worden. Diese Updates sind noch nicht auf dem 2. Rechner eingespielt worden, der auch unter Kernel 74 läuft und bei dem der Zugriff auf die tty Schnittstellen möglich ist.

Die Vermutung liegt daher nahe, dass der Fehler durch das Einspielen von firmware/microcode sichtbar/verursacht geworden ist.

Da das Problem offensichtlich nicht an der Applikation "Arduino" sondern eher zum Thema Kernel/Firmware Upgrade gehört, werde ich dort das Thema platzieren.

bitte löschen (doppelpost...)