Opened 6 months ago

#34080 new defect

Avoid double delays from ReconnectTimeout

Reported by: dcf Owned by:
Priority: Medium Milestone:
Component: Circumvention/Snowflake Version:
Severity: Normal Keywords:
Cc: cohosh, phw, arlolra, dcf Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

ReconnectTimeout is used in 2 places:

  • In exchangeSDP, where it is a delay inserted between calls to broker.Negotiate until one of them succeeds.
    Failed to retrieve answer. Retrying in 10s
    
  • In the main ConnectLoop, where it is a delay inserted between every check for getting a new snowflake.
    WebRTC: <errmsg>  Retrying in 10s...
    

The broker itself also terminates requests after 10s when the chosen proxy doesn't respond: BrokerChannel Response: 504 Gateway Timeout.

This situation sometimes results in double delays. Here are two cases I've identified.

  • The client requests a proxy, the broker responds immediately with an answer, but the proxy doesn't work. After waiting the DataChannelTimeout to decide that the proxy doesn't work, the client waits an additional ReconnectTimeout in ConnectLoop. Here, I've set DataChannelTimeout to 10s. Notice that between DataChannel created and Collecting a new Snowflake there are 20s (which is DataChannelTimeout + ReconnectTimeout), when it really should only be 10s.
    2020/04/30 22:38:29 Received Answer.
    2020/04/30 22:38:29 WebRTC: DataChannel created.
    2020/04/30 22:38:39 establishDataChannel: timeout waiting for DataChannel.OnOpen
    2020/04/30 22:38:39 WebRTC: closing PeerConnection
    2020/04/30 22:38:39 WebRTC: Closing
    2020/04/30 22:38:39 WebRTC: WebRTC: Could not establish DataChannel  Retrying in 10s...
    2020/04/30 22:38:49 WebRTC: Collecting a new Snowflake. Currently at [0/1]
    
  • The client requests a proxy, and the broker waits for 10s to respond with a 504 Gateway Timeout (indicating that the chosen proxy did not return an answer to the broker in time). The client waits 10s for the broker to respond, then waits another ReconnectTimeout in exchangeSDP before trying the broker again.
    2020/04/30 22:39:30 Negotiating via BrokerChannel...
    2020/04/30 22:39:41 BrokerChannel Response: 504 Gateway Timeout
    2020/04/30 22:39:41 BrokerChannel Error: Unexpected error, no answer.
    2020/04/30 22:39:41 Failed to retrieve answer. Retrying in 10s
    2020/04/30 22:39:51 Negotiating via BrokerChannel...
    

Both these cases can probably be fixed by running the timer in parallel with the periodic operation they are rate limiting. That is, instead of

for {
        operation()
        <-time.After(ReconnectTimeout)
}

it can be

for {
        timer := time.After(ReconnectTimeout)
        operation()
        <-timer
}

That way, if the operation itself takes more than 10s, ReconnectTimeout doesn't impose any additional delay.

Child Tickets

Change History (0)

Note: See TracTickets for help on using tickets.