rstudio / httpuv

HTTP and WebSocket server package for R
Other
229 stars 86 forks source link

Only show HttpRequest error messages when debug messages are enabled #223

Closed wch closed 5 years ago

wch commented 5 years ago

This resolves rstudio/shiny#2371 and rstudio/shiny#2501.

On Unixes, httpuv applications occasionally printed ERROR: [uv_write] bad file descriptor, and on Windows, it was ERROR: [uv_write] broken pipe.

These messages occur when a httpuv app's onHeaders function schedules data to be written after the socket has already closed.

To reproduce, run this app. If you wait 3 seconds, the browser will show "Hello headers!". If you close the browser window (or reload it) in less than 3 seconds, then the server will print out ERROR: [uv_write] bad file descriptor on Mac, and ERROR: [uv_write] broken pipe on Windows.

library(httpuv)
s <- startServer("0.0.0.0", 5000,
  list(
    onHeaders = function(req) {
      Sys.sleep(3)
      list(
        status = 200L,
        headers = list('Content-Type' = 'text/html'),
        body = "Hello headers!"
      )
    }
  )
)

The line of code that generates that message is at https://github.com/rstudio/httpuv/blob/605f668/src/httpresponse.cpp#L107

When this error happens, it is handled correctly, and everything gets cleaned up properly. This PR simply makes it not print out the error message, unless debugging has been enabled.

jcheng5 commented 5 years ago

This would suppress all fatal errors though, no? I'd be far more comfortable whitelisting the error codes we know to be benign (as we already do elsewhere in this file--maybe centralize).

wch commented 5 years ago

Well, they're fatal in the sense that they're fatal to the HttpRequest object, but they're not problematic to the R process as a whole. I think reporting them to users as ERROR: is unnecessarily alarming.

Maybe we could soften the language instead? Or both whitelist and soften the language.

wch commented 5 years ago

I've made some changes to this PR, which greatly improve the debug logging.

To test it out, run the following:

library(httpuv)

s <- startServer("0.0.0.0", 5000,
  list(
    call = function(req) {
      list(
        status = 200L,
        headers = list('Content-Type' = 'text/html'),
        body = "Hello world!"
      )
    }
  )
)

httpuv:::logLevel("DEBUG")

Then visit 127.0.0.1:5000. The console will print lots of information, like this:

HttpRequest::_on_message_begin
HttpRequest::_on_url
HttpRequest::_on_header_field
HttpRequest::_on_header_value
HttpRequest::_on_header_field
HttpRequest::_on_header_value
HttpRequest::_on_header_field
HttpRequest::_on_header_value
HttpRequest::_on_headers_complete
HttpRequest::_schedule_on_headers_complete_complete
HttpRequest::_on_headers_complete_complete
HttpRequest::_on_message_complete
RWebApplication::getResponse
HttpRequest::responseScheduled
HttpRequest::_on_message_complete_complete
HttpResponse::writeResponse
HttpRequest::requestCompleted
HttpResponse::onResponseWritten
HttpResponse::~HttpResponse
HttpRequest::close
HttpRequest::_on_closed
WebSocketConnection::~WebSocketConnection
HttpRequest::~HttpRequest