Bug 2055504 - Set gutenprint53+usb backend to use the default USB context
Summary: Set gutenprint53+usb backend to use the default USB context
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: gutenprint
Version: 35
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Zdenek Dohnal
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 2055871 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-02-17 06:27 UTC by Matt Fagnani
Modified: 2022-04-05 15:43 UTC (History)
14 users (show)

Fixed In Version: gutenprint-5.3.4-8.fc36 gutenprint-5.3.4-8.fc34 gutenprint-5.3.4-8.fc35
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-04-05 00:15:55 UTC
Type: Bug


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github libusb libusb pull 1073 0 None open Fix late transfer free's 2022-02-18 07:51:48 UTC

Description Matt Fagnani 2022-02-17 06:27:02 UTC
Description of problem:

I was using Plasma 5.23.5 on Wayland in a Fedora 35 KDE Plasma installation. I attached an hp psc 1200 printer by USB to an hp laptop. Errors like "python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable" occurred in the journal. 

Feb 17 00:55:35 kernel: usb 2-4: new full-speed USB device number 4 using xhci_hcd
Feb 17 00:55:35 kernel: usb 2-4: New USB device found, idVendor=03f0, idProduct=2f11, bcdDevice= 1.00
Feb 17 00:55:35 kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Feb 17 00:55:35 kernel: usb 2-4: Product: psc 1200 series
Feb 17 00:55:35 kernel: usb 2-4: Manufacturer: Hewlett-Packard
Feb 17 00:55:35 kernel: usb 2-4: SerialNumber: MY3CHG83TW5H
Feb 17 00:55:35 root[8396]: loading HP Device 002 004
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2185: [8397] hpmud_make_usb_uri() bus=002 dev=004
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2232: invalid product id string ret=-4
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2237: invalid serial id string ret=-4
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2104: invalid product id string ret=-4
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2109: invalid serial id string ret=-4
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:36 python3[8397]: io/hpmud/musb.c 2114: invalid manufacturer string ret=-4
Feb 17 00:55:36 hp-config_usb_printer[8397]: hp-config_usb_printer[8397]: error: This is not a valid device
Feb 17 00:55:36 systemd[5417]: Reached target Printer.
Feb 17 00:55:36 systemd[1]: Created slice Slice /system/configure-printer.
Feb 17 00:55:36 systemd[1]: Reached target Printer Support.
Feb 17 00:55:36 systemd[1]: Started Configure Plugged-In Printer.
Feb 17 00:55:36 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=configure-printer@usb-002-004 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 17 00:55:36 kernel: usblp 2-4:1.1: usblp0: USB Bidirectional printer dev 4 if 1 alt 0 proto 2 vid 0x03F0 pid 0x2F11
Feb 17 00:55:36 kernel: usbcore: registered new interface driver usblp
Feb 17 00:55:36 udev-configure-printer[8402]: add usb-002-004
Feb 17 00:55:36 udev-configure-printer[8402]: device devpath is /devices/pci0000:00/0000:00:10.0/usb2/2-4
Feb 17 00:55:36 udev-configure-printer[8402]: MFG:Hewlett-Packard MDL:psc 1200 series SERN:MY3CHG83TW5H serial:MY3CHG83TW5H
Feb 17 00:55:41 cupsd[938]: REQUEST localhost - - "POST / HTTP/1.1" 401 244 CUPS-Get-Devices successful-ok
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 2104: invalid product id string ret=-4
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 2109: invalid serial id string ret=-4
Feb 17 00:55:41 audit[8408]: ANOM_ABEND auid=4294967295 uid=0 gid=7 ses=4294967295 subj=system_u:system_r:cupsd_t:s0-s0:c0.c1023 pid=8408 comm="gutenprint53+us" exe="/usr/lib/cups/backend/gutenprint53+usb" sig=11 res=1
Feb 17 00:55:41 kernel: gutenprint53+us[8408]: segfault at 38 ip 00007f983cb2fe24 sp 00007ffd494f5fb8 error 4 in libc.so.6[7f983cacb000+176000]
Feb 17 00:55:41 kernel: Code: 8d 0d f0 53 13 00 ba 4e 02 00 00 48 8d 35 01 d2 12 00 48 8d 3d 25 d2 12 00 e8 38 a5 fa ff e8 d3 02 09 00 0f 1f 00 f3 0f 1e fa <8b> 47 10 89 c2 81 e2 7f 01 00 00 90 83 e0 7c 0f 85 a7 00 00 00 53
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 hp[8405]: io/hpmud/musb.c 2114: invalid manufacturer string ret=-4
Feb 17 00:55:41 systemd[1]: Created slice Slice /system/systemd-coredump.
Feb 17 00:55:41 audit: BPF prog-id=55 op=LOAD
Feb 17 00:55:41 audit: BPF prog-id=56 op=LOAD
Feb 17 00:55:41 audit: BPF prog-id=57 op=LOAD
Feb 17 00:55:41 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@0-8418-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 17 00:55:41 systemd[1]: Started Process Core Dump (PID 8418/UID 0).
Feb 17 00:55:41 kernel: usblp0: removed
Feb 17 00:55:41 kernel: usblp 2-4:1.1: usblp0: USB Bidirectional printer dev 4 if 1 alt 0 proto 2 vid 0x03F0 pid 0x2F11
Feb 17 00:55:41 kernel: "filter_IN_drop_DROP: "IN=enp1s0 OUT= MAC= SRC=fe80:0000:0000:0000:265c:5b24:c7aa:102b DST=ff02:0000:0000:0000:0000:0000:0000:00fb LEN=93 TC=0 HOPLIMIT=255 FLOWLBL=827613 PROTO=UDP SPT=5353 DPT=5353 LEN=53 
Feb 17 00:55:41 kernel: "filter_IN_drop_DROP: "IN=enp1s0 OUT= MAC= SRC=192.168.2.10 DST=224.0.0.251 LEN=73 TOS=0x00 PREC=0x00 TTL=255 ID=23227 DF PROTO=UDP SPT=5353 DPT=5353 LEN=53 
Feb 17 00:55:41 systemd-coredump[8420]: Process 8408 (gutenprint53+us) of user 0 dumped core.
                                        
                                        Found module /usr/lib/cups/backend/gutenprint53+usb with build-id: 867e27a84e98294daddbf6af083100dde6d7e378
                                        Found module linux-vdso.so.1 with build-id: e9457b6ffb05c1aa01ea1ea1d3b9c93e2ead1ce9
                                        Found module libgcc_s.so.1 with build-id: 0028b8616fa79ea1496e4812c3fc9c7bf9607a56
                                        Found module ld-linux-x86-64.so.2 with build-id: 4e2c368b1240116994daff7f0f248a01f6e53198
                                        Found module libudev.so.1 with build-id: 4a00048d488bd5a48980577f23fcaced551223c3
                                        Found module libc.so.6 with build-id: 881b4882a363c5c193cddf6e4991e1873f593364
                                        Found module libusb-1.0.so.0 with build-id: fa95764702ff10837d5bcaf7cd39ff430c9c761c
                                        Stack trace of thread 8408:
                                        #0  0x00007f983cb2fe24 ___pthread_mutex_lock (libc.so.6 + 0x90e24)
                                        #1  0x00007f983ccb9c59 libusb_get_device_list (libusb-1.0.so.0 + 0xac59)
                                        #2  0x00005623bdd3207e n/a (/usr/lib/cups/backend/gutenprint53+usb + 0x3907e)
Feb 17 00:55:41 cupsd[938]: [cups-deviced] PID 8408 (gutenprint53+usb) crashed on signal 11!
Feb 17 00:55:41 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@0-8418-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 17 00:55:41 systemd[1]: systemd-coredump: Deactivated successfully.
Feb 17 00:55:41 audit: BPF prog-id=0 op=UNLOAD
Feb 17 00:55:41 audit: BPF prog-id=0 op=UNLOAD
Feb 17 00:55:41 audit: BPF prog-id=0 op=UNLOAD
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 2104: invalid product id string ret=-4
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 2109: invalid serial id string ret=-4
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 153: unable get_string_descriptor -4: Resource temporarily unavailable
Feb 17 00:55:41 python3[8413]: io/hpmud/musb.c 2114: invalid manufacturer string ret=-4
Feb 17 00:55:41 cupsd[938]: REQUEST localhost - root "POST / HTTP/1.1" 200 1164 CUPS-Get-Devices -
Feb 17 00:55:41 udev-configure-printer[8402]: no corresponding CUPS device found
Feb 17 00:55:41 systemd[1]: configure-printer: Deactivated successfully.
Feb 17 00:55:41 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=configure-printer@usb-002-004 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 17 00:55:46 plasmashell[5588]: kf.plasma.quick: Couldn't create KWindowShadow for ToolTipDialog(0x55dd50221dc0)
Feb 17 00:55:46 plasmashell[5588]: kf.plasma.quick: Couldn't create KWindowShadow for ToolTipDialog(0x55dd50221dc0)
Feb 17 00:55:46 plasmashell[5588]: kf.plasma.quick: Couldn't create KWindowShadow for ToolTipDialog(0x55dd50221dc0)
Feb 17 00:55:48 abrt-server[8429]: Deleting problem directory ccpp-2022-02-17-00:55:41.958743-8408 (dup of ccpp-2022-02-16-18:47:58.95132-12849)
Feb 17 00:55:48 abrt-notification[8474]: Process 12849 (gutenprint53+usb) crashed in __pthread_mutex_lock.5()

/usr/lib/cups/backend/gutenprint53+usb segmentation faulted in ___pthread_mutex_lock at pthread_mutex_lock.c:76 in glibc-2.34-25.fc35.
mutex=0x28 looked like an invalid pointer.


Core was generated by `gutenprint53+usb'.
Program terminated with signal SIGSEGV, Segmentation fault.

#0  ___pthread_mutex_lock (mutex=mutex@entry=0x28) at pthread_mutex_lock.c:76
76        unsigned int type = PTHREAD_MUTEX_TYPE_ELISION (mutex);
[Current thread is 1 (Thread 0x7f4deb095d40 (LWP 1089))]
(gdb) bt
#0  ___pthread_mutex_lock (mutex=mutex@entry=0x28) at pthread_mutex_lock.c:76
#1  0x00007f4deb024c59 in usbi_mutex_lock (mutex=0x28) at os/threads_posix.h:46
#2  libusb_get_device_list (ctx=0x0, list=0x7fff234ffeb8)
    at /usr/src/debug/libusb1-1.0.25-3.fc35.x86_64/libusb/core.c:837
#3  0x00005581e1d3307e in find_and_enumerate (conn=<optimized out>, 
    num_claim_attempts=<optimized out>, scan_only=<optimized out>, make=<optimized out>, 
    match_serno=<optimized out>, backend=<optimized out>, list=<optimized out>, ctx=<optimized out>)
    at /usr/src/debug/gutenprint-5.3.4-6.fc35.x86_64/src/cups/backend_common.c:780
#4  print_help (argv0=<optimized out>, backend=<optimized out>)
    at /usr/src/debug/gutenprint-5.3.4-6.fc35.x86_64/src/cups/backend_common.c:1075
#5  0x00005581e1d019cb in main (argc=1, argv=0x7fff23500258) 
    at /usr/src/debug/gutenprint-5.3.4-6.fc35.x86_64/src/cups/backend_common.c:1426

PDF files didn't print out from Thunderbird and okular. I also saw these crashes using the Fedora 36 image Fedora-KDE-Live-x86_64-36-20220215.n.0.iso, but the PDFs did print from okular in F36.

Version-Release number of selected component (if applicable):
gutenprint-5.3.4-6.fc35
libusb1-1.0.25-3.fc35
glibc-2.34-25.fc35
hplip-3.21.12-1.fc35.x86_64
cups-2.3.3op2-13.fc35.x86_64
plasma-desktop-5.23.5-1.fc35.x86_64
kf5-plasma-5.90.0-1.fc35.x86_64
qt5-qtbase-5.15.2-30.fc35.x86_64

How reproducible:
gutenprint53+usb crashed each of several times I started the hp printer.

Steps to Reproduce:
1. Boot a Fedora 35 KDE Plasma installation updated to 2022-2-16 with updates-testing enabled.
2. Log in to Plasma 5.23.5 on Wayland
3. attach an hp psc 1200 printer by USB
4. Start the printer


Actual results:
gutenprint53+usb segmentation faulted in ___pthread_mutex_lock when starting a printer attached by USB

Expected results:
No crash would happen. PDF files would print out normally.

Additional info:
cupsd was denied reading the directory faillock repeatedly when I tried to print the PDFs to the same printer as I reported at https://bugzilla.redhat.com/show_bug.cgi?id=2055445 After I allowed that access as setroubleshoot suggested, the gutenprint53+usb crash still happened.

Comment 1 Zdenek Dohnal 2022-02-17 09:00:45 UTC
Hi Matt,

thank you for reporting the issue!

Yes, that 'mutex' looks suspicious - it is taken from libusb library from its default context, so the further investigation can happen there.

I'll reassign the bug to libusb and it would be great if you filed a separate one for your printing issues (for hplip) and put there data from the following steps https://docs.fedoraproject.org/en-US/quick-docs/how-to-debug-printing-problems/#_i_have_hp_printer_installed_it_with_hplip_and_have_a_problem_with_it .

Thank you in advance!

Comment 2 Matt Fagnani 2022-02-17 20:29:04 UTC
(In reply to Zdenek Dohnal from comment #1)
> Hi Matt,
> 
> thank you for reporting the issue!
> 
> Yes, that 'mutex' looks suspicious - it is taken from libusb library from
> its default context, so the further investigation can happen there.
> 
> I'll reassign the bug to libusb and it would be great if you filed a
> separate one for your printing issues (for hplip) and put there data from
> the following steps
> https://docs.fedoraproject.org/en-US/quick-docs/how-to-debug-printing-
> problems/
> #_i_have_hp_printer_installed_it_with_hplip_and_have_a_problem_with_it .
> 
> Thank you in advance!

OK that makes sense. I've reported the hp printer errors against hplip with the cups debug logging enabled journal attached at https://bugzilla.redhat.com/show_bug.cgi?id=2055871 Thanks.

Comment 3 Benjamin Berg 2022-02-18 07:51:48 UTC
Please downgrade libusb1 to version 1.0.24 for now. 1.0.25 had a regression, and my attempt to fix it made things even worse.

Upstream PR for this issue is https://github.com/libusb/libusb/pull/1073

Comment 4 Matt Fagnani 2022-02-19 02:33:15 UTC
(In reply to Benjamin Berg from comment #3)
> Please downgrade libusb1 to version 1.0.24 for now. 1.0.25 had a regression,
> and my attempt to fix it made things even worse.
> 
> Upstream PR for this issue is https://github.com/libusb/libusb/pull/1073

I downgraded to libusb1-1.0.24-4.fc35 and rebooted. I started the printer. There weren't any of the errors or gutenprint53+usb crashes with libusb1-1.0.24-4.fc35. I printed a PDF normally with okular. Thanks.

Comment 5 Sammy 2022-02-20 15:40:58 UTC
Having the exact same problem with HP Deskjet 3050A J611 printer on usb port. Spent an hour trying to figure it out. I was getting the same messages. Downgrading to libusb1 1.0.24-4 also resolved the problem.

Comment 6 Sammy 2022-02-20 19:05:49 UTC
The updated 1073 patch solved the cups/hp problem for me but gutenprint still crashes.

Comment 7 Benjamin Berg 2022-02-20 20:08:02 UTC
Hrm, the mutex thing is a NULL pointer, i.e. no default USB context.

That smells like it is caused by https://github.com/libusb/libusb/commit/32a22069428cda9d63aa666e92fb8882a83d4515

i.e. that gutenprint is first calling libusb_init with an out pointer, but then relying on the default USB context being set and calling libusb_get_device_list with a NULL pointer rather than the context.

Comment 8 Zdenek Dohnal 2022-02-21 05:49:04 UTC
*** Bug 2055871 has been marked as a duplicate of this bug. ***

Comment 9 Benjamin Berg 2022-02-21 10:17:14 UTC
OK, while libusb1 is the reason for the regression, this *is* a gutenprint bug. The below patch should fix this (untested).

Assigning back to gutenprint. But, I am happy to add a conflicts to any new upload I do for libusb1.

diff --git a/cups/backend_common.c b/cups/backend_common.c
index 6333408..95708ee 100644
--- a/cups/backend_common.c
+++ b/cups/backend_common.c
@@ -1008,9 +1008,8 @@ along with this program; if not, see <https://www.gnu.org/licenses/>.\n\n";
        fprintf(logger, "%s", license);
 }
 
-void print_help(const char *argv0, const struct dyesub_backend *backend)
+void print_help(const char *argv0, const struct dyesub_backend *backend, struct libusb_context *ctx)
 {
-       struct libusb_context *ctx = NULL;
        struct libusb_device **list = NULL;
 
        const char *ptr = getenv("BACKEND");
@@ -1423,7 +1422,7 @@ int main (int argc, char **argv)
 
        /* If we don't have a valid backend, print help and terminate */
        if (!backend && !stats_only) {
-               print_help(argv[0], NULL); // probes all devices
+               print_help(argv[0], NULL, ctx); // probes all devices
                ret = CUPS_BACKEND_OK;
                goto done;
        }
@@ -1431,7 +1430,7 @@ int main (int argc, char **argv)
        /* If we're in standalone mode, print help only if no args */
        if ((!uri || !strlen(uri)) && !stats_only) {
                if (argc < 2) {
-                       print_help(argv[0], backend); // probes all devices
+                       print_help(argv[0], backend, ctx); // probes all devices
                        ret = CUPS_BACKEND_OK;
                        goto done;
                }

Comment 10 Zdenek Dohnal 2022-02-21 13:07:05 UTC
(In reply to Benjamin Berg from comment #7)
> Hrm, the mutex thing is a NULL pointer, i.e. no default USB context.
> 

According `usbi_get_context()` [1] you get the default USB context if you pass NULL pointer. Then the context is saved into `ctx` [2]. The broken mutex is acquired by derefencing 'ctx' got from `usbi_get_context()` which is passed into `usbi_mutex_lock()` [3] which causes the segfault.

So IMHO the cause of crash is a corrupted mutex from default USB context.

However, if I move libusb_init() under the scopes with 'print_help()' (to ensure we don't get a local context, but a default one in `libusb_get_device_list`), the crash happens either way. Seems like getting a default USB context is no longer available... is this intentional?

> That smells like it is caused by
> https://github.com/libusb/libusb/commit/
> 32a22069428cda9d63aa666e92fb8882a83d4515
> 
> i.e. that gutenprint is first calling libusb_init with an out pointer, but
> then relying on the default USB context being set and calling
> libusb_get_device_list with a NULL pointer rather than the context.

That sounds reasonable, but it would be great if libusb rejects requests with ctx==NULL as argument if the default context is no longer accessible.

The previous behavior seemed to be that both contexts - default and libusb_init() generated - worked fine.

[1] https://github.com/libusb/libusb/blob/4622bfcf44db373c53502e3fe873bd611e8332f6/libusb/libusbi.h#L444
[2] https://github.com/libusb/libusb/blob/4622bfcf44db373c53502e3fe873bd611e8332f6/libusb/core.c#L828
[3] https://github.com/libusb/libusb/blob/4622bfcf44db373c53502e3fe873bd611e8332f6/libusb/core.c#L837

I can update the gutenprint code and send it upstream, but it would be great if we knew whether default USB context should work and libusb was fixed appropriately.

Comment 11 Zdenek Dohnal 2022-02-21 13:08:35 UTC
Either way, I'm able to reproduce the crash if I install the broken libusb1 version from bodhi - libusb1-1.0.24-4.fc35.x86_64 works fine.

Comment 12 Benjamin Berg 2022-02-21 13:39:17 UTC
> According `usbi_get_context()` [1] you get the default USB context if you pass NULL pointer. Then the context is saved into `ctx` [2]. The broken mutex is acquired by derefencing 'ctx' got from `usbi_get_context()` which is passed into `usbi_mutex_lock()` [3] which causes the segfault.

Well, the default context is NULL. Then, the pointer (0x28) we are seeing is just the offset into the struct, i.e.:

#1  0x00007f4deb024c59 in usbi_mutex_lock (mutex=0x28) at os/threads_posix.h:46

> However, if I move libusb_init() under the scopes with 'print_help()' (to ensure we don't get a local context, but a default one in `libusb_get_device_list`), the crash happens either way. Seems like getting a default USB context is no longer available... is this intentional?
>
> I can update the gutenprint code and send it upstream, but it would be great if we knew whether default USB context should work and libusb was fixed appropriately.

So, the default USB context is only created/available after calling libusb_init(NULL), and I don't think that happens in the codebase. libusb does not create this default context implicitly!

You could use the default context everywhere by calling libusb_init(NULL)/libusb_exit(NULL). The default context is reference counted, so it is safe to call libusb_init(NULL) multiple times (it should just be balanced with libusb_exit(NULL) calls.

What exactly did you try to do code wise? Maybe it would be easier to just rely on the libusb default context and call libusb_init/libusb_exit with a NULL argument?

Comment 13 Zdenek Dohnal 2022-02-21 14:21:56 UTC
(In reply to Benjamin Berg from comment #12)
> Well, the default context is NULL. Then, the pointer (0x28) we are seeing is
> just the offset into the struct, i.e.:
> 
> #1  0x00007f4deb024c59 in usbi_mutex_lock (mutex=0x28) at
> os/threads_posix.h:46
> 

Ok, my bad, I've read your comment as 'not default USB context', not 'no default USB context', which implied to me the NULL pointer is not from default context.

> > However, if I move libusb_init() under the scopes with 'print_help()' (to ensure we don't get a local context, but a default one in `libusb_get_device_list`), the crash happens either way. Seems like getting a default USB context is no longer available... is this intentional?
> >
> > I can update the gutenprint code and send it upstream, but it would be great if we knew whether default USB context should work and libusb was fixed appropriately.
> 
> So, the default USB context is only created/available after calling
> libusb_init(NULL), and I don't think that happens in the codebase. libusb
> does not create this default context implicitly!

Seems like it did in 1.0.24, since the same gutenprint codebase works there. Was that a bug in 1.0.24?

> 
> You could use the default context everywhere by calling
> libusb_init(NULL)/libusb_exit(NULL). The default context is reference
> counted, so it is safe to call libusb_init(NULL) multiple times (it should
> just be balanced with libusb_exit(NULL) calls.
> 
> What exactly did you try to do code wise? Maybe it would be easier to just
> rely on the libusb default context and call libusb_init/libusb_exit with a
> NULL argument?

I have a brief idea - ctx in 'print_help()' is needed only for device discovery for printing available devices on stdout, ctx in 'main()' does discovery and communication with the devices (opening, sending, receiving, closing...).

'print_help()' is actually used in global macro and its arguments are globals there, so ctx would have to be a global there as well, so I'm thinking whether 'libusb_init(NULL)'/'libusb_exit(NULL)' can be added into 'print_help()' only.

Comment 14 Sammy 2022-02-21 14:32:00 UTC
For the gutenprint patch....there are two more fixes for print_help in backend_common.h.

Comment 15 Sammy 2022-02-21 15:00:46 UTC
With the updated 1073 patch for libusb1 and the corrected gutenprint patch things seem to be ok.

Comment 16 Benjamin Berg 2022-02-21 16:57:32 UTC
> Seems like it did in 1.0.24, since the same gutenprint codebase works there. Was that a bug in 1.0.24?

Kind of. libusb 1.0.24 would set the default context even when initializing a specific one. i.e. backend-common.c:1416

	/* Libusb setup */
	ret = libusb_init(&ctx);

would result in ctx to also be the default libusb context. And, then, the libusb_get_device_list in print_help would just use that default ctx (it always passes NULL there).

To be honest, I think just using a NULL context everywhere is sane, i.e. something like the below patch. There are a number of possible and valid fixes.

Are you able to push an update out before the F36 beta freeze (starts tomorrow, Tue 2022-02-22, 14:00 UTC). In that case, I could push out a new libusb 1.0.25 with the updated upstream patch, and hopefully all this is fixed. If not, I'll probably need to downgrade libusb again.

diff --git a/cups/backend_common.c b/cups/backend_common.c
index 6333408..b19668d 100644
--- a/cups/backend_common.c
+++ b/cups/backend_common.c
@@ -753,8 +753,7 @@ static struct dyesub_backend *backends[] = {
 	NULL,
 };
 
-static int find_and_enumerate(struct libusb_context *ctx,
-			      struct libusb_device ***list,
+static int find_and_enumerate(struct libusb_device ***list,
 			      const struct dyesub_backend *backend,
 			      const char *match_serno,
 			      const char *make,
@@ -777,7 +776,7 @@ static int find_and_enumerate(struct libusb_context *ctx,
 	STATE("+org.gutenprint.searching-for-device\n");
 
 	/* Enumerate and find suitable device */
-	num = libusb_get_device_list(ctx, list);
+	num = libusb_get_device_list(NULL, list);
 
 	/* See if we can actually match on the supplied make! */
 	if (backend && make) {
@@ -1010,7 +1009,6 @@ along with this program; if not, see <https://www.gnu.org/licenses/>.\n\n";
 
 void print_help(const char *argv0, const struct dyesub_backend *backend)
 {
-	struct libusb_context *ctx = NULL;
 	struct libusb_device **list = NULL;
 
 	const char *ptr = getenv("BACKEND");
@@ -1072,7 +1070,7 @@ void print_help(const char *argv0, const struct dyesub_backend *backend)
 	}
 
 	/* Scan for all printers for the specified backend */
-	find_and_enumerate(ctx, &list, backend, NULL, ptr, 1, 1, NULL);
+	find_and_enumerate(&list, backend, NULL, ptr, 1, 1, NULL);
 	libusb_free_device_list(list, 1);
 }
 
@@ -1251,7 +1249,6 @@ done:
 
 int main (int argc, char **argv)
 {
-	struct libusb_context *ctx = NULL;
 	struct libusb_device **list = NULL;
 
 	struct dyesub_backend *backend = NULL;
@@ -1414,7 +1411,7 @@ int main (int argc, char **argv)
 #endif
 
 	/* Libusb setup */
-	ret = libusb_init(&ctx);
+	ret = libusb_init(NULL);
 	if (ret) {
 		ERROR("Failed to initialize libusb (%d)\n", ret);
 		ret = CUPS_BACKEND_RETRY_CURRENT;
@@ -1438,7 +1435,7 @@ int main (int argc, char **argv)
 	}
 
 	/* Enumerate devices */
-	found = find_and_enumerate(ctx, &list, backend, use_serno, backend_str, 0, NUM_CLAIM_ATTEMPTS, &conn);
+	found = find_and_enumerate(&list, backend, use_serno, backend_str, 0, NUM_CLAIM_ATTEMPTS, &conn);
 
 	if (found == -1) {
 		ERROR("Printer open failure (No matching printers found!)\n");
@@ -1572,7 +1569,7 @@ done:
 	if (list)
 		libusb_free_device_list(list, 1);
 
-	libusb_exit(ctx);
+	libusb_exit(NULL);
 
 	return ret;
 }

Comment 17 Zdenek Dohnal 2022-02-22 06:41:49 UTC
(In reply to Benjamin Berg from comment #16)
> Are you able to push an update out before the F36 beta freeze (starts
> tomorrow, Tue 2022-02-22, 14:00 UTC). In that case, I could push out a new
> libusb 1.0.25 with the updated upstream patch, and hopefully all this is
> fixed. If not, I'll probably need to downgrade libusb again.
> 

I'm not gutenprint upstream, so I would like to discuss it with upstream before pushing it into Fedora. Robert, one of the people working in gutenprint upstream, is a Red Hatter, which can speed up the things.

I'll send the patch to upstream via email as well.

Comment 18 Zdenek Dohnal 2022-02-22 06:44:15 UTC
So I would go with 'I'm not going to make it till freeze' for now.

Comment 19 Zdenek Dohnal 2022-02-22 07:02:00 UTC
Sent email to gimp-print-devel.net.

Robert, would you mind helping us here?

It would be great if you could review the patch as Gutenprint upstream - it would be good if we managed to fix it before F35 beta freeze -  Tue 2022-02-22, 14:00 UTC .

Comment 20 Benjamin Berg 2022-02-22 09:09:14 UTC
OK, I'll have a look into writing a patch that effectively reverts parts of upstream commit https://github.com/libusb/libusb/commit/32a22069428cda9d63aa666e92fb8882a83d4515 for F36/F37. That said, I would prefer fixing gutenprint obviously, that patch is quite simple and then we may be able to catch similar regressions elsewhere in beta.

Comment 21 Benjamin Berg 2022-02-22 13:09:39 UTC
OK, https://bodhi.fedoraproject.org/updates/FEDORA-2022-b445cd59eb should get things working again. It should log a warning about the API misuse though.

Comment 22 Robert Krawitz 2022-02-22 16:15:33 UTC
Zdenek, let me take a look, but this isn't my code so I'm going to let the maintainer of that area handle it.  That said, the maintainer of this code is very responsive and I expect that he'll look at it promptly.

Comment 23 Pavel Roskin 2022-02-22 19:04:48 UTC
I installed libusb1-1.0.25-8.fc36.x86_64 on Fedora 35 and rebooted. There are no signs of gutenprint crash in the kernel log. Two USB printers work normally. They were not working with earlier 1.0.25 builds, and gutenprint was crashing.

Comment 24 Sammy 2022-02-22 19:19:04 UTC
I can confirm that on FC35 too. I rebuilt the rpm from source.

Comment 25 Robert Krawitz 2022-02-22 19:42:41 UTC
Per Gutenprint maintainer for this component:

On Tue, Feb 22, 2022 at 07:55:18AM +0100, Zdenek Dohnal wrote:
> there were changes in libusb 1.0.25 which is in Fedora 36 - f.e. default USB
> context is not initialized unless you specifically pass NULL into
> `libusb_init()` - gutenprint53+usb backend actually depended on this hidden
> behavior, because it passes its own context address into `libusb_init()`
> instead of NULL. So the change causes the backend to crash if you run it:

Yikes!  

> According libusb maintainer, Ben Berg, the backend can work with the default
> USB context and he prepared the patch for it (the file is attached). I was
> able to verify the patch fixes the crash, but I don't have a device
> supported by gutenprint itself, so I couldn't do an additional sanity
> testing. The patch looks good to me though.

Will this work for multi-threaded stuff where there could conceivably be 
multiple contexts in use?  That's not being exercised in the current 
gutenprint code but some of the stuff I have cooking will change that.

> Would you mind adding the patch to the project if it looks good for you?

I won't be able to physically test any of this until this coming weekend 
(out of town and while I have remote access everything pertinent is 
turned off) but when I'm back, I'll be able to at least it doesn't 
introduce any regressions on F34 & F35.

Comment 26 Zdenek Dohnal 2022-02-23 08:40:21 UTC
Thanks for letting us know, Pavel and Sammy! So the temporary revert in libusb works, but I will leave the bug opened until there is a fix for gutenprint upstream.

Thank you for looking into it, Robert! I've invited Solomon to join us here as well, once he is able to.

Ben, according the email Solomon plans to introduce multi-threading into gutenprint backend - would the default USB context work or should we use different libusb context there?

Comment 27 Benjamin Berg 2022-02-23 09:25:21 UTC
About multi-threading. libusb itself is thread-safe, so, it depends on what exactly the needs are. Having separate contexts means that you can choose to only process events on one of them at a time. This avoids any issue where one thread is suddenly processing events for another (i.e. it is undefined which thread executes the callbacks for asynchronous transfers).

But, e.g. just doing an enumeration from a different thread using the same context should be completely fine.

Comment 28 Solomon Peachy 2022-03-18 14:59:28 UTC
I didn't have time to properly look into this until today (in the middle of a long trip with very crappy internet access at the moment) but the proposed patch look good.

I had to modify it for application to the git master code, but everything should be good now.

Comment 29 Fedora Update System 2022-03-28 10:35:22 UTC
FEDORA-2022-59c07c5ccf has been submitted as an update to Fedora 36. https://bodhi.fedoraproject.org/updates/FEDORA-2022-59c07c5ccf

Comment 30 Fedora Update System 2022-03-28 10:49:46 UTC
FEDORA-2022-b1570f0952 has been submitted as an update to Fedora 35. https://bodhi.fedoraproject.org/updates/FEDORA-2022-b1570f0952

Comment 31 Fedora Update System 2022-03-28 11:04:36 UTC
FEDORA-2022-22af30e355 has been submitted as an update to Fedora 34. https://bodhi.fedoraproject.org/updates/FEDORA-2022-22af30e355

Comment 32 Fedora Update System 2022-03-29 01:22:43 UTC
FEDORA-2022-59c07c5ccf has been pushed to the Fedora 36 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2022-59c07c5ccf`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2022-59c07c5ccf

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 33 Fedora Update System 2022-03-29 01:31:50 UTC
FEDORA-2022-b1570f0952 has been pushed to the Fedora 35 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2022-b1570f0952`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2022-b1570f0952

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 34 Fedora Update System 2022-03-29 01:39:25 UTC
FEDORA-2022-22af30e355 has been pushed to the Fedora 34 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2022-22af30e355`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2022-22af30e355

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 35 Fedora Update System 2022-04-05 00:15:55 UTC
FEDORA-2022-59c07c5ccf has been pushed to the Fedora 36 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 36 Fedora Update System 2022-04-05 15:27:37 UTC
FEDORA-2022-22af30e355 has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 37 Fedora Update System 2022-04-05 15:43:00 UTC
FEDORA-2022-b1570f0952 has been pushed to the Fedora 35 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.