New issue
Advanced search Search tips

Issue 792525 link

Starred by 2 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Fuchsia
Pri: 3
Type: Bug

Blocking:
issue 738275



Sign in to add a comment

SpdyHttpStreamTest.SpdyURLTest

Project Member Reported by w...@chromium.org, Dec 6 2017

Issue description

Flaked on the Fuchsia bot:

[ RUN      ] SpdyHttpStreamTest.SpdyURLTest
../../net/spdy/chromium/spdy_http_stream_unittest.cc:861: Failure
Value of: HasSpdySession(http_session_->spdy_session_pool(), key_)
  Actual: true
Expected: false
[3:598563959:1206/111135.197555:259761443:FATAL:socket_test_util.cc(442)] Check failed: !helper_.AllWriteDataConsumed().
...

The expectation states that "we abandoned the stream", but I don't see anything in the test that is actually abandoning it.  The original change by erikchen@ that added the expectation also invoked data()->CompleteRead(), but that was subsequently removed, it seems.

Is the expectation that sending EOF causes the abandonment?
 

Comment 1 by w...@chromium.org, Dec 6 2017

Blocking: 738275

Comment 2 by rch@chromium.org, Dec 6 2017

Components: -Internals>Network>QUIC Internals>Network>HTTP2
Owner: b...@chromium.org

Comment 4 by b...@chromium.org, Dec 14 2017

Cc: b...@chromium.org scottmg@chromium.org
Owner: w...@chromium.org
https://logs.chromium.org/v/?s=chromium%2Fbb%2Fchromium.fyi%2FFuchsia%2F11946%2F%2B%2Frecipes%2Fsteps%2Fnet_unittests%2F0%2Fstdout shows the following:

[00260.273] 03763.03789> [4583/19143] SpdyHttpStreamTest.ChunkedPostWithEmptyPayload (19 ms)
[00260.273] 03763.03789> [ RUN      ] SpdyHttpStreamTest.SpdyURLTest
[00260.273] 03763.03789> ../../net/spdy/chromium/spdy_http_stream_unittest.cc:861: Failure
[00260.273] 03763.03789> Valu127.0.0.1 - - [06/Dec/2017 03:11:38] "GET /kill?port=59010 HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:39] "POST /start HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:40] "GET /kill?port=36809 HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:41] "POST /start HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:42] "GET /kill?port=41741 HTTP/1.1" 200 -
e of: HasSpdySession(http_session_->spdy_session_pool(), key_)
[00260.273] 03763.03789>   Actual: true
[00260.273] 03763.03789> Expected: false
[00260.274] 03763.03789> [3:598563959:1206/111135.197555:259761443:FATAL:socket_test_util.cc(442)] Check failed: !helper_.AllWriteDataConsumed().
#00: pc 0xcfaf4680ca0 (app:net_unittests,0x3089ca0)
#01: pc 0xcfaf4627281 (app:net_unittests,0x3030281)
#02: pc 0xcfaf45e7643 (app:net_unittests,0x2ff0643)
#03: pc 0xcfaf45e9da1 (app:net_unittests,0x2ff2da1)
#04: pc 0xcfaf455495e (app:net_unittests,0x2f5d95e)
#05: pc 0xcfaf4554202 (app:net_unittests,0x2f5d202)
#06: pc 0xcfaf45540f9 (app:net_unittests,0x2f5d0f9)
#07: pc 0xcfaf462f8d7 (app:net_unittests,0x30388d7)
#08: pc 0xcfaf462cde4 (app:net_unittests,0x3035de4)
#09: pc 0xcfaf462d3d7 (app:net_unittests,0x30363d7)
#10: pc 0xcfaf4683c39 (app:net_unittests,0x308cc39)
#11: pc 0xcfaf4640194 (app:net_unittests,0x3049194)
#12: pc 0xcfaf365efaa (app:net_unittests,0x2067faa)
#13: pc 0xcfaf3c66480 (app:net_unittests,0x266f480)
#14: pc 0xcfaf3c66967 (app:net_unittests,0x266f967)
#15: pc 0xcfaf3c6cae7 (app:net_unittests,0x2675ae7)
#16: pc 0xcfaf3c6c733 (app:net_unittests,0x2675733)
#17: pc 0xcfaf48c5538 (app:net_unittests,0x32ce538)
#18: pc 0xcfaf48c8afc (app:net_unittests,0x32d1afc)
#19: pc 0xcfaf48c89ba (app:net_unittests,0x32d19ba)
#20: pc 0xcfaf38e0cf2 (app:net_unittests,0x22e9cf2)
#21: pc 0x74c0d3b8812e (libc.so,0x1b12e)
[00260.280] 03763.03789>
[00260.280] 03763.03789> [4584/19143] SpdyHttpStreamTest.SpdyURLTest (CRASHED)
[00261.335] 02734.15296> netstack: ErrNotSupported: socket: unknown network protocol: 16
[00262.932] 02734.15296> netstack: ErrNotSupported: socket: unknown network protocol: 16
[00264.844] 02734.03421> netstack: ErrNotSupported: socket: unknown network protocol: 16
[00266.519] 03763.03789> [4585/19143] DiskCacheBackendTest.SimpleCacheShutdownWithPendingFileIO (6690 ms)

Note how this is two separate output streams interleaved.  The first one is test output, as seen above in the opening post.  However, the following data seem to be interrupting it mid-line, in the middle of the word "Value":

127.0.0.1 - - [06/Dec/2017 03:11:38] "GET /kill?port=59010 HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:39] "POST /start HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:40] "GET /kill?port=36809 HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:41] "POST /start HTTP/1.1" 200 -
127.0.0.1 - - [06/Dec/2017 03:11:42] "GET /kill?port=41741 HTTP/1.1" 200 -

Is this the restart of some test controller?  I suspect that this is causing the test to fail.

Otherwise yes, reading EOF causes the stream to be abandoned.  Since the EOF is synchronous, it is read at the point callback.WaitForResult() is called.  Note that the same idiom (synchronous EOF, callback.WaitForResult(), no separate RunLoop() call) is used in the same file in SendRequest, SendChunkedPost, SendChunkedPostLastEmpty, and DataReadErrorSynchronous tests, and in each of these there is a similar EXPECT_FALSE(HasSpdySession()) expectation.

Note that this test operates solely on mock network data, so actual network activities, other tests running in parallel etc. should not influence it.

Also, "FATAL:socket_test_util.cc(442) Check failed: !helper_.AllWriteDataConsumed()" means that the network stack is trying to write more data, but there is no matching mock write data.

Comment 5 by w...@chromium.org, Jan 26 2018

Labels: -M-65 M-66

Comment 6 by w...@chromium.org, Feb 15 2018

Labels: -Pri-2 -M-66 Pri-3
Owner: ----
Status: Available (was: Assigned)

Sign in to add a comment