Montée de version de Yunohost vers Buster

Cette semaine, j’ai fait la montée de version de Yunohost depuis Stretch vers Buster, sur mon B3.

Tout a commencé quand j’ai reçut des messages de Thunderbird m’informant qu’il refusait de récupérer mon mail à cause d’un problème de certificat SSL échu. Vu que le certificat est fourni par Let’s Encrypt, ça ne présageait rien de bon. Et avant de creuser le problème, j’ai préféré partir sur une montée de version. D’autant que plusieurs semaines après la publication de la montée de version, les problèmes de mise à jour semblaient bien traités.

J’ai donc lancé la commande yunohost tools migrations migrate --accept-disclaimer dans un screen.

Seul point délicat, une clé GPG foireuse sur le dépôt Sury

Imprimante

Mais quelques jours plus tard, je me rend compte qu’une fonction n’est plus au rendez-vous : l’impression. Quand je lui soumet des tâches, elle imprime un gros triangle rectangle noir aux dimensions de la feuille.

Premier réflexe : évacuer le doute d’une coïncidence et vérifier que l’imprimante en elle même fonctionne toujours. Je lui fait donc faire un Self-test avec les boutons Cancel + Color Copy. La page de test est OK. L’imprimante est donc toujours opérationnelle sur le plan matériel.

Un premier temps, j’ai fouillé tous les logs, trouvant des messages qui se sont avérés sans issue.

/var/log/cups/error_log :

D [25/Mar/2021:20:54:27 +0000] [Job 454] PID 25588 (/usr/lib/cups/filter/hpcups) stopped with status 1.
D [25/Mar/2021:20:54:27 +0000] [Job 454] PID 25589 (/usr/lib/cups/backend/usb) exited with no errors.

/var/log/messages :

Mar 25 20:51:08 home kernel: [388977.634243] usblp0: removed
Mar 25 20:51:14 home kernel: [388984.165259] usblp 1-1.2:1.1: usblp0: USB Bidirectional printer dev 5 if 1 alt 0 proto 2 vid 0x03F0 pid 0x6C11

/var/log/syslog :

Mar 25 21:08:21 home kernel: [390010.990090] usblp0: removed
Mar 25 21:08:28 home hpcups[25874]: prnt/hpcups/HPCupsFilter.cpp 568: cupsRasterOpen failed, fd = 0
Mar 25 21:08:28 home kernel: [390017.553466] usblp 1-1.2:1.1: usblp0: USB Bidirectional printer dev 7 if 1 alt 0 proto 2 vid 0x03F0 pid 0x6C11

Avec hplip :

Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:07 home kernel: [391796.565986] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 561: released 7/1/2 interface
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 961: new PRINT channel=2 clientCnt=1 channelCnt=1
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 427: Found interface conf=0, iface=1, altset=0, index=1
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 389: Active kernel driver on interface=1 ret=0
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 535: claimed 7/1/2 interface
Mar 25 21:38:07 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:08 home kernel: [391797.109535] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:09 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:10 home kernel: [391799.109973] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:11 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:12 home kernel: [391801.110617] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:13 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:14 home kernel: [391803.111258] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:15 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:16 home kernel: [391805.111850] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:18 home hp[27016]: io/hpmud/musb.c 781: read actual device_id successfully fd=1 len=271
Mar 25 21:38:18 home kernel: [391807.112487] Did not find alt setting 1 for intf 0, config 1
Mar 25 21:38:18 home hp[27016]: io/hpmud/musb.c 561: released 7/1/2 interface
Mar 25 21:38:18 home hp[27016]: io/hpmud/musb.c 976: removed PRINT channel=2 clientCnt=0 channelCnt=0

Suivant quelques pages, glanées ça et là, j’ai tenté des correctifs

lpadmin -p <printer> -o usb-unidir-default=true

colord-sane: io/hpmud/musb.c 2101: Invalid usb_open: Permission denied

-> sudo usermod -a -G lp colord

Mais sans effet.

La preuve par deux

Je branche donc l’imprimante sur une autre machine (i686) sous Debian buster, j’installe et configure rapidement et… ça fonctionne.

Du coup, ça ne vient clairement pas de l’imprimante (plan matériel), ni des drivers, ni de CUPS… La seule différence semble être l’architecture.

Cupsfilter

Faisant le constat que je n’en savais pas assez, je suis parti en quête de documentation sur le debug des problèmes CUPS.

J’ai donc décomposé avec cupsfilter.

1. le fichier original (hp-setup test page) est un PS
2. en sortie de gstopdf, le PDF semble correct
3. en sortie de pdftopdf, le PDF est altéré : la page est pivotée de 270°
4. en sortie de gstoraster le document est blanc sur une page
5. en sortie de hpcups le document est étrangement léger et semble contenir deux pages

Ghostscript

J’arrive donc à identifier que le coupable se situe sur la commande

gs -dQUIET -dPARANOIDSAFER -dNOPAUSE -dBATCH -dNOINTERPOLATE
-dNOMEDIAATTRS -dShowAcroForm -sstdout=%stderr -sOutputFile=%stdout
-sDEVICE=cups -sMediaType=Automatic -sOutputType=0 -r600x600
-dMediaPosition=7 -dDEVICEWIDTHPOINTS=595 -dDEVICEHEIGHTPOINTS=841
-dcupsMediaType=-1 -dcupsBitsPerColor=8 -dcupsColorOrder=0
-dcupsColorSpace=17 -dcupsInteger0=26 -scupsPageSizeName=A4
-I/usr/share/cups/fonts -c '<</.HWMargins[9.000000 9.000000 9.000000
9.000000] /Margins[0 0]>>setpagedevice' -f -_ < /tmp/input.cups-pdf >
/tmp/output.cups-raster

Je découvre alors le flag -dPDFDEBUG. Et celui-ci rend les choses bien plus rapides à valider. En effet, sous i686 tout semble aller pour le mieux dans le log de debug. Par contre, sur armel, j’obtiens :

...
8.33333 0 0 8.33333 0 0 cm
BT
   **** Error reading a content stream. The page may be incomplete.
               Output may be incorrect.
   **** Error: Form stream has unbalanced q/Q operators (too many q's)
               Output may be incorrect.
Q
Q
   **** Error: File did not complete the page properly and may be damaged.
               Output may be incorrect.
%Resolving: [1 0]

Ce serait donc l’interpreteur PDF qui dysfonctionne sur armel ? Les version de ghostscript sont identiques sur les deux machines : GPL Ghostscript 9.27 (2019-04-04).

J’ouvre donc un bug chez Debian.

Avec un debootstrap en testing, je constate que gs (version 2.53) n’est plus affecté par le problème. Avec un debootstrap en stable, je teste différentes versions du package issues de Debian Snapshots.

• 9.26a~dfsg-0+deb9u7 (stretch) : OK
• 9.26a~dfsg-1 : KO
• 9.26a~dfsg-2 : KO
• 9.27~dfsg-1 : KO
• 9.27~dfsg-2+deb10u4 (buster) : KO

Conclusion

Bon, je crois que je ne peux plus faire grand chose à part attendre un correctif ou une sollicitation du maintainer Debian.

Par contre, j’ai pu constater que je pouvais réinstaller les 3 paquets de ghostscript en version stretch sur buster sans la moindre difficulté. C’est donc ce que je fais pour retrouver ma machine pleinement fonctionnelle.

Références

• https://gist.github.com/maxvt/7b1e32cd28e37a8f8de6cfacae76ae8a

• https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=596475

• https://askubuntu.com/questions/1245202/colord-sane-io-hpmud-musb-c-2101-invalid-usb-open-permission-denied