1497985 - Intermittent ProfileBuffer parse error: expected one or more frame entriesAssertion failure: false (expected one or more frame entries), at z:/build/build/src/tools/profiler/core/ProfileBufferEntry.cpp:1102

Reporter

Description

•

3 years ago

treeherder

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=204566496&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/Mk9v1TOdTkWjl3pIGGASqw/runs/0/artifacts/public/logs/live_backing.log

18:05:07     INFO -  TEST-START | GeckoProfiler.Counters
18:05:08     INFO -  ProfileBuffer parse error: expected one or more frame entriesAssertion failure: false (expected one or more frame entries), at z:/build/build/src/tools/profiler/core/ProfileBufferEntry.cpp:1102
18:05:27     INFO -  #01: ProfiledThreadData::StreamJSON(ProfileBuffer const &,JSContext *,SpliceableJSONWriter &,mozilla::TimeStamp const &,double) [tools/profiler/core/ProfiledThreadData.cpp:66]
18:05:27     INFO -  #02: static void locked_profiler_stream_json_for_this_process(const class mozilla::BaseAutoLock<PSMutex &> & const, class SpliceableJSONWriter & const, double, bool) [tools/profiler/core/platform.cpp:1894]
18:05:27     INFO -  #03: profiler_stream_json_for_this_process(SpliceableJSONWriter &,double,bool) [tools/profiler/core/platform.cpp:1957]
18:05:27     INFO -  #04: GeckoProfiler_Counters_Test::TestBody() [tools/profiler/tests/gtest/GeckoProfiler.cpp:569]
18:05:27     INFO -  #05: testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2406]
18:05:27     INFO -  #06: testing::Test::Run() [testing/gtest/gtest/src/gtest.cc:2476]
18:05:27     INFO -  #07: testing::TestInfo::Run() [testing/gtest/gtest/src/gtest.cc:2662]
18:05:27     INFO -  #08: testing::TestCase::Run() [testing/gtest/gtest/src/gtest.cc:2775]
18:05:27     INFO -  #09: testing::internal::UnitTestImpl::RunAllTests() [testing/gtest/gtest/src/gtest.cc:4650]
18:05:27     INFO -  #10: testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2406]
18:05:27     INFO -  #11: testing::UnitTest::Run() [testing/gtest/gtest/src/gtest.cc:4259]
18:05:27     INFO -  #12: mozilla::RunGTestFunc(int *,char * *) [testing/gtest/mozilla/GTestRunner.cpp:113]
18:05:27     INFO -  #13: XREMain::XRE_mainStartup(bool *) [toolkit/xre/nsAppRunner.cpp:3968]
18:05:27     INFO -  #14: XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:4907]
18:05:27     INFO -  #15: XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:5014]
18:05:27     INFO -  #16: NS_internal_main(int,char * *,char * *) [browser/app/nsBrowserApp.cpp:315]
18:05:27     INFO -  #17: wmain [toolkit/xre/nsWindowsWMain.cpp:143]
18:05:27     INFO -  #18: static int __scrt_common_main_seh() [f:/dd/vctools/crt/vcstartup/src/startup/exe_common.inl:288]
18:05:27     INFO -  #19: KERNEL32.DLL + 0x12774
18:05:27     INFO -  #20: ntdll.dll + 0x70d61
18:05:27     INFO -  mozcrash INFO | Copy/paste: Z:\task_1539193664\build\win32-minidump_stackwalk.exe Z:\task_1539193664\build\tests\gtest\3aa2463f-4cd5-4ea7-8844-c3fee24820fe.dmp Z:\task_1539193664\build\symbols
18:05:36     INFO -  mozcrash INFO | Saved minidump as Z:\task_1539193664\build\blobber_upload_dir\3aa2463f-4cd5-4ea7-8844-c3fee24820fe.dmp
18:05:36     INFO -  mozcrash INFO | Saved app info as Z:\task_1539193664\build\blobber_upload_dir\3aa2463f-4cd5-4ea7-8844-c3fee24820fe.extra
18:05:36  WARNING -  PROCESS-CRASH | gtest | application crashed [@ ProfileBuffer::StreamSamplesToJSON(SpliceableJSONWriter &,int,double,UniqueStacks &)]
18:05:36     INFO -  Crash dump filename: Z:\task_1539193664\build\tests\gtest\3aa2463f-4cd5-4ea7-8844-c3fee24820fe.dmp
18:05:36     INFO -  Operating system: Windows NT
18:05:36     INFO -                    10.0.15063
18:05:36     INFO -  CPU: amd64
18:05:36     INFO -       family 6 model 63 stepping 2
18:05:36     INFO -       8 CPUs
18:05:36     INFO -  GPU: UNKNOWN
18:05:36     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
18:05:36     INFO -  Crash address: 0x7ffe562ad7c4
18:05:36     INFO -  Process uptime: 479 seconds
18:05:36     INFO -  Thread 0 (crashed)
18:05:36     INFO -   0  xul.dll!ProfileBuffer::StreamSamplesToJSON(SpliceableJSONWriter &,int,double,UniqueStacks &) [ProfileBufferEntry.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 1102 + 0x0]
18:05:36     INFO -      rax = 0x0000000000000000   rdx = 0x000000b152dfebc8
18:05:36     INFO -      rcx = 0x00000000ffffffff   rbx = 0x000000b152dfee80
18:05:36     INFO -      rsi = 0x0000000000000000   rdi = 0x0002000100000000
18:05:36     INFO -      rbp = 0x00000000000014c3   rsp = 0x000000b152dfebb0
18:05:36     INFO -       r8 = 0x000000b152dfebc0    r9 = 0x000000b152dfebb8
18:05:36     INFO -      r10 = 0x0000000000000000   r11 = 0x000000b152dfa1f0
18:05:36     INFO -      r12 = 0x00000000000014c3   r13 = 0x00000000000018d0
18:05:36     INFO -      r14 = 0x0000022086c5a540   r15 = 0x000000b152dff380
18:05:36     INFO -      rip = 0x00007ffe562ad7c4
18:05:36     INFO -      Found by: given as instruction pointer in context
18:05:36     INFO -   1  xul.dll!StreamSamplesAndMarkers(char const *,int,ProfileBuffer const &,SpliceableJSONWriter &,mozilla::TimeStamp const &,mozilla::TimeStamp const &,mozilla::TimeStamp const &,double,UniqueStacks &) [ProfiledThreadData.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 157 + 0x20]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dfed40   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe562b0771
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   2  xul.dll!ProfiledThreadData::StreamJSON(ProfileBuffer const &,JSContext *,SpliceableJSONWriter &,mozilla::TimeStamp const &,double) [ProfiledThreadData.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 60 + 0x2d]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dfee20   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe562b00f1
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   3  xul.dll!static void locked_profiler_stream_json_for_this_process(const class mozilla::BaseAutoLock<PSMutex &> & const, class SpliceableJSONWriter & const, double, bool) [platform.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 1899 + 0x16]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff060   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe562b415d
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   4  xul.dll!profiler_stream_json_for_this_process(SpliceableJSONWriter &,double,bool) [platform.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 1957 + 0x13]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff290   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe562b2f85
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   5  xul.dll!GeckoProfiler_Counters_Test::TestBody() [GeckoProfiler.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 569 + 0xc]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff300   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe570cfd09
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   6  xul.dll!testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 2389 + 0x2]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff420   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cf1a90
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   7  xul.dll!testing::Test::Run() [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 2476 + 0x2b]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff490   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56ccd144
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   8  xul.dll!testing::TestInfo::Run() [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 2658 + 0x8]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff4d0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cce6e0
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -   9  xul.dll!testing::TestCase::Run() [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 2776 + 0x5]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff550   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cced77
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  10  xul.dll!testing::internal::UnitTestImpl::RunAllTests() [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 4651 + 0x5]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff5c0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cd8a07
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  11  xul.dll!testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 2389 + 0x2]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff650   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cf2390
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  12  xul.dll!testing::UnitTest::Run() [gtest.cc:5899ae8c1e091aed4697af62b98a621118e1059d : 4259 + 0x2f]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff6c0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cd8664
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  13  xul.dll!mozilla::RunGTestFunc(int *,char * *) [GTestRunner.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 113 + 0xd]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff710   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56cf3876
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  14  xul.dll!XREMain::XRE_mainStartup(bool *) [nsAppRunner.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 3968 + 0x10]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff7b0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe5665bf82
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  15  xul.dll!XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 4907 + 0xd]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dff9c0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56663128
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  16  xul.dll!XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 5014 + 0x10]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dffaa0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe56663f38
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  17  firefox.exe!NS_internal_main(int,char * *,char * *) [nsBrowserApp.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 315 + 0x3d]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dffc60   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ff783ad16d8
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  18  firefox.exe!wmain [nsWindowsWMain.cpp:5899ae8c1e091aed4697af62b98a621118e1059d : 143 + 0x15]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dffe00   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ff783ad122e
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  19  firefox.exe!static int __scrt_common_main_seh() [exe_common.inl : 288 + 0x22]
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dffeb0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ff783b40810
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  20  kernel32.dll!BaseThreadInitThunk + 0x14
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dffef0   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe86bd2774
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  21  ntdll.dll!SdbpCheckMatchingRegistryEntry + 0x29d
18:05:36     INFO -      rbx = 0x000000b152dfee80   rbp = 0x00000000000014c3
18:05:36     INFO -      rsp = 0x000000b152dfff20   r12 = 0x00000000000014c3
18:05:36     INFO -      r13 = 0x00000000000018d0   r14 = 0x0000022086c5a540
18:05:36     INFO -      r15 = 0x000000b152dff380   rip = 0x00007ffe880a0d61
18:05:36     INFO -      Found by: call frame info
18:05:36     INFO -  22  KERNELBASE.dll + 0x67c0
18:05:36     INFO -      rsp = 0x000000b152dfff50   rip = 0x00007ffe84b267c0
18:05:36     INFO -      Found by: stack scanning

Andreea Pavel [:apavel]

Comment 1

•

3 years ago

This appears to be from Bug 1471197: 

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&selectedJob=204566496&searchStr=windows,10,x64,debug,test-windows10-64%2Fdebug-gtest,(gtest)&tochange=5899ae8c1e091aed4697af62b98a621118e1059d&fromchange=9330053d330f2d8144cab69a6b035cdd6aedf0ee

Aki, can you take a look ?

Flags: needinfo?(aki)

Comment hidden (Intermittent Failures Robot)

16 failures in 552 pushes (0.029 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-central: 8
* mozilla-inbound: 3
* autoland: 5

Platform breakdown:
* windows7-32-msvc: 6
* windows7-32: 7
* windows10-64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-10&endday=2018-10-10&tree=all

Sebastian Hengst [:aryx] (needinfo on intermittent or backout)

Comment 3

•

3 years ago

Regression from bug 1464509? Randall, can you take a look at this, please?

Blocks: 1464509

Flags: needinfo?(aki)

Comment hidden (Intermittent Failures Robot)

32 failures in 537 pushes (0.06 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-central: 8
* autoland: 12
* mozilla-inbound: 8
* try: 4

Platform breakdown:
* windows7-32: 22
* windows7-32-msvc: 4
* windows10-64: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-11&endday=2018-10-11&tree=all

Comment hidden (Intermittent Failures Robot)

29 failures in 515 pushes (0.056 failures/push) were associated with this bug yesterday.

Repository breakdown:
* try: 1
* mozilla-central: 8
* mozilla-inbound: 5
* autoland: 15

Platform breakdown:
* windows10-64: 3
* windows7-32-msvc: 3
* windows7-32: 22
* windows10-64-msvc: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-12&endday=2018-10-12&tree=all

Comment hidden (Intermittent Failures Robot)

17 failures in 147 pushes (0.116 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-central: 4
* autoland: 6
* mozilla-inbound: 7

Platform breakdown:
* windows7-32: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-13&endday=2018-10-13&tree=all

Julien Wajsberg [:julienw]

Comment 7

•

3 years ago

Hey Randell, looks like bug 1464509 made this test very intermittent (10%!!). Can you look at it shortly, or backout the patch if possible?
Thanks!

Flags: needinfo?(rjesup)

Julien Wajsberg [:julienw]

Updated

•

3 years ago

status-firefox63: --- → unaffected

status-firefox64: --- → affected

Keywords: crash

Randell Jesup [:jesup] (needinfo me)

Assignee

Comment 8

•

3 years ago

I'll try to look at this this afternoon and/or on the plane later.

Randell Jesup [:jesup] (needinfo me)

Assignee

Comment 9

•

3 years ago

Hmmm.   Code seems reasonable, so I suppose it's a timing issue with the tests - perhaps it doesn't start sampling in the 200ms I give it in automation (though I ran a couple of dozen retriggers across multiple platforms before landing).  I've run it several dozen times locally on linux with no failures.  All the failures reported above are from windows, but I can't windows to run local gtests (works fine on Linux).

We could simply up the timeout from 200ms to 500ms (which the other tests use).  10ms seemed to work for Linux; I upped it to 200 just to be safe (and Markus commented we should add a function to wait for it to start before processing).

However.... we must have a ThreadID and a Time to get to this assertion, but apparently no following stack samples.  That's odd, and I don't see how that can happen.  I'd love to repro in a debugger.   (Counters and ResidentMemory use Time entries, but don't prefix them with a ThreadId.)

Any thoughts Markus?

Flags: needinfo?(rjesup) → needinfo?(mstange)

Comment hidden (Intermittent Failures Robot)

115 failures in 2740 pushes (0.042 failures/push) were associated with this bug in the last 7 days.

This is the #11 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. ** 

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. ** 

Repository breakdown:
* try: 10
* autoland: 45
* mozilla-central: 31
* mozilla-inbound: 29

Platform breakdown:
* windows10-64-msvc: 1
* windows10-64: 12
* windows7-32-msvc: 13
* windows7-32: 89

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-08&endday=2018-10-14&tree=all

Randell Jesup [:jesup] (needinfo me)

Assignee

Comment 11

•

3 years ago

I've looked more at this.  It's failing mostly on Win7 debug (32 bit) - near permafail - much lower but non-0 failure rate on win10x64 debug.

https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=205523140&revision=ec4db0afd9476a7ae66cd3e332c1a2017f474bf8

Running a local windows 64bit debug build, even looping the COunters test 100 times doesn't fail on my local laptop

Randell Jesup [:jesup] (needinfo me)

Assignee

Comment 12

•

3 years ago

Attached patch Allow for MergeStacks() not writing any stacks within a sample — Details — Splinter Review

Attachment #9017336 - Flags: review?(mstange)

Randell Jesup [:jesup] (needinfo me)

Assignee

Updated

•

3 years ago

Assignee: nobody → rjesup

Status: NEW → ASSIGNED

Markus Stange [:mstange]

Comment 13

•

3 years ago

Comment on attachment 9017336 [details] [diff] [review]
Allow for MergeStacks() not writing any stacks within a sample

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

::: tools/profiler/core/ProfileBufferEntry.cpp
@@ +1098,5 @@
>        }
>      }
>  
>      if (numFrames == 0) {
> +      // If you have just the Threads feature enabled, MergeStacks() might

Let's not mention the Threads feature here, it's unrelated. Let's just say "It is possible to have empty stacks if native stackwalking is disabled. Skip samples with empty stacks."

Attachment #9017336 - Flags: review?(mstange) → review+

Pulsebot

Comment 14

•

3 years ago

Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ec837a14f8e8
Allow for MergeStacks() not writing any stacks within a sample r=mstange

Comment hidden (Intermittent Failures Robot)

32 failures in 475 pushes (0.067 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-central: 3
* try: 8
* mozilla-inbound: 6
* autoland: 15

Platform breakdown:
* windows10-64: 4
* windows7-32: 28

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-15&endday=2018-10-15&tree=all

Eliza Balazs [:ebalazs_]

Comment 16

•

3 years ago

bugherder

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

Status: ASSIGNED → RESOLVED

Closed: 3 years ago

status-firefox64: affected → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla64

Ryan VanderMeulen [:RyanVM]

Updated

•

3 years ago

status-firefox62: --- → unaffected

status-firefox-esr60: --- → unaffected

Eliza Balazs [:ebalazs_]

Updated

•

3 years ago

Blocks: 1500015

Julien Wajsberg [:julienw]

Updated

•

3 years ago

Duplicate of this bug: 1500015

Comment hidden (Intermittent Failures Robot)

47 failures in 2759 pushes (0.017 failures/push) were associated with this bug in the last 7 days.

This is the #40 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

Repository breakdown:
* mozilla-inbound: 9
* autoland: 23
* mozilla-central: 6
* try: 9

Platform breakdown:
* windows7-32: 42
* windows10-64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1497985&startday=2018-10-15&endday=2018-10-21&tree=all

Julien Wajsberg [:julienw]

Comment 19

•

3 years ago

> ** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

We see on the link above that it completely stopped since October 17. 👍

Eliza Balazs [:ebalazs_]

Comment 20

•

3 years ago

Clearing the [stockwell disable-recommended] tag. See Comment 19.

Whiteboard: [stockwell disable-recommended]