[PATCH v3 1/2] elf(tls): Add debug logging for TLS operations
Adhemerval Zanella Netto
adhemerval.zanella@linaro.org
Tue Feb 3 14:06:04 GMT 2026
On 27/01/26 19:17, Frédéric Bérat wrote:
> This commit introduces extensive debug logging for thread-local storage
> (TLS) operations within the dynamic linker. When `LD_DEBUG=tls` is
> enabled, messages are printed for:
> - TLS module assignment and release.
> - DTV (Dynamic Thread Vector) resizing events.
> - TLS block allocations and deallocations.
> - `__tls_get_addr` slow path events (DTV updates, lazy allocations, and
> static TLS usage).
>
> The log format is standardized to use the calling function name as a
> prefix ("%s: ...") and identifies modules using the "module %lu"
> convention. To aid in debugging multithreaded applications, most logs
> include the Thread Control Block (TCB) address to identify the context
> of the operation.
>
> A new test module `tst-tls-debug-mod.c` and a corresponding shell script
> `tst-tls-debug-recursive.sh` have been added. Additionally, the existing
> `tst-dl-debug-tid` NPTL test has been updated to verify these TLS debug
> messages in a multithreaded context.
> ---
> elf/Makefile | 15 ++++++
> elf/dl-close.c | 6 +++
> elf/dl-tls.c | 94 +++++++++++++++++++++++++++++-----
> elf/rtld.c | 6 +++
> elf/tst-tls-debug-recursive.sh | 61 ++++++++++++++++++++++
> nptl/Makefile | 5 +-
> nptl/tst-dl-debug-tid.c | 13 +++++
> nptl/tst-dl-debug-tid.sh | 21 ++++++++
> nptl/tst-tls-debug-mod.c | 9 ++++
> sysdeps/x86_64/dl-tls.c | 34 ++++++++++--
> 10 files changed, 247 insertions(+), 17 deletions(-)
> create mode 100755 elf/tst-tls-debug-recursive.sh
> create mode 100644 nptl/tst-tls-debug-mod.c
>
> diff --git a/elf/Makefile b/elf/Makefile
> index 01cc51636e..fe1d1847d1 100644
> --- a/elf/Makefile
> +++ b/elf/Makefile
> @@ -3534,3 +3534,18 @@ $(objpfx)tst-origin.out: tst-origin.sh $(objpfx)tst-origin
> $(evaluate-test)
>
> $(objpfx)tst-dlopen-sgid.out: $(objpfx)tst-dlopen-sgid-mod.so
> +
> +
> +ifeq ($(run-built-tests),yes)
> +tests-special += $(objpfx)tst-tls-debug-recursive.out
> +
> +$(objpfx)tst-tls-debug-recursive.out: tst-tls-debug-recursive.sh \
> + $(objpfx)tst-recursive-tls \
> + $(objpfx)tst-recursive-tlsmallocmod.so \
> + $(patsubst %,$(objpfx)tst-recursive-tlsmod%.so, \
> + 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15)
> + $(SHELL) $< $(common-objpfx) '$(test-wrapper-env)' \
> + '$(rtld-prefix)' '$(run_program_env)' \
> + $(objpfx)tst-recursive-tls > $@; \
> + $(evaluate-test)
> +endif
> diff --git a/elf/dl-close.c b/elf/dl-close.c
> index fca877534e..481ff6729d 100644
> --- a/elf/dl-close.c
> +++ b/elf/dl-close.c
> @@ -74,6 +74,12 @@ remove_slotinfo (size_t idx, struct dtv_slotinfo_list *listp, size_t disp,
> if (__glibc_likely (old_map != NULL))
> {
> /* Mark the entry as unused. These can be read concurrently. */
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: modid %lu released from %s [%lu], TCB=0x%lx\n", __func__,
> + (unsigned long int) idx, DSO_FILENAME (old_map->l_name),
> + (unsigned long int) old_map->l_ns,
> + (unsigned long int) THREAD_SELF);
> atomic_store_relaxed (&listp->slotinfo[idx - disp].gen,
> GL(dl_tls_generation) + 1);
> atomic_store_relaxed (&listp->slotinfo[idx - disp].map, NULL);
> diff --git a/elf/dl-tls.c b/elf/dl-tls.c
> index 8cef809261..708a953185 100644
> --- a/elf/dl-tls.c
> +++ b/elf/dl-tls.c
> @@ -220,6 +220,13 @@ _dl_assign_tls_modid (struct link_map *l)
> }
>
> l->l_tls_modid = result;
> +
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu assigned to %s [%lu]\n",
> + __func__,
I think dumping implementation details on logging is a good approach here,
the consumers are not only glibc developers. I would prefer a more descriptive
tag than the function name.
Same for the other __func__ usage in this patch.
> + (unsigned long int) result,
> + DSO_FILENAME (l->l_name),
> + (unsigned long int) l->l_ns);
The Lmid_t is a signed type, so it might be confusing printing it as unsigned.
> }
>
>
> @@ -538,7 +545,7 @@ _dl_allocate_tls_storage (void)
> if (result == NULL)
> free (allocated);
> else if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> - _dl_debug_printf ("TCB allocated: 0x%lx\n", (unsigned long int) result);
> + _dl_debug_printf ("%s: TCB=0x%lx\n", __func__, (unsigned long int) result);
>
> _dl_tls_allocate_end ();
> return result;
> @@ -551,13 +558,19 @@ extern dtv_t _dl_static_dtv[];
> #endif
>
> static dtv_t *
> -_dl_resize_dtv (dtv_t *dtv, size_t max_modid)
> +_dl_resize_dtv (dtv_t *dtv, size_t max_modid, void *tcb)
> {
> /* Resize the dtv. */
> dtv_t *newp;
> size_t newsize = max_modid + DTV_SURPLUS;
> size_t oldsize = dtv[-1].counter;
>
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: DTV resized: oldsize=%lu, newsize=%lu, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) oldsize, (unsigned long int) newsize,
> + (unsigned long int) tcb);
> +
> _dl_tls_allocate_begin ();
> if (dtv == GL(dl_initial_dtv))
> {
> @@ -626,7 +639,7 @@ _dl_allocate_tls_init (void *result, bool main_thread)
> if (dtv[-1].counter < GL(dl_tls_max_dtv_idx))
> {
> /* Resize the dtv. */
> - dtv = _dl_resize_dtv (dtv, GL(dl_tls_max_dtv_idx));
> + dtv = _dl_resize_dtv (dtv, GL(dl_tls_max_dtv_idx), result);
>
> /* Install this new dtv in the thread data structures. */
> INSTALL_DTV (result, &dtv[-1]);
> @@ -717,9 +730,14 @@ rtld_hidden_def (_dl_allocate_tls_init)
> void *
> _dl_allocate_tls (void *mem)
> {
> - return _dl_allocate_tls_init (mem == NULL
> - ? _dl_allocate_tls_storage ()
> - : allocate_dtv (mem), false);
> + void *result = _dl_allocate_tls_init (mem == NULL
> + ? _dl_allocate_tls_storage ()
> + : allocate_dtv (mem), false);
> + if (__glibc_unlikely (result != NULL
> + && (GLRO (dl_debug_mask) & DL_DEBUG_TLS)))
> + _dl_debug_printf ("%s: TLS initialized, TCB=0x%lx\n", __func__,
> + (unsigned long int) result);
> + return result;
> }
> rtld_hidden_def (_dl_allocate_tls)
>
> @@ -728,14 +746,23 @@ void
> _dl_deallocate_tls (void *tcb, bool dealloc_tcb)
> {
> if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> - _dl_debug_printf ("TCB deallocating: 0x%lx (dealloc_tcb=%d)\n",
> - (unsigned long int) tcb, dealloc_tcb);
> + _dl_debug_printf ("%s: TCB=0x%lx, dealloc_tcb=%d\n",
> + __func__, (unsigned long int) tcb, dealloc_tcb);
>
> dtv_t *dtv = GET_DTV (tcb);
>
> /* We need to free the memory allocated for non-static TLS. */
> for (size_t cnt = 0; cnt < dtv[-1].counter; ++cnt)
> - free (dtv[1 + cnt].pointer.to_free);
> + {
> + if (dtv[1 + cnt].pointer.to_free != NULL
> + && __glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: TLS block 0x%lx for modid %lu"
> + " deallocated for TCB=0x%lx\n",
> + __func__, (unsigned long int) dtv[1 + cnt].pointer.to_free,
> + (unsigned long int) (1 + cnt), (unsigned long int) tcb);
> + free (dtv[1 + cnt].pointer.to_free);
> + }
>
> /* The array starts with dtv[-1]. */
> if (dtv != GL(dl_initial_dtv))
> @@ -790,6 +817,13 @@ allocate_and_init (struct link_map *map)
> (map->l_tls_align, map->l_tls_blocksize);
> if (result.val == NULL)
> oom ();
> + else if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: TLS block 0x%lx for modid %lu"
> + " allocated: size=%lu, TCB=0x%lx\n",
> + __func__, (unsigned long int) result.to_free,
> + (unsigned long int) map->l_tls_modid,
> + (unsigned long int) map->l_tls_blocksize,
> + (unsigned long int) THREAD_SELF);
>
> /* Initialize the memory. */
> memset (__mempcpy (result.val, map->l_tls_initimage,
> @@ -891,7 +925,7 @@ _dl_update_slotinfo (unsigned long int req_modid, size_t new_gen)
> continue;
>
> /* Resizing the dtv aborts on failure: bug 16134. */
> - dtv = _dl_resize_dtv (dtv, max_modid);
> + dtv = _dl_resize_dtv (dtv, max_modid, THREAD_SELF);
>
> assert (modid <= dtv[-1].counter);
>
> @@ -912,6 +946,14 @@ _dl_update_slotinfo (unsigned long int req_modid, size_t new_gen)
> least some dynamic TLS usage by interposed mallocs. */
> if (dtv[modid].pointer.to_free != NULL)
> {
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: TLS block 0x%lx for modid %lu"
> + " deallocated during DTV update, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) dtv[modid].pointer.to_free,
> + (unsigned long int) modid,
> + (unsigned long int) THREAD_SELF);
> _dl_tls_allocate_begin ();
> free (dtv[modid].pointer.to_free);
> _dl_tls_allocate_end ();
> @@ -1004,6 +1046,12 @@ tls_get_addr_tail (tls_index *ti, dtv_t *dtv, struct link_map *the_map)
> dtv[ti->ti_module].pointer.to_free = NULL;
> dtv[ti->ti_module].pointer.val = p;
>
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu using static TLS, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) ti->ti_module,
> + (unsigned long int) THREAD_SELF);
> +
> return tls_get_addr_adjust (p, ti);
> }
> else
> @@ -1059,18 +1107,29 @@ __tls_get_addr (tls_index *ti)
> {
> if (_dl_tls_allocate_active ()
> && ti->ti_module < _dl_tls_initial_modid_limit)
> + {
> /* This is a reentrant __tls_get_addr call, but we can
> satisfy it because it's an initially-loaded module ID.
> These TLS slotinfo slots do not change, so the
> out-of-date generation counter does not matter. However,
> if not in a TLS update, still update_get_addr below, to
> get off the slow path eventually. */
> - ;
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu reentrant TLS usage, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) ti->ti_module,
> + (unsigned long int) THREAD_SELF);
> + }
> else
> {
> /* Update DTV up to the global generation, see CONCURRENCY NOTES
> in _dl_update_slotinfo. */
> gen = atomic_load_acquire (&GL(dl_tls_generation));
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: modid %lu update DTV to gen %lu, TCB=0x%lx\n", __func__,
> + (unsigned long int) ti->ti_module, (unsigned long int) gen,
> + (unsigned long int) THREAD_SELF);
> return update_get_addr (ti, gen);
> }
> }
> @@ -1078,7 +1137,14 @@ __tls_get_addr (tls_index *ti)
> void *p = dtv[ti->ti_module].pointer.val;
>
> if (__glibc_unlikely (p == TLS_DTV_UNALLOCATED))
> - return tls_get_addr_tail (ti, dtv, NULL);
> + {
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu lazy allocation, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) ti->ti_module,
> + (unsigned long int) THREAD_SELF);
> + return tls_get_addr_tail (ti, dtv, NULL);
> + }
>
> return tls_get_addr_adjust (p, ti);
> }
> @@ -1149,6 +1215,10 @@ _dl_tls_initial_modid_limit_setup (void)
> break;
> }
> _dl_tls_initial_modid_limit = idx;
> +
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: initial modid limit set to %lu\n",
> + __func__, (unsigned long int) idx);
> }
>
>
> diff --git a/elf/rtld.c b/elf/rtld.c
> index 29e7a4ddfa..457aa9c452 100644
> --- a/elf/rtld.c
> +++ b/elf/rtld.c
> @@ -1192,6 +1192,12 @@ rtld_setup_main_map (struct link_map *main_map)
>
> /* This image gets the ID one. */
> GL(dl_tls_max_dtv_idx) = main_map->l_tls_modid = 1;
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu assigned to %s [%lu]\n",
> + __func__,
> + (unsigned long int) main_map->l_tls_modid,
> + DSO_FILENAME (main_map->l_name),
> + (unsigned long int) main_map->l_ns);
> }
> break;
>
> diff --git a/elf/tst-tls-debug-recursive.sh b/elf/tst-tls-debug-recursive.sh
> new file mode 100755
> index 0000000000..b1d5483f6f
> --- /dev/null
> +++ b/elf/tst-tls-debug-recursive.sh
> @@ -0,0 +1,61 @@
> +#!/bin/sh
Missing copyright header.
> +set -e
> +common_objpfx="$1"
> +test_wrapper_env="$2"
> +rtld_prefix="$3"
> +run_program_env="$4"
> +test_program="$5"
> +
> +debug_output="${common_objpfx}elf/tst-tls-debug-recursive.debug"
> +rm -f "${debug_output}".*
> +
> +# Run the test program with LD_DEBUG=tls.
> +eval "${test_wrapper_env}" LD_DEBUG=tls LD_DEBUG_OUTPUT="${debug_output}" \
> + "${rtld_prefix}" "${test_program}"
> +
> +debug_output=$(ls "${debug_output}".*)
> +
> +fail=0
> +
> +# Check for expected messages
> +if ! grep -q 'DTV resized' "${debug_output}"; then
> + echo "FAIL: DTV resized message not found"
> + fail=1
> +fi
> +
> +if ! grep -q 'modid .* deallocated during DTV update' "${debug_output}"; then
> + echo "FAIL: module deallocated during DTV update message not found"
> + fail=1
> +fi
> +
> +if ! grep -q 'modid .* assigned to' "${debug_output}"; then
> + echo "FAIL: module assigned message not found"
> + fail=1
> +fi
> +
> +if ! grep -q 'modid .* allocated' "${debug_output}"; then
> + echo "FAIL: module allocated message not found"
> + fail=1
> +fi
> +
> +if ! grep -q 'update DTV to gen' "${debug_output}"; then
> + echo "FAIL: update DTV message not found"
> + fail=1
> +fi
> +
> +if ! grep -q 'initial modid limit set to' "${debug_output}"; then
> + echo "FAIL: initial modid limit message not found"
> + fail=1
> +fi
> +
> +if [ $fail -ne 0 ]; then
> + echo "Test FAILED"
> + cat "${debug_output}"
> + rm -f "${debug_output}"
> + exit 1
> +fi
> +
> +echo "Test PASSED"
> +cat "${debug_output}"
> +rm -f "${debug_output}"
> +exit 0
> diff --git a/nptl/Makefile b/nptl/Makefile
> index 08b8ba8a31..85f95dd0cf 100644
> --- a/nptl/Makefile
> +++ b/nptl/Makefile
> @@ -266,6 +266,7 @@ CFLAGS-tst-thread-exit-clobber.o = -std=gnu++11
> LDLIBS-tst-thread-exit-clobber = -lstdc++
> CFLAGS-tst-minstack-throw.o = -std=gnu++11
> LDLIBS-tst-minstack-throw = -lstdc++
> +LDLIBS-tst-dl-debug-tid = $(libdl)
>
> tests = \
> tst-attr2 \
> @@ -485,6 +486,7 @@ modules-names = \
> tst-audit-threads-mod2 \
> tst-compat-forwarder-mod \
> tst-stack4mod \
> + tst-tls-debug-mod \
> tst-tls3mod \
> tst-tls5mod \
> tst-tls5moda \
> @@ -710,7 +712,8 @@ tst-stackguard1-ARGS = --command "$(host-test-program-cmd) --child"
> tst-stackguard1-static-ARGS = --command "$(objpfx)tst-stackguard1-static --child"
>
> ifeq ($(run-built-tests),yes)
> -$(objpfx)tst-dl-debug-tid.out: tst-dl-debug-tid.sh $(objpfx)tst-dl-debug-tid
> +$(objpfx)tst-dl-debug-tid.out: tst-dl-debug-tid.sh $(objpfx)tst-dl-debug-tid \
> + $(objpfx)tst-tls-debug-mod.so
> $(SHELL) $< $(common-objpfx) '$(test-wrapper-env)' '$(rtld-prefix)' \
> '$(run-program-env)' \
> $(objpfx)tst-dl-debug-tid > $@; $(evaluate-test)
> diff --git a/nptl/tst-dl-debug-tid.c b/nptl/tst-dl-debug-tid.c
> index b530d2170a..faa3b795b5 100644
> --- a/nptl/tst-dl-debug-tid.c
> +++ b/nptl/tst-dl-debug-tid.c
> @@ -27,12 +27,25 @@
> #include <support/xthread.h>
> #include <stdio.h>
> #include <unistd.h>
> +#include <dlfcn.h>
> +#include <support/xdlfcn.h>
> +#include <support/check.h>
>
> static void *
> thread_function (void *arg)
> {
> if (arg)
> pthread_barrier_wait ((pthread_barrier_t *) arg);
> +
> + /* Load a module with TLS to verify allocation/deallocation logs. */
> + void *h = xdlopen ("tst-tls-debug-mod.so", RTLD_NOW);
> +
> + /* Call a function that accesses TLS. */
> + int (*fp) (void) = (int (*) (void)) xdlsym (h, "in_dso");
> + TEST_COMPARE (fp (), 0);
> +
> + xdlclose (h);
> +
> return NULL;
> }
>
> diff --git a/nptl/tst-dl-debug-tid.sh b/nptl/tst-dl-debug-tid.sh
> index 12a4aa2b34..23e826406a 100644
> --- a/nptl/tst-dl-debug-tid.sh
> +++ b/nptl/tst-dl-debug-tid.sh
> @@ -67,5 +67,26 @@ if ! grep -q 'TCB allocated\|TCB deallocating\|TCB reused\|TCB deallocated' \
> exit 1
> fi
>
> +# Check for TLS module ID assignment.
> +if ! grep -q 'modid .* assigned to' "${debug_output}"; then
> + echo "error: Expected 'modid ... assigned to' message not found"
> + cat "${debug_output}"
> + exit 1
> +fi
> +
> +# Check for TLS block allocation.
> +if ! grep -q 'modid .* allocated' "${debug_output}"; then
> + echo "error: Expected 'modid ... allocated' message not found"
> + cat "${debug_output}"
> + exit 1
> +fi
> +
> +# TLS block deallocation might be skipped due to DTV surplus.
> +if grep -q 'modid .* deallocated' "${debug_output}"; then
> + echo "INFO: module deallocated message found"
> +else
> + echo "INFO: module deallocated message not found (may be due to DTV surplus)"
> +fi
> +
> cat "${debug_output}"
> rm -f "${debug_output}"
> diff --git a/nptl/tst-tls-debug-mod.c b/nptl/tst-tls-debug-mod.c
> new file mode 100644
> index 0000000000..99da97592d
> --- /dev/null
> +++ b/nptl/tst-tls-debug-mod.c
> @@ -0,0 +1,9 @@
> +
Missing copyright header.
> +__thread int tls_var __attribute__ ((tls_model ("global-dynamic")));
> +
> +int
> +in_dso (void)
> +{
> + tls_var = 42;
> + return tls_var - 42;
> +}
> diff --git a/sysdeps/x86_64/dl-tls.c b/sysdeps/x86_64/dl-tls.c
> index a1877eeaed..fbeead4f64 100644
> --- a/sysdeps/x86_64/dl-tls.c
> +++ b/sysdeps/x86_64/dl-tls.c
> @@ -41,11 +41,37 @@ __tls_get_addr_slow (tls_index *ti)
> dtv_t *dtv = THREAD_DTV ();
>
> size_t gen = atomic_load_acquire (&GL(dl_tls_generation));
> - if (__glibc_unlikely (dtv[0].counter != gen)
> + if (__glibc_unlikely (dtv[0].counter != gen))
> + {
> /* See comment in __tls_get_addr in elf/dl-tls.c. */
> - && !(_dl_tls_allocate_active ()
> - && ti->ti_module < _dl_tls_initial_modid_limit))
> - return update_get_addr (ti, gen);
> + if (_dl_tls_allocate_active ()
> + && ti->ti_module < _dl_tls_initial_modid_limit)
> + {
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: modid %lu reentrant TLS usage, TCB=0x%lx\n", __func__,
> + (unsigned long int) ti->ti_module,
> + (unsigned long int) THREAD_SELF);
> + }
> + else
> + {
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf (
> + "%s: modid %lu update DTV to gen %lu, TCB=0x%lx\n", __func__,
> + (unsigned long int) ti->ti_module, (unsigned long int) gen,
> + (unsigned long int) THREAD_SELF);
> + return update_get_addr (ti, gen);
> + }
> + }
> +
> + if (__glibc_unlikely (dtv[ti->ti_module].pointer.val == TLS_DTV_UNALLOCATED))
> + {
> + if (__glibc_unlikely (GLRO (dl_debug_mask) & DL_DEBUG_TLS))
> + _dl_debug_printf ("%s: modid %lu lazy allocation, TCB=0x%lx\n",
> + __func__,
> + (unsigned long int) ti->ti_module,
> + (unsigned long int) THREAD_SELF);
> + }
>
> return tls_get_addr_tail (ti, dtv, NULL);
> }
Would be worth to add similar debug info for other ABI specific TLS routines,
like sysdeps/aarch64/libc-tls.c?
And, should we be worried about the performance implications on the extra
branches on the TLS slow path here?
More information about the Libc-alpha
mailing list