Problem with the CH341 driver in Ubuntu 20.04

Wed Jan 6 16:37:09 UTC 2021

Il giorno mer 6 gen 2021 alle ore 10:42 Thadeu Lima de Souza Cascardo
<cascardo at canonical.com> ha scritto:
>
> On Tue, Jan 05, 2021 at 05:30:45PM +0100, Augusto Ciuffoletti wrote:
> > I run into this problem trying to program an ESP8266 board, which uses
> > the CH341 chip in the programming interface as a USB-to-Serial
> > interface. The problem appeared after an upgrade from Ubuntu 19.10 to
> > 20.04 (that I carried out one week ago).
> >
>
> So, if I understand it, it did work before you upgraded. Can you try booting
> with one of the old 5.3 kernels, and send the output of lsusb?

I'm working with my production machine and (after 20+ years of
experience with Linix) quite scared to touch at the grub
configuration, In addition, consider that the new installation
operates with the 5.4 kernel, with little chances to complete the
boot, and even worse to have a significant hint. BUT, I have a logfile
preceding the upgrade, and there I luckily found the trace of the
module installation, and the successful loading of a sketch into the
Wemos device:

=========
Dec 30 12:22:43 Legion kernel: [2354065.515635] usb 1-3: new
full-speed USB device number 30 using xhci_hcd
Dec 30 12:22:43 Legion kernel: [2354065.664692] usb 1-3: New USB
device found, idVendor=1a86, idProduct=7523, bcdDevice= 2.64
Dec 30 12:22:43 Legion kernel: [2354065.664697] usb 1-3: New USB
device strings: Mfr=0, Product=2, SerialNumber=0
Dec 30 12:22:43 Legion kernel: [2354065.664701] usb 1-3: Product: USB Serial
Dec 30 12:22:43 Legion kernel: [2354065.666768] ch341 1-3:1.0:
ch341-uart converter detected
Dec 30 12:22:43 Legion kernel: [2354065.667695] usb 1-3: ch341-uart
converter now attached to ttyUSB1
Dec 30 12:22:43 Legion mtp-probe: checking bus 1, device 30:
"/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3"
Dec 30 12:22:43 Legion mtp-probe: bus: 1, device: 30 was not an MTP device
Dec 30 12:22:43 Legion snapd[15280]: hotplug.go:199: hotplug device
add event ignored, enable experimental.hotplug
Dec 30 12:22:43 Legion mtp-probe: checking bus 1, device 30:
"/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3"
Dec 30 12:22:43 Legion mtp-probe: bus: 1, device: 30 was not an MTP device
Dec 30 12:22:45 Legion ModemManager[1198]: <info>  Couldn't check
support for device '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3':
not supported by any plugin
Dec 30 12:22:46 Legion systemd[6301]: tracker-extract.service: Succeeded.
Dec 30 12:22:46 Legion dbus-daemon[1183]: [system] Activating via
systemd: service name='net.reactivated.Fprint' unit='fprintd.service'
requested by ':1.52054' (uid=1000 pid=18287 comm="/usr/bin/gnome-shell
" label="unconfined")
Dec 30 12:22:46 Legion systemd[1]: Starting Fingerprint Authentication Daemon...
Dec 30 12:22:46 Legion dbus-daemon[1183]: [system] Successfully
activated service 'net.reactivated.Fprint'
Dec 30 12:22:46 Legion systemd[1]: Started Fingerprint Authentication Daemon.
Dec 30 12:22:50 Legion NetworkManager[1193]: <info>  [1609327370.5477]
agent-manager: req[0x5574cc0e7540,
:1.52054/org.gnome.Shell.NetworkAgent/1000]: agent registered
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-DEBUG]
Registering StatusNotifierItem
:1.87/org/ayatana/NotificationItem/software_update_available
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-DEBUG]
Registering StatusNotifierItem
:1.82/org/ayatana/NotificationItem/dropbox_client_18678
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-DEBUG]
Registering StatusNotifierItem
:1.110/org/ayatana/NotificationItem/whatsdesk1
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-FATAL]
unable to update overlay icon
Dec 30 12:22:50 Legion gnome-shell[18287]: message repeated 5 times: [
[AppIndicatorSupport-FATAL] unable to update overlay icon]
Dec 30 12:22:50 Legion gnome-shell[18287]: Couldn’t parse
user-home.desktop as a desktop file, will treat it as a regular file.
Dec 30 12:22:50 Legion gnome-shell[18287]: Couldn’t parse
trash-can.desktop as a desktop file, will treat it as a regular file.
Dec 30 12:22:50 Legion gnome-shell[18287]: Couldn’t parse
network.desktop as a desktop file, will treat it as a regular file.
Dec 30 12:22:50 Legion gnome-shell[18287]: Couldn’t parse
computer.desktop as a desktop file, will treat it as a regular file.
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-WARN]
Attempting to re-register
:1.82/org/ayatana/NotificationItem/dropbox_client_18678; resetting
instead
Dec 30 12:22:50 Legion gnome-shell[18287]: [AppIndicatorSupport-WARN]
Item :1.82/org/ayatana/NotificationItem/dropbox_client_18678 is
already registered
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 31 with keysym 31 (keycode a).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 32 with keysym 32 (keycode b).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 33 with keysym 33 (keycode c).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 38 with keysym 38 (keycode 11).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 39 with keysym 39 (keycode 12).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 34 with keysym 34 (keycode d).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 35 with keysym 35 (keycode e).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 36 with keysym 36 (keycode f).
Dec 30 12:22:51 Legion gnome-shell[18287]: Window manager warning:
Overwriting existing binding of keysym 37 with keysym 37 (keycode 10).
Dec 30 12:23:06 Legion tracker-store[17432]: OK
Dec 30 12:23:06 Legion systemd[6301]: tracker-store.service: Succeeded.
Dec 30 12:23:17 Legion systemd[1]: fprintd.service: Succeeded.
Dec 30 12:23:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1' unit='tracker-store.service' requested
by ':1.74' (uid=1000 pid=18568 comm="/usr/lib/tracker/tracker-miner-fs
" label="unconfined")
Dec 30 12:23:35 Legion systemd[6301]: Starting Tracker metadata
database store and lookup manager...
Dec 30 12:23:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service 'org.freedesktop.Tracker1'
Dec 30 12:23:35 Legion systemd[6301]: Started Tracker metadata
database store and lookup manager.
Dec 30 12:23:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1.Miner.Extract'
unit='tracker-extract.service' requested by ':1.74' (uid=1000
pid=18568 comm="/usr/lib/tracker/tracker-miner-fs "
label="unconfined")
Dec 30 12:23:35 Legion systemd[6301]: Starting Tracker metadata extractor...
Dec 30 12:23:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service
'org.freedesktop.Tracker1.Miner.Extract'
Dec 30 12:23:35 Legion systemd[6301]: Started Tracker metadata extractor.
Dec 30 12:23:46 Legion systemd[6301]: tracker-extract.service: Succeeded.
Dec 30 12:24:06 Legion tracker-store[17590]: OK
Dec 30 12:24:06 Legion systemd[6301]: tracker-store.service: Succeeded.
Dec 30 12:24:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1' unit='tracker-store.service' requested
by ':1.74' (uid=1000 pid=18568 comm="/usr/lib/tracker/tracker-miner-fs
" label="unconfined")
Dec 30 12:24:35 Legion systemd[6301]: Starting Tracker metadata
database store and lookup manager...
Dec 30 12:24:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service 'org.freedesktop.Tracker1'
Dec 30 12:24:35 Legion systemd[6301]: Started Tracker metadata
database store and lookup manager.
Dec 30 12:24:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1.Miner.Extract'
unit='tracker-extract.service' requested by ':1.74' (uid=1000
pid=18568 comm="/usr/lib/tracker/tracker-miner-fs "
label="unconfined")
Dec 30 12:24:35 Legion systemd[6301]: Starting Tracker metadata extractor...
Dec 30 12:24:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service
'org.freedesktop.Tracker1.Miner.Extract'
Dec 30 12:24:35 Legion systemd[6301]: Started Tracker metadata extractor.
Dec 30 12:24:46 Legion systemd[6301]: tracker-extract.service: Succeeded.
Dec 30 12:25:06 Legion tracker-store[17687]: OK
Dec 30 12:25:06 Legion systemd[6301]: tracker-store.service: Succeeded.
Dec 30 12:25:13 Legion gnome-shell[18287]: Opzioni di compilazione
cambiate, ricompilo tutto
Dec 30 12:25:14 Legion gnome-shell[18287]: Lo sketch usa 263420 byte
(25%) dello spazio disponibile per i programmi. Il massimo è 1044464
byte.
Dec 30 12:25:14 Legion gnome-shell[18287]: Le variabili globali usano
26904 byte (32%) di memoria dinamica, lasciando altri 55016 byte
liberi per le variabili locali. Il massimo è 81920 byte.
Dec 30 12:25:14 Legion gnome-shell[18287]: esptool.py v2.6
Dec 30 12:25:14 Legion gnome-shell[18287]: Traceback (most recent call last):
Dec 30 12:25:14 Legion gnome-shell[18287]:   File
"/home/augusto/.arduino15/packages/esp8266/hardware/esp8266/2.5.2/tools/upload.py",
line 25, in <module>
Dec 30 12:25:14 Legion gnome-shell[18287]:     esptool.main(fakeargs)
Dec 30 12:25:14 Legion gnome-shell[18287]: 2.6
Dec 30 12:25:14 Legion gnome-shell[18287]: esptool.py v2.6
Dec 30 12:25:14 Legion gnome-shell[18287]:   File
"/home/augusto/.arduino15/packages/esp8266/hardware/esp8266/2.5.2/tools/esptool/esptool.py",
line 2652, in main
Dec 30 12:25:14 Legion gnome-shell[18287]: Serial port /dev/ttyUSB0
Dec 30 12:25:14 Legion gnome-shell[18287]:     esp =
chip_class(each_port, initial_baud, args.trace)
Dec 30 12:25:14 Legion gnome-shell[18287]:   File
"/home/augusto/.arduino15/packages/esp8266/hardware/esp8266/2.5.2/tools/esptool/esptool.py",
line 222, in __init__
Dec 30 12:25:14 Legion gnome-shell[18287]:     self._port =
serial.serial_for_url(port)
Dec 30 12:25:14 Legion gnome-shell[18287]:   File
"/home/augusto/.arduino15/packages/esp8266/hardware/esp8266/2.5.2/tools/pyserial/serial/__init__.py",
line 88, in serial_for_url
Dec 30 12:25:14 Legion gnome-shell[18287]:     instance.open()
Dec 30 12:25:14 Legion gnome-shell[18287]:   File
"/home/augusto/.arduino15/packages/esp8266/hardware/esp8266/2.5.2/tools/pyserial/serial/serialposix.py",
line 268, in open
Dec 30 12:25:14 Legion gnome-shell[18287]:     raise
SerialException(msg.errno, "could not open port {}:
{}".format(self._port, msg))
Dec 30 12:25:14 Legion gnome-shell[18287]:
serial.serialutil.SerialException: [Errno 2] could not open port
/dev/ttyUSB0: [Errno 2] No such file or directory: '/dev/ttyUSB0'
Dec 30 12:25:14 Legion gnome-shell[18287]: Errore durante il
caricamento dello sketch
Dec 30 12:25:24 Legion gnome-shell[18287]: Lo sketch usa 263420 byte
(25%) dello spazio disponibile per i programmi. Il massimo è 1044464
byte.
Dec 30 12:25:24 Legion gnome-shell[18287]: Le variabili globali usano
26904 byte (32%) di memoria dinamica, lasciando altri 55016 byte
liberi per le variabili locali. Il massimo è 81920 byte.
Dec 30 12:25:24 Legion gnome-shell[18287]: esptool.py v2.6
Dec 30 12:25:24 Legion gnome-shell[18287]: 2.6
Dec 30 12:25:24 Legion gnome-shell[18287]: esptool.py v2.6
Dec 30 12:25:24 Legion gnome-shell[18287]: Serial port /dev/ttyUSB1
Dec 30 12:25:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1' unit='tracker-store.service' requested
by ':1.74' (uid=1000 pid=18568 comm="/usr/lib/tracker/tracker-miner-fs
" label="unconfined")
Dec 30 12:25:35 Legion systemd[6301]: Starting Tracker metadata
database store and lookup manager...
Dec 30 12:25:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service 'org.freedesktop.Tracker1'
Dec 30 12:25:35 Legion systemd[6301]: Started Tracker metadata
database store and lookup manager.
Dec 30 12:25:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Activating via systemd: service
name='org.freedesktop.Tracker1.Miner.Extract'
unit='tracker-extract.service' requested by ':1.74' (uid=1000
pid=18568 comm="/usr/lib/tracker/tracker-miner-fs "
label="unconfined")
Dec 30 12:25:35 Legion systemd[6301]: Starting Tracker metadata extractor...
Dec 30 12:25:35 Legion dbus-daemon[18113]: [session uid=1000
pid=18113] Successfully activated service
'org.freedesktop.Tracker1.Miner.Extract'
Dec 30 12:25:35 Legion systemd[6301]: Started Tracker metadata extractor.
Dec 30 12:25:38 Legion gnome-shell[18287]:
Connecting........_____....._____....._____....._
Dec 30 12:25:38 Legion gnome-shell[18287]: Chip is ESP8266EX
Dec 30 12:25:38 Legion gnome-shell[18287]: Features: WiFi
Dec 30 12:25:38 Legion gnome-shell[18287]: MAC: 8c:ce:4e:e1:dc:be
Dec 30 12:25:38 Legion gnome-shell[18287]: Uploading stub...
Dec 30 12:25:38 Legion gnome-shell[18287]: Running stub...
Dec 30 12:25:38 Legion gnome-shell[18287]: Stub running...
Dec 30 12:25:38 Legion gnome-shell[18287]: Changing baud rate to 460800
Dec 30 12:25:38 Legion gnome-shell[18287]: Changed.
Dec 30 12:25:38 Legion gnome-shell[18287]: Configuring flash size...
Dec 30 12:25:38 Legion gnome-shell[18287]: Auto-detected Flash size: 4MB
Dec 30 12:25:38 Legion gnome-shell[18287]: Compressed 267568 bytes to 195058...
Dec 30 12:25:43 Legion gnome-shell[18287]: #015Writing at
0x00000000... (8 %)#015Writing at 0x00004000... (16 %)#015Writing at
0x00008000... (25 %)#015Writing at 0x0000c000... (33 %)#015Writing at
0x00010000... (41 %)#015Writing at 0x00014000... (50 %)#015Writing at
0x00018000... (58 %)#015Writing at 0x0001c000... (66 %)#015Writing at
0x00020000... (75 %)#015Writing at 0x00024000... (83 %)#015Writing at
0x00028000... (91 %)#015Writing at 0x0002c000... (100 %)#015Wrote
267568 bytes (195058 compressed) at 0x00000000 in 4.4 seconds
(effective 483.5 kbit/s)...
Dec 30 12:25:43 Legion gnome-shell[18287]: Hash of data verified.
Dec 30 12:25:43 Legion gnome-shell[18287]: Leaving...
Dec 30 12:25:43 Legion gnome-shell[18287]: Hard resetting via RTS pin...
Dec 30 12:25:46 Legion systemd[6301]: tracker-extract.service: Succeeded.
Dec 30 12:26:06 Legion tracker-store[17872]: OK
Dec 30 12:26:06 Legion systemd[6301]: tracker-store.service: Succeeded.
========

This is an integral dump, so you find some lines that are clearly not
related to the CH341. I have several traces of this kind.

>
> Please do send that in a bug in launchpad, where we can more easily track the
> status of the bug.

I find difficult to use launchpad: I do not have a crash report, there
is no reference package for the kernel module. If give me a suggestion
about that I'll be happy to submit the ticket.

>
> > This is the kernel I am using:
> >
> > ===
> > $ uname -r
> > 5.4.0-58-generic
> > ===
> >
> > When I connect the ESP8266 board (a Wemos D1 mini) to the USB there is
> > no activity on the syslog (or dmesg), and the kernel module is not
> > loaded. In fact I do not see the /dev/ttyACM0 device in the /dev
> > directory and no useful device appears in the Arduino GUI.
> >
> > I have found the module in the kernel tree but, even forcing the
> > installation, nothing happens:
> >
> > ===
> > augusto at Legion:~$ ls
> > /usr/lib/modules/5.4.0-58-generic/kernel/drivers/usb/serial/ch*
> > /usr/lib/modules/5.4.0-58-generic/kernel/drivers/usb/serial/ch341.ko
> > augusto at Legion:~$ sudo modprobe ch341
> > [sudo] password di augusto:
> > augusto at Legion:~$ lsusb
> > Bus 002 Device 002: ID 05e3:0626 Genesys Logic, Inc. USB3.1 Hub
> > Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
> > Bus 001 Device 003: ID 13d3:56a6 IMC Networks Integrated Camera
> > Bus 001 Device 005: ID 0cf3:e500 Qualcomm Atheros Communications
> > Bus 001 Device 006: ID 046d:c517 Logitech, Inc. LX710 Cordless Desktop Laser
> > Bus 001 Device 004: ID 093a:2510 Pixart Imaging, Inc. Optical Mouse
> > Bus 001 Device 002: ID 05e3:0610 Genesys Logic, Inc. 4-port hub
> > Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
>
> The device does not seem present, does it? So, I wonder if this is plugged in a
> hub, and the hub code is broken, not the serial driver. Otherwise, which one of
> these is the device you are trying to match?

The device is directly plugged in the PC, suspect a USB v3. The device
does not appear in the lsusb: this is the name of problem :-)

>
> > augusto at Legion:~$ lsmod | grep ch34
> > ch341                  20480  0
> > usbserial              53248  1 ch341
> > ===
> >
> > Without this module it is impossible to work with a relevant number of
> > SBC devices, besides the named Wemos D1 Mini.
> >
> > Trying to solve the problem I also downloaded and installed the module
> > source from https://github.com/juliagoda/CH341SER and compiled on my
> > PC, after removing the "secure boot" feature.
> >
>
> You didn't say it, but I assume it didn't work either. Is that correct?

Yes. In both cases the manual modprobe works, but the device is not recognized.

>
> Thanks.
> Cascardo.
>
> > Thank you for any help.
> >
> > Note: I originally posted this question on AskUbuntu
> > (https://askubuntu.com/questions/1304116/problem-with-the-ch341-driver-in-ubuntu-20-04),
> > but with no answer after 40+ views. I bounced to the
> > linux-usb at vger.kernel.org maillist which suggested submitting the
> > problem to the Ubuntu kernel team. Here I am...
> >
> > --
> > kernel-team mailing list
> > kernel-team at lists.ubuntu.com
> > https://lists.ubuntu.com/mailman/listinfo/kernel-team