Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

services/horizon/internal: Use custom timeout middleware #1870

Merged
merged 2 commits into from
Oct 24, 2019

Conversation

tamirms
Copy link
Contributor

@tamirms tamirms commented Oct 22, 2019

PR Checklist

PR Structure

  • This PR has reasonably narrow scope (if not, break it down into smaller PRs).
  • This PR avoids mixing refactoring changes with feature changes (split into two PRs
    otherwise).
  • This PR's title starts with name of package that is most changed in the PR, ex.
    services/friendbot, or all or doc if the changes are broad or impact many
    packages.

Thoroughness

  • This PR adds tests for the most critical parts of the new functionality or fixes.
  • I've updated any docs (developer docs, .md
    files, etc... affected by this change). Take a look in the docs folder for a given service,
    like this one.

Release planning

  • I've updated the relevant CHANGELOG (here for Horizon) if
    needed with deprecations, added features, breaking changes, and DB schema changes.
  • I've decided if this PR requires a new major/minor version according to
    semver, or if it's mainly a patch change. The PR is targeted at the next
    release branch if it's not a patch change.

Summary

Close #1684

Instances of "multiple response.WriteHeader calls" appear in horizon logs. The cause of these warnings is that there is a timeout middleware which terminates a request and responds with http.StatusGatewayTimeout if the request exceeds some amount of time.

Here's what happens:

  • A new streaming request is sent to Horizon.
  • SSE preamble is sent in WritePreamble that contains: w.WriteHeader(200) call.
  • ...stream is active, 55 seconds pass...
  • Context started in Timeout middleware timeouts and executes another call sending a new header: >w.WriteHeader(http.StatusGatewayTimeout).

This PR fixes this issue by using a custom timeout middleware after the logging middleware. The logging middleware wraps the http.ResponseWriter in a chi WrapResponseWriter instance. The custom timeout middleware then checks that the response status has not been set before calling WriteHeader(http.StatusGatewayTimeout)

@cla-bot cla-bot bot added the cla: yes label Oct 22, 2019
@tamirms tamirms force-pushed the connection-timeout branch 2 times, most recently from 5fb2238 to d032dc6 Compare October 22, 2019 20:12
@tamirms tamirms changed the title services/horizon/internal: Configure http.Server timeouts instead of using timeout middleware services/horizon/internal: Reorder middlewares to avoid multiple response.WriteHeader calls Oct 22, 2019
@tamirms tamirms force-pushed the connection-timeout branch from d032dc6 to 5e8fa3b Compare October 22, 2019 20:32
@tamirms tamirms changed the title services/horizon/internal: Reorder middlewares to avoid multiple response.WriteHeader calls services/horizon/internal: Use custom timeout middleware Oct 22, 2019
@tamirms tamirms requested review from bartekn and abuiles October 22, 2019 20:35
@tamirms tamirms force-pushed the connection-timeout branch from 5e8fa3b to 0c966d9 Compare October 23, 2019 08:10
cancel()
if ctx.Err() == context.DeadlineExceeded {
if mw, ok := w.(middleware.WrapResponseWriter); !ok {
log.Warn("expected ResponseWriter instance to be WrapResponseWriter")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this relies on WrapResponseWriter created in loggerMiddleware. If we ever remove this or change the order of middlewares code here will stop working. Can't we just create a new WrapResponseWriter here? It will also remove a need for type checking.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@bartekn fixed

To prevent WriteHeader from being called multiple times we have created
a timeout middleware which checks that the response status hasn't already
been written  before setting the status to http.StatusGatewayTimeout
@tamirms tamirms force-pushed the connection-timeout branch from 0c966d9 to c1f0ce9 Compare October 23, 2019 13:03
Copy link
Contributor

@bartekn bartekn left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM! Last question: you check if w is middleware.WrapResponseWriter but we don't do this in loggerMiddleware. I'm wondering if two WrapResponseWriters can work together, if not we should add a check to loggerMiddleware too.

ctx, cancel := context.WithTimeout(r.Context(), timeout)
defer func() {
cancel()
if ctx.Err() == context.DeadlineExceeded {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we do any other handling up the hierarchy chain if ct.Err() is different to context.DeadlineExceeded?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think so

@tamirms tamirms merged commit dc438fc into stellar:release-horizon-v0.23.0 Oct 24, 2019
@tamirms tamirms deleted the connection-timeout branch October 24, 2019 08:05
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants