Fedora Account System
Red Hat Associate
Red Hat Customer
I noticed in Fedora 43 that perl-Image-Sane build-time tests randomly does terminate. So far I reduced it to this command: Install sane-backends and sane-backends-drivers-scanners and execute: $ while true; do scanimage --verbose --device=test --batch-count=2; done Output format is not set, using pnm as a default. Scanning 2 pages, incrementing by 1, numbering from 1 Scanning page 1 scanimage: scanning image of size 157x196 pixels at 8 bits/pixel scanimage: acquiring gray frame scanimage: min/max graylevel value = 255/0 scanimage: read 30772 bytes in total Scanned page 1. (scanner status = 5) Scanning page 2 scanimage: scanning image of size 157x196 pixels at 8 bits/pixel scanimage: acquiring gray frame scanimage: min/max graylevel value = 255/0 scanimage: read 30772 bytes in total Scanned page 2. (scanner status = 5) Batch terminated, 2 pages scanned [...] Output format is not set, using pnm as a default. Scanning 2 pages, incrementing by 1, numbering from 1 Scanning page 1 scanimage: scanning image of size 157x196 pixels at 8 bits/pixel scanimage: acquiring gray frame scanimage: min/max graylevel value = 255/0 scanimage: read 30772 bytes in total Scanned page 1. (scanner status = 5) Scanning page 2 scanimage: scanning image of size 157x196 pixels at 8 bits/pixel scanimage: acquiring gray frame scanimage: min/max graylevel value = 255/0 scanimage: read 30772 bytes in total Scanned page 2. (scanner status = 5) Batch terminated, 2 pages scanned After few iterations the scanimage executable hangs. A debugger shows a hang on a futex in dlclose() when handling an error: (gdb) bt #0 futex_wait (futex_word=0x7f75d4947a08 <_rtld_local+2568>, expected=2, private=0) at ../sysdeps/nptl/futex-internal.h:146 #1 __GI___lll_lock_wait (futex=futex@entry=0x7f75d4947a08 <_rtld_local+2568>, private=0) at lowlevellock.c:49 #2 0x00007f75d468a2d8 in lll_mutex_lock_optimized (mutex=0x7f75d4947a08 <_rtld_local+2568>) at pthread_mutex_lock.c:48 #3 ___pthread_mutex_lock (mutex=0x7f75d4947a08 <_rtld_local+2568>) at pthread_mutex_lock.c:128 #4 0x00007f75d491280d in _dl_close (_map=0x563b83ab6650) at dl-close.c:765 #5 0x00007f75d4911716 in __GI__dl_catch_exception (exception=exception@entry=0x7ffeda6d08d0, operate=0x7f75d49127f0 <_dl_close>, args=0x563b83ab6650) at dl-catch.c:241 #6 0x00007f75d4911869 in _dl_catch_error (objname=0x7ffeda6d0938, errstring=0x7ffeda6d0940, mallocedp=0x7ffeda6d0937, operate=<optimized out>, args=<optimized out>) at dl-catch.c:260 #7 0x00007f75d4682ae3 in _dlerror_run (operate=<optimized out>, args=<optimized out>) at dlerror.c:138 #8 0x00007f75d4682823 in __dlclose (handle=<optimized out>) at dlclose.c:31 #9 0x00007f75d48e7e0a in sane_dll_exit () at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/backend/dll.c:1005 #10 0x00007f75d48e7f19 in sane_exit () at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/backend/dll-s.c:88 #11 0x0000563b76447fd9 in scanimage_exit (status=status@entry=0) at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/frontend/scanimage.c:2004 #12 0x0000563b76444f5d in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/frontend/scanimage.c:2976 I don't say there is no bug in sane-backends sources (because it does not manifest with different options of scanimage), but this hang happens after upgrading glibc from 2.41.9000-15.fc43.x86_64 to 2.41.9000-16.fc43.x86_64. So some change in glibc triggers this error. Could you please look what it is? Tested with sane-backends-1.4.0-2.fc43.x86_64 in Fedora 43 as well as with sane-backends-1.4.0-2.fc42.x86_64 in Fedora 42 where I bisected the glibc release because in Fedora 43 an artificial a new dependency on "glibc >= 2.41.9000-20" in many packages prevents from downgrading glibc.
I also see a different kind of hang: #0 futex_wait (futex_word=0x7f4284000030, expected=2, private=0) at ../sysdeps/nptl/futex-internal.h:146 #1 __GI___lll_lock_wait_private (futex=futex@entry=0x7f4284000030) at lowlevellock.c:34 #2 0x00007f4289cd5c9c in get_free_list () at /usr/src/debug/glibc-2.41.9000-20.fc43.x86_64/malloc/arena.c:709 #3 0x00007f4289cd8c15 in arena_get2 (size=65536, avoid_arena=0x0) at /usr/src/debug/glibc-2.41.9000-20.fc43.x86_64/malloc/arena.c:808 #4 __libc_malloc2 (bytes=65536) at malloc.c:3461 #5 0x00007f42898ef58d in init_picture_buffer (test_device=0x55718c3da150, buffer=0x7f42897e9d50, buffer_size=0x7f42897e9d58) at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/backend/test-picture.c:74 #6 reader_process (test_device=0x55718c3da150, fd=4) at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/backend/test.c:1486 #7 reader_task (data=0x55718c3da150) at /usr/src/debug/sane-backends-1.4.0-2.fc43.x86_64/backend/test.c:1562 #8 0x00007f42898ed711 in local_thread (arg=0x7f4289906120 <td>) at ../sanei/sanei_thread.c:352 #9 0x00007f4289cc8ca4 in start_thread (arg=<optimized out>) at pthread_create.c:448 #10 0x00007f4289d4b62c in __GI___clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78 The other thread at this oint is blocked on a pipe read in sane_test_read, so there should not be any acquired malloc lock. Reviewing the changes in -16, it is not immediately obvious what is causing this.
Bisected to: commit cbfd7988107b27b9ff1d0b57fa2c8f13a932e508 Author: Cupertino Miranda <cupertino.miranda> Date: Fri Jun 13 15:29:59 2025 +0000 malloc: add tcache support for large chunk caching Existing tcache implementation in glibc seems to focus in caching smaller data size allocations, limiting the size of the allocation to 1KB. This patch changes tcache implementation to allow to cache any chunk size allocations. The implementation adds extra bins (linked-lists) which store chunks with different ranges of allocation sizes. Bin selection is done in multiples in powers of 2 and chunks are inserted in growing size ordering within the bin. The last bin contains all other sizes of allocations. This patch although by default preserves the same implementation, limitting caches to 1KB chunks, it now allows to increase the max size for the cached chunks with the tunable glibc.malloc.tcache_max. It also now verifies if chunk was mmapped, in which case __libc_free will not add it to tcache. Reviewed-by: Wilco Dijkstra <Wilco.Dijkstra>
I brought this up on the upstream patch review thread: https://inbox.sourceware.org/libc-alpha/lhusej64u39.fsf@oldenburg.str.redhat.com/
This is not a recent regression, it's just more likely to occur in later glibc releases. My guess is that it's related to pthread_cancel.
Sorry, not a glibc bug. The application turns on asynchronous cancellation and then does all kinds of stuff, including calling malloc: #if defined (__APPLE__) && defined (__MACH__) struct sigaction act; sigemptyset(&(act.sa_mask)); act.sa_flags = 0; act.sa_handler = thread_exit_handler; sigaction( SIGUSR2, &act, 0 ); #else int old; pthread_setcancelstate( PTHREAD_CANCEL_ENABLE, &old ); pthread_setcanceltype ( PTHREAD_CANCEL_ASYNCHRONOUS, &old ); #endif DBG( 2, "thread started, calling func() now...\n" ); status = ltd->func( ltd->func_data ); Cancellation is set to asynchronous mode: (gdb) break pthread_setcanceltype Function "pthread_setcanceltype" not defined. Make breakpoint pending on future shared library load? (y or [n]) y Breakpoint 1 (pthread_setcanceltype) pending. (gdb) r Starting program: /usr/bin/scanimage --verbose --device=test --batch-count=2 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib64/libthread_db.so.1". Output format is not set, using pnm as a default. Scanning 2 pages, incrementing by 1, numbering from 1 Scanning page 1 [New Thread 0x7ffff785c6c0 (LWP 943604)] [Switching to Thread 0x7ffff785c6c0 (LWP 943604)] Thread 2 "scanimage" hit Breakpoint 1, __GI___pthread_setcanceltype (type=type@entry=1, oldtype=oldtype@entry=0x7ffff785be44) at pthread_setcanceltype.c:25 25 { (gdb) up #1 0x00007ffff795f6f8 in local_thread (arg=0x7ffff7978120 <td>) at ../sanei/sanei_thread.c:347 347 pthread_setcanceltype ( PTHREAD_CANCEL_ASYNCHRONOUS, &old ); Let see if we call malloc from this thread that has enabled asynchronous cancellation: (gdb) set scheduler-locking on (gdb) break malloc Breakpoint 2 at 0x7ffff7d3fd50: malloc. (11 locations) (gdb) c Continuing. Thread 2 "scanimage" hit Breakpoint 2.1, __GI___libc_malloc (bytes=bytes@entry=65536) at malloc.c:3385 3385 { So there is a call from to malloc from the same thread. We can look at the TCB to check if asynchronous mode is still on (but we did not see a second pthread_setcanceltype call): (gdb) print ((struct pthread *) $fs_base)->cancelhandling $1 = 2 And these are the bitmasks: /* Flags determining processing of cancellation. */ int cancelhandling; /* Bit set if cancellation is disabled. */ #define CANCELSTATE_BIT 0 #define CANCELSTATE_BITMASK (1 << CANCELSTATE_BIT) /* Bit set if asynchronous cancellation mode is selected. */ #define CANCELTYPE_BIT 1 #define CANCELTYPE_BITMASK (1 << CANCELTYPE_BIT) /* Bit set if canceling has been initiated. */ #define CANCELING_BIT 2 #define CANCELING_BITMASK (1 << CANCELING_BIT) /* Bit set if canceled. */ #define CANCELED_BIT 3 #define CANCELED_BITMASK (1 << CANCELED_BIT) /* Bit set if thread is exiting. */ #define EXITING_BIT 4 #define EXITING_BITMASK (1 << EXITING_BIT) /* Bit set if thread terminated and TCB is freed. */ #define TERMINATED_BIT 5 #define TERMINATED_BITMASK (1 << TERMINATED_BIT) /* Bit set if thread is supposed to change XID. */ #define SETXID_BIT 6 #define SETXID_BITMASK (1 << SETXID_BIT) 2 corresponds to CANCELTYPE_BIT or “Bit set if asynchronous cancellation mode is selected.”. According to POSIX, asynchronous cancellation modee is very restricted in which functions you can call, and malloc is not one of the three permitted functions. So this is just an application bug.
The application should just use deferred cancellation to get access to very similar behaviour with the exception that it cannot be cancelled out of tight loops. The application developers should be aware the asynchronous arriving signals behave *as-if* asynchronous cancellation was in effect, so the signal handlers may have to disable cancellation before doing certain operations.
Thanks for the analysis.
Thank you for all your analysis! I will try to switch the cancellation mode for now, and do more testing next week. I can reproduce the issue by command Petr provided.
The patch from https://src.fedoraproject.org/rpms/sane-backends/pull-request/11 fixes the hang at least - going to test further next week.
The tests (measured performance and output) went fine, filed MR upstream https://gitlab.com/sane-project/backends/-/merge_requests/881 .
Fixed as https://bodhi.fedoraproject.org/updates/FEDORA-2025-a418a897ca .