"trace_test (with patch)" is flaky |
|||||||||||
Issue description"trace_test (with patch)" is flaky. This issue was created automatically by the chromium-try-flakes app. Please find the right owner to fix the respective test/step and assign this issue to them. If the step/test is infrastructure-related, please add Infra-Troopers label and change issue status to Untriaged. When done, please remove the issue from Sheriff Bug Queue by removing the Sheriff-Chromium label. We have detected 3 recent flakes. List of all flakes can be found at https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyIgsSBUZsYWtlIhd0cmFjZV90ZXN0ICh3aXRoIHBhdGNoKQw. Flaky tests should be disabled within 30 minutes unless culprit CL is found and reverted. Please see more details here: https://sites.google.com/a/chromium.org/dev/developers/tree-sheriffs/sheriffing-bug-queues#triaging-auto-filed-flakiness-bugs
,
Apr 1 2016
,
Apr 1 2016
OTOH, there are other flaky tests in the most recent 5 reports: - trace_test.2DCanvasWebGL x 1 - trace_test.WebGLGreenTriangle x 4 - trace_test.ScissorTestWithPreserveDrawingBuffer x 4
,
Apr 1 2016
The assertion failure causing these tests to fail is:
[ RUN ] trace_test.2DCanvasWebGL
(INFO) 2016-04-01 10:35:08,757 chrome_tracing_agent._CreateTraceConfigFile:175 Trace config file string: {"trace_config":{"included_categories": ["disabled-by-default-gpu.service", "disabled-by-default-gpu.device"], "record_mode": "record-as-much-as-possible"}}
(INFO) 2016-04-01 10:35:08,762 tracing_backend.StartTracing:120 Start Tracing Request: {'params': {'transferMode': 'ReturnAsStream', 'options': 'record-as-much-as-possible', 'categories': 'disabled-by-default-gpu.service,disabled-by-default-gpu.device'}, 'method': 'Tracing.start'}
[4452:4600:0401/103508:FATAL:trace_event_impl.cc(188)] Check failed: duration_.ToInternalValue() == -1 (3 vs. -1)
Backtrace:
GetHandleVerifier [0x636B8567+254679]
RelaunchChromeBrowserWithNewCommandLineIfNeeded [0x63671761+2232129]
GetHandleVerifier [0x636CBC22+334226]
GetHandleVerifier [0x63686EF3+52323]
GetHandleVerifier [0x636AB085+200181]
GetHandleVerifier [0x636AA391+196865]
GetHandleVerifier [0x636DCA52+403394]
GetHandleVerifier [0x636A2B32+166050]
BaseThreadInitThunk [0x74AF337A+18]
RtlInitializeExceptionChain [0x76F592B2+99]
RtlInitializeExceptionChain [0x76F59285+54]
The bug is that TraceEvent::UpdateDuration is being called more than once.
I'm still looking through the git log since yesterday to see what could have caused this flakiness. Possible candidate:
tracing: Add the TimeTicks clock source as trace metadata
https://codereview.chromium.org/1826973004
Still looking.
,
Apr 1 2016
Found by zmo@ from https://chromium.googlesource.com/chromium/src/+log/master/base/trace_event : [tracing] Adding task information to heap profiler https://chromium.googlesource.com/chromium/src/+/533c402f8b21e503ebcaf3f0de427f41076b4de1 [tracing] Add thread name to the pseudo stack of heap profiler https://chromium.googlesource.com/chromium/src/+/b3fabc66203904dd110597b11ebb89b89697f1a9
,
Apr 1 2016
I went through the entire git log since yesterday and none are obvious culprits. We really need symbolized stack traces on Windows on the bots -- Issue 561763 . I am going to mark all of these tests as flaky on Windows and in parallel try to reproduce the crash locally so we get a stack trace.
,
Apr 1 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/04c35ed6a7a894c6be4fec983c2b51084d11af0a commit 04c35ed6a7a894c6be4fec983c2b51084d11af0a Author: kbr <kbr@chromium.org> Date: Fri Apr 01 19:16:40 2016 Mark all tests in trace_test flaky on Windows. BUG= 599794 NOTRY=true CQ_INCLUDE_TRYBOTS=tryserver.chromium.win:win_optional_gpu_tests_rel;tryserver.chromium.mac:mac_optional_gpu_tests_rel Review URL: https://codereview.chromium.org/1851893002 Cr-Commit-Position: refs/heads/master@{#384657} [modify] https://crrev.com/04c35ed6a7a894c6be4fec983c2b51084d11af0a/content/test/gpu/gpu_tests/trace_test_expectations.py
,
Apr 1 2016
Thanks for helping out - based on #c7, I'll remove this bug from sheriffs' queue.
,
Apr 1 2016
Aha! Here's a failure on Linux which does have a symbolized stack trace. https://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_rel_ng/builds/205571 [ RUN ] trace_test.2DCanvasWebGL (INFO) 2016-04-01 10:55:18,259 chrome_tracing_agent._CreateTraceConfigFile:175 Trace config file string: {"trace_config":{"included_categories": ["disabled-by-default-gpu.service", "disabled-by-default-gpu.device"], "record_mode": "record-as-much-as-possible"}} (INFO) 2016-04-01 10:55:18,265 tracing_backend.StartTracing:120 Start Tracing Request: {'params': {'transferMode': 'ReturnAsStream', 'options': 'record-as-much-as-possible', 'categories': 'disabled-by-default-gpu.service,disabled-by-default-gpu.device'}, 'method': 'Tracing.start'} [14392:14424:0401/105518:FATAL:trace_event_impl.cc(188)] Check failed: duration_.ToInternalValue() == -1 (2 vs. -1) #0 0x7fb4d38dc02e base::debug::StackTrace::StackTrace() #1 0x7fb4d38f2d7b logging::LogMessage::~LogMessage() #2 0x7fb4d396fefe base::trace_event::TraceEvent::UpdateDuration() #3 0x7fb4d3958fb9 base::trace_event::TraceLog::UpdateTraceEventDuration() #4 0x7fb4d3937fd5 base::SequencedWorkerPool::Inner::ThreadLoop() #5 0x7fb4d3937732 base::SequencedWorkerPool::Worker::Run() #6 0x7fb4d393b01d base::SimpleThread::ThreadMain() #7 0x7fb4d3936ebd base::(anonymous namespace)::ThreadFunc() #8 0x7fb4caa43182 start_thread #9 0x7fb4c7c3147d clone That seems like a pretty generic stack trace though. Can anyone more familiar with the tracing subsystem look at that stack and see why the trace event's being updated twice?
,
Apr 1 2016
,
Apr 1 2016
Its Probably my change, I dded a trace event in SequencedWorkerPool::Inner::ThreadLoop, can you please revert my patch and I will take a look when i have time. [tracing] Adding task information to heap profiler https://chromium.googlesource.com/chromium/src/+/533c402f8b21e503ebcaf3f0de427f41076b4de1
,
Apr 1 2016
,
Apr 1 2016
Thanks ssid@. Reverting in https://codereview.chromium.org/1846333002/ .
,
Apr 1 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/fa6a6c8ffd27e62b30b2313ad74018570eadabaa commit fa6a6c8ffd27e62b30b2313ad74018570eadabaa Author: kbr <kbr@chromium.org> Date: Fri Apr 01 21:47:44 2016 Revert of Mark all tests in trace_test flaky on Windows. (patchset #1 id:1 of https://codereview.chromium.org/1851893002/ ) Reason for revert: Root cause has been reverted in https://codereview.chromium.org/1846333002/ . Original issue's description: > Mark all tests in trace_test flaky on Windows. > > BUG= 599794 > NOTRY=true > CQ_INCLUDE_TRYBOTS=tryserver.chromium.win:win_optional_gpu_tests_rel;tryserver.chromium.mac:mac_optional_gpu_tests_rel > > Committed: https://crrev.com/04c35ed6a7a894c6be4fec983c2b51084d11af0a > Cr-Commit-Position: refs/heads/master@{#384657} TBR=zmo@chromium.org # Skipping CQ checks because original CL landed less than 1 days ago. NOPRESUBMIT=true NOTREECHECKS=true NOTRY=true BUG= 599794 Review URL: https://codereview.chromium.org/1855443003 Cr-Commit-Position: refs/heads/master@{#384696} [modify] https://crrev.com/fa6a6c8ffd27e62b30b2313ad74018570eadabaa/content/test/gpu/gpu_tests/trace_test_expectations.py
,
Apr 1 2016
Calling this fixed. Please reopen if the flakiness persists.
,
Aug 17 2016
|
|||||||||||
►
Sign in to add a comment |
|||||||||||
Comment 1 by lukasza@chromium.org
, Apr 1 2016