QHY device IDs and udev rule fxload error

deletio · August 26, 2023, 7:56am

I could not get my QHY cameras detected by the system (fresh install of Rapberry Pi OS + manually built indi + libqhy + indi-qhy). lsusb was showing the camera’s ID but no vendor or product ID like this:

Bus 001 Device 020: ID 1618:0920
Syslog was showing the following message whenever I’d plug the camera in:

systemd-udevd[2166]: 1-1.2.4.2:1.0: Process '/sbin/fxload -t fx2 -I /lib/firmware/qhy/QHY5II.HEX -D ' failed with exit code 1

Trying to execute that command manually quickly revealed that /sbin/fxload was missing, while the fxload package itself was listed as installed:

$ apt list fxload 2>&1 | grep installed fxload/oldstable,now 0.0.20081013-1+b2 arm64 [installed]
So that is the first strange thing.

Reinstalling the package had an immediate effect of getting the camera recognized:

Bus 001 Device 020: ID 1618:0921 QHY-CCD   QHY5-II

This is very much the same experience as what people reported here and here.

I wonder why the device ID has changed from 0920 to 0921.

Syslog at this point looks as following:

Aug 26 16:22:14 0-astropi kernel: [ 2990.663493] usb 1-1.2.4.2: new high-speed USB device number 27 using xhci_hcd Aug 26 16:22:14 0-astropi kernel: [ 2990.763915] usb 1-1.2.4.2: New USB device found, idVendor=1618, idProduct=0920, bcdDevice= 0.00 Aug 26 16:22:14 0-astropi kernel: [ 2990.763946] usb 1-1.2.4.2: New USB device strings: Mfr=0, Product=0, SerialNumber=0 Aug 26 16:22:14 0-astropi mtp-probe: checking bus 1, device 27: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.4/1-1.2.4.2" Aug 26 16:22:14 0-astropi mtp-probe: bus: 1, device: 27 was not an MTP device Aug 26 16:22:14 0-astropi systemd-udevd[2316]: 1-1.2.4.2:1.0: Process '/sbin/fxload -t fx2 -I /lib/firmware/qhy/QHY5II.HEX -D ' failed with exit code 255. Aug 26 16:22:14 0-astropi mtp-probe: checking bus 1, device 27: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.4/1-1.2.4.2" Aug 26 16:22:14 0-astropi mtp-probe: bus: 1, device: 27 was not an MTP device Aug 26 16:22:14 0-astropi kernel: [ 2990.954182] usb 1-1.2.4.2: USB disconnect, device number 27 Aug 26 16:22:16 0-astropi kernel: [ 2992.711517] usb 1-1.2.4.2: new high-speed USB device number 28 using xhci_hcd Aug 26 16:22:16 0-astropi kernel: [ 2992.811988] usb 1-1.2.4.2: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 64 Aug 26 16:22:16 0-astropi kernel: [ 2992.812023] usb 1-1.2.4.2: config 1 interface 0 altsetting 0 bulk endpoint 0x1 has invalid maxpacket 64 Aug 26 16:22:16 0-astropi kernel: [ 2992.812454] usb 1-1.2.4.2: New USB device found, idVendor=1618, idProduct=0921, bcdDevice= 0.00 Aug 26 16:22:16 0-astropi kernel: [ 2992.812475] usb 1-1.2.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Aug 26 16:22:16 0-astropi kernel: [ 2992.812491] usb 1-1.2.4.2: Product: QHY5-II Aug 26 16:22:16 0-astropi kernel: [ 2992.812506] usb 1-1.2.4.2: Manufacturer: QHY-CCD Aug 26 16:22:16 0-astropi mtp-probe: checking bus 1, device 28: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.4/1-1.2.4.2" Aug 26 16:22:16 0-astropi mtp-probe: bus: 1, device: 28 was not an MTP device Aug 26 16:22:16 0-astropi mtp-probe: checking bus 1, device 28: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.4/1-1.2.4.2" Aug 26 16:22:16 0-astropi mtp-probe: bus: 1, device: 28 was not an MTP device

Does this look like it recognizes the device by the original 1618:0920 ID but ends up disconnecting it and reconnecting with the new ID 1618:0921?

A separate question is of the udev rule for the original device ID, which tries to execute fxload and still fails, although not because of fxload missing, but because of missing an argument to the -D parameter.
The rule itself is

ATTRS{idVendor}=="1618", ATTRS{idProduct}=="0920", RUN+="/sbin/fxload -t fx2 -I /lib/firmware/qhy/QHY5II.HEX -D $env{DEVNAME}", so clearly the issue is with $env{DEVNAME}.

As a matter of experiment (not really fully understanding what I am doing) I tried the following:

Adding a copy of this rule for the idProduct 0921 had no effect. Similarly, the device is being first recognized as 0920, then disconnected, then reconnected as 0921, for which udev tries to execute my new rule, but fails in exactly the same way not having $env{DEVNAME} to feed to the -D parameter of fxload.
Removing the RUN+=… part of the rule: after all, the command is anyway failing, so I expected that removing it would not have an effect, but indeed without it the rule is just ignored by udev.
Finally, removing the rule completely threw me back to the very beginning where the camera was not being recognized at all.

Overall it looks like it is necessary to have the rule, but okay to have the fxload fail. Why even have that command in the rule then?

On a side but probably related note: my QHY268m is being recognized by the system as Cypress WestBridge and is not visible by qhy_ccd_test binary.

Aug 26 16:50:42 0-astropi kernel: [ 132.147813] usb 1-1.2.2: USB disconnect, device number 11 Aug 26 16:50:45 0-astropi kernel: [ 134.931139] usb 1-1.2.2: new high-speed USB device number 12 using xhci_hcd Aug 26 16:50:45 0-astropi kernel: [ 135.032079] usb 1-1.2.2: New USB device found, idVendor=1618, idProduct=c268, bcdDevice= 1.00 Aug 26 16:50:45 0-astropi kernel: [ 135.032114] usb 1-1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 26 16:50:45 0-astropi kernel: [ 135.032132] usb 1-1.2.2: Product: WestBridge Aug 26 16:50:45 0-astropi kernel: [ 135.032146] usb 1-1.2.2: Manufacturer: Cypress Aug 26 16:50:45 0-astropi kernel: [ 135.032160] usb 1-1.2.2: SerialNumber: 0000000004BE Aug 26 16:50:45 0-astropi mtp-probe: checking bus 1, device 12: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.2" Aug 26 16:50:45 0-astropi mtp-probe: bus: 1, device: 12 was not an MTP device Aug 26 16:50:45 0-astropi systemd-udevd[1363]: 1-1.2.2: Process '/sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D /dev/bus/usb/001/012' failed with exit code 255. Aug 26 16:50:45 0-astropi systemd-udevd[1363]: 1-1.2.2:1.0: Process '/sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D ' failed with exit code 255. Aug 26 16:50:45 0-astropi mtp-probe: checking bus 1, device 12: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.2" Aug 26 16:50:45 0-astropi mtp-probe: bus: 1, device: 12 was not an MTP device

deletio · August 26, 2023, 8:12am

Just went through a parallel thread and found a post by Norman where he explains that devices are being flashed firmware before being reloaded with updated device IDs.
This sounds like the fxload command is not as useless (as I came to concluding in my post above) after all.

And if I then assume my QHY268m connection issues (still showing as Cypress WestBridge) are due to the firmware not being flashed (fxload failure), it starts looking that udev should after all provide fxload with the correct $env{DEVNAME} value to the -D parameter.

Would anybody have a clue why it may be failing?

Re-building and reinstalling libqhy and indi-qhy did not help.

porkyhttp · August 26, 2023, 8:29am

Look at the /sbin/fxload -t fx3 command, if you have old fxload that not support fx3 the initialization do not occur

porkyhttp · August 26, 2023, 8:34am

$ apt list fxload 2>&1 | grep installed
fxload/oldstable,now 0.0.20081013-1+b2 arm64 [installed]

It seems very old package.
My is this one
apt list fxload 2>&1 | grep installato
fxload/sconosciuto,now 1.0+stable~202302190457 arm64 [installato, automatico]

deletio · August 26, 2023, 9:17am

Thank you Alessandro!

After your comment I went back to indi-3rdparty/indi-qhy/README and saw a comment on fxload together with a link to a repo with an updated version (https://github.com/lhondareyte/fxload).

I removed the old package and built a newer fxload from that repo:

$ fxload -V Aug 26 2003 (development)
Both my cameras are now being correctly recognized, although I still see fxload failure messages:

Aug 26 17:46:21 0-astropi kernel: [ 989.878532] usb 1-1.2.2: USB disconnect, device number 11 Aug 26 17:46:23 0-astropi kernel: [ 992.150838] usb 1-1.2.2: new high-speed USB device number 12 using xhci_hcd Aug 26 17:46:23 0-astropi kernel: [ 992.255823] usb 1-1.2.2: New USB device found, idVendor=1618, idProduct=c268, bcdDevice= 1.00 Aug 26 17:46:23 0-astropi kernel: [ 992.255866] usb 1-1.2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Aug 26 17:46:23 0-astropi kernel: [ 992.255884] usb 1-1.2.2: Product: WestBridge Aug 26 17:46:23 0-astropi kernel: [ 992.255898] usb 1-1.2.2: Manufacturer: Cypress Aug 26 17:46:23 0-astropi kernel: [ 992.255912] usb 1-1.2.2: SerialNumber: 0000000004BE Aug 26 17:46:23 0-astropi mtp-probe: checking bus 1, device 12: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.2" Aug 26 17:46:23 0-astropi mtp-probe: bus: 1, device: 12 was not an MTP device Aug 26 17:46:23 0-astropi systemd-udevd[1803]: 1-1.2.2:1.0: Process '/sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D ' failed with exit code 255. Aug 26 17:46:23 0-astropi mtp-probe: checking bus 1, device 12: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2.2" Aug 26 17:46:23 0-astropi mtp-probe: bus: 1, device: 12 was not an MTP device Aug 26 17:46:23 0-astropi kernel: [ 992.438947] usb 1-1.2.2: USB disconnect, device number 12 Aug 26 17:46:24 0-astropi kernel: [ 993.303018] usb 2-2.2: new SuperSpeed USB device number 6 using xhci_hcd Aug 26 17:46:24 0-astropi kernel: [ 993.323563] usb 2-2.2: LPM exit latency is zeroed, disabling LPM. Aug 26 17:46:24 0-astropi kernel: [ 993.324297] usb 2-2.2: New USB device found, idVendor=1618, idProduct=c269, bcdDevice= 0.00 Aug 26 17:46:24 0-astropi kernel: [ 993.324305] usb 2-2.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Aug 26 17:46:24 0-astropi kernel: [ 993.324311] usb 2-2.2: Product: QHY268C-V230614 Aug 26 17:46:24 0-astropi kernel: [ 993.324316] usb 2-2.2: Manufacturer: QHYCCD

But since the camera is now being recognized, it almost looks like fxload is somehow working behind the scenes. What do you think?

Thank you once again for the nudge in the right direction!

P.S.: Peculiarly, somehow this change made my internal wi-fi interface wlan0 stop seeing my home wi-fi network (2.4G). At least the hotspot (usb wi-fi wlan1) is still working.

porkyhttp · August 26, 2023, 9:32am

Try to execute manually the command /sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D

Also look at the correct path of fxload and firmware folder.
Probably there is a qhyccd.rules that recal this command and path are not correct, for example my fxload is located at usr/bin/fxload.

For the wifi … i do not know how but there could be problems with interferences. When I connect the USB3.0 i lost the GPS fix

deletio · August 26, 2023, 9:45am

It’s complaining specifically about the missing value for the -D argument:

$ /sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D /sbin/fxload: option requires an argument -- 'D'
But the camera works.

Do you not get this problem in the syslog? I wonder if only I’m seeing this artifact.

Agreed about possible interferences. My GPS behaves somewhat as a quantum particle. It works at home, but never in the field (which is a balcony in the next-door building). As you said, just the fix is lost, the messages are received fine, but the LED is not blinking and there is no fix.

porkyhttp · August 26, 2023, 10:21am

sorry, after the -D must be specified the $env{DEVNAME}. Actually I do not remebere how is the format.
I have only MTP related warning but it is normal

deletio · August 26, 2023, 10:44am

That’s exactly the problem. Our udev rules are the same (I believe they come from the indi-3rdparty repo), the one for my camera looks like this:

ATTRS{idVendor}=="1618", ATTRS{idProduct}=="c268", RUN+="/sbin/fxload -t fx3 -I /lib/firmware/qhy/QHY268.img -D $env{DEVNAME}"

and they all have $env{DEVNAME} in the end, for that matter.

However, my syslog shows that apparently those DEVNAME variables somehow end up empty.
(But at the same time the cameras are being initialized fine)

porkyhttp · August 26, 2023, 10:51am

Actually I do not have under my hands my 183M to check what I see, but my camerta works with latest version. I do not rember if the udev rules has been deprecated or not.
The goal is that now you have all working

deletio · August 26, 2023, 11:04am

I’ve checked the output of udevadm monitor --udev --subsystem-match=usb --property as I plugged in the camera and saw step by step what udev was doing.
It looks like in this process of identifying device → connecting it → flashing it → disconnecting it → re-identifying it → re-connecting it the DEVNAME variable is not always set.

Further, I’ve played around with the command to run from udev and added echo $env{DEVNAME} && prefix to fxload.
This was now producing an additional line in syslog: one with the $end{DEVNAME} populated by a correct value, and one where it is empty.

So after all it just looks like fxload is basically silent when everything is alright it has no problems.
It’s just that in the whole tribal dance of recognizing the USB devices via flashing and reconnecting them, the first and critical run of fxload is done silently before the device is reloaded with the new firmware, and then once again it is reloaded but without the DEVNAME populated, and fxload chokes on it producing the syslog error line, but it does not matter as nothing needs to be flashed any more.

OK I think I’ll take it easy at this point and switch to other issues.

Thanks again Alessandro for your participation! Clear skies!