From 2b21665208e843aac66790101ccc5b8f03c7f1b7 Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Thu, 6 May 2021 16:30:54 -0700 Subject: [PATCH 1/6] Adds error code for context deadline exceeded --- lib/netext/httpext/error_codes.go | 9 +++++++++ lib/netext/httpext/error_codes_test.go | 6 ++++++ 2 files changed, 15 insertions(+) diff --git a/lib/netext/httpext/error_codes.go b/lib/netext/httpext/error_codes.go index 7c9f2fd90bf..297064c05b7 100644 --- a/lib/netext/httpext/error_codes.go +++ b/lib/netext/httpext/error_codes.go @@ -31,6 +31,8 @@ import ( "runtime" "syscall" + "context" + "golang.org/x/net/http2" "go.k6.io/k6/lib/netext" @@ -82,6 +84,8 @@ const ( // Custom k6 content errors, i.e. when the magic fails // defaultContentError errCode = 1700 // reserved for future use responseDecompressionErrorCode errCode = 1701 + + requestTimeoutErrorCode errCode = 1800 ) const ( @@ -98,6 +102,7 @@ const ( http2ConnectionErrorCodeMsg = "http2: connection error with http2 ErrCode %s" x509HostnameErrorCodeMsg = "x509: certificate doesn't match hostname" x509UnknownAuthority = "x509: unknown authority" + requestTimeoutErrorCodeMsg = "Request timeout" ) func http2ErrCodeOffset(code http2.ErrCode) errCode { @@ -215,6 +220,10 @@ func errorCodeForError(err error) (errCode, string) { return errorCodeForError(wrappedErr) } + if errors.Is(e, context.DeadlineExceeded) { + return requestTimeoutErrorCode, requestTimeoutErrorCodeMsg + } + return defaultErrorCode, err.Error() } } diff --git a/lib/netext/httpext/error_codes_test.go b/lib/netext/httpext/error_codes_test.go index c1dd5e42c90..57ef506e0fa 100644 --- a/lib/netext/httpext/error_codes_test.go +++ b/lib/netext/httpext/error_codes_test.go @@ -21,6 +21,7 @@ package httpext import ( + "context" "crypto/tls" "crypto/x509" "errors" @@ -218,3 +219,8 @@ func TestDnsResolve(t *testing.T) { assert.Equal(t, dnsNoSuchHostErrorCode, code) assert.Equal(t, dnsNoSuchHostErrorCodeMsg, msg) } + +func TestContextDeadlineExceeded(t *testing.T) { + t.Parallel() + testErrorCode(t, requestTimeoutErrorCode, context.DeadlineExceeded) +} From c79562e4f758f544685a8a4cafc3b4146a041016 Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Mon, 10 May 2021 12:52:54 -0700 Subject: [PATCH 2/6] Check if resErr is context deadline exceeded in request lifecycle --- js/modules/k6/http/request_test.go | 4 ++-- lib/netext/httpext/error_codes.go | 9 +-------- lib/netext/httpext/error_codes_test.go | 6 ------ lib/netext/httpext/request.go | 3 +++ lib/netext/httpext/request_test.go | 4 ++-- 5 files changed, 8 insertions(+), 18 deletions(-) diff --git a/js/modules/k6/http/request_test.go b/js/modules/k6/http/request_test.go index 954cc162a37..f09c3b14218 100644 --- a/js/modules/k6/http/request_test.go +++ b/js/modules/k6/http/request_test.go @@ -326,7 +326,7 @@ func TestRequestAndBatch(t *testing.T) { `)) endTime := time.Now() require.Error(t, err) - assert.Contains(t, err.Error(), "context deadline exceeded") + assert.Contains(t, err.Error(), "Request timeout") assert.WithinDuration(t, startTime.Add(1*time.Second), endTime, 2*time.Second) logEntry := hook.LastEntry() @@ -344,7 +344,7 @@ func TestRequestAndBatch(t *testing.T) { `)) endTime := time.Now() require.Error(t, err) - assert.Contains(t, err.Error(), "context deadline exceeded") + assert.Contains(t, err.Error(), "Request timeout") assert.WithinDuration(t, startTime.Add(1*time.Second), endTime, 2*time.Second) logEntry := hook.LastEntry() diff --git a/lib/netext/httpext/error_codes.go b/lib/netext/httpext/error_codes.go index 297064c05b7..7169331c3b4 100644 --- a/lib/netext/httpext/error_codes.go +++ b/lib/netext/httpext/error_codes.go @@ -31,8 +31,6 @@ import ( "runtime" "syscall" - "context" - "golang.org/x/net/http2" "go.k6.io/k6/lib/netext" @@ -48,6 +46,7 @@ const ( // non specific defaultErrorCode errCode = 1000 defaultNetNonTCPErrorCode errCode = 1010 + requestTimeoutErrorCode errCode = 1050 // DNS errors defaultDNSErrorCode errCode = 1100 dnsNoSuchHostErrorCode errCode = 1101 @@ -84,8 +83,6 @@ const ( // Custom k6 content errors, i.e. when the magic fails // defaultContentError errCode = 1700 // reserved for future use responseDecompressionErrorCode errCode = 1701 - - requestTimeoutErrorCode errCode = 1800 ) const ( @@ -220,10 +217,6 @@ func errorCodeForError(err error) (errCode, string) { return errorCodeForError(wrappedErr) } - if errors.Is(e, context.DeadlineExceeded) { - return requestTimeoutErrorCode, requestTimeoutErrorCodeMsg - } - return defaultErrorCode, err.Error() } } diff --git a/lib/netext/httpext/error_codes_test.go b/lib/netext/httpext/error_codes_test.go index 57ef506e0fa..c1dd5e42c90 100644 --- a/lib/netext/httpext/error_codes_test.go +++ b/lib/netext/httpext/error_codes_test.go @@ -21,7 +21,6 @@ package httpext import ( - "context" "crypto/tls" "crypto/x509" "errors" @@ -219,8 +218,3 @@ func TestDnsResolve(t *testing.T) { assert.Equal(t, dnsNoSuchHostErrorCode, code) assert.Equal(t, dnsNoSuchHostErrorCodeMsg, msg) } - -func TestContextDeadlineExceeded(t *testing.T) { - t.Parallel() - testErrorCode(t, requestTimeoutErrorCode, context.DeadlineExceeded) -} diff --git a/lib/netext/httpext/request.go b/lib/netext/httpext/request.go index 3f5223adf0f..6296bfa38d3 100644 --- a/lib/netext/httpext/request.go +++ b/lib/netext/httpext/request.go @@ -339,6 +339,9 @@ func MakeRequest(ctx context.Context, preq *ParsedHTTPRequest) (*Response, error } resp.Body, resErr = readResponseBody(state, preq.ResponseType, res, resErr) + if resErr == context.DeadlineExceeded { + resErr = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, resErr) + } finishedReq := tracerTransport.processLastSavedRequest(wrapDecompressionError(resErr)) if finishedReq != nil { updateK6Response(resp, finishedReq) diff --git a/lib/netext/httpext/request_test.go b/lib/netext/httpext/request_test.go index 57b9b6d0599..be3a52c6f51 100644 --- a/lib/netext/httpext/request_test.go +++ b/lib/netext/httpext/request_test.go @@ -271,8 +271,8 @@ func TestMakeRequestTimeout(t *testing.T) { allSamples := sampleCont.GetSamples() require.Len(t, allSamples, 9) expTags := map[string]string{ - "error": "context deadline exceeded", - "error_code": "1000", + "error": "Request timeout", + "error_code": "1050", "status": "0", "expected_response": "true", // we wait for status code 0 "method": "GET", From c5edd39edb6a52993d692631287d7680eea6d094 Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Mon, 10 May 2021 16:02:30 -0700 Subject: [PATCH 3/6] fix tests, use strict timeout check --- lib/netext/httpext/request.go | 6 +++--- lib/netext/httpext/request_test.go | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/lib/netext/httpext/request.go b/lib/netext/httpext/request.go index 6296bfa38d3..6f9d3bdbf7b 100644 --- a/lib/netext/httpext/request.go +++ b/lib/netext/httpext/request.go @@ -329,6 +329,9 @@ func MakeRequest(ctx context.Context, preq *ParsedHTTPRequest) (*Response, error mreq := preq.Req.WithContext(reqCtx) res, resErr := client.Do(mreq) + if err, ok := resErr.(net.Error); ok && err.Timeout() { + resErr = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, resErr) + } // TODO(imiric): It would be safer to check for a writeable // response body here instead of status code, but those are // wrapped in a read-only body when using client timeouts and are @@ -339,9 +342,6 @@ func MakeRequest(ctx context.Context, preq *ParsedHTTPRequest) (*Response, error } resp.Body, resErr = readResponseBody(state, preq.ResponseType, res, resErr) - if resErr == context.DeadlineExceeded { - resErr = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, resErr) - } finishedReq := tracerTransport.processLastSavedRequest(wrapDecompressionError(resErr)) if finishedReq != nil { updateK6Response(resp, finishedReq) diff --git a/lib/netext/httpext/request_test.go b/lib/netext/httpext/request_test.go index be3a52c6f51..57b9b6d0599 100644 --- a/lib/netext/httpext/request_test.go +++ b/lib/netext/httpext/request_test.go @@ -271,8 +271,8 @@ func TestMakeRequestTimeout(t *testing.T) { allSamples := sampleCont.GetSamples() require.Len(t, allSamples, 9) expTags := map[string]string{ - "error": "Request timeout", - "error_code": "1050", + "error": "context deadline exceeded", + "error_code": "1000", "status": "0", "expected_response": "true", // we wait for status code 0 "method": "GET", From 609081fca7c0245f6bfd87c47c42998f7c0fd76a Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Mon, 10 May 2021 19:33:30 -0700 Subject: [PATCH 4/6] move error wrapping closer to source --- lib/netext/httpext/request.go | 3 --- lib/netext/httpext/transport.go | 3 +++ 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/netext/httpext/request.go b/lib/netext/httpext/request.go index 6f9d3bdbf7b..3f5223adf0f 100644 --- a/lib/netext/httpext/request.go +++ b/lib/netext/httpext/request.go @@ -329,9 +329,6 @@ func MakeRequest(ctx context.Context, preq *ParsedHTTPRequest) (*Response, error mreq := preq.Req.WithContext(reqCtx) res, resErr := client.Do(mreq) - if err, ok := resErr.(net.Error); ok && err.Timeout() { - resErr = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, resErr) - } // TODO(imiric): It would be safer to check for a writeable // response body here instead of status code, but those are // wrapped in a read-only body when using client timeouts and are diff --git a/lib/netext/httpext/transport.go b/lib/netext/httpext/transport.go index c812bf35a8a..f162e228a4e 100644 --- a/lib/netext/httpext/transport.go +++ b/lib/netext/httpext/transport.go @@ -243,6 +243,9 @@ func (t *transport) RoundTrip(req *http.Request) (*http.Response, error) { reqWithTracer := req.WithContext(httptrace.WithClientTrace(ctx, tracer.Trace())) resp, err := t.state.Transport.RoundTrip(reqWithTracer) + if typErr, ok := err.(net.Error); ok && typErr.Timeout() { + err = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, err) + } t.saveCurrentRequest(&unfinishedRequest{ ctx: ctx, tracer: tracer, From 87894ceadc39d1275cb0d82921de9511a98ef8f4 Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Tue, 18 May 2021 09:46:09 -0700 Subject: [PATCH 5/6] Code review feedback --- lib/netext/httpext/error_codes.go | 6 ------ lib/netext/httpext/error_codes_test.go | 2 -- 2 files changed, 8 deletions(-) diff --git a/lib/netext/httpext/error_codes.go b/lib/netext/httpext/error_codes.go index 7169331c3b4..28915829be5 100644 --- a/lib/netext/httpext/error_codes.go +++ b/lib/netext/httpext/error_codes.go @@ -57,7 +57,6 @@ const ( tcpBrokenPipeErrorCode errCode = 1201 netUnknownErrnoErrorCode errCode = 1202 tcpDialErrorCode errCode = 1210 - tcpDialTimeoutErrorCode errCode = 1211 tcpDialRefusedErrorCode errCode = 1212 tcpDialUnknownErrnoCode errCode = 1213 tcpResetByPeerErrorCode errCode = 1220 @@ -87,7 +86,6 @@ const ( const ( tcpResetByPeerErrorCodeMsg = "%s: connection reset by peer" - tcpDialTimeoutErrorCodeMsg = "dial: i/o timeout" tcpDialRefusedErrorCodeMsg = "dial: connection refused" tcpBrokenPipeErrorCodeMsg = "%s: broken pipe" netUnknownErrnoErrorCodeMsg = "%s: unknown errno `%d` on %s with message `%s`" @@ -142,10 +140,6 @@ func errorCodeForNetOpError(err *net.OpError) (errCode, string) { } } - // err.Op is "dial" - if err.Timeout() { - return tcpDialTimeoutErrorCode, tcpDialTimeoutErrorCodeMsg - } if iErr, ok := err.Err.(*os.SyscallError); ok { if errno, ok := iErr.Err.(syscall.Errno); ok { if errno == syscall.ECONNREFUSED || diff --git a/lib/netext/httpext/error_codes_test.go b/lib/netext/httpext/error_codes_test.go index c1dd5e42c90..26ee2574a5d 100644 --- a/lib/netext/httpext/error_codes_test.go +++ b/lib/netext/httpext/error_codes_test.go @@ -129,7 +129,6 @@ func TestTCPErrors(t *testing.T) { econnrefused = &net.OpError{Net: "tcp", Op: "dial", Err: &os.SyscallError{Err: syscall.ECONNREFUSED}} errnounknown = &net.OpError{Net: "tcp", Op: "dial", Err: &os.SyscallError{Err: syscall.E2BIG}} tcperror = &net.OpError{Net: "tcp", Err: errors.New("tcp error")} - timeoutedError = &net.OpError{Net: "tcp", Op: "dial", Err: timeoutError(true)} notTimeoutedError = &net.OpError{Net: "tcp", Op: "dial", Err: timeoutError(false)} ) @@ -141,7 +140,6 @@ func TestTCPErrors(t *testing.T) { tcpDialUnknownErrnoCode: errnounknown, defaultTCPErrorCode: tcperror, tcpDialErrorCode: notTimeoutedError, - tcpDialTimeoutErrorCode: timeoutedError, } testMapOfErrorCodes(t, testTable) From 1675211ebc22d4c99e4aac52fe0ac78af60e3360 Mon Sep 17 00:00:00 2001 From: Vishal Kuo Date: Tue, 18 May 2021 10:05:08 -0700 Subject: [PATCH 6/6] Fix build and lint --- core/local/local_test.go | 2 +- lib/netext/httpext/transport.go | 6 ++++-- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/core/local/local_test.go b/core/local/local_test.go index 23eb2a7fed3..76eb0fe59eb 100644 --- a/core/local/local_test.go +++ b/core/local/local_test.go @@ -1026,7 +1026,7 @@ func TestDNSResolver(t *testing.T) { expErr := sr(`dial tcp 127.0.0.254:HTTPBIN_PORT: connect: connection refused`) if runtime.GOOS == "windows" { - expErr = "context deadline exceeded" + expErr = "Request timeout" } for name, tc := range testCases { tc := tc diff --git a/lib/netext/httpext/transport.go b/lib/netext/httpext/transport.go index f162e228a4e..add7b538c6f 100644 --- a/lib/netext/httpext/transport.go +++ b/lib/netext/httpext/transport.go @@ -22,6 +22,7 @@ package httpext import ( "context" + "errors" "net" "net/http" "net/http/httptrace" @@ -243,8 +244,9 @@ func (t *transport) RoundTrip(req *http.Request) (*http.Response, error) { reqWithTracer := req.WithContext(httptrace.WithClientTrace(ctx, tracer.Trace())) resp, err := t.state.Transport.RoundTrip(reqWithTracer) - if typErr, ok := err.(net.Error); ok && typErr.Timeout() { - err = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, err) + var netError net.Error + if errors.As(err, &netError) && netError.Timeout() { + err = NewK6Error(requestTimeoutErrorCode, requestTimeoutErrorCodeMsg, netError) } t.saveCurrentRequest(&unfinishedRequest{ ctx: ctx,