Skip to content

Commit

Permalink
Add test case for http/tchannel client/server logs
Browse files Browse the repository at this point in the history
  • Loading branch information
@jacobgreenleaf
Jacob Greenleaf authored and jacobgreenleaf committed Aug 23, 2018
1 parent 110f904 commit db3d663
Show file tree
Hide file tree
Showing 3 changed files with 178 additions and 25 deletions.
39 changes: 38 additions & 1 deletion runtime/client_http_request_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -240,7 +240,44 @@ func TestMakingClientCallWithRespHeaders(t *testing.T) {
assert.Equal(t, "Example-Value", headers["Example-Header"])

logs := bgateway.AllLogs()
assert.Len(t, logs["Finished an outgoing client HTTP request"], 1)
logMsgs := logs["Finished an outgoing client HTTP request"]
assert.Len(t, logMsgs, 1)
logMsg := logMsgs[0]

dynamicHeaders := []string{
"url",
"timestamp-finished",
"Request-Header-Uber-Trace-Id",
"Response-Header-Content-Length",
"timestamp-started",
"Response-Header-Date",
"ts",
"hostname",
"pid",
}
for _, dynamicValue := range dynamicHeaders {
assert.Contains(t, logMsg, dynamicValue)
delete(logMsg, dynamicValue)
}

expectedValues := map[string]interface{}{
"msg": "Finished an outgoing client HTTP request",
"env": "production",
"clientID": "bar",
"Response-Header-Example-Header": "Example-Value",
"statusCode": float64(200),
"Request-Header-Content-Type": "application/json",
"Response-Header-Content-Type": "text/plain; charset=utf-8",
"level": "info",
"methodName": "Normal",
"method": "POST",
"Request-Header-X-Client-Id": "bar",
"zone": "unknown",
"service": "example-gateway",
}
for actualKey, actualValue := range logMsg {
assert.Equal(t, expectedValues[actualKey], actualValue, "unexpected header %q", actualKey)
}
}

func TestMakingClientCallWithThriftException(t *testing.T) {
Expand Down
78 changes: 78 additions & 0 deletions runtime/server_http_request_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1370,3 +1370,81 @@ func TestSpanCreated(t *testing.T) {
}
assert.Equal(t, "200 OK", resp.Status)
}

func TestIncomingHTTPRequestServerLog(t *testing.T) {
gateway, err := benchGateway.CreateGateway(
defaultTestConfig,
defaultTestOptions,
exampleGateway.CreateGateway,
)

if !assert.NoError(t, err) {
return
}
defer gateway.Close()

bgateway := gateway.(*benchGateway.BenchGateway)
bgateway.ActualGateway.HTTPRouter.Register(
"GET", "/foo", zanzibar.NewRouterEndpoint(
bgateway.ActualGateway.Logger,
bgateway.ActualGateway.AllHostScope,
bgateway.ActualGateway.Tracer,
"foo", "foo",
func(
ctx context.Context,
req *zanzibar.ServerHTTPRequest,
res *zanzibar.ServerHTTPResponse,
) {
res.WriteJSONBytes(200, nil, []byte(`{"ok":true}`))
},
),
)

_, err = gateway.MakeRequest("GET", "/foo?bar=bar", nil, nil)
assert.NoError(t, err)

allLogs := bgateway.AllLogs()
assert.Equal(t, 1, len(allLogs["Finished an incoming server HTTP request"]))

tags := allLogs["Finished an incoming server HTTP request"][0]
dynamicHeaders := []string{
"remoteAddr",
"timestamp-started",
"ts",
"hostname",
"host",
"pid",
"timestamp-finished",
}
for _, dynamicValue := range dynamicHeaders {
assert.Contains(t, tags, dynamicValue)
delete(tags, dynamicValue)
}

expectedValues := map[string]interface{}{
"msg": "Finished an incoming server HTTP request",
"env": "production",
"clientID": "baz",
"level": "info",
"serviceName": "bazService",
"serviceMethod": "SimpleService::call",
"methodName": "Call",
"zone": "unknown",
"service": "example-gateway",
"Request-Header-Foo-Bar": "Baz",
"Request-Header-x-uuid": "uuid",
"Request-Header-x-token": "token",
"Response-Header-some-res-header": "something",
"method": "GET",
"pathname": "/foo?bar=bar",
"statusCode": float64(200),
"Response-Header-Content-Type": "application/json",
"Request-Header-Accept-Encoding": "gzip",
"Request-Header-User-Agent": "Go-http-client/1.1",
"handlerID": "foo",
"endpointID": "foo",
}
for actualKey, actualValue := range tags {
assert.Equal(t, expectedValues[actualKey], actualValue, "unexpected header %q", actualKey)
}
}
86 changes: 62 additions & 24 deletions test/endpoints/tchannel/baz/baz_simpleservice_method_call_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -105,32 +105,70 @@ func TestCallTChannelSuccessfulRequestOKResponse(t *testing.T) {
assert.Equal(t, 1, len(allLogs["Finished an incoming server TChannel request"]))

tags := allLogs["Finished an incoming server TChannel request"][0]
assert.Equal(t, "info", tags["level"])
assert.Equal(t, "Finished an incoming server TChannel request", tags["msg"])
assert.Equal(t, "bazTChannel", tags["endpointID"])
assert.Equal(t, "call", tags["handlerID"])
assert.Equal(t, "SimpleService::Call", tags["method"])
assert.Equal(t, "token", tags["Request-Header-x-token"])
assert.Equal(t, "uuid", tags["Request-Header-x-uuid"])
assert.Equal(t, "something", tags["Response-Header-some-res-header"])
assert.Equal(t, "test-gateway", tags["calling-service"])
assert.Contains(t, tags["remoteAddr"], getLocalAddr(t))
assert.NotNil(t, tags["timestamp-started"])
assert.NotNil(t, tags["timestamp-finished"])
dynamicHeaders := []string{
"timestamp-started",
"timestamp-finished",
"remoteAddr",
"ts",
"hostname",
"pid",
}
for _, dynamicValue := range dynamicHeaders {
assert.Contains(t, tags, dynamicValue)
delete(tags, dynamicValue)
}

expectedValues := map[string]interface{}{
"level": "info",
"env": "test",
"service": "example-gateway",
"msg": "Finished an incoming server TChannel request",
"endpointID": "bazTChannel",
"handlerID": "call",
"method": "SimpleService::Call",
"Request-Header-x-token": "token",
"Request-Header-x-uuid": "uuid",
"Response-Header-some-res-header": "something",
"calling-service": "test-gateway",
"zone": "unknown",
}
for actualKey, actualValue := range tags {
assert.Equal(t, expectedValues[actualKey], actualValue, "unexpected header %q", actualKey)
}

tags = allLogs["Finished an outgoing client TChannel request"][0]
assert.Equal(t, "info", tags["level"])
assert.Equal(t, "Finished an outgoing client TChannel request", tags["msg"])
assert.Equal(t, "baz", tags["clientID"])
assert.Equal(t, "bazService", tags["serviceName"])
assert.Equal(t, "Call", tags["methodName"])
assert.Equal(t, "SimpleService::call", tags["serviceMethod"])
assert.Equal(t, "token", tags["Request-Header-x-token"])
assert.Equal(t, "uuid", tags["Request-Header-x-uuid"])
assert.Equal(t, "something", tags["Response-Header-some-res-header"])
assert.Contains(t, tags["remoteAddr"], "127.0.0.1")
assert.NotNil(t, tags["timestamp-started"])
assert.NotNil(t, tags["timestamp-finished"])
dynamicHeaders = []string{
"remoteAddr",
"timestamp-started",
"ts",
"hostname",
"pid",
"timestamp-finished",
"Request-Header-$tracing$uber-trace-id",
}
for _, dynamicValue := range dynamicHeaders {
assert.Contains(t, tags, dynamicValue)
delete(tags, dynamicValue)
}

expectedValues = map[string]interface{}{
"msg": "Finished an outgoing client TChannel request",
"env": "test",
"clientID": "baz",
"level": "info",
"serviceName": "bazService",
"serviceMethod": "SimpleService::call",
"methodName": "Call",
"zone": "unknown",
"service": "example-gateway",
"Request-Header-Foo-Bar": "Baz",
"Request-Header-x-uuid": "uuid",
"Request-Header-x-token": "token",
"Response-Header-some-res-header": "something",
}
for actualKey, actualValue := range tags {
assert.Equal(t, expectedValues[actualKey], actualValue, "unexpected header %q", actualKey)
}
}

func getLocalAddr(t *testing.T) string {
Expand Down

0 comments on commit db3d663

Please sign in to comment.