Re: svn commit: r360233 - in head: contrib/jemalloc . . . : This partially breaks a 2-socket 32-bit powerpc (old PowerMac G4) based on head -r360311

From: Mark Millard <marklmi_at_yahoo.com>
Date: Thu, 7 May 2020 12:06:15 -0700
[mountd failure example: also at sz_size2index_lookup assert
for the same zero'd memory problem.]

> On 2020-May-7, at 00:46, Mark Millard <marklmi_at_yahoo.com> wrote:
> 
> [__je_sz_size2index_tab seems messed up in 2 of the
> asserting contexts: first 384 are zero in both. More
> before that is also messed up (all zero). I show the
> details later below.]
> 
> On 2020-May-6, at 16:57, Mark Millard <marklmi at yahoo.com> wrote:
> 
>> [This explores process crashes that happen during system
>> shutdown, in a context not having MALLOC_PRODUCTION= .
>> So assert failures are reported as the stopping points.]
>> 
>> It looks like shutdown -p now, shutdown -r now, and the
>> like can lead some processes to assert during their exit
>> attempt, including a sshd failure (that I've not seen
>> before), rpcbind, and nfsd. I show information about the
>> observed asserts for those below.
>> 
>> 
>> sshd hit an assert, failing slab == extent_slab_get(extent) :
>> 
>> (gdb) bt 
>> #0  thr_kill () at thr_kill.S:4
>> #1  0x50927170 in __raise (s=6) at /usr/src/lib/libc/gen/raise.c:52
>> #2  0x50886cc0 in abort () at /usr/src/lib/libc/stdlib/abort.c:67
>> #3  0x508834b0 in arena_dalloc (tsdn=<optimized out>, ptr=<optimized out>, tcache=<optimized out>, alloc_ctx=<optimized out>, slow_path=<optimized out>)
>>   at /usr/src/contrib/jemalloc/include/jemalloc/internal/arena_inlines_b.h:315
>> #4  idalloctm (tsdn=0x500dd040, ptr=0x5008a180, tcache=0x500dd160, alloc_ctx=<optimized out>, is_internal=<optimized out>, slow_path=<optimized out>)
>>   at /usr/src/contrib/jemalloc/include/jemalloc/internal/jemalloc_internal_inlines_c.h:118
>> #5  0x5087b0a4 in ifree (tsd=0x500dd040, ptr=0x5008a180, tcache=0x500dd160, slow_path=<optimized out>) at jemalloc_jemalloc.c:2590
>> #6  0x5087acac in __je_free_default (ptr=0x5008a180) at jemalloc_jemalloc.c:2784
>> #7  0x5087b294 in __free (ptr=0x5008a180) at jemalloc_jemalloc.c:2852
>> #8  0x10029464 in server_accept_loop (config_s=<optimized out>, sock_in=<optimized out>, sock_out=<optimized out>, newsock=<optimized out>) at /usr/src/crypto/openssh/sshd.c:1185
>> #9  main (ac=<optimized out>, av=0xffffde3c) at /usr/src/crypto/openssh/sshd.c:2009
>> 
>> . . .
>> (gdb) up
>> #2  0x50886cc0 in abort () at /usr/src/lib/libc/stdlib/abort.c:67
>> 67		(void)raise(SIGABRT);
>> (gdb) up
>> #3  0x508834b0 in arena_dalloc (tsdn=<optimized out>, ptr=<optimized out>, tcache=<optimized out>, alloc_ctx=<optimized out>, slow_path=<optimized out>)
>>   at /usr/src/contrib/jemalloc/include/jemalloc/internal/arena_inlines_b.h:315
>> 315			assert(slab == extent_slab_get(extent));
>> 
>> (gdb) list
>> 310			rtree_ctx = tsd_rtree_ctx(tsdn_tsd(tsdn));
>> 311			extent_t *extent = rtree_extent_read(tsdn, &extents_rtree,
>> 312			    rtree_ctx, (uintptr_t)ptr, true);
>> 313			assert(szind == extent_szind_get(extent));
>> 314			assert(szind < SC_NSIZES);
>> 315			assert(slab == extent_slab_get(extent));
>> 316		}
>> 317	
>> 318		if (likely(slab)) {
>> 319			/* Small allocation. */
>> 
>> More fully:
>> 
>> 285	JEMALLOC_ALWAYS_INLINE void
>> 286	arena_dalloc(tsdn_t *tsdn, void *ptr, tcache_t *tcache,
>> 287	    alloc_ctx_t *alloc_ctx, bool slow_path) {
>> 288		assert(!tsdn_null(tsdn) || tcache == NULL);
>> 289		assert(ptr != NULL);
>> 290	
>> 291		if (unlikely(tcache == NULL)) {
>> 292			arena_dalloc_no_tcache(tsdn, ptr);
>> 293			return;
>> 294		}
>> 295	
>> 296		szind_t szind;
>> 297		bool slab;
>> 298		rtree_ctx_t *rtree_ctx;
>> 299		if (alloc_ctx != NULL) {
>> 300			szind = alloc_ctx->szind;
>> 301			slab = alloc_ctx->slab;
>> 302			assert(szind != SC_NSIZES);
>> 303		} else {
>> 304			rtree_ctx = tsd_rtree_ctx(tsdn_tsd(tsdn));
>> 305			rtree_szind_slab_read(tsdn, &extents_rtree, rtree_ctx,
>> 306			    (uintptr_t)ptr, true, &szind, &slab);
>> 307		}
>> 308	
>> 309		if (config_debug) {
>> 310			rtree_ctx = tsd_rtree_ctx(tsdn_tsd(tsdn));
>> 311			extent_t *extent = rtree_extent_read(tsdn, &extents_rtree,
>> 312			    rtree_ctx, (uintptr_t)ptr, true);
>> 313			assert(szind == extent_szind_get(extent));
>> 314			assert(szind < SC_NSIZES);
>> 315			assert(slab == extent_slab_get(extent));
>> 316		}
>> 317	
>> 318		if (likely(slab)) {
>> 319			/* Small allocation. */
>> 320			tcache_dalloc_small(tsdn_tsd(tsdn), tcache, ptr, szind,
>> 321			    slow_path);
>> 322		} else {
>> 323			arena_dalloc_large(tsdn, ptr, tcache, szind, slow_path);
>> 324		}
>> 325	}
> 
> The following are only shown for contrast with the later
> cases of lots of zeros showing up where below shows
> non-zero values (taken from sshd.core, which failed
> differently):
> 
> (gdb) x/4x __je_arenas+16368/4
> 0x50981ab0 <__je_arenas+16368>:	0x00000000	0x00000000	0x00000000	0x00000009
> (gdb) print/x __je_arenas_lock 
> $1 = {{{prof_data = {tot_wait_time = {ns = 0x0}, max_wait_time = {ns = 0x0}, n_wait_times = 0x0, n_spin_acquired = 0x0, max_n_thds = 0x0, n_waiting_thds = {repr = 0x0}, n_owner_switches = 0x0, 
>        prev_owner = 0x0, n_lock_ops = 0x0}, lock = 0x5008bf00, postponed_next = 0x50974070, locked = {repr = 0x0}}}, witness = {name = 0x50760b04, rank = 0x3, comp = 0x0, opaque = 0x0, link = {
>      qre_next = 0x50981b10, qre_prev = 0x50981b10}}, lock_order = 0x0}
> (gdb) print/x __je_narenas_auto
> $2 = 0x8
> (gdb) print/x malloc_conf
> $3 = 0x0
> (gdb) print/x __je_ncpus
> $4 = 0x2
> (gdb) print/x __je_manual_arena_base
> $5 = 0x9
> (gdb) print/x __je_sz_pind2sz_tab 
> $6 = {0x1000, 0x2000, 0x3000, 0x4000, 0x5000, 0x6000, 0x7000, 0x8000, 0xa000, 0xc000, 0xe000, 0x10000, 0x14000, 0x18000, 0x1c000, 0x20000, 0x28000, 0x30000, 0x38000, 0x40000, 0x50000, 0x60000, 
>  0x70000, 0x80000, 0xa0000, 0xc0000, 0xe0000, 0x100000, 0x140000, 0x180000, 0x1c0000, 0x200000, 0x280000, 0x300000, 0x380000, 0x400000, 0x500000, 0x600000, 0x700000, 0x800000, 0xa00000, 0xc00000, 
>  0xe00000, 0x1000000, 0x1400000, 0x1800000, 0x1c00000, 0x2000000, 0x2800000, 0x3000000, 0x3800000, 0x4000000, 0x5000000, 0x6000000, 0x7000000, 0x8000000, 0xa000000, 0xc000000, 0xe000000, 
>  0x10000000, 0x14000000, 0x18000000, 0x1c000000, 0x20000000, 0x28000000, 0x30000000, 0x38000000, 0x40000000, 0x50000000, 0x60000000, 0x70000000, 0x70001000}
> (gdb) print/x __je_sz_index2size_tab
> $7 = {0x8, 0x10, 0x20, 0x30, 0x40, 0x50, 0x60, 0x70, 0x80, 0xa0, 0xc0, 0xe0, 0x100, 0x140, 0x180, 0x1c0, 0x200, 0x280, 0x300, 0x380, 0x400, 0x500, 0x600, 0x700, 0x800, 0xa00, 0xc00, 0xe00, 0x1000, 
>  0x1400, 0x1800, 0x1c00, 0x2000, 0x2800, 0x3000, 0x3800, 0x4000, 0x5000, 0x6000, 0x7000, 0x8000, 0xa000, 0xc000, 0xe000, 0x10000, 0x14000, 0x18000, 0x1c000, 0x20000, 0x28000, 0x30000, 0x38000, 
>  0x40000, 0x50000, 0x60000, 0x70000, 0x80000, 0xa0000, 0xc0000, 0xe0000, 0x100000, 0x140000, 0x180000, 0x1c0000, 0x200000, 0x280000, 0x300000, 0x380000, 0x400000, 0x500000, 0x600000, 0x700000, 
>  0x800000, 0xa00000, 0xc00000, 0xe00000, 0x1000000, 0x1400000, 0x1800000, 0x1c00000, 0x2000000, 0x2800000, 0x3000000, 0x3800000, 0x4000000, 0x5000000, 0x6000000, 0x7000000, 0x8000000, 0xa000000, 
>  0xc000000, 0xe000000, 0x10000000, 0x14000000, 0x18000000, 0x1c000000, 0x20000000, 0x28000000, 0x30000000, 0x38000000, 0x40000000, 0x50000000, 0x60000000, 0x70000000}
> (gdb) print/x __je_sz_size2index_tab
> $2 = {0x0, 0x0, 0x1, 0x2, 0x2, 0x3, 0x3, 0x4, 0x4, 0x5, 0x5, 0x6, 0x6, 0x7, 0x7, 0x8, 0x8, 0x9, 0x9, 0x9, 0x9, 0xa, 0xa, 0xa, 0xa, 0xb, 0xb, 0xb, 0xb, 0xc, 0xc, 0xc, 0xc, 0xd, 0xd, 0xd, 0xd, 0xd, 
>  0xd, 0xd, 0xd, 0xe, 0xe, 0xe, 0xe, 0xe, 0xe, 0xe, 0xe, 0xf, 0xf, 0xf, 0xf, 0xf, 0xf, 0xf, 0xf, 0x10, 0x10, 0x10, 0x10, 0x10, 0x10, 0x10, 0x10, 0x11 <repeats 16 times>, 0x12 <repeats 16 times>, 
>  0x13 <repeats 16 times>, 0x14 <repeats 16 times>, 0x15 <repeats 32 times>, 0x16 <repeats 32 times>, 0x17 <repeats 32 times>, 0x18 <repeats 32 times>, 0x19 <repeats 64 times>, 
>  0x1a <repeats 64 times>, 0x1b <repeats 64 times>, 0x1c <repeats 64 times>}
> 
> 
>> rpcbind hit an assert, failing ret == sz_size2index_compute(size) :
>> 
>> (gdb) bt
>> #0  thr_kill () at thr_kill.S:4
>> #1  0x502f2170 in __raise (s=6) at /usr/src/lib/libc/gen/raise.c:52
>> #2  0x50251d04 in abort () at /usr/src/lib/libc/stdlib/abort.c:79
>> #3  0x5024f260 in sz_size2index_lookup (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:159
>> #4  sz_size2index (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:166
>> #5  imalloc_body (sopts=0xffffb360, dopts=0xffffb340, tsd=0x5009a018) at jemalloc_jemalloc.c:2066
>> #6  0x50244874 in imalloc (sopts=0xffffb360, dopts=0xffffb340) at /usr/src/contrib/jemalloc/include/jemalloc/internal/tsd.h:331
>> #7  0x50244fe8 in __calloc (num=1, size=96) at jemalloc_jemalloc.c:2498
>> #8  0x50265690 in svc_xprt_alloc () at /usr/src/lib/libc/rpc/svc.c:541
>> #9  0x502635f4 in makefd_xprt (fd=14, sendsize=9000, recvsize=9000) at /usr/src/lib/libc/rpc/svc_vc.c:250
>> #10 0x502644b4 in rendezvous_request (xprt=0x5004c000, msg=<optimized out>) at /usr/src/lib/libc/rpc/svc_vc.c:315
>> #11 0x50265a98 in svc_getreq_common (fd=<optimized out>) at /usr/src/lib/libc/rpc/svc.c:640
>> #12 0x50265d1c in svc_getreq_poll (pfdp=<optimized out>, pollretval=1) at /usr/src/lib/libc/rpc/svc.c:739
>> #13 0x10018568 in my_svc_run () at /usr/src/usr.sbin/rpcbind/rpcb_svc_com.c:1167
>> #14 0x10014ad8 in main (argc=<optimized out>, argv=<optimized out>) at /usr/src/usr.sbin/rpcbind/rpcbind.c:250
>> (gdb) up 3
>> #3  0x5024f260 in sz_size2index_lookup (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:159
>> 159		assert(ret == sz_size2index_compute(size));
>> (gdb) print ret
>> $1 = 0
>> 
>> 154	JEMALLOC_ALWAYS_INLINE szind_t
>> 155	sz_size2index_lookup(size_t size) {
>> 156		assert(size <= SC_LOOKUP_MAXCLASS);
>> 157		szind_t ret = (sz_size2index_tab[(size + (ZU(1) << SC_LG_TINY_MIN) - 1)
>> 158						 >> SC_LG_TINY_MIN]);
>> 159		assert(ret == sz_size2index_compute(size));
>> 160		return ret;
>> 161	}
> 
> gdb reports for sz_size2index_tab (really JEMALLOC_N(sz_size2index_tab),
> i.e., __je_sz_size2index_tab):
> 
> (gdb) print/x __je_sz_size2index_tab
> $1 = {0x0 <repeats 384 times>, 0x1a, 0x1b <repeats 64 times>, 0x1c <repeats 64 times>}
> 
> Also:
> 
> (gdb) x/4x __je_arenas+16368/4
> 0x5034cab0 <__je_arenas+16368>:	0x00000000	0x00000000	0x00000000	0x00000000
> (gdb) print/x __je_arenas_lock                                                                                                                 
> $8 = {{{prof_data = {tot_wait_time = {ns = 0x0}, max_wait_time = {ns = 0x0}, n_wait_times = 0x0, n_spin_acquired = 0x0, max_n_thds = 0x0, n_waiting_thds = {repr = 0x0}, n_owner_switches = 0x0, 
>        prev_owner = 0x0, n_lock_ops = 0x0}, lock = 0x0, postponed_next = 0x0, locked = {repr = 0x0}}}, witness = {name = 0x0, rank = 0x0, comp = 0x0, opaque = 0x0, link = {qre_next = 0x0, 
>      qre_prev = 0x0}}, lock_order = 0x0}
> (gdb) print/x __je_narenas_auto
> $9 = 0x0
> (gdb) print/x malloc_conf      
> $10 = 0x0
> (gdb) print/x __je_ncpus 
> $11 = 0x0
> (gdb) print/x __je_manual_arena_base
> $12 = 0x0
> (gdb) print/x __je_sz_pind2sz_tab   
> $13 = {0x0 <repeats 72 times>}
> (gdb) print/x __je_sz_index2size_tab
> $14 = {0x0 <repeats 104 times>}
> 
> 
>> nfsd hit an assert, failing ret == sz_size2index_compute(size)
> 
> [Correction: That should have referenced sz_index2size_lookup(index).]
> 
>> (also, but a different caller of sz_size2index):
> 
> [Correction: The "also" comment should be ignored:
> sz_index2size_lookup(index) is referenced below.]
> 
>> 
>> (gdb) bt
>> #0  thr_kill () at thr_kill.S:4
>> #1  0x502b2170 in __raise (s=6) at /usr/src/lib/libc/gen/raise.c:52
>> #2  0x50211cc0 in abort () at /usr/src/lib/libc/stdlib/abort.c:67
>> #3  0x50206104 in sz_index2size_lookup (index=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:200
>> #4  sz_index2size (index=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:207
>> #5  ifree (tsd=0x50094018, ptr=0x50041028, tcache=0x50094138, slow_path=<optimized out>) at jemalloc_jemalloc.c:2583
>> #6  0x50205cac in __je_free_default (ptr=0x50041028) at jemalloc_jemalloc.c:2784
>> #7  0x50206294 in __free (ptr=0x50041028) at jemalloc_jemalloc.c:2852
>> #8  0x50287ec8 in ns_src_free (src=0x50329004, srclistsize=<optimized out>) at /usr/src/lib/libc/net/nsdispatch.c:452
>> #9  ns_dbt_free (dbt=0x50329000) at /usr/src/lib/libc/net/nsdispatch.c:436
>> #10 vector_free (vec=0x50329000, count=<optimized out>, esize=12, free_elem=<optimized out>) at /usr/src/lib/libc/net/nsdispatch.c:253
>> #11 nss_atexit () at /usr/src/lib/libc/net/nsdispatch.c:578
>> #12 0x5028d958 in __cxa_finalize (dso=0x0) at /usr/src/lib/libc/stdlib/atexit.c:240
>> #13 0x502117f8 in exit (status=0) at /usr/src/lib/libc/stdlib/exit.c:74
>> #14 0x10013f9c in child_cleanup (signo=<optimized out>) at /usr/src/usr.sbin/nfsd/nfsd.c:969
>> #15 <signal handler called>
>> #16 0x00000000 in ?? ()
>> 
>> (gdb) up 3
>> #3  0x50206104 in sz_index2size_lookup (index=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:200
>> 200		assert(ret == sz_index2size_compute(index));
>> 
>> (ret is optimized out.)
>> 
>> 197	JEMALLOC_ALWAYS_INLINE size_t
>> 198	sz_index2size_lookup(szind_t index) {
>> 199		size_t ret = (size_t)sz_index2size_tab[index];
>> 200		assert(ret == sz_index2size_compute(index));
>> 201		return ret;
>> 202	}
> 
> (gdb) print/x __je_sz_index2size_tab
> $3 = {0x0 <repeats 104 times>}
> 
> Also:
> 
> (gdb) x/4x __je_arenas+16368/4
> 0x5030cab0 <__je_arenas+16368>:	0x00000000	0x00000000	0x00000000	0x00000000
> (gdb) print/x __je_arenas_lock                                                                                                                 
> $8 = {{{prof_data = {tot_wait_time = {ns = 0x0}, max_wait_time = {ns = 0x0}, n_wait_times = 0x0, n_spin_acquired = 0x0, max_n_thds = 0x0, n_waiting_thds = {repr = 0x0}, n_owner_switches = 0x0, 
>        prev_owner = 0x0, n_lock_ops = 0x0}, lock = 0x0, postponed_next = 0x0, locked = {repr = 0x0}}}, witness = {name = 0x0, rank = 0x0, comp = 0x0, opaque = 0x0, link = {qre_next = 0x0, 
>      qre_prev = 0x0}}, lock_order = 0x0}
> (gdb) print/x __je_narenas_auto
> $9 = 0x0
> (gdb) print/x malloc_conf      
> $10 = 0x0
> (gdb) print/x __je_ncpus 
> $11 = 0x0
> (gdb) print/x __je_manual_arena_base
> $12 = 0x0
> (gdb) print/x __je_sz_pind2sz_tab   
> $13 = {0x0 <repeats 72 times>}
> (gdb) print/x __je_sz_size2index_tab
> $1 = {0x0 <repeats 384 times>, 0x1a, 0x1b <repeats 64 times>, 0x1c <repeats 64 times>}
> 
>> Booting and immediately trying something like:
>> 
>> service nfsd stop
>> 
>> did not lead to a failure. But may be after
>> a while it would and be less drastic than a
>> reboot or power down.
> 
> More detail:
> 
> So, for rpcbind and nfds at some point a large part of
> __je_sz_size2index_tab is being stomped on, as is all of
> __je_sz_index2size_tab and more.
> 
> For rpcbind, the following area is zero but in a
> live process is not all-zero (I show the partially
> non-zero live-process context instead of the all-zero
> .core file content):
> 
> 0x5034cab0 <__je_arenas+16368>:	0x00000000	0x00000000	0x00000000	0x00000009
> 0x5034cac0 <__je_arenas_lock>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5034cad0 <__je_arenas_lock+16>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5034cae0 <__je_arenas_lock+32>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5034caf0 <__je_arenas_lock+48>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5034cb00 <__je_arenas_lock+64>:	0x00000000	0x5033f070	0x00000000	0x00000000
> 0x5034cb10 <__je_arenas_lock+80>:	0x5012bb04	0x00000003	0x00000000	0x00000000
> 0x5034cb20 <__je_arenas_lock+96>:	0x5034cb10	0x5034cb10	0x00000000	0x00000000
> 
> Then the memory in the crash continues to be zero until:
> 
> 0x5034d000 <__je_sz_size2index_tab+384>:	0x1a1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
> 
> Notice the interesting page boundary for where non-zero
> is first available again!
> 
> Between __je_arenas_lock and __je_sz_size2index_tab are:
> 
> 0x5034cb30 __je_narenas_auto
> 0x5034cb38 malloc_conf
> 0x5034cb3c __je_ncpus
> 0x5034cb40 __je_manual_arena_base
> 0x5034cb80 __je_sz_pind2sz_tab
> 0x5034ccc0 __je_sz_index2size_tab
> 0x5034ce80 __je_sz_size2index_tab
> 
> For nfsd, it is similar (again showing the partially
> non-zero live process context instead of the all-zeros
> from the .core file):
> 
> 0x5030cab0 <__je_arenas+16368>:	0x00000000	0x00000000	0x00000000	0x00000009
> 0x5030cac0 <__je_arenas_lock>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5030cad0 <__je_arenas_lock+16>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5030cae0 <__je_arenas_lock+32>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5030caf0 <__je_arenas_lock+48>:	0x00000000	0x00000000	0x00000000	0x00000000
> 0x5030cb00 <__je_arenas_lock+64>:	0x00000000	0x502ff070	0x00000000	0x00000000
> 0x5030cb10 <__je_arenas_lock+80>:	0x500ebb04	0x00000003	0x00000000	0x00000000
> 0x5030cb20 <__je_arenas_lock+96>:	0x5030cb10	0x5030cb10	0x00000000	0x00000000
> 
> Then the memory in the crash continues to be zero until:
> 
> 0x5030d000 <__je_sz_size2index_tab+384>:	0x1a1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
> 
> Notice the interesting page boundary for where non-zero
> is first available again!
> 
> Between __je_arenas_lock and __je_sz_size2index_tab are:
> 
> 0x5030cb30 __je_narenas_auto
> 0x5030cb38 malloc_conf
> 0x5030cb3c __je_ncpus
> 0x5030cb40 __je_manual_arena_base
> 0x5030cb80 __je_sz_pind2sz_tab
> 0x5030ccc0 __je_sz_index2size_tab
> 0x5030ce80 __je_sz_size2index_tab
> 
> 
> Note: because __je_arenas is normally
> mostly zero for these contexts, I can
> not tell where the memory trashing
> started, only where it replaced non-zero
> values with zeros.
> 

I got a mountd assert failure in sz_size2index_lookup
while attempting __calloc during makefd_xprt.

(gdb) bt
#0  thr_kill () at thr_kill.S:4
#1  0x50301170 in __raise (s=6) at /usr/src/lib/libc/gen/raise.c:52
#2  0x50260cc0 in abort () at /usr/src/lib/libc/stdlib/abort.c:67
#3  0x5025e260 in sz_size2index_lookup (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:159
#4  sz_size2index (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:166
#5  imalloc_body (sopts=0xffffd000, dopts=0xffffcfe0, tsd=0x50094018) at jemalloc_jemalloc.c:2066
#6  0x50253874 in imalloc (sopts=0xffffd000, dopts=0xffffcfe0) at /usr/src/contrib/jemalloc/include/jemalloc/internal/tsd.h:331
#7  0x50253fe8 in __calloc (num=1, size=96) at jemalloc_jemalloc.c:2498
#8  0x50274690 in svc_xprt_alloc () at /usr/src/lib/libc/rpc/svc.c:541
#9  0x502725f4 in makefd_xprt (fd=10, sendsize=9000, recvsize=9000) at /usr/src/lib/libc/rpc/svc_vc.c:250
#10 0x502734b4 in rendezvous_request (xprt=0x5007b120, msg=<optimized out>) at /usr/src/lib/libc/rpc/svc_vc.c:315
#11 0x50274a98 in svc_getreq_common (fd=<optimized out>) at /usr/src/lib/libc/rpc/svc.c:640
#12 0x502748e0 in svc_getreqset (readfds=<optimized out>) at /usr/src/lib/libc/rpc/svc.c:611
#13 0x1001434c in main (argc=<optimized out>, argv=0xffffde3c) at /usr/src/usr.sbin/mountd/mountd.c:683

(gdb) up 3
#3  0x5025e260 in sz_size2index_lookup (size=<optimized out>) at /usr/src/contrib/jemalloc/include/jemalloc/internal/sz.h:159
159		assert(ret == sz_size2index_compute(size));

Again there is that area of memory that has been zeroed, with
the same stopping point in __je_sz_size2index_tab:

(gdb) print/x __je_narenas_auto
$2 = 0x0
(gdb) print/x malloc_conf 
$3 = 0x0
(gdb) print/x __je_ncpus
$4 = 0x0
(gdb) print/x __je_manual_arena_base
$5 = 0x0
(gdb) print/x __je_sz_pind2sz_tab
$6 = {0x0 <repeats 72 times>}
(gdb) print/x __je_sz_size2index_tab
$7 = {0x0 <repeats 384 times>, 0x1a, 0x1b <repeats 64 times>, 0x1c <repeats 64 times>}

Showing where the zeroing stopped:

. . .
(gdb) x/156x __je_sz_size2index_tab
0x5035be80 <__je_sz_size2index_tab>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035be90 <__je_sz_size2index_tab+16>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bea0 <__je_sz_size2index_tab+32>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035beb0 <__je_sz_size2index_tab+48>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bec0 <__je_sz_size2index_tab+64>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bed0 <__je_sz_size2index_tab+80>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bee0 <__je_sz_size2index_tab+96>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bef0 <__je_sz_size2index_tab+112>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf00 <__je_sz_size2index_tab+128>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf10 <__je_sz_size2index_tab+144>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf20 <__je_sz_size2index_tab+160>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf30 <__je_sz_size2index_tab+176>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf40 <__je_sz_size2index_tab+192>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf50 <__je_sz_size2index_tab+208>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf60 <__je_sz_size2index_tab+224>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf70 <__je_sz_size2index_tab+240>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf80 <__je_sz_size2index_tab+256>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bf90 <__je_sz_size2index_tab+272>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bfa0 <__je_sz_size2index_tab+288>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bfb0 <__je_sz_size2index_tab+304>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bfc0 <__je_sz_size2index_tab+320>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bfd0 <__je_sz_size2index_tab+336>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bfe0 <__je_sz_size2index_tab+352>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035bff0 <__je_sz_size2index_tab+368>:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c000 <__je_sz_size2index_tab+384>:	0x1a1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
0x5035c010 <__je_sz_size2index_tab+400>:	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
0x5035c020 <__je_sz_size2index_tab+416>:	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
0x5035c030 <__je_sz_size2index_tab+432>:	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b	0x1b1b1b1b
0x5035c040 <__je_sz_size2index_tab+448>:	0x1b1c1c1c	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c
0x5035c050 <__je_sz_size2index_tab+464>:	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c
0x5035c060 <__je_sz_size2index_tab+480>:	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c
0x5035c070 <__je_sz_size2index_tab+496>:	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c	0x1c1c1c1c
0x5035c080 <__je_sz_size2index_tab+512>:	0x1c000000	0x00000000	0x50303474	0x00000000
0x5035c090:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c0a0:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c0b0:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c0c0:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c0d0:	0x00000000	0x00000000	0x00000000	0x00000000
0x5035c0e0:	0x00000000	0x00000000	0x00000000	0x00000000

Again: a nice page boundary: 0x5035c000 for where the
zeros stop.

Note that, despite the address ranges shifting around
between programs, the same global variables are being
stomped on, stopping at the same index into
__je_sz_size2index_tab in each of the 3 programs. It
always is page aligned there in my context.

(The sshd example is different. I've yet to explore it
much.)



===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)
Received on Thu May 07 2020 - 17:06:38 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:41:23 UTC