diff --git a/pkg/router/functionHandler.go b/pkg/router/functionHandler.go index 978548ba..1bf6c68b 100644 --- a/pkg/router/functionHandler.go +++ b/pkg/router/functionHandler.go @@ -296,12 +296,18 @@ func (roundTripper RetryingRoundTripper) RoundTrip(req *http.Request) (*http.Res if roundTripper.timeout <= 0 { roundTripper.timeout = fv1.DEFAULT_FUNCTION_TIMEOUT } - roundTripper.logger.Debug("Creating context for request for ", zap.Any("Time", roundTripper.timeout)) - ctx, closeCtx := context.WithTimeout(context.Background(), time.Duration(roundTripper.timeout)*time.Second) + + roundTripper.logger.Debug("Creating context for request for ", zap.Any("time", roundTripper.timeout)) + // pass request context as parent context for the case + // that user aborts connection before timeout. Otherwise, + // the request won't be canceled until the deadline exceeded + // which may be a potential security issue. + ctx, closeCtx := context.WithTimeout(req.Context(), time.Duration(roundTripper.timeout)*time.Second) // forward the request to the function service resp, err = ocRoundTripper.RoundTrip(req.WithContext(ctx)) closeCtx() + if err == nil { // Track metrics httpMetricLabels.code = resp.StatusCode @@ -348,7 +354,6 @@ func (roundTripper RetryingRoundTripper) RoundTrip(req *http.Request) (*http.Res // if transport.RoundTrip returns a non-network dial error (e.g. "context canceled"), then relay it back to user if !isNetDialErr { - err = errors.Wrapf(err, "error sending request to function %v", fnMeta.Name) return resp, err } @@ -459,6 +464,7 @@ func (fh functionHandler) handler(responseWriter http.ResponseWriter, request *h funcHandler: &fh, timeout: timeout, }, + ErrorHandler: getProxyErrorHandler(fh.logger, fh.function), } proxy.ServeHTTP(responseWriter, request) @@ -499,6 +505,32 @@ func getCanaryBackend(fnMetadatamap map[string]*metav1.ObjectMeta, fnWtDistribut return fnMetadatamap[fnName] } +// getProxyErrorHandler returns a reverse proxy error handler +func getProxyErrorHandler(logger *zap.Logger, fnMeta *metav1.ObjectMeta) func(rw http.ResponseWriter, req *http.Request, err error) { + return func(rw http.ResponseWriter, req *http.Request, err error) { + status := http.StatusBadGateway + switch err { + case context.Canceled: + // 499 CLIENT CLOSED REQUEST + // A non-standard status code introduced by nginx for the case + // when a client closes the connection while nginx is processing the request. + // Reference: https://httpstatuses.com/499 + status = 499 + logger.Debug("client closes the connection", + zap.Any("function", fnMeta), zap.Any("request_header", req.Header)) + case context.DeadlineExceeded: + status = http.StatusGatewayTimeout + logger.Error("function not responses before the timeout", + zap.Any("function", fnMeta), zap.Any("request_header", req.Header)) + default: + logger.Error("error sending request to function", + zap.Error(err), zap.Any("function", fnMeta), zap.Any("request_header", req.Header)) + } + // TODO: return error message that contains traceable UUID back to user. Issue #693 + rw.WriteHeader(status) + } +} + // addForwardedHostHeader add "forwarded host" to request header func (roundTripper RetryingRoundTripper) addForwardedHostHeader(req *http.Request) { // for more detailed information, please visit: diff --git a/pkg/router/functionHandler_test.go b/pkg/router/functionHandler_test.go index 0a6a4933..9826e634 100644 --- a/pkg/router/functionHandler_test.go +++ b/pkg/router/functionHandler_test.go @@ -17,6 +17,8 @@ limitations under the License. package router import ( + "context" + "errors" "log" "net/http" "net/http/httptest" @@ -24,6 +26,7 @@ import ( "testing" "time" + "github.com/stretchr/testify/assert" "go.uber.org/zap" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -90,3 +93,25 @@ func TestFunctionProxying(t *testing.T) { testRequest(fhURL, testResponseString) } + +func TestProxyErrorHandler(t *testing.T) { + logger, err := zap.NewDevelopment() + assert.Nil(t, err) + errHandler := getProxyErrorHandler(logger, nil) + + req, err := http.NewRequest("GET", "http://foobar.com", nil) + assert.Nil(t, err) + + req.Header.Set("foo", "bar") + respRecorder := httptest.NewRecorder() + errHandler(respRecorder, req, context.Canceled) + assert.Equal(t, 499, respRecorder.Code) + + respRecorder = httptest.NewRecorder() + errHandler(respRecorder, req, context.DeadlineExceeded) + assert.Equal(t, http.StatusGatewayTimeout, respRecorder.Code) + + respRecorder = httptest.NewRecorder() + errHandler(respRecorder, req, errors.New("dummy")) + assert.Equal(t, http.StatusBadGateway, respRecorder.Code) +} diff --git a/test/tests/test_function_timeout.sh b/test/tests/test_function_timeout.sh new file mode 100755 index 00000000..f5a89b38 --- /dev/null +++ b/test/tests/test_function_timeout.sh @@ -0,0 +1,63 @@ +#!/bin/bash + +set -euo pipefail +source $(dirname $0)/../utils.sh + +TEST_ID=$(generate_test_id) +echo "TEST_ID = $TEST_ID" + +tmp_dir="/tmp/test-$TEST_ID" +mkdir -p $tmp_dir + +ROOT=$(dirname $0)/../.. + +env=nodejs-$TEST_ID +fn=nodejs-hello-$TEST_ID + +export FISSION_ROUTER=localhost:8888 + +cleanup() { + log "Cleaning up..." + clean_resource_by_id $TEST_ID + rm -rf $tmp_dir +} + +if [ -z "${TEST_NOCLEANUP:-}" ]; then + trap cleanup EXIT +else + log "TEST_NOCLEANUP is set; not cleaning up test artifacts afterwards." +fi + +# Create a function in nodejs, test it with an HTTP trigger. +# Update it and check it's output, the output should be +# different from the previous one. + +log "Creating nodejs env" +fission env create --name $env --image $NODE_RUNTIME_IMAGE + +log "Creating function" +echo 'function sleep(e){return new Promise(t=>{setTimeout(t,e)})}module.exports=async function(e){return await sleep(5000),{status:200,body:"hello, world!\n"}};' > $tmp_dir/foo.js +fission fn create --name $fn --env $env --code $tmp_dir/foo.js --fntimeout 10 + +log "Creating route" +fission route create --function $fn --url /$fn --method GET + +log "Waiting for router to catch up" +sleep 10 + +log "Checking for valid response" +timeout 60 bash -c "test_fn $fn 'hello, world!'" + +log "Updating function timeout setting" +fission fn update --name $fn --fntimeout 2 + +log "Waiting for router to update cache" +sleep 10 + +log "Doing an HTTP GET on the function's route" +response=$(curl -s -o /dev/null -w "%{http_code}" http://$FISSION_ROUTER/$fn) + +log "Checking for status code" +echo $response | grep -i 504 + +log "All done."