[RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[Lv Ying]

When LD_DEBUG environment variable is set except "unused" value, symbol lookup error
in _dl_lookup_symbol_x will output unrelated debugging information which mess up the
"files" "libs" "reloc" log.

"undefined symbol" debugging information should only output when LD_DEBUG="symbols|all".
---
 elf/dl-lookup.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/elf/dl-lookup.c b/elf/dl-lookup.c
index 4c86dc694e..6085c6c90c 100644
--- a/elf/dl-lookup.c
+++ b/elf/dl-lookup.c
@@ -781,7 +781,7 @@ _dl_lookup_symbol_x (const char *undef_name, struct link_map *undef_map,
   if (__glibc_unlikely (current_value.s == NULL))
     {
       if ((*ref == NULL || ELFW(ST_BIND) ((*ref)->st_info) != STB_WEAK)
-	  && !(GLRO(dl_debug_mask) & DL_DEBUG_UNUSED))
+	  && (GLRO(dl_debug_mask) & DL_DEBUG_SYMBOLS))
 	{
 	  /* We could find no value for a strong reference.  */
 	  const char *reference_name = undef_map ? undef_map->l_name : "";
-- 
2.27.0

Re: [RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[Florian Weimer]

* Lv Ying:

> When LD_DEBUG environment variable is set except "unused" value, symbol lookup error
> in _dl_lookup_symbol_x will output unrelated debugging information which mess up the
> "files" "libs" "reloc" log.
>
> "undefined symbol" debugging information should only output when LD_DEBUG="symbols|all".
> ---
>  elf/dl-lookup.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/elf/dl-lookup.c b/elf/dl-lookup.c
> index 4c86dc694e..6085c6c90c 100644
> --- a/elf/dl-lookup.c
> +++ b/elf/dl-lookup.c
> @@ -781,7 +781,7 @@ _dl_lookup_symbol_x (const char *undef_name, struct link_map *undef_map,
>    if (__glibc_unlikely (current_value.s == NULL))
>      {
>        if ((*ref == NULL || ELFW(ST_BIND) ((*ref)->st_info) != STB_WEAK)
> -	  && !(GLRO(dl_debug_mask) & DL_DEBUG_UNUSED))
> +	  && (GLRO(dl_debug_mask) & DL_DEBUG_SYMBOLS))
>  	{
>  	  /* We could find no value for a strong reference.  */
>  	  const char *reference_name = undef_map ? undef_map->l_name : "";

The current code looks like this:

      if ((*ref == NULL || ELFW(ST_BIND) ((*ref)->st_info) != STB_WEAK)
	  && !(GLRO(dl_debug_mask) & DL_DEBUG_UNUSED))
	{
	  /* We could find no value for a strong reference.  */
	  const char *reference_name = undef_map ? undef_map->l_name : "";
	  const char *versionstr = version ? ", version " : "";
	  const char *versionname = (version && version->name
				     ? version->name : "");
	  struct dl_exception exception;
	  /* XXX We cannot translate the message.  */
	  _dl_exception_create_format
	    (&exception, DSO_FILENAME (reference_name),
	     "undefined symbol: %s%s%s",
	     undef_name, versionstr, versionname);
	  _dl_signal_cexception (0, &exception, N_("symbol lookup error"));
	  _dl_exception_free (&exception);
	}

I think in general, we want to signal an exception here, and we can't
mask that except in debug mode because it does not result in the right
behavior.

Do you have a reproducer that shows what you want to fix?

Thanks,
Florian

Re: [RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[Lv Ying]

Hi, Florian.
Sorry to reply you too late, and thanks for your reply. I took some time to reproduce this problem.
And I resend this email again to cc libc-alpha@sourceware.org.

> Do you have a reproducer that shows what you want to fix?
Yes, here is the reproduce processing:
I want to get shrared object library search paths in openEuler 22.03(https://ftp.belnet.be/mirror/openeuler/openEuler-22.03-LTS/):


# export LD_DEBUG=libs
# whoami
     40503:    find library=libc.so.6 [0]; searching
     40503:     search cache=/etc/ld.so.cache
     40503:      trying file=/usr/lib64/libc.so.6
     40503:   
     40503:   
     40503:    calling init: /lib64/ld-linux-x86-64.so.2
     40503:   
     40503:   
     40503:    calling init: /usr/lib64/libc.so.6
     40503:   
     40503:   
     40503:    initialize program: whoami
     40503:   
     40503:   
     40503:    transferring control: whoami
     40503:   
     40503:    find library=libnss_sss.so.2 [0]; searching
     40503:     search cache=/etc/ld.so.cache
     40503:      trying file=/usr/lib64/libnss_sss.so.2
     40503:   
     40503:   
     40503:    calling init: /usr/lib64/libnss_sss.so.2
     40503:   
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endaliasent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endetherent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endprotoent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endrpcent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endsgent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endspent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getaliasbyname_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getaliasent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getcanonname_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getetherent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_gethostbyaddr2_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_gethostbyname3_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_gethostbyname4_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_gethostton_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getntohost_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getprotobyname_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getprotobynumber_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getprotoent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getpublickey (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getrpcbyname_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getrpcbynumber_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getrpcent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getsecretkey (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getsgent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getsgnam_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getspent_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_getspnam_r (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_netname2user (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setaliasent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setetherent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setprotoent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setrpcent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setsgent (fatal)
     40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_setspent (fatal)
root


As ld.so man page(https://man7.org/linux/man-pages/man8/ld-linux.so.8.html) said, LD_DEBUG=libs, only display library search paths.
"symbol lookup error" debug info message should not mess the debuginfo.
Because there are LD_DEBUG=reloc and LD_DEBUG=all to display relocation processing.

 

> The current code looks like this:
>
>       if ((*ref == NULL || ELFW(ST_BIND) ((*ref)->st_info) != STB_WEAK)
> 	  && !(GLRO(dl_debug_mask) & DL_DEBUG_UNUSED))
> 	{
> 	  /* We could find no value for a strong reference.  */
> 	  const char *reference_name = undef_map ? undef_map->l_name : "";
> 	  const char *versionstr = version ? ", version " : "";
> 	  const char *versionname = (version && version->name
> 				     ? version->name : "");
> 	  struct dl_exception exception;
> 	  /* XXX We cannot translate the message.  */
> 	  _dl_exception_create_format
> 	    (&exception, DSO_FILENAME (reference_name),
> 	     "undefined symbol: %s%s%s",
> 	     undef_name, versionstr, versionname);
> 	  _dl_signal_cexception (0, &exception, N_("symbol lookup error"));
> 	  _dl_exception_free (&exception);
> 	}
>
> I think in general, we want to signal an exception here, and we can't
> mask that except in debug mode because it does not result in the right
> behavior.

As the above said, we do not mask that, we only display the exception in the corresponding
reloc LD_DEBUG mode.

Thanks
Lv Ying

Re: [RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[Florian Weimer]

* Lv Ying:

> Hi, Florian.
> Sorry to reply you too late, and thanks for your reply. I took some time to reproduce this problem.
> And I resend this email again to cc libc-alpha@sourceware.org.
>
>> Do you have a reproducer that shows what you want to fix?
> Yes, here is the reproduce processing:
> I want to get shrared object library search paths in openEuler 22.03(https://ftp.belnet.be/mirror/openeuler/openEuler-22.03-LTS/):
>
>
> # export LD_DEBUG=libs
> # whoami
>      40503:    find library=libc.so.6 [0]; searching
>      40503:     search cache=/etc/ld.so.cache
>      40503:      trying file=/usr/lib64/libc.so.6
>      40503:   
>      40503:   
>      40503:    calling init: /lib64/ld-linux-x86-64.so.2
>      40503:   
>      40503:   
>      40503:    calling init: /usr/lib64/libc.so.6
>      40503:   
>      40503:   
>      40503:    initialize program: whoami
>      40503:   
>      40503:   
>      40503:    transferring control: whoami
>      40503:   
>      40503:    find library=libnss_sss.so.2 [0]; searching
>      40503:     search cache=/etc/ld.so.cache
>      40503:      trying file=/usr/lib64/libnss_sss.so.2
>      40503:   
>      40503:   
>      40503:    calling init: /usr/lib64/libnss_sss.so.2
>      40503:   
>      40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endaliasent (fatal)
>      40503:    /usr/lib64/libnss_sss.so.2: error: symbol lookup error: undefined symbol: _nss_sss_endetherent (fatal)

I see.  If we want to make the change, we would have to tweak
_dl_signal_cexception, not remove the call to it.  But I'm not sure if
this kind of change would be appropriate for "libs".  Maybe we can add a
new LD_DEBUG variant that prints more useful information.

In my experience, ld.so trace output isn't that helpful today for
discovering root causes of real issues, so I'd welcome concrete
proposals for improvements.

Thanks,
Florian

Re: [RFC] elf: fine-grained output LD_DEBUG log when symbol lookup error

[Lv Ying]

Hi Florian:

Thanks again for your reply, I should express clearly the reason for this modification.


> I see.  If we want to make the change, we would have to tweak
> _dl_signal_cexception, not remove the call to it.  But I'm not sure if
> this kind of change would be appropriate for "libs".  Maybe we can add a
> new LD_DEBUG variant that prints more useful information.
This patch does not remove the call to it, just call it when LD_DEBUG=symbols or LD_DEBUG=all,
because the exception message belongs to the symbol lookup process. This patch is inspired by
commit ff9f1c5f324(Fix DL_DEBUG_UNUSED to elide the VDSO and handle PLT references properly.),
As this commit msg said:

elf/dl-lookup (_dl_lookup_symbol_x): If DL_DEBUG_UNUSED, ignore undefined symbol errors.
Before this commit, the undefined symbol error will output if LD_DEBUG is set any value（except statistics）.
This commit believes that when LD_DEBUG is set to DL_DEBUG_UNUSED, there is no need to report
undefined symbol errors. Similarly, LD_DEBUG environment variable may support more settings in the future.
These settings may have the same considerations as DL_DEBUG_UNUSED, therefore, based on scalability considerations,
refined output of debug info, that is, LD_DEBUG=symbols/all output these debug info.
> In my experience, ld.so trace output isn't that helpful today for
> discovering root causes of real issues, so I'd welcome concrete
> proposals for improvements.
Florian, thank you for the experience you shared. As a newbie, this trace output is very helpful for me to understand the ld.so processing.
Please consider my proposal.


Thanks again!
Lv Ying