New issue
Advanced search Search tips

Issue 832600 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Apr 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: ----



Sign in to add a comment

services_unittests failing on chromium.android/KitKat Phone Tester (dbg)

Project Member Reported by sheriff-...@appspot.gserviceaccount.com, Apr 13 2018

Issue description

Filed by sheriff-o-matic@appspot.gserviceaccount.com on behalf of arthursonzogni@google.com

services_unittests failing on chromium.android/KitKat Phone Tester (dbg)

Builders failed on: 
- KitKat Phone Tester (dbg): 
  https://build.chromium.org/p/chromium.android/builders/KitKat%20Phone%20Tester%20%28dbg%29

The flaky tests are:
SimpleURLLoaderTest.BigResponseBodyWithSizeAboveLimitPartialResponse/1
SimpleURLLoaderTest.BigResponseBodyWithSizeAboveLimitPartialResponse/2

 
Components: Internals>Network Internals>Mojo
It became flaky since build #5327. I don't see any suspect in build #5327/5326/5325.

StackTrace is:
```
  00e25261  logging::LogMessage::~LogMessage()                                                                                                                                                                                                                                                                                                             ../../base/logging.cc:594:29
  00d0c33d  mojo::ScopedHandleBase<mojo::DataPipeConsumerHandle>::operator->() const                                                                                                                                                                                                                                                                       ../../mojo/public/cpp/system/handle.h:98:5
  01da5e3b  network::NetToMojoPendingBuffer::BeginWrite(mojo::ScopedHandleBase<mojo::DataPipeProducerHandle>*, scoped_refptr<network::NetToMojoPendingBuffer>*, unsigned int*)                                                                                                                                                                             ../../services/network/public/cpp/net_adapters.cc:32:7
  01da017d  network::URLLoader::ReadMore()                                                                                                                                                                                                                                                                                                                 ../../services/network/url_loader.cc:589:25
  00cbaae5  base::OnceCallback<void ()>::Run() &&                                                                                                                                                                                                                                                                                                          ../../base/callback.h:95:12
  00e1531f  base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)                                                                                                                                                                                                                                                                           ../../base/debug/task_annotator.cc:101:33
  00e29099  base::internal::IncomingTaskQueue::RunTask(base::PendingTask*)                                                                                                                                                                                                                                                                                 ../../base/message_loop/incoming_task_queue.cc:124:19
  00e2ab2d  base::MessageLoop::RunTask(base::PendingTask*)                                                                                                                                                                                                                                                                                                 ../../base/message_loop/message_loop.cc:354:25
  00e2ad33  base::MessageLoop::DeferOrRunPendingTask(base::PendingTask)                                                                                                                                                                                                                                                                                    ../../base/message_loop/message_loop.cc:364:5
  00e2ae01  base::MessageLoop::DoWork()                                                                                                                                                                                                                                                                                                                    ../../base/message_loop/message_loop.cc:408:16
  00e2c3c1  base::MessagePumpLibevent::Run(base::MessagePump::Delegate*)                                                                                                                                                                                                                                                                                   ../../base/message_loop/message_pump_libevent.cc:210:31
  00e2a8f3  base::MessageLoop::Run(bool)                                                                                                                                                                                                                                                                                                                   ../../base/message_loop/message_loop.cc:306:12
  00e4075b  base::RunLoop::Run()                                                                                                                                                                                                                                                                                                                           ../../base/run_loop.cc:130:14
  02628c1f  net::test_server::EmbeddedTestServer::PostTaskToIOThreadAndWait(base::RepeatingCallback<void ()> const&)                                                                                                                                                                                                                                       ../../net/test/embedded_test_server/embedded_test_server.cc:490:12
  02628409  net::test_server::EmbeddedTestServer::ShutdownAndWaitUntilComplete()                                                                                                                                                                                                                                                                           ../../net/test/embedded_test_server/embedded_test_server.cc:187:10
  026282e3  net::test_server::EmbeddedTestServer::~EmbeddedTestServer()                                                                                                                                                                                                                                                                                    ../../net/test/embedded_test_server/embedded_test_server.cc:63:21
  00d3b5e3  network::(anonymous namespace)::SimpleURLLoaderTestBase::~SimpleURLLoaderTestBase()                                                                                                                                                                                                                                                            ../../services/network/public/cpp/simple_url_loader_unittest.cc:549:39
  00d3ac31  network::(anonymous namespace)::SimpleURLLoaderTest_DataURL_Test::~SimpleURLLoaderTest_DataURL_Test()                                                                                                                                                                                                                                          ../../services/network/public/cpp/simple_url_loader_unittest.cc:1123:1
  01578747  testing::TestInfo::Run()                                                                                                                                                                                                                                                                                                                       ../../third_party/googletest/src/googletest/src/gtest.cc:2672:3
  01578935  testing::TestCase::Run()                                                                                                                                                                                                                                                                                                                       ../../third_party/googletest/src/googletest/src/gtest.cc:2785:28
  0157c339  testing::internal::UnitTestImpl::RunAllTests()                                                                                                                                                                                                                                                                                                 ../../third_party/googletest/src/googletest/src/gtest.cc:5047:43
  0157c199  testing::UnitTest::Run()                                                                                                                                                                                                                                                                                                                       ../../third_party/googletest/src/googletest/src/gtest.cc:4663:10
  025bdf61  base::TestSuite::Run()                                                                                                                                                                                                                                                                                                                         ../../base/test/test_suite.cc:275:16
  00e1fad1  base::OnceCallback<bool ()>::Run() &&                                                                                                                                                                                                                                                                                                          ../../base/callback.h:95:12
  v------>  base::(anonymous namespace)::LaunchUnitTestsInternal(base::OnceCallback<int ()>, unsigned int, int, bool, base::OnceCallback<void ()>)                                                                                                                                                                                                         ../../base/test/launcher/unit_test_launcher.cc:201:36
  025c7403  base::LaunchUnitTests(int, char**, base::OnceCallback<int ()>)                                                                                                                                                                                                                                                                                 ../../base/test/launcher/unit_test_launcher.cc:576:0
  02498389  service_manager::InitializeAndLaunchUnitTests(int, char**, base::OnceCallback<int ()>)                                                                                                                                                                                                                                                         ../../services/service_manager/public/cpp/test/common_initialization.cc:46:10
  00e02ce5  main                                                          
```

+CC mmenke FYI.
Cc: mmenke@chromium.org
Description: Show this description
Owner: mmenke@chromium.org
I wanted to start a bisection, but I can't reproduce it locally. It always passes [25/25].

mmenke@ Can I assign this issue to you?

Comment 5 by mmenke@chromium.org, Apr 13 2018

I have too much of a backlog to look into this anytime soon, unfortunately.
Yes, I imagine... ;-)
If you know a better owner, let me know.

Looking at the trace, it looks like the callback network::URLLoader::ReadMore() is called, but in the meantime, the mojo data pipe: 'response_body_stream_' has been closed.

It looks like a race condition. Maybe we need to check whether or not the pipe has been closed and return early when it happens.

Comment 7 by gab@chromium.org, Apr 13 2018

Labels: -Pri-2 Pri-1
Status: Assigned (was: Available)
This is flaking try-bots. As such it's P1. Please disable the test if not fixing ASAP. Thanks!

I think the problem is that the members in SimpleURLLoaderTestBase list EmbeddedTestServer last. As such it's destroyed first. Usually task environment are destroyed last (as is ScopedTaskEnvironment here). Destroying the other members first would let them know to shutdown and cancel any remaining tasks (before the destructor attempts to force flush them). (now: whether destroying those members will cancel the right stuff here or there's more state, I don't know)

 protected:
  base::test::ScopedTaskEnvironment scoped_task_environment_;

  std::unique_ptr<network::mojom::NetworkService> network_service_;
  network::mojom::NetworkContextPtr network_context_;
  network::mojom::URLLoaderFactoryPtr url_loader_factory_;

  net::test_server::EmbeddedTestServer test_server_;

Comment 8 by mmenke@chromium.org, Apr 13 2018

Destroying the test server should not make a SimpleURLLoader crash.  While reordering items may prevent the failure, it seems like there's something else going on.

Comment 9 by mmenke@chromium.org, Apr 13 2018

Disabling all 4 "exceeds limits" tests.  I'm pretty sure there's a URLLoader bug, but haven't yet been able to repro (I suspect there's a posted read task, due to a sync read completion, we close the data pipe, and then the task executes, and we crash).
I believe this is fallout from  a DCHECK added in  issue 821030 , which would explain why I can reproduce it locally in a somewhat older checkout.  Fix shouldn't be too bad, I believe.
Project Member

Comment 11 by bugdroid1@chromium.org, Apr 18 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/de4f39b6ec411a54732a05e16da0ab5483f03535

commit de4f39b6ec411a54732a05e16da0ab5483f03535
Author: Matt Menke <mmenke@chromium.org>
Date: Wed Apr 18 15:26:53 2018

Fix URLLoader trying to read from a closed handle in some cases.

It's possible to URLLoader to have a posted ReadMore task when it
learns its producer data pipe has been closed. If this happens, when
ReadMore is executed, it would DCHECK, since reading from a pipe a
consumer knows is closed it a possible symptom of a bug.

This CL fixes that behavior, by deleting the URLLoader when either the
data pipe or the client pipe is closed, or when the request is
complete, rather than waiting for both consumer pipes to be closed.

Bug:  832600 
Cq-Include-Trybots: master.tryserver.chromium.linux:linux_mojo
Change-Id: I0334773c8e701eb7dd106fa1c0fe0890e80861e7
Reviewed-on: https://chromium-review.googlesource.com/1012455
Reviewed-by: Andrey Kosyakov <caseq@chromium.org>
Reviewed-by: John Abd-El-Malek <jam@chromium.org>
Commit-Queue: Matt Menke <mmenke@chromium.org>
Cr-Commit-Position: refs/heads/master@{#551684}
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/content/browser/devtools/devtools_url_loader_interceptor.cc
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/content/browser/loader/navigation_url_loader_network_service_unittest.cc
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/services/network/public/cpp/simple_url_loader_unittest.cc
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/services/network/url_loader.cc
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/services/network/url_loader.h
[modify] https://crrev.com/de4f39b6ec411a54732a05e16da0ab5483f03535/services/network/url_loader_unittest.cc

Labels: -Restrict-View-Google
Status: Fixed (was: Assigned)
Note that in release builds, the DCHECK won't be triggered, and the call will harmlessly be ignored, so I don't think this is worth merging to M67, since the fix affects some lifetime issues, and I want to give it plenty of time to bake before making it to stable, out of paranoia.

Since it's not actually a security issue, no reason to access-restrict this bug.
Project Member

Comment 13 by bugdroid1@chromium.org, Apr 18 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/e793c0b3fe1112c205e67d857fbbdc63bd83f602

commit e793c0b3fe1112c205e67d857fbbdc63bd83f602
Author: Matt Menke <mmenke@chromium.org>
Date: Wed Apr 18 17:17:32 2018

Disable URLLoaderTest.CloseResponseBodyConsumerBeforeProducer

It's failing on the tree.  It most likely broke due to
https://chromium-review.googlesource.com/1012455.  Will revert the
CL if there are any other failures.

TBR=jam@chromium.org
NOTREECHECKS=true
NOTRY=TRUE

Bug:  832600 
Cq-Include-Trybots: master.tryserver.chromium.linux:linux_mojo
Change-Id: I35da207aa89350bafcc36395a62e436cbbb6e5a4
Reviewed-on: https://chromium-review.googlesource.com/1016707
Commit-Queue: Matt Menke <mmenke@chromium.org>
Reviewed-by: Matt Menke <mmenke@chromium.org>
Cr-Commit-Position: refs/heads/master@{#551728}
[modify] https://crrev.com/e793c0b3fe1112c205e67d857fbbdc63bd83f602/services/network/url_loader_unittest.cc

Project Member

Comment 14 by bugdroid1@chromium.org, Apr 24 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/fc4ece303d96ec8985dfd922eb5017dbbbe5235d

commit fc4ece303d96ec8985dfd922eb5017dbbbe5235d
Author: Matt Menke <mmenke@chromium.org>
Date: Tue Apr 24 01:47:22 2018

Fix URLLoaderTest.CloseResponseBodyConsumerBeforeProducer.

This was broken by
https://chromium-review.googlesource.com/c/chromium/src/+/1016707.

It was exercising three URLLoader destruction paths, with that CL
landed:
* Mojo notification that the data pipe was closed.
* Mojo notification that the URLLoader pipe was closed.
* Noticing the data pipe was closed when trying to write to it.

The above CL made the first case fail with ERR_FAILED and the
other cases fail by just closing the pipe. This CL fixes that.

It also moves the URLLoader pipe closed case to another test,
and re-enables a new test I disabled pre-emptively when
disabling URLLoaderTest.CloseResponseBodyConsumerBeforeProducer,
which was not flaky.

Bug:  832600 
Cq-Include-Trybots: master.tryserver.chromium.linux:linux_mojo
Change-Id: I788b8a4d2819d623fc2e46a7a8109f91c32d0fbc
Reviewed-on: https://chromium-review.googlesource.com/1017441
Reviewed-by: John Abd-El-Malek <jam@chromium.org>
Commit-Queue: Matt Menke <mmenke@chromium.org>
Cr-Commit-Position: refs/heads/master@{#552951}
[modify] https://crrev.com/fc4ece303d96ec8985dfd922eb5017dbbbe5235d/services/network/url_loader.cc
[modify] https://crrev.com/fc4ece303d96ec8985dfd922eb5017dbbbe5235d/services/network/url_loader_unittest.cc

Sign in to add a comment