Debugging dlopen

NevemTeve · 01-29-2020, 11:39 PM

I have found an interesting problem on SO, that includes php, php-ffi, libffi, a large shared object, and results in a message from dlopen:

Code:

Inconsistency detected by ld.so: dl-minimal.c: 136:
realloc: Assertion `ptr == alloc_last_block' failed!

Sure, I don't know what the actual problem is, but I'd like to collect some notes about the possible debugging ideas.
First ideas:

Code:

LD_DEBUG=all php testscript.php

LD_PRELOAD=/usr/lib/libefence.so php testscript.php

LD_DEBUG=all LD_PRELOAD=/usr/lib/libefence.so php testscript.php

gdb --args $(which php) testscript.php
set exec-wrapper env 'LD_PRELOAD=/usr/lib/libefence.so' 'LD_DEBUG=all'

Disclaimer: I'm not the Problem Owner, but could reproduce the error on my computer.

NevemTeve · 01-29-2020, 11:48 PM

First note: my platform is linux/x64 (Debian-8.11; libc version 2.19-18+deb8u10); php-7.4.2 compiled from source (with debug); ffi-3.3 compiled from source (with debug)
ulimit seems to be not-restrictive:

Code:

$ ulimit -S -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 31533
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 65536
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 31533
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Edit: yet another idea:

Code:

LD_DEBUG=all MALLOC_CHECK_=1 php somescript.php

Seems to freeze here:

Code:

(gdb) bt
#0  0x00007f51b4ed9beb in g_hash_table_lookup () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#1  0x00007f51b4efb014 in g_intern_static_string () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#2  0x00007f51b51bb5c0 in ?? () from /usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0
#3  0x00007f51c02c7bea in ?? () from /lib64/ld-linux-x86-64.so.2

it comes from package:

Code:

ii  libglib2.0-0:amd64           2.42.1-1+deb8u3     amd64               GLib library of C routines

Maybe I should try it from source. e.g.: http://ftp.gnome.org/pub/gnome/sourc...-2.58.3.tar.xz

NevemTeve · 01-30-2020, 04:43 AM

Here is where it seems to stop (or loop for ever):

Code:

#0  0x00007f95f64bc0b5 in g_hash_table_lookup_node (hash_table=0x1f82c00, key=0x7f95f67f58d3, hash_return=0x7fff20904598)
    at ghash.c:388
#1  0x00007f95f64bd08e in g_hash_table_lookup (hash_table=0x1f82c00, key=0x7f95f67f58d3) at ghash.c:1153
#2  0x00007f95f64e4e31 in quark_from_string (string=0x7f95f67f58d3 "GInterface", duplicate=0) at gquark.c:182
#3  0x00007f95f64e5072 in quark_intern_string_locked (string=0x7f95f67f58d3 "GInterface", duplicate=0) at gquark.c:313
#4  0x00007f95f64e50db in g_intern_static_string (string=0x7f95f67f58d3 "GInterface") at gquark.c:354
#5  0x00007f95f67e537e in gobject_init () at gtype.c:4408
#6  0x00007f95f67e5436 in gobject_init_ctor () at gtype.c:4488
#7  0x00007f96018c7bea in ?? () from /lib64/ld-linux-x86-64.so.2
#8  0x00007f96018c7cd3 in ?? () from /lib64/ld-linux-x86-64.so.2
#9  0x00007f96018cbe38 in ?? () from /lib64/ld-linux-x86-64.so.2
#10 0x00007f96018c7aa4 in ?? () from /lib64/ld-linux-x86-64.so.2
#11 0x00007f96018cb62b in ?? () from /lib64/ld-linux-x86-64.so.2
#12 0x00007f95ffdaa02b in ?? () from /lib/x86_64-linux-gnu/libdl.so.2
#13 0x00007f96018c7aa4 in ?? () from /lib64/ld-linux-x86-64.so.2
#14 0x00007f95ffdaa5dd in ?? () from /lib/x86_64-linux-gnu/libdl.so.2
#15 0x00007f95ffdaa0c1 in dlopen () from /lib/x86_64-linux-gnu/libdl.so.2
#16 0x000000000057254c in zim_FFI_cdef (execute_data=0x7f95f92130a0, return_value=0x7f95f9213080)
    at /usr/local/src/php-7.4.2/ext/ffi/ffi.c:2847
#17 0x0000000000b67529 in ZEND_DO_FCALL_SPEC_RETVAL_USED_HANDLER () at /usr/local/src/php-7.4.2/Zend/zend_vm_execute.h:1730
#18 execute_ex (ex=0x7f95f9213020) at /usr/local/src/php-7.4.2/Zend/zend_vm_execute.h:53821

I think the linker-loader (/lib64/ld-linux-x86-64.so.2) has just loaded file /usr/local/lib64/libglib-2.0.so, and called its constructor gtype.c:gobject_init_ctor, which calls gobject_init, etc

NevemTeve · 01-30-2020, 05:55 AM

Good news: compiled glib-2.58.3 from source, Mozilla Firefox ceased to work:

Code:

$ /opt/firefox/firefox

(firefox:574): GLib-GObject-CRITICAL **: 12:53:27.553: g_object_ref: assertion 'object->ref_count > 0' failed
ExceptionHandler::GenerateDump cloned child 617
ExceptionHandler::SendContinueSignalToChild sent continue signal to child
ExceptionHandler::WaitForContinueSignal waiting for continue signal...

SoftSprocket · 01-30-2020, 07:36 AM

Have you tried running valgrind?

Code:

valgrind --leak-check=full --track-origins=yes $(which php) testscript.php

NevemTeve · 01-30-2020, 08:05 AM

547	  node = type_node_any_new_W (NULL, ftype, name, NULL, type_flags);
(gdb) next
549

(gdb) print node[0]
$42 = {ref_count = 4115261048, plugin = 0x0, n_children = 0, n_supers = 0, n_prerequisites = 0, is_classed = 0, is_instantiatable = 0, 
  mutatable_check_cache = 0, children = 0x0, data = 0x0, qname = 4, global_gdata = 0x0, _prot = {iface_entries = {data = 0x0}, 
    offsets = {data = 0x0}}, prerequisites = 0x0, supers = {4}}

NevemTeve · 01-30-2020, 08:27 AM

Code:

419	type_node_any_new_W (TypeNode             *pnode,
420			     GType                 ftype,
421			     const gchar          *name,
422			     GTypePlugin          *plugin,
423			     GTypeFundamentalFlags type_flags)
424	{
425	  guint n_supers;
426	  GType type;
427	  TypeNode *node;
428	  guint i, node_size = 0;
429	
430	  n_supers = pnode ? pnode->n_supers + 1 : 0;
431	  
432	  if (!pnode)
433	    node_size += SIZEOF_FUNDAMENTAL_INFO;	      /* fundamental type info */
434	  node_size += SIZEOF_BASE_TYPE_NODE ();	      /* TypeNode structure */
435	  node_size += (sizeof (GType) * (1 + n_supers + 1)); /* self + ancestors + (0) for ->supers[] */
436	  node = g_malloc0 (node_size);
437	  if (!pnode)					      /* offset fundamental types */
438	    {
439	      node = G_STRUCT_MEMBER_P (node, SIZEOF_FUNDAMENTAL_INFO);
440	      static_fundamental_type_nodes[ftype >> G_TYPE_FUNDAMENTAL_SHIFT] = node;
441	      type = ftype;
442	    }
443	  else
444	    type = (GType) node;
445	  
446	  g_assert ((type & TYPE_ID_MASK) == 0);
447	  
448	  node->n_supers = n_supers;
449	  if (!pnode)
450	    {
451	      node->supers[0] = type;
452	      node->supers[1] = 0;
453	      
454	      node->is_classed = (type_flags & G_TYPE_FLAG_CLASSED) != 0;
455	      node->is_instantiatable = (type_flags & G_TYPE_FLAG_INSTANTIATABLE) != 0;
456	      
457	      if (NODE_IS_IFACE (node))
458		{
459	          IFACE_NODE_N_PREREQUISITES (node) = 0;
460		  IFACE_NODE_PREREQUISITES (node) = NULL;
461		}
462	      else
463		_g_atomic_array_init (CLASSED_NODE_IFACES_ENTRIES (node));
464	    }
465	  else
466	    {
467	      node->supers[0] = type;
468	      memcpy (node->supers + 1, pnode->supers, sizeof (GType) * (1 + pnode->n_supers + 1));
469	      
470	      node->is_classed = pnode->is_classed;
471	      node->is_instantiatable = pnode->is_instantiatable;
472	      
473	      if (NODE_IS_IFACE (node))
474		{
475		  IFACE_NODE_N_PREREQUISITES (node) = 0;
476		  IFACE_NODE_PREREQUISITES (node) = NULL;
477		}
478	      else
479		{
480		  guint j;
481		  IFaceEntries *entries;
482	
483		  entries = _g_atomic_array_copy (CLASSED_NODE_IFACES_ENTRIES (pnode),
484						  IFACE_ENTRIES_HEADER_SIZE,
485						  0);
486		  if (entries)
487		    {
488		      for (j = 0; j < IFACE_ENTRIES_N_ENTRIES (entries); j++)
489			{
490			  entries->entry[j].vtable = NULL;
491			  entries->entry[j].init_state = UNINITIALIZED;
492			}
493		      _g_atomic_array_update (CLASSED_NODE_IFACES_ENTRIES (node),
494					      entries);
495		    }
496		}
497	
498	      i = pnode->n_children++;
499	      pnode->children = g_renew (GType, pnode->children, pnode->n_children);
500	      pnode->children[i] = type;
501	    }
502
503	  TRACE(GOBJECT_TYPE_NEW(name, node->supers[1], type));
504	
505	  node->plugin = plugin;
506	  node->n_children = 0;
507	  node->children = NULL;
508	  node->data = NULL;
509	  node->qname = g_quark_from_string (name);
510	  node->global_gdata = NULL;
511	  g_hash_table_insert (static_type_nodes_ht,
512			       (gpointer) g_quark_to_string (node->qname),
513			       (gpointer) type);
514	
515	  g_atomic_int_inc ((gint *)&type_registration_serial);
516	
517	  return node;
518	}

suspicious:

Code:

436	  node = g_malloc0 (node_size);
(gdb) print node_size
$44 = 96
(gdb) n
437

(gdb) print node[0]
$45 = {ref_count = 4115261048, plugin = 0x7ffff549e678, n_children = 0, n_supers = 0, n_prerequisites = 0, is_classed = 0, 
  is_instantiatable = 0, mutatable_check_cache = 0, children = 0x0, data = 0x0, qname = 0, global_gdata = 0x0, _prot = {
    iface_entries = {data = 0x0}, offsets = {data = 0x0}}, prerequisites = 0x0, supers = {0}}

Also this part:

Code:

129	      mem = calloc (1, n_bytes);
(gdb) n

(gdb) print mem
$46 = (gpointer) 0x18306e0
(gdb) x/8x mem
0x18306e0:	0xf549e678	0x00007fff	0xf549e678	0x00007fff
0x18306f0:	0x00000000	0x00000000	0x00000000	0x00000000

NevemTeve · 01-30-2020, 09:28 AM

Interesting difference in LD_DEBUG-output:
simple test program:

Code:

      1961:<--->symbol=calloc;  lookup in file=/home/projects/devel/test/dltest64 [0]                                                   
      1961:<--->symbol=calloc;  lookup in file=/lib/x86_64-linux-gnu/libdl.so.2 [0]                                                     
      1961:<--->symbol=calloc;  lookup in file=/lib/x86_64-linux-gnu/libc.so.6 [0]                                                      
      1961:<--->binding file /usr/local/lib64/../lib64/libglib-2.0.so.0 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]

php

Code:

     31988:<--->symbol=calloc;  lookup in file=./libsomething.so [0]                                                                    
     31988:<--->symbol=calloc;  lookup in file=/lib64/ld-linux-x86-64.so.2 [0]                                                          
     31988:<--->binding file /usr/local/lib64/libglib-2.0.so.0 [0] to /lib64/ld-linux-x86-64.so.2 [0]: normal symbol `calloc' [GLIBC_2.2.5]

Indeed, there is a 'calloc' in /lib64/ld-linux-x86-64.so.2:

Code:

$ nm -D /lib64/ld-linux-x86-64.so.2
0000000000015b40 W calloc
0000000000015b80 W free
0000000000015b30 W malloc
0000000000015cf0 W realloc

Other modules need 'calloc' too:

Code:

     31988:	binding file /opt/OraHome_Current/lib/libclntsh.so.12.1 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /lib/x86_64-linux-gnu/libdl.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file php [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /usr/local/lib64/libonig.so.5 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /usr/local/lib64/libglib-2.0.so.0 [0] to /lib64/ld-linux-x86-64.so.2 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /usr/lib/x86_64-linux-gnu/libpixman-1.so.0 [0] to /lib64/ld-linux-x86-64.so.2 [0]: normal symbol `calloc' [GLIBC_2.2.5]
     31988:	binding file /usr/local/lib64/libglib-2.0.so.0 [0] to /lib64/ld-linux-x86-64.so.2 [0]: normal symbol `calloc' [GLIBC_2.2.5]

So something has changed with /usr/local/lib64/libglib-2.0.so.0

NevemTeve · 01-30-2020, 10:07 AM

Okay, here is one of the problems: the shared object in question (for some linking problem I don't really get) depends on /lib64/ld-linux-x86-64.so.2, even worse, it is the first dependency:

Code:

  Tag        Type                         Name/Value
 0x0000000000000001 (NEEDED)             Shared library: [ld-linux-x86-64.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libdl.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libpthread.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libgdk-x11-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libX11.so.6]
 0x0000000000000001 (NEEDED)             Shared library: [libgdk_pixbuf-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libgtk-x11-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libgobject-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libglib-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libgthread-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libgmodule-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libpango-1.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libcairo.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libatk-1.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libxml2.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libpangocairo-1.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libc.so.6]
 0x000000000000000e (SONAME)             Library soname: [libsomething.so]

That should be removed from the linking.
The other problem: what kind if calloc exist in ld-linux-x86-64, and it really doesn't clear the allocated memory, or some memory has been corrupted and a random piece of code is executed?

NevemTeve · 01-30-2020, 10:16 AM

Also it it strange the order of the "scopes":
simple dlopen test program:

Code:

 object=./libsomething.so [0]                                                                                            
  scope 0: /home/projects/devel/test/dltest64 /lib/x86_64-linux-gnu/libdl.so.2 /lib/x86_64-linux-gnu/libc.so.6 ...
  scope 1: ./libsomething.so /lib64/ld-linux-x86-64.so.2 /lib/x86_64-linux-gnu/libdl.so.2 ...

with php:

Code:

 object=./libsomething.so [0]                                                                                            
  scope 0: ./libsomething.so /lib64/ld-linux-x86-64.so.2 /lib/x86_64-linux-gnu/libdl.so.2 ...
  scope 1: php /usr/local/lib64/libbz2.so.1 /usr/local/lib64/libcrypto.so.1.1 ...

So in the first case, scope 0 is the main executable; in the second case it is the module to be loaded.

NevemTeve · 01-30-2020, 10:56 AM

Related:
https://stackoverflow.com/questions/...nd-ld-linux-so
https://stackoverflow.com/questions/...out-the-memory

Also 'calloc' in 'ld.linux' calls 'malloc', but doesn't call 'memset' -- guess it assumes 'malloc' returns cleared memory. But for some reason it is 'malloc' from 'libc.so'that is called, not the builtin 'malloc'.

Edit: the following line seems to validate this:

Code:

binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib64/ld-linux-x86-64.so.2 [0]:
    normal symbol `_r_debug'
...
binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]: 
    normal symbol `__libc_memalign' [GLIBC_2.2.5]
binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]:
    normal symbol `malloc' [GLIBC_2.2.5]
binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]:
    normal symbol `realloc' [GLIBC_2.2.5]
binding file /lib64/ld-linux-x86-64.so.2 [0] to /lib/x86_64-linux-gnu/libc.so.6 [0]:
    normal symbol `free' [GLIBC_2.2.5]

Edit: glibc/elf/dl-minimal.c is (similiar to) this: https://code.woboq.org/userspace/gli...minimal.c.html

NevemTeve · 01-30-2020, 02:17 PM

Now here is how I think I could create such a broken shared objects:

Code:

gcc -shared -o demodule.so demodule.o /lib64/ld-linux-x86-64.so.2 -lglib-2.0

readelf result:

Code:

$ readelf -d demodule.so

Dynamic section at offset 0x828 contains 26 entries:
  Tag        Type                         Name/Value
 0x0000000000000001 (NEEDED)             Shared library: [ld-linux-x86-64.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libglib-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libc.so.6]

Suggested change:

Code:

gcc -shared -o demodule.so demodule.o -lglib-2.0

readelf:

Code:

$ readelf -d demodule.so

Dynamic section at offset 0x7f8 contains 25 entries:
  Tag        Type                         Name/Value
 0x0000000000000001 (NEEDED)             Shared library: [libglib-2.0.so.0]
 0x0000000000000001 (NEEDED)             Shared library: [libc.so.6]

NevemTeve · 02-01-2020, 04:10 AM

https://sourceware.org/bugzilla/show_bug.cgi?id=25486