Skip to content

Commit

Permalink
graphql: strip out request IDs from response (#4687)
Browse files Browse the repository at this point in the history
  • Loading branch information
MichaelJCompton authored Jan 30, 2020
1 parent feec1cc commit 6fac5d7
Show file tree
Hide file tree
Showing 12 changed files with 74 additions and 220 deletions.
4 changes: 1 addition & 3 deletions graphql/admin/schema.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,6 @@ import (
dgoapi "github.com/dgraph-io/dgo/v2/protos/api"
"github.com/dgraph-io/dgraph/edgraph"
"github.com/dgraph-io/dgraph/gql"
"github.com/dgraph-io/dgraph/graphql/api"
"github.com/dgraph-io/dgraph/graphql/resolve"
"github.com/dgraph-io/dgraph/graphql/schema"
"github.com/dgraph-io/dgraph/x"
Expand Down Expand Up @@ -143,8 +142,7 @@ func (asr *updateSchemaResolver) Mutate(
asr.admin.resetSchema(asr.newGQLSchema)
asr.admin.schema = asr.newSchema

glog.Infof("[%s] Successfully loaded new GraphQL schema. Serving New GraphQL API.",
api.RequestID(ctx))
glog.Infof("Successfully loaded new GraphQL schema. Serving New GraphQL API.")

return assigned, result, nil
}
Expand Down
73 changes: 0 additions & 73 deletions graphql/api/context.go

This file was deleted.

11 changes: 5 additions & 6 deletions graphql/api/panics.go
Original file line number Diff line number Diff line change
Expand Up @@ -28,13 +28,12 @@ import (
//
// If PanicHandler recovers from a panic, it logs a stack trace, creates an error
// and applies fn to the error.
func PanicHandler(requestID string, fn func(error)) {
func PanicHandler(fn func(error)) {
if err := recover(); err != nil {
glog.Errorf("[%s] panic: %s.\n trace: %s", requestID, err, string(debug.Stack()))
glog.Errorf("panic: %s.\n trace: %s", err, string(debug.Stack()))

fn(errors.Errorf("[%s] Internal Server Error - a panic was trapped. "+
"This indicates a bug in the GraphQL server. A stack trace was logged. "+
"Please let us know : https://github.com/dgraph-io/dgraph/issues.",
requestID))
fn(errors.Errorf("Internal Server Error - a panic was trapped. " +
"This indicates a bug in the GraphQL server. A stack trace was logged. " +
"Please let us know : https://github.com/dgraph-io/dgraph/issues."))
}
}
7 changes: 3 additions & 4 deletions graphql/dgraph/execute.go
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@ import (
dgoapi "github.com/dgraph-io/dgo/v2/protos/api"
"github.com/dgraph-io/dgraph/edgraph"
"github.com/dgraph-io/dgraph/gql"
"github.com/dgraph-io/dgraph/graphql/api"
"github.com/dgraph-io/dgraph/graphql/schema"
"github.com/dgraph-io/dgraph/x"
)
Expand All @@ -41,7 +40,7 @@ func Query(ctx context.Context, query *gql.GraphQuery) ([]byte, error) {
queryStr := AsString(query)

if glog.V(3) {
glog.Infof("[%s] Executing Dgraph query: \n%s\n", api.RequestID(ctx), queryStr)
glog.Infof("Executing Dgraph query: \n%s\n", queryStr)
}

req := &dgoapi.Request{
Expand Down Expand Up @@ -76,8 +75,8 @@ func Mutate(
muts[i] = m.String()
}

glog.Infof("[%s] Executing Dgraph mutation; with\nQuery: \n%s\nMutations:%s",
api.RequestID(ctx), queryStr, strings.Join(muts, "\n"))
glog.Infof("Executing Dgraph mutation; with\nQuery: \n%s\nMutations:%s",
queryStr, strings.Join(muts, "\n"))
}

req := &dgoapi.Request{
Expand Down
19 changes: 0 additions & 19 deletions graphql/e2e/common/common.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,6 @@ import (
"github.com/dgraph-io/dgo/v2"
"github.com/dgraph-io/dgo/v2/protos/api"
"github.com/dgraph-io/dgraph/x"
"github.com/google/uuid"
"github.com/pkg/errors"
"github.com/stretchr/testify/require"
"google.golang.org/grpc"
Expand Down Expand Up @@ -385,8 +384,6 @@ func (params *GraphQLParams) Execute(t *testing.T, req *http.Request) *GraphQLRe
err = json.Unmarshal(res, &result)
require.NoError(t, err)

requireContainsRequestID(t, result)

return result

}
Expand Down Expand Up @@ -498,22 +495,6 @@ func runGQLRequest(req *http.Request) ([]byte, error) {
return body, nil
}

func requireContainsRequestID(t *testing.T, resp *GraphQLResponse) {

v, ok := resp.Extensions["requestID"]
require.True(t, ok,
"GraphQL response didn't contain a request ID - response was:\n%s",
serializeOrError(resp))

str, ok := v.(string)
require.True(t, ok, "GraphQL requestID is not a string - response was:\n%s",
serializeOrError(resp))

_, err := uuid.Parse(str)
require.NoError(t, err, "GraphQL requestID is not a UUID - response was:\n%s",
serializeOrError(resp))
}

func requireUID(t *testing.T, uid string) {
_, err := strconv.ParseUint(uid, 0, 64)
require.NoError(t, err)
Expand Down
7 changes: 3 additions & 4 deletions graphql/e2e/common/error.go
Original file line number Diff line number Diff line change
Expand Up @@ -250,10 +250,9 @@ func panicCatcher(t *testing.T) {
gqlResponse := test.ExecuteAsPost(t, ts.URL)

require.Equal(t, x.GqlErrorList{
{Message: fmt.Sprintf("[%s] Internal Server Error - a panic was trapped. "+
"This indicates a bug in the GraphQL server. A stack trace was logged. "+
"Please let us know : https://github.com/dgraph-io/dgraph/issues.",
gqlResponse.Extensions["requestID"].(string))}},
{Message: fmt.Sprintf("Internal Server Error - a panic was trapped. " +
"This indicates a bug in the GraphQL server. A stack trace was logged. " +
"Please let us know : https://github.com/dgraph-io/dgraph/issues.")}},
gqlResponse.Errors)

require.Nil(t, gqlResponse.Data)
Expand Down
5 changes: 2 additions & 3 deletions graphql/resolve/query.go
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,6 @@ import (
otrace "go.opencensus.io/trace"

"github.com/dgraph-io/dgraph/gql"
"github.com/dgraph-io/dgraph/graphql/api"
"github.com/dgraph-io/dgraph/graphql/schema"
"github.com/dgraph-io/dgraph/x"
)
Expand Down Expand Up @@ -121,8 +120,8 @@ func (qr *queryResolver) rewriteAndExecute(

resp, err := qr.queryExecutor.Query(ctx, dgQuery)
if err != nil {
glog.Infof("[%s] query execution failed : %s", api.RequestID(ctx), err)
return nil, schema.GQLWrapf(err, "[%s] failed to resolve query", api.RequestID(ctx))
glog.Infof("Dgraph query execution failed : %s", err)
return nil, schema.GQLWrapf(err, "Dgraph query failed")
}

return resp, nil
Expand Down
47 changes: 17 additions & 30 deletions graphql/resolve/resolver.go
Original file line number Diff line number Diff line change
Expand Up @@ -301,28 +301,22 @@ func (r *RequestResolver) Resolve(ctx context.Context, gqlReq *schema.Request) *
stop := x.SpanTimer(span, methodResolve)
defer stop()

reqID := api.RequestID(ctx)

if r == nil {
glog.Errorf("[%s] Call to Resolve with nil RequestResolver", reqID)
return schema.ErrorResponse(errors.New("Internal error"), reqID)
glog.Errorf("Call to Resolve with nil RequestResolver")
return schema.ErrorResponse(errors.New("Internal error"))
}

if r.schema == nil {
glog.Errorf("[%s] Call to Resolve with no schema", reqID)
return schema.ErrorResponse(errors.New("Internal error"), reqID)
glog.Errorf("Call to Resolve with no schema")
return schema.ErrorResponse(errors.New("Internal error"))
}

op, err := r.schema.Operation(gqlReq)
if err != nil {
return schema.ErrorResponse(err, reqID)
return schema.ErrorResponse(err)
}

resp := &schema.Response{
Extensions: &schema.Extensions{
RequestID: reqID,
},
}
resp := &schema.Response{}

if glog.V(3) {
// don't log the introspection queries they are sent too frequently
Expand All @@ -333,8 +327,8 @@ func (r *RequestResolver) Resolve(ctx context.Context, gqlReq *schema.Request) *
if err != nil {
glog.Infof("Failed to marshal variables for logging : %s", err)
}
glog.Infof("[%s] Resolving GQL request: \n%s\nWith Variables: \n%s\n",
reqID, gqlReq.Query, string(b))
glog.Infof("Resolving GQL request: \n%s\nWith Variables: \n%s\n",
gqlReq.Query, string(b))
}
}

Expand All @@ -356,7 +350,7 @@ func (r *RequestResolver) Resolve(ctx context.Context, gqlReq *schema.Request) *

go func(q schema.Query, storeAt int) {
defer wg.Done()
defer api.PanicHandler(api.RequestID(ctx),
defer api.PanicHandler(
func(err error) {
allResolved[storeAt] = &Resolved{Err: err}
})
Expand Down Expand Up @@ -589,8 +583,7 @@ func completeDgraphResult(ctx context.Context, field schema.Field, dgResult []by
}

dgraphError := func() ([]byte, error) {
glog.Errorf("[%s] Could not process Dgraph result : \n%s",
api.RequestID(ctx), string(dgResult))
glog.Errorf("Could not process Dgraph result : \n%s", string(dgResult))
return nullResponse(),
x.GqlErrorf("Couldn't process the result from Dgraph. " +
"This probably indicates a bug in the Dgraph GraphQL layer. " +
Expand All @@ -605,8 +598,7 @@ func completeDgraphResult(ctx context.Context, field schema.Field, dgResult []by
var valToComplete map[string]interface{}
err := json.Unmarshal(dgResult, &valToComplete)
if err != nil {
glog.Errorf("[%s] %+v \n Dgraph result :\n%s\n",
api.RequestID(ctx),
glog.Errorf("%+v \n Dgraph result :\n%s\n",
errors.Wrap(err, "failed to unmarshal Dgraph query result"),
string(dgResult))
return nullResponse(),
Expand Down Expand Up @@ -637,16 +629,13 @@ func completeDgraphResult(ctx context.Context, field schema.Field, dgResult []by
//
// We'll continue and just try the first item to return some data.

glog.Errorf("[%s] Got a list of length %v from Dgraph when expecting a "+
"one-item list.\n"+
"GraphQL query was : %s\n",
api.RequestID(ctx), len(val), api.QueryString(ctx))
glog.Error("Got a list of length %v from Dgraph when expecting a " +
"one-item list.\n")

errs = append(errs,
x.GqlErrorf(
"Dgraph returned a list, but %s (type %s) was expecting just one item. "+
"The first item in the list was used to produce the result. "+
"Logged as a potential bug; see the API log for more details.",
"The first item in the list was used to produce the result.",
field.Name(), field.Type().String()).WithLocations(field.Location()))
}

Expand Down Expand Up @@ -683,11 +672,9 @@ func completeDgraphResult(ctx context.Context, field schema.Field, dgResult []by
//
// This isn't really an observable GraphQL error, so no need to add anything
// to the payload of errors for the result.
glog.Errorf("[%s] Top level completeObject didn't return a result. "+
"That's only possible if the query result is non-nullable. "+
"There's something wrong in the GraphQL schema. \n"+
"GraphQL query was : %s\n",
api.RequestID(ctx), api.QueryString(ctx))
glog.Errorf("Top level completeObject didn't return a result. " +
"That's only possible if the query result is non-nullable. " +
"There's something wrong in the GraphQL schema.")
return nullResponse(), append(errs, gqlErrs...)
}

Expand Down
3 changes: 1 addition & 2 deletions graphql/resolve/resolver_error_test.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -252,8 +252,7 @@
{ "getAuthor": { "name": "A.N. Author" } }
errors:
[ { "message": "Dgraph returned a list, but getAuthor (type Author) was expecting just one
item. The first item in the list was used to produce the result.
Logged as a potential bug; see the API log for more details.",
item. The first item in the list was used to produce the result.",
"locations": [ { "column":3, "line":2 } ] } ]

-
Expand Down
Loading

0 comments on commit 6fac5d7

Please sign in to comment.