960603 - Uninitialised value use relating to nsJSContext::EndCycleCollectionCallback

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[Julian Seward [:jseward]]

When running m-c either 32- or 64-bit linux, I get errors as follows

Conditional jump or move depends on uninitialised value(s)
   at 0x57AFE1B: dosprintf(SprintfStateStr*, char16_t const*, __va_list_tag*) (nsTextFormatter.cpp:294)
   by 0x57B1A48: nsTextFormatter::vsmprintf(char16_t const*, __va_list_tag*) (nsTextFormatter.cpp:1249)
   by 0x57B1AFC: nsTextFormatter::smprintf(char16_t const*, ...) (nsTextFormatter.cpp:1210)
   by 0x6558D0F: nsJSContext::EndCycleCollectionCallback(mozilla::CycleCollectorResults&) (nsJSEnvironment.cpp:2332)
   by 0x6486797: XPCJSRuntime::EndCycleCollectionCallback(mozilla::CycleCollectorResults&) (XPCJSRuntime.cpp:721)
   by 0x57CC75E: nsCycleCollector::CleanupAfterCollection() (nsCycleCollector.cpp:2955)
   by 0x57CDF80: nsCycleCollector::Collect(ccType, js::SliceBudget&, nsICycleCollectorListener*) (nsCycleCollector.cpp:3027)
   by 0x57CE0C6: nsCycleCollector_collectSlice(long) (nsCycleCollector.cpp:3566)
   by 0x655790A: nsJSContext::RunCycleCollectorSlice(long) (nsJSEnvironment.cpp:2151)
   by 0x65584F6: CCTimerFired(nsITimer*, void*) (nsJSEnvironment.cpp:2449)
   by 0x580724A: nsTimerImpl::Fire() (nsTimerImpl.cpp:551)
   by 0x5807311: nsTimerEvent::Run() (nsTimerImpl.cpp:635)
 Uninitialised value was created by a stack allocation
   at 0x6558785: nsJSContext::EndCycleCollectionCallback(mozilla::CycleCollectorResults&) (nsJSEnvironment.cpp:2213)

I don't know if this remotely relevant, but this is a build with
"ac_add_options --enable-profiling" and started like this:

MOZ_PROFILER_INTERVAL=50 MOZ_PROFILER_MODE=native MOZ_PROFILER_NEW=1 \
MOZ_PROFILER_VERBOSE=1 MOZ_PROFILER_STACK_SCAN=0 MOZ_PROFILER_STARTUP= \
vTRUNK --track-origins=yes --smc-check=all-non-file --fair-sched=yes \
  ./ff-opt-linux/dist/bin/firefox-bin -P dev -no-remote

Comment 1

[Julian Seward [:jseward]]

(analysis)

This clearly relates to the second call to nsTextFormatter::smprintf.
At first I thought some of the passed values might be uninitialised, so
I added this

    VALGRIND_CHECK_VALUE_IS_DEFINED(endCCTime);
    VALGRIND_CHECK_VALUE_IS_DEFINED(ccNowDuration);

etc (one for each passed value) just before the call, but none of those
produced any output, which suggests that they are all properly defined.

I was a bit mystified therefore, until I compared the 32-bit and 64-bit
error reports.  The 32-bit ones start like this

Conditional jump or move depends on uninitialised value(s)
   at 0x8BD11CF: dosprintf(SprintfStateStr*, char16_t const*, char*) (nsTextFormatter.cpp:252)

whereas the 64-bit ones are like this

Conditional jump or move depends on uninitialised value(s)
   at 0x57AFE1B: dosprintf(SprintfStateStr*, char16_t const*, __va_list_tag*) (nsTextFormatter.cpp:294)

that is, they are taking different paths in nsTextFormatter.cpp.  Line 252 is inside
cvt_l() whereas line 294 is inside cvt_ll().

---

One theory is that there is a format string mismatch for the call.  The various
args are passed in memory on the stack, possibly with some alignment holes, and because
the string doesn't match the args, in some cases the holes get picked up by dosprintf().

I notice nsTextFormatter.h doesn't mark smprintf() as __attribute__((printf)) or
whatever magic is needed to get printf-style format string checking.

Comment 2

[Julian Seward [:jseward]]

I compared the format types and actual parameter types for the
offending call to nsTextFormatter::smprintf, with the following
result:

 %llu  TimeStamp(uint64_t?)  endCCTime
 %llu  uint32_t  ccNowDuration
 %llu  uint32_t  gCCStats.mMaxSliceTime
 %llu  uint32_t  gCCStats.mTotalSliceTime
 %llu  uint32_t  gCCStats.mMaxGCDuration
 %llu  uint32_t  gCCStats.mMaxSkippableDuration
 %lu   uint32_t  gCCStats.mSuspected
 %lu   uint32_t  aResults.mVisitedRefCounted
 %lu   uint32_t  aResults.mVisitedGCed
 %lu   uint32_t  aResults.mFreedRefCounted
 %lu   uint32_t  aResults.mFreedGCed
 %lu   uint32_t  sCCollectedWaitingForGC
 %lu   uint32_t  sLikelyShortLivingObjectsNeedingGC
 %d    bool      aResults.mForcedGC
 %lu   uint32_t  sForgetSkippableBeforeCC
 %lu   uint32_t  minForgetSkippableTime / PR_USEC_PER_MSEC
 %lu   uint32_t  sMaxForgetSkippableTime / PR_USEC_PER_MSEC
 %lu   uint32_t  (sTotalForgetSkippableTime / cleanups) / PR_USEC_PER_MSEC
 %lu   uint32_t  sTotalForgetSkippableTime / PR_USEC_PER_MSEC
 %lu   uint32_t  sRemovedPurples

It seems to me the 2nd through 6th %llus should be %lu, to be
consistent with the rest of it.  IMO that still isn't really right:
%lu can be interpreted to mean "unsigned machine word", which matches
uint32_t on 32 bit targets but not on 64 bit targets.  Really I think
we should use plain %u for uint32_t.

Comment 3

[Julian Seward [:jseward]]

Attachment: a fix

Per the comments above, I don't believe this is really right,
but it at least stops V complaining on both 32- and 64-bit x86.
I didn't check whether the output of the smprintf is still
as expected -- don't know how to do that.

Comment 4

[Andrew McCreight [:mccr8]]

Comment on attachment 8361607 [details] [diff] [review]
a fix

thanks!

Comment 5

[Julian Seward [:jseward]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/7bbace751a58

Comment 6

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/7bbace751a58

Comment 7

[Andrew McCreight [:mccr8]]

Comment on attachment 8361607 [details] [diff] [review]
a fix

[Approval Request Comment]
Bug caused by (feature/regressing bug #): maybe bug 948554
User impact if declined: breaks some addons on 32-bit builds, like MemChaser
Testing completed (on m-c, etc.): it has been on m-c for a while
Risk to taking this patch (and alternatives if risky): very low, and it should only affect these addons
String or IDL/UUID changes made by this patch: none

Comment 8

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/0a57931de082