fn: perform call.End() after request is processed (#918)

* fn: perform call.End() after request is processed

call.End() performs several tasks in sequence; insert call,
insert log, (todo) remove mq entry, fireAfterCall callback, etc.
These currently add up to the request latency as return
from agent.Submit() is blocked on these. We also haven't been
able to apply any timeouts on these operations since they are
handled during request processing and it is hard to come up
with a strategy for it. Also the error cases
(couldn't insert call or log) are not propagated to the caller.

With this change, call.End() handling becomes asynchronous where
we perform these tasks after the request is done. This improves
latency and we no longer have to block the call on these operations.
The changes will also free up the agent slot token more quickly
and now we are no longer tied to hiccups in call.End().

Now, a timeout policy is also added to this which can
be adjusted with an env variable. (default 10 minutes)

This accentuates the fact that call/log/fireAfterCall are not
completed when request is done. So, there's a window there where
call is done, but call/log/fireAfterCall are not yet propagated.
This was already the case especially for error cases.

There's slight risk of accumulating call.End() operations in
case of hiccups in these log/call/callback systems.

* fn: address risk of overstacking of call.End() calls.
This commit is contained in:
Tolga Ceylan
2018-04-05 14:42:12 -07:00
committed by GitHub
parent 82bf532fa7
commit 81954bcf53
3 changed files with 59 additions and 23 deletions

View File

@@ -193,7 +193,7 @@ func TestRouteRunnerIOPipes(t *testing.T) {
containerIds := make([]string, 0)
for i, test := range []struct {
testCases := []struct {
path string
body string
method string
@@ -235,7 +235,11 @@ func TestRouteRunnerIOPipes(t *testing.T) {
// CASE IV: should land on CASE III container
{"/r/zoo/http/", ok, "GET", http.StatusOK, "", nil, 0},
} {
}
callIds := make([]string, len(testCases))
for i, test := range testCases {
body := strings.NewReader(test.body)
_, rec := routerRequest(t, srv.Router, test.method, test.path, body)
respBytes, _ := ioutil.ReadAll(rec.Body)
@@ -246,6 +250,7 @@ func TestRouteRunnerIOPipes(t *testing.T) {
}
containerIds = append(containerIds, "N/A")
callIds[i] = rec.Header().Get("Fn_call_id")
if rec.Code != test.expectedCode {
isFailure = true
@@ -260,13 +265,6 @@ func TestRouteRunnerIOPipes(t *testing.T) {
}
if test.expectedLogsSubStr != nil {
callID := rec.Header().Get("Fn_call_id")
if !checkLogs(t, i, ds, callID, test.expectedLogsSubStr) {
isFailure = true
}
}
if rec.Code == http.StatusOK {
dockerId, err := getDockerId(respBytes)
if err != nil {
@@ -281,6 +279,14 @@ func TestRouteRunnerIOPipes(t *testing.T) {
time.Sleep(test.sleepAmount)
}
for i, test := range testCases {
if test.expectedLogsSubStr != nil {
if !checkLogs(t, i, ds, callIds[i], test.expectedLogsSubStr) {
isFailure = true
}
}
}
jsonIds := containerIds[0:5]
// now cross check JSON container ids:
@@ -374,7 +380,7 @@ func TestRouteRunnerExecution(t *testing.T) {
bigoutput := `{"echoContent": "_TRX_ID_", "isDebug": true, "trailerRepeat": 1000}` // 1000 trailers to exceed 2K
smalloutput := `{"echoContent": "_TRX_ID_", "isDebug": true, "trailerRepeat": 1}` // 1 trailer < 2K
for i, test := range []struct {
testCases := []struct {
path string
body string
method string
@@ -413,7 +419,11 @@ func TestRouteRunnerExecution(t *testing.T) {
{"/r/myapp/mybigoutputhttp", smalloutput, "GET", http.StatusOK, nil, "", nil},
{"/r/myapp/mybigoutputcold", bigoutput, "GET", http.StatusBadGateway, nil, "", nil},
{"/r/myapp/mybigoutputcold", smalloutput, "GET", http.StatusOK, nil, "", nil},
} {
}
callIds := make([]string, len(testCases))
for i, test := range testCases {
trx := fmt.Sprintf("_trx_%d_", i)
body := strings.NewReader(strings.Replace(test.body, "_TRX_ID_", trx, 1))
_, rec := routerRequest(t, srv.Router, test.method, test.path, body)
@@ -424,6 +434,8 @@ func TestRouteRunnerExecution(t *testing.T) {
maxBody = 1024
}
callIds[i] = rec.Header().Get("Fn_call_id")
if rec.Code != test.expectedCode {
isFailure = true
t.Errorf("Test %d: Expected status code to be %d but was %d. body: %s",
@@ -453,10 +465,11 @@ func TestRouteRunnerExecution(t *testing.T) {
}
}
}
}
for i, test := range testCases {
if test.expectedLogsSubStr != nil {
callID := rec.Header().Get("Fn_call_id")
if !checkLogs(t, i, ds, callID, test.expectedLogsSubStr) {
if !checkLogs(t, i, ds, callIds[i], test.expectedLogsSubStr) {
isFailure = true
}
}