Skip site navigation (1)Skip section navigation (2)
Date:      Sun, 3 May 2020 20:35:35 -0700
From:      Mark Millard <marklmi@yahoo.com>
To:        "vangyzen@freebsd.org" <vangyzen@FreeBSD.org>, svn-src-head@freebsd.org, FreeBSD Current <freebsd-current@freebsd.org>, FreeBSD Hackers <freebsd-hackers@freebsd.org>, FreeBSD PowerPC ML <freebsd-ppc@freebsd.org>
Subject:   Re: svn commit: r360233 - in head: contrib/jemalloc . . . : This partially breaks a 2-socket 32-bit powerpc (old PowerMac G4) based on head -r360311
Message-ID:  <695E6836-F860-4557-B7DE-CC1EDB347F18@yahoo.com>
In-Reply-To: <17ACDA02-D7EF-4F26-874A-BB3E935CD072@yahoo.com>
References:  <C24EE1A1-FAED-42C2-8204-CA7B1D20A369@yahoo.com> <8479DD58-44F6-446A-9CA5-D01F0F7C1B38@yahoo.com> <17ACDA02-D7EF-4F26-874A-BB3E935CD072@yahoo.com>

next in thread | previous in thread | raw e-mail | index | archive | help
This note just reports things from looking at 2
.core files (mountd and rpcbind) from the new
jemalloc context's failures. May be someone that
knows more can get something out of it. I've
not included any of the prior message history.


For mountd:

Core was generated by `/usr/sbin/mountd -r'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x50235df0 in cache_bin_dalloc_easy (bin=3D<optimized out>, =
bin_info=3D<optimized out>, ptr=3D0x50049160) at =
/usr/src/contrib/jemalloc/include/jemalloc/internal/cache_bin.h:121

warning: Source file is more recent than executable.
121		if (unlikely(bin->ncached =3D=3D bin_info->ncached_max)) =
{

It turns out that bin_info traces back to:

        cache_bin_t *bin =3D tcache_small_bin_get(tcache, =
alloc_ctx.szind);
        cache_bin_info_t *bin_info =3D =
&tcache_bin_info[alloc_ctx.szind];
        if (!cache_bin_dalloc_easy(bin, bin_info, ptr)) {
                return false;
        }

based on:

#define tcache_bin_info JEMALLOC_N(tcache_bin_info)
and:
#  define JEMALLOC_N(n) __je_##n

But gdb reports:

(gdb) print __je_tcache_bin_info
$3 =3D (cache_bin_info_t *) 0x0

(gdb) print alloc_ctx
$1 =3D {szind =3D 0, slab =3D <synthetic pointer>}

so bin_info =3D NULL and bin_info->ncached_max would
fail (and does).

By contrast, bin->ncached seems to be from:

(gdb) print *(cache_bin_t*)0x50094018
$6 =3D {low_water =3D 65536, ncached =3D 1, tstats =3D {nrequests =3D =
4796680610075595179}, avail =3D 0x0}


For rpcbind:

Core was generated by `/usr/sbin/rpcbind'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x50243fec in rendezvous_request (xprt=3D<optimized out>, =
msg=3D<optimized out>) at /usr/src/lib/libc/rpc/svc_vc.c:323
323			newxprt->xp_raddr =3D *(struct sockaddr_in =
*)newxprt->xp_rtaddr.buf;

(gdb) print *newxprt
$5 =3D {xp_fd =3D 14, xp_port =3D 0, xp_ops =3D 0x50329e1c, xp_addrlen =3D=
 0, xp_raddr =3D {sin_len =3D 0 '\000', sin_family =3D 0 '\000', =
sin_port =3D 0, sin_addr =3D {s_addr =3D 0},=20
    sin_zero =3D "\000\000\000\000P1O\374"}, xp_ops2 =3D 0x50329e34, =
xp_tp =3D 0x0, xp_netid =3D 0x50047310 "unix", xp_ltaddr =3D {maxlen =3D =
1345322064, len =3D 1970170232, buf =3D 0x2020}, xp_rtaddr =3D {
    maxlen =3D 268500992, len =3D 16, buf =3D 0x0}, xp_verf =3D =
{oa_flavor =3D 0, oa_base =3D 0x202d2020 <error: Cannot access memory at =
address 0x202d2020>, oa_length =3D 538976364}, xp_p1 =3D 0x6f6f7000,=20
  xp_p2 =3D 0x0, xp_p3 =3D 0x202d2020, xp_type =3D 538976288}

so newxprt->xp_rtaddr.buf =3D=3D 0x0 . But taht is very odd . . .

        /*
         * make a new transporter (re-uses xprt)
         */
        newxprt =3D makefd_xprt(sock, r->sendsize, r->recvsize);
        newxprt->xp_rtaddr.buf =3D mem_alloc(len);
        if (newxprt->xp_rtaddr.buf =3D=3D NULL)
                return (FALSE);
        memcpy(newxprt->xp_rtaddr.buf, &addr, len);
        newxprt->xp_rtaddr.len =3D len;
#ifdef PORTMAP
        if (addr.ss_family =3D=3D AF_INET || addr.ss_family =3D=3D =
AF_LOCAL) {
                newxprt->xp_raddr =3D *(struct sockaddr_in =
*)newxprt->xp_rtaddr.buf;
                newxprt->xp_addrlen =3D sizeof (struct sockaddr_in);
        }
#endif                          /* PORTMAP */

Or, in machine code terms:

   0x50243f90 <+260>:	mr      r28,r3
   0x50243f94 <+264>:	lwz     r4,0(r24)
   0x50243f98 <+268>:	lwz     r5,4(r24)
   0x50243f9c <+272>:	mr      r3,r28
   0x50243fa0 <+276>:	bl      0x5024308c <makefd_xprt>
   0x50243fa4 <+280>:	lwz     r27,36(r1)
   0x50243fa8 <+284>:	mr      r29,r3
   0x50243fac <+288>:	li      r3,1
   0x50243fb0 <+292>:	mr      r4,r27
   0x50243fb4 <+296>:	bl      0x502e3214 <00000000.plt_pic32.calloc>
   0x50243fb8 <+300>:	cmplwi  r3,0
   0x50243fbc <+304>:	stw     r3,64(r29)
   0x50243fc0 <+308>:	beq     0x50244160 <rendezvous_request+724>

Note: getting here means that newxprt->xp_rtaddr.buf
ws not NULL . Also the value was stored to 64(r29).

   0x50243fc4 <+312>:	addi    r4,r1,296
   0x50243fc8 <+316>:	mr      r5,r27
   0x50243fcc <+320>:	bl      0x502e3264 <00000000.plt_pic32.memcpy>

Note: getting here means that memcpy was able to
store where ewxprt->xp_rtaddr.buf indicated (as
the r3 value).

   0x50243fd0 <+324>:	lbz     r3,297(r1)
   0x50243fd4 <+328>:	stw     r27,60(r29)
   0x50243fd8 <+332>:	addi    r3,r3,-1
   0x50243fdc <+336>:	clrlwi  r3,r3,24
   0x50243fe0 <+340>:	cmplwi  r3,1
   0x50243fe4 <+344>:	bgt     0x50244014 <rendezvous_request+392>
   0x50243fe8 <+348>:	lwz     r3,64(r29)
=3D> 0x50243fec <+352>:	lwz     r4,0(r3)

Note: the failure was above with r3=3D=3D0x0:

(gdb) info reg
r0             0x50243fb8          1344552888
r1             0xffffb400          4294947840
r2             0x500a1018          1342836760
r3             0x0                 0
r4             0xffffb538          4294948152
r5             0x10                16
r6             0x50047328          1342468904
r7             0x0                 0
r8             0x50047324          1342468900
r9             0x0                 0
r10            0x20                32
r11            0x502d691c          1345153308
r12            0x24200880          606079104
r13            0x0                 0
r14            0x0                 0
r15            0xffffbc28          4294949928
r16            0x10002848          268445768
r17            0x10040000          268697600
r18            0x2                 2
r19            0x0                 0
r20            0x1                 1
r21            0x5004c044          1342488644
r22            0xffffb63c          4294948412
r23            0x80                128
r24            0x50048010          1342472208
r25            0x14                20
r26            0xffffb630          4294948400
r27            0x10                16
r28            0xe                 14
r29            0x500472e0          1342468832
r30            0x5030112c          1345327404
r31            0x10040000          268697600
pc             0x50243fec          0x50243fec <rendezvous_request+352>
msr            <unavailable>
cr             0x84200080          2216689792
lr             0x50243fd0          0x50243fd0 <rendezvous_request+324>
ctr            0x0                 0
xer            0x0                 0
fpscr          0x0                 0
vscr           <unavailable>
vrsave         <unavailable>

Note: The rest of the 2 assignments would have been
done by:

   0x50243ff0 <+356>:	stw     r4,16(r29)
   0x50243ff4 <+360>:	lwz     r4,4(r3)
   0x50243ff8 <+364>:	stw     r4,20(r29)
   0x50243ffc <+368>:	lwz     r4,8(r3)
   0x50244000 <+372>:	stw     r4,24(r29)
   0x50244004 <+376>:	li      r4,16
   0x50244008 <+380>:	lwz     r3,12(r3)
   0x5024400c <+384>:	stw     r4,12(r29)
   0x50244010 <+388>:	stw     r3,28(r29)

My only guesses for alternatives are:

A) A processor context switch where the other
processor did not (yet) see the value stored
via 64(r29) and so it used an older value.

B) Something trashed the memory at 64(r29)
after it was updated by the code above.

C) r29's value was trashed by something,
changing where 64(r29) referenced.

D) r3 was trashed between the two back-to-back
instructions:

   0x50243fe8 <+348>:	lwz     r3,64(r29)
=3D> 0x50243fec <+352>:	lwz     r4,0(r3)

E) ???

I've no clue which.


Both .core files seem to have zero's showing up in
unexpected places previously non-zero.

=3D=3D=3D
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?695E6836-F860-4557-B7DE-CC1EDB347F18>