1380096 - Intermittent browser/base/content/test/referrer/browser_referrer_simple_click.js | application crashed [@ strncpy + 0x38]

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Treeherder Bug Filer]

Filed by: wkocher [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=113314089&repo=autoland

https://archive.mozilla.org/pub/firefox/tinderbox-builds/autoland-win64/1499767582/autoland_win8_64_test-mochitest-e10s-browser-chrome-3-bm111-tests1-windows-build242.txt.gz

Comment 1

[Andrew McCreight [:mccr8]]

This is a crash where BackgroundHangManager::RunMonitorThread() is calling into Sampler::SuspendAndSampleAndResumeThread. Maybe this looks familiar to mystor.Sampler::SuspendAndSampleAndResumeThread

Comment 2

[Nika Layzell [:nika] (ni? for response)]

Looks like the crash is on this line: http://searchfox.org/mozilla-central/rev/5dadcbe55b4ddd1e448c06c77390ff6483aa009b/xpcom/threads/ThreadStackHelper.cpp#152 (as that's the only strncpy call in the callback). It seems like we're reading an invalid string pointer out of sMainThreadRunnableName http://searchfox.org/mozilla-central/rev/5dadcbe55b4ddd1e448c06c77390ff6483aa009b/xpcom/threads/nsThread.cpp#102.

My only theory right now is that we're sometimes getting aIsMainThread passed in as true when not pausing the main thread? Not sure.

Comment 3

[Nika Layzell [:nika] (ni? for response)]

Attachment: Don't require that sMainThreadRunnableName is null-terminated

My current best bet is that we're somehow getting a non-null terminated string
into the nsAutoCString. This should help with avoiding that hopefully.

MozReview-Commit-ID: 9Zo1vjmKzZC

Comment 4

[Eric Rahm [:erahm]]

Comment on attachment 8885459 [details] [diff] [review]
Don't require that sMainThreadRunnableName is null-terminated

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

r+ as long as it compiles, I added some notes for possible improvements but don't let those block fixing a crash.

::: xpcom/threads/ThreadStackHelper.cpp
@@ +138,5 @@
>    ScopedSetPtr<NativeStack> nativeStackPtr(mNativeStackToFill, aNativeStack);
>  #endif
>  
>    char nameBuffer[1000] = {0};
> +  uint32_t nameLength = 0;

I guess this could just be |Vector<char, 1000> nameBuffer;|

@@ +151,5 @@
>      // value in the case that we are currently suspending the main thread.
>      if (aIsMainThread && nsThread::sMainThreadRunnableName) {
> +      nameLength = std::min(static_cast<uint32_t>(sizeof(nameBuffer)),
> +                            nsThread::sMainThreadRunnableName->Length());
> +      memcpy(nameBuffer, nsThread::sMainThreadRunnableName, nameLength);

... and then

> nameBuffer.append(nsThread::sMainThreadRunnableName->BeginReading(),
                    std::min(...->Length(), nameBuffer::sMaxInlineStorage));

Which is a little bit clearer to me, but meh this is probably almost fine as-is, I think you need a |->BeginReading()| in the memcpy call now that we store nsACString pointer.

::: xpcom/threads/nsThread.cpp
@@ +1429,1 @@
>            sMainThreadRunnableName = restoreRunnableName;

Can we simplify this and always set sMainThreadRunnableName to nullptr and get rid of restorRunnableName? Or is there some way this is run recursively?

Comment 6

[Nika Layzell [:nika] (ni? for response)]

(In reply to Eric Rahm [:erahm] (please no mozreview requests) from comment #4)
> Comment on attachment 8885459 [details] [diff] [review]
> Don't require that sMainThreadRunnableName is null-terminated
> 
> Review of attachment 8885459 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> r+ as long as it compiles, I added some notes for possible improvements but
> don't let those block fixing a crash.
> 
> ::: xpcom/threads/ThreadStackHelper.cpp
> @@ +138,5 @@
> >    ScopedSetPtr<NativeStack> nativeStackPtr(mNativeStackToFill, aNativeStack);
> >  #endif
> >  
> >    char nameBuffer[1000] = {0};
> > +  uint32_t nameLength = 0;
> 
> I guess this could just be |Vector<char, 1000> nameBuffer;|
> 
> @@ +151,5 @@
> >      // value in the case that we are currently suspending the main thread.
> >      if (aIsMainThread && nsThread::sMainThreadRunnableName) {
> > +      nameLength = std::min(static_cast<uint32_t>(sizeof(nameBuffer)),
> > +                            nsThread::sMainThreadRunnableName->Length());
> > +      memcpy(nameBuffer, nsThread::sMainThreadRunnableName, nameLength);
> 
> ... and then
> 
> > nameBuffer.append(nsThread::sMainThreadRunnableName->BeginReading(),
>                     std::min(...->Length(), nameBuffer::sMaxInlineStorage));
> 
> Which is a little bit clearer to me, but meh this is probably almost fine
> as-is, I think you need a |->BeginReading()| in the memcpy call now that we
> store nsACString pointer.

Yup, that was my mistake.
 
> ::: xpcom/threads/nsThread.cpp
> @@ +1429,1 @@
> >            sMainThreadRunnableName = restoreRunnableName;
> 
> Can we simplify this and always set sMainThreadRunnableName to nullptr and
> get rid of restorRunnableName? Or is there some way this is run recursively?

Nested event loops let this run recursively.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/8fe427b20f90
Don't require that sMainThreadRunnableName is null-terminated, r=erahm

Comment 8

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backed out for crashing Marionette test_refresh_firefox.py TestFirefoxRefresh.testReset and mochitests on Windows x64:

https://hg.mozilla.org/integration/mozilla-inbound/rev/88e332b0ef13624c71010057c06eeb8370f5713f

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=703825995ef40591a932983f7a812c335f50ec75&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=runnable
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=113771409&repo=mozilla-inbound

20:19:13     INFO -  [GPU 1732] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
20:22:18     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/I3_tVjNLQl6vp3QDp-ITvw/artifacts/public/build/target.crashreporter-symbols.zip
20:22:27     INFO -  mozcrash Copy/paste: Z:\task_1499890048\build\win32-minidump_stackwalk.exe c:\users\genericworker\appdata\local\temp\tmpzstzyv.mozrunner\minidumps\a7dd30f0-13e3-4fdb-908c-02c4675a8700.dmp c:\users\genericworker\appdata\local\temp\tmpto2r8o
20:22:36     INFO -  mozcrash Saved minidump as Z:\task_1499890048\build\blobber_upload_dir\a7dd30f0-13e3-4fdb-908c-02c4675a8700.dmp
20:22:36     INFO -  mozcrash Saved app info as Z:\task_1499890048\build\blobber_upload_dir\a7dd30f0-13e3-4fdb-908c-02c4675a8700.extra
20:22:36    ERROR -  PROCESS-CRASH | test_refresh_firefox.py TestFirefoxRefresh.testReset | application crashed [@ std::_Invoker_functor::_Call<<lambda_8f88644993ed9f95565e4e8e87ef337b> &,void * *,unsigned __int64,bool>(<lambda_8f88644993ed9f95565e4e8e87ef337b> &,void * * &&,unsigned __int64 &&,bool &&)]
20:22:36     INFO -  Crash dump filename: c:\users\genericworker\appdata\local\temp\tmpzstzyv.mozrunner\minidumps\a7dd30f0-13e3-4fdb-908c-02c4675a8700.dmp
20:22:36     INFO -  Operating system: Windows NT
20:22:36     INFO -                    10.0.15063
20:22:36     INFO -  CPU: amd64
20:22:36     INFO -       family 6 model 63 stepping 2
20:22:36     INFO -       8 CPUs
20:22:36     INFO -  GPU: UNKNOWN
20:22:36     INFO -  Crash reason:  EXCEPTION_ACCESS_VIOLATION_READ
20:22:36     INFO -  Crash address: 0x0
20:22:36     INFO -  Process uptime: 7 seconds
20:22:36     INFO -  Thread 24 (crashed)
20:22:36     INFO -   0  xul.dll!std::_Invoker_functor::_Call<<lambda_8f88644993ed9f95565e4e8e87ef337b> &,void * *,unsigned __int64,bool>(<lambda_8f88644993ed9f95565e4e8e87ef337b> &,void * * &&,unsigned __int64 &&,bool &&) [type_traits:703825995ef4 : 1375 + 0x61]
20:22:36     INFO -      rax = 0x0000000000000001   rdx = 0x0000000000000000
20:22:36     INFO -      rcx = 0x00000089b73ff2d8   rbx = 0x00000089b73ff2c0
20:22:36     INFO -      rsi = 0x0000000000000001   rdi = 0x0000000000000017
20:22:36     INFO -      rbp = 0x0000000000000000   rsp = 0x00000089b73fac20
20:22:36     INFO -       r8 = 0x0000000000000001    r9 = 0x00000089b73fac90
20:22:36     INFO -      r10 = 0x0000000000000000   r11 = 0x0000000000000246
20:22:36     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000001a4f
20:22:36     INFO -      r14 = 0x00000089b73ff288   r15 = 0x00000089b73fb220
20:22:36     INFO -      rip = 0x00007ffb986a45b8
20:22:36     INFO -      Found by: given as instruction pointer in context
20:22:36     INFO -   1  xul.dll!Sampler::SuspendAndSampleAndResumeThread<<lambda_9ef629a8fdd5902ffadc87afeb9a3606> >(mozilla::BaseAutoLock<PSMutex> const &,ThreadInfo const &,<lambda_9ef629a8fdd5902ffadc87afeb9a3606> const &) [platform-win32.cpp:703825995ef4 : 164 + 0x6d]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73fac70   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffb9aa39dbd
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   2  xul.dll!profiler_suspend_and_sample_thread(int,std::function<void > const &,bool) [platform.cpp:703825995ef4 : 3138 + 0x45]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73fb1c0   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffb9aa49ff9
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   3  xul.dll!mozilla::ThreadStackHelper::GetStacksInternal(mozilla::Telemetry::HangStack *,std::vector<unsigned __int64,std::allocator<unsigned __int64> > *,nsACString &) [ThreadStackHelper.cpp:703825995ef4 : 175 + 0x35]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff250   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffb986ab57b
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   4  xul.dll!mozilla::BackgroundHangManager::RunMonitorThread() [BackgroundHangMonitor.cpp:703825995ef4 : 369 + 0x8]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff700   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffb986ae632
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   5  xul.dll!mozilla::BackgroundHangManager::MonitorThread(void *) [BackgroundHangMonitor.cpp:703825995ef4 : 71 + 0x8]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff760   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffb986ac04e
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   6  nss3.dll!PR_NativeRunThread [pruthr.c:703825995ef4 : 397 + 0x7]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff790   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffbb9b2640a
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   7  nss3.dll!pr_root [w95thred.c:703825995ef4 : 95 + 0x6]
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff7c0   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffbb9b1965e
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   8  ucrtbase.dll!BaseDllModifyMappedFile + 0x4d
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff7f0   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffbcbe20369
20:22:36     INFO -      Found by: call frame info
20:22:36     INFO -   9  ntdll.dll!SdbpCheckMatchingRegistryEntry + 0x29d
20:22:36     INFO -      rbx = 0x00000089b73ff2c0   rbp = 0x0000000000000000
20:22:36     INFO -      rsp = 0x00000089b73ff850   r12 = 0x0000000000000000
20:22:36     INFO -      r13 = 0x0000000000001a4f   r14 = 0x00000089b73ff288
20:22:36     INFO -      r15 = 0x00000089b73fb220   rip = 0x00007ffbcf8b0d61
20:22:36     INFO -      Found by: call frame info

Comment 9

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Windows x64 opt mochitest failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=0fef3ce5bc6360bedb4548cc4c3396c7480f6406&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=runnable

Comment 10

[Intermittent Failures Robot]

8 failures in 720 pushes (0.011 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 4
* mozilla-inbound: 3
* pine: 1

Platform breakdown:
* windows8-64: 7
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1380096&startday=2017-07-10&endday=2017-07-16&tree=all

Comment 12

[Nika Layzell [:nika] (ni? for response)]

Attachment: Avoid non-null terminated strings and heap for main thread runnable name

For some reason, I continuously ran into windows x64 specific failures when
trying to read this heap allocated data while the main thread was paused. I
don't know specifically how this happened, but I am able to avoid it by instead
directly allocating the buffer in a `mozilla::Array` in static storage, and
copying that data instead.

MozReview-Commit-ID: 473d6IpHlc4

Comment 13

[Eric Rahm [:erahm]]

Comment on attachment 8887160 [details] [diff] [review]
Avoid non-null terminated strings and heap for main thread runnable name

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

So it kind of clicked that we could use a `Span` here for the push/pop runnable name portion. I don't feel super strongly about this and would rather avoid a ton of review churn. So r+ as-is b/c I think it gets the job done, but I'd be happy to review a different version (if it even makes sense).

::: xpcom/threads/ThreadStackHelper.cpp
@@ +137,5 @@
>  #ifdef MOZ_THREADSTACKHELPER_NATIVE
>    ScopedSetPtr<NativeStack> nativeStackPtr(mNativeStackToFill, aNativeStack);
>  #endif
>  
> +  Array<char, nsThread::kRunnableNameBufSize> runnableName;

I suppose this is an argument for nsAutoCString<size_t N>, I've got a bug filed for that somewhere. I wonder if just doing the following would suffice:

> nsCString runnableName;
> runnableName.SetCapacity(1000);

I don't feel strongly either way here. One has a dynamic allocation but handles string stuff, the other just uses the stack with some hand-holding.

::: xpcom/threads/nsThread.cpp
@@ +98,5 @@
>  #define LOG(args) MOZ_LOG(sThreadLog, mozilla::LogLevel::Debug, args)
>  
>  NS_DECL_CI_INTERFACE_GETTER(nsThread)
>  
> +Array<char, nsThread::kRunnableNameBufSize> nsThread::sMainThreadRunnableName;

I wonder if this could just be a Span<char> and we could avoid copying. I guess it depends on the lifetime of the data though, although the previous version indicates that would probably be fine.

@@ +1430,1 @@
>            sMainThreadRunnableName = restoreRunnableName;

It's kind of a shame that this copies 1000 chars each time when we're probably using 16 or so.

@@ +1438,5 @@
> +        // terminating null.
> +        uint32_t length = std::min((uint32_t) kRunnableNameBufSize - 1,
> +                                   (uint32_t) name.Length());
> +        memcpy(sMainThreadRunnableName.begin(), name.BeginReading(), length);
> +        sMainThreadRunnableName[length] = '\0';

(continuing span thought) ...and then this would just be |sMainTheadRunnableName = name|

Comment 14

[Nika Layzell [:nika] (ni? for response)]

I agree it would be nicer - but I think I just want to fix the crash now, and then come back to making this more efficient if it turns out we need it.

If we get some perf hits or this starts appearing in profiles, I'll definitely improve perf.

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/bd9af2730ced
Avoid non-null terminated strings and heap for main thread runnable name, r=erahm

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/bd9af2730ced