New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 599794 link

Starred by 0 users

Issue metadata

Status: Fixed
Owner:
OOO until 2019-01-24
Closed: Apr 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug

Blocking:
issue 594803
issue 638744



Sign in to add a comment

"trace_test (with patch)" is flaky

Project Member Reported by chromium...@appspot.gserviceaccount.com, Apr 1 2016

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
 
Flakiness happens mainly in these 2 tests:
trace_test.WebGLGreenTriangle
trace_test.ScissorTestWithPreserveDrawingBuffer
Cc: kbr@chromium.org zmo@chromium.org osh...@chromium.org
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

Comment 4 by kbr@chromium.org, Apr 1 2016

Cc: nduca@chromium.org nedngu...@google.com charliea@chromium.org dyen@chromium.org
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.

Comment 5 by kbr@chromium.org, Apr 1 2016

Cc: ssid@chromium.org
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

Comment 6 by kbr@chromium.org, Apr 1 2016

Owner: kbr@chromium.org
Status: Assigned (was: Untriaged)
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.

Project Member

Comment 7 by bugdroid1@chromium.org, 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

Labels: -Sheriff-Chromium
Thanks for helping out - based on #c7, I'll remove this bug from sheriffs' queue.

Comment 9 by kbr@chromium.org, Apr 1 2016

Cc: zh...@chromium.org primiano@chromium.org
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?

Comment 10 by kbr@chromium.org, Apr 1 2016

Components: Internals>GPU>Testing Internals>Tracing

Comment 11 by ssid@chromium.org, 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

Comment 12 by kbr@chromium.org, Apr 1 2016

Blocking: 594803

Comment 13 by kbr@chromium.org, Apr 1 2016

Thanks ssid@. Reverting in https://codereview.chromium.org/1846333002/ .

Project Member

Comment 14 by bugdroid1@chromium.org, 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

Comment 15 by kbr@chromium.org, Apr 1 2016

Status: Fixed (was: Assigned)
Calling this fixed. Please reopen if the flakiness persists.

Comment 16 by kbr@chromium.org, Aug 17 2016

Blocking: 638744

Sign in to add a comment