1158809 - Tracing of JS objects in CC appears to be mangled

Status: RESOLVED FIXED

(Core :: JavaScript: GC, defect)

Description

[Andrew McCreight [:mccr8]]

Looking at a CC log locally, the objects appear to be mangled somehow.  The descriptions contain a bunch of non-ASCII garbage.  More worrying, the fields with the garbage descriptions don't appear in the JS log at all.  Except for the description code, this should be the same as what we run in the CC normally, so it seems like we're just reading weird garbage out of memory.

Do you have any idea what is going on here, Terrence?  You've been refactoring a bunch of this, so maybe something broke.  

GC log:
0x124adac40 G Object <no private>
> 0x130401190 G group
> 0x1334d1268 G shape
> 0x12fa86680 G type
> 0x151060a60 G _owner
> 0x13016b5e0 G _context
> 0x14474bea0 G props

CC log:
0x124adac40 [gc] JS Object (Object)
> 0x130136f70 <<garbage>>
> 0x12ee60540 <<garbage>>
> 0x140eee160 <<garbage>>
> 0x11ae27100 <<garbage>>
> 0x12fa86680 type
> 0x151060a60 _owner
> 0x13016b5e0 _context
> 0x14474bea0 props

What led me to look at the CC logs is that I'm seeing huge CC pauses frequently (but not 100% of the time), which may or may not be related:

CC(T+53746.9) max pause: 1394ms, total time: 1671ms, slices: 47, suspected: 391, visited: 239505 RCed and 1143688 GCed, collected: 0 RCed and 0 GCed (56|0|1331 waiting for GC)
ForgetSkippable 5 times before CC, min: 1 ms, max: 1 ms, avg: 1 ms, total: 5 ms, max sync: 0 ms, removed: 415

Comment 1

[Terrence Cole [:terrence]]

Just bisected this down to bug 1153959.

Comment 2

[Andrew McCreight [:mccr8]]

Given that this seems to be the cycle collector reading odd values out of the JS engine, even without logging, I'm going to mark this as high.  It would be difficult, though not impossible, to exploit something like that.  It may also turn out to be benign, somehow.

Comment 3

[Terrence Cole [:terrence]]

Attachment: missing_strcpy-v0.diff

JSTracer::getTracingEdgeName returns via both a buffer and the return value. The CC only makes use of the buffer. The issue is that if a debug printer or index is not set, we return the "name" string directly without copying the contents into the buffer. The CC then goes on to use the totally uninitialized buffer.

This issue appears to have existed before the blocking bug, probably all the way back to JSTracer in antiquity. I have no idea why this has not bitten us before: we probably just got very lucky.

As this is only an issue with getTracingEdgeName callers that use the buffer preferentially, this is only relevant for the CC and GC heap dump paths. Thus, I think this bug probably warrants sec-low and uplift to beta.

Comment 4

[Andrew McCreight [:mccr8]]

Yeah, I guess the other differences in objects I saw might just be the shape tracing stuff, where it shows up differently in the two logs.

Comment 5

[Eric Rahm [:erahm]]

Comment on attachment 8598271 [details] [diff] [review]
missing_strcpy-v0.diff

Review of attachment 8598271 [details] [diff] [review]:
-----------------------------------------------------------------

::: js/src/gc/Tracer.cpp
@@ +390,3 @@
>      }
> +    strncpy(buffer, contextName_, bufferSize - 1);
> +    buffer[bufferSize] = '\0';

Note: this is an OOB write. 

Fun side note: strncpy is a jerk and will zero out that whole buffer for you regardless of the number of characters in the src, so it's pretty inefficient to use. I'd suggest using something else that's less error prone and more efficient: strlcpy is the recommended replacement but is non-standard, we also have PL_strncpyz in NSPR as well, but I don't think you can use that in js-land.

Comment 6

[Terrence Cole [:terrence]]

Wow, I /really/ shouldn't program when this tired. I even got the size right in the line above.

Comment 7

[Jon Coppeard (:jonco)]

Comment on attachment 8598271 [details] [diff] [review]
missing_strcpy-v0.diff

Review of attachment 8598271 [details] [diff] [review]:
-----------------------------------------------------------------

Looks fine apart from string termination issue.

::: js/src/gc/Tracer.cpp
@@ +390,3 @@
>      }
> +    strncpy(buffer, contextName_, bufferSize - 1);
> +    buffer[bufferSize] = '\0';

Another option is to use JS_snprintf(..., "%s", ...) as this isn't performance sensitive.

Let's assert that bufferSize is not zero at the start of the function too.

Comment 8

[Terrence Cole [:terrence]]

Good idea! I've just used JS_snprintf.

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=5ac3ca4b4222

Comment 9

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/5ac3ca4b4222