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

Issue 848178 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Jun 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 2
Type: Bug



Sign in to add a comment

Some QUIC connections are not notified once it becomes possible to write again

Reported by slus...@gmail.com, May 31 2018

Issue description

UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/604.5.6 (KHTML, like Gecko) Version/11.0.3 Safari/604.5.6

Example URL:

Steps to reproduce the problem:
While I was investigating the higher ratio of failed handshakes due to idle timeouts, I've noticed the following problem:

1. Connection 1 tries to write and the writer becomes write blocked
2. Connection 2 tries to write: some packets (handshake, TLP, RTO) are serialized even if the writer is write blocked. They are queued, but OnWriteBlocked() is not called.
3. When writer becomes writable again,  connection 2 is not notified and it does not write queued packets.
4. All subsequent write attempts for connection 2 are not realized, packets are queued (not sent).

The problem may disappear in some situations, for example, if the connection processes some packet.

The following patch (against chromium) shows a possible fix for the problem and  the unittest. The test would fail without the change in quic_connection.cc.
It's worth considering other ways to fix this problem: a better way could be to call OnWriteBlocked() from SendOrQueuePacket() if some packet is queued.
I think that if some connection has queued packets, than it must be added to the list of write blocked connections.

diff --git a/net/third_party/quic/core/quic_connection.cc b/net/third_party/quic/core/quic_connection.cc
index c3b1ccc..2672b0f 100644
--- a/net/third_party/quic/core/quic_connection.cc
+++ b/net/third_party/quic/core/quic_connection.cc
@@ -1987,6 +1987,7 @@ bool QuicConnection::WritePacket(SerializedPacket* packet) {
   // Termination packets are encrypted and saved, so don't exit early.
   const bool is_termination_packet = IsTerminationPacket(*packet);
   if (writer_->IsWriteBlocked() && !is_termination_packet) {
+    visitor_->OnWriteBlocked();
     return false;
   }

diff --git a/net/third_party/quic/core/quic_connection_test.cc b/net/third_party/quic/core/quic_connection_test.cc
index 1cabcb4..7954fb4 100644
--- a/net/third_party/quic/core/quic_connection_test.cc
+++ b/net/third_party/quic/core/quic_connection_test.cc
@@ -363,6 +363,8 @@ class TestPacketWriter : public QuicPacketWriter {

   void SetWritable() override { write_blocked_ = false; }

+  void SetWritable(bool writable) { write_blocked_ = !writable; }
+
   void SetShouldWriteFail() { write_should_fail_ = true; }

   QuicByteCount GetMaxPacketSize(
@@ -6827,6 +6829,30 @@ TEST_P(QuicConnectionTest, ValidStatelessResetToken) {
   EXPECT_TRUE(connection_.IsValidStatelessResetToken(kTestToken));
 }

+TEST_P(QuicConnectionTest, TLPWhenWriteBlocked) {
+  if (!connection_.session_decides_what_to_write()) {
+    return;
+  }
+
+  SendStreamDataToPeer(3, "foo", 0, NO_FIN, nullptr);
+  EXPECT_EQ(1u, stop_waiting()->least_unacked);
+  QuicTime retransmission_time =
+      connection_.GetRetransmissionAlarm()->deadline();
+
+  EXPECT_CALL(*send_algorithm_, OnPacketSent(_, _, _, _, _)).Times(0);
+  EXPECT_EQ(0u, connection_.NumQueuedPackets());
+
+  // Simulate the retransmission alarm firing and sending a tlp,
+  // so send algorithm's OnRetransmissionTimeout is not called.
+  clock_.AdvanceTime(retransmission_time - clock_.Now());
+  EXPECT_CALL(visitor_, OnWriteBlocked()).Times(AtLeast(1));
+  writer_->SetWritable(false);
+  connection_.GetRetransmissionAlarm()->Fire();
+  EXPECT_TRUE(writer_->IsWriteBlocked());
+  EXPECT_EQ(1u, connection_.NumQueuedPackets());
+  EXPECT_TRUE(connection_.HasQueuedData());
+}
+
 }  // namespace
 }  // namespace test
 }  // namespace net

What is the expected behavior?

What went wrong?
See steps to reproduce the problem.

Did this work before? N/A 

Chrome version: trunk  Channel: n/a
OS Version: OS X 10.13.3
Flash Version:
 

Comment 1 by mmenke@chromium.org, May 31 2018

Components: -Internals>Network Internals>Network>QUIC
Cc: ianswett@chromium.org
Cc: zhongyi@chromium.org
Labels: Needs-Feedback
Can you collect a NetLog when repro the issue? Instructions are available at https://sites.google.com/a/chromium.org/dev/for-testers/providing-network-details

Connection 1 and connection 2 uses different writers, the two connection shouldn't interfere each other. 

If a packet is failed to be written as writer is blocked, the QuicConnection::WritePacket returns false and caller is responsible to re-queue the packet. When writer finally becomes unblocked, QuicChromiumPacketWriter will notify its delegate of write unblock event, which eventually calls the connection to write again. 
I think Stanislav may be referring to the server code, where they share a writer?

Comment 5 by slus...@gmail.com, May 31 2018

Yes, I was referring to the server code, where we have a shared writer.
Is that expected/supported ?

I think that it used to be, at the time we wrote our own writer, but I am not sure.

Therefore I am not able to provide the Netlog, I have not reproduced the problem with Chrome browser.





 
Project Member

Comment 6 by sheriffbot@chromium.org, May 31 2018

Labels: -Needs-Feedback
Thank you for providing more feedback. Adding the requester to the cc list.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Comment 7 by ianswett@google.com, May 31 2018

Cc: rch@chromium.org
The behavior you describe is not expected, and seems like a bug to me.  Adding rch@ in case he can explain why this isn't a bug?
Ryan and I discussed this today, and agreed this seems like a real issue, but we think the issue might be more widespread than the patch you included above.  In particular, I'm concerned about the writer already being blocked when a packet is processed, and then the connection not being added to the write blocked list.

Comment 9 by slus...@gmail.com, Jun 19 2018

Thanks for the confirmation and for getting back to this.
I agree that the proposed patch is simple and a better solution is preferable.
I would like to fully understand your concerns, because I have been working on a fix for us.

We do not write in response to  packets processed when the writer is write blocked. 
Therefore the packets are NOT queued and the connection is NOT added to the write blocked list
(the original problem was that packets were queued and not added to the write blocked list).

Do you see this as a problem because when the writer becomes writable, connection does not get its 
chance to write ?

 

Owner: wub@chromium.org
Bin has a fix landing soon, which I believe fixes this and reduces the chances we'll reintroduce a similar issue.

We haven't directly observed this, but we've observed some other odd behavior which could be caused by this issue when we see a lot of write blocking.
Project Member

Comment 11 by bugdroid1@chromium.org, Jun 26 2018

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

commit 5a77af81098ef315afc35a563ea03726ed1d9633
Author: Bin Wu <wub@chromium.org>
Date: Tue Jun 26 22:03:31 2018

If a QuicConnection is writer blocked, always add it to the write blocked list. Protected by --quic_reloadable_flag_quic_add_to_blocked_list_if_writer_blocked.

If --quic_reloadable_flag_quic_add_to_blocked_list_if_writer_blocked is true,
QuicConnection::ProcessPacket will also add the connection to write blocked list
if it is write blocked, and will not attempt to write before the writer unblocks.

Merge internal change: 201524024

R=rch@chromium.org

Bug:  848178 
Change-Id: I2e7087ccb6fe11d575ceb7bea57fbaa9b1aeb68c
Reviewed-on: https://chromium-review.googlesource.com/1114923
Reviewed-by: Ryan Hamilton <rch@chromium.org>
Commit-Queue: Bin Wu <wub@chromium.org>
Cr-Commit-Position: refs/heads/master@{#570545}
[modify] https://crrev.com/5a77af81098ef315afc35a563ea03726ed1d9633/net/third_party/quic/core/quic_connection.cc
[modify] https://crrev.com/5a77af81098ef315afc35a563ea03726ed1d9633/net/third_party/quic/core/quic_connection.h
[modify] https://crrev.com/5a77af81098ef315afc35a563ea03726ed1d9633/net/third_party/quic/core/quic_connection_test.cc
[modify] https://crrev.com/5a77af81098ef315afc35a563ea03726ed1d9633/net/third_party/quic/core/quic_flags_list.h

Sign in to add a comment