newrelic / newrelic-node-apollo-server-plugin

Apache License 2.0
62 stars 29 forks source link

Internal server error for some graphql-upload requests #206

Closed philjt closed 2 years ago

philjt commented 2 years ago

Description

We are currently using the graphql-upload package to add upload support to our graphql api, however for certain upload mutations we are receiving the error below which prevents the upload from succeeding. Disabling the newrelic addin solves the issue however that isn't a solution we want to consider in our production environment.

Example request

POST https://xxxxx.com/ HTTP/1.1
Content-Type: multipart/form-data; boundary="ef0e2df4-f746-4871-a349-4634341a5a24"
Host: xxxx.com
Content-Length: 131811
Expect: 100-continue

--ef0e2df4-f746-4871-a349-4634341a5a24
Content-Type: text/plain; charset=utf-8
Content-Disposition: form-data; name="operations"

{
    "operationName": "uploadDocument",
    "query": "\r\nmutation($file: Upload!) \r\n{\r\n    upload(input : {file: $file})\r\n    {\r\n        code, \r\n        error,\r\n        message,\r\n        uniqueId\r\n    }\r\n}"
}

--ef0e2df4-f746-4871-a349-4634341a5a24
Content-Type: text/plain; charset=utf-8
Content-Disposition: form-data; name="map"

{"file":["variables.file"] }
--ef0e2df4-f746-4871-a349-4634341a5a24
Content-Disposition: form-data; name="file"; filename="TST-101349-1384.pdf"
Content-Type: application/pdf

%PDF-1.4
%    
...

Errror

{
  "errors": [
    {
      "message": "Cannot read properties of undefined (reading 'selectionSet')",
      "extensions":
      {
        "code": "INTERNAL_SERVER_ERROR",
        "exception":
        {
          "stacktrace": ["TypeError: Cannot read properties of undefined (reading 'selectionSet')", "    at isIntrospectionQuery (/node_modules/@newrelic/apollo-server-plugin/lib/create-plugin.js:461:20)", "    at shouldIgnoreTransaction (/node_modules/@newrelic/apollo-server-plugin/lib/create-plugin.js:476:46)", "    at Object.didResolveOperation (/node_modules/@newrelic/apollo-server-plugin/lib/create-plugin.js:105:15)", "    at /node_modules/apollo-server-core/dist/utils/dispatcher.js:21:31", "    at Array.map (<anonymous>)", "    at Dispatcher.callTargets (/node_modules/apollo-server-core/dist/utils/dispatcher.js:18:24)", "    at Dispatcher.<anonymous> (/node_modules/apollo-server-core/dist/utils/dispatcher.js:27:43)", "    at Generator.next (<anonymous>)", "    at /node_modules/apollo-server-core/dist/utils/dispatcher.js:8:71", "    at new Promise (<anonymous>)"]
        }
      }
    }
  ]
}

Expected Behavior

The newrelic plugin shouldn't throw an error - it should ensure that any errors are captured and logged and not bubbled up to the calling application.

Steps to Reproduce

See steps above in the description

Your Environment

node 16.15 "@newrelic/apollo-server-plugin": "^1.3.0", "apollo-server": "^3.8.1", "graphql": "^15.5.0", graphql-upload": "^13.0.0", "newrelic": "^8.12.0",

Additional context

I have raised a PR to prevent the error from occurring, see: https://github.com/newrelic/newrelic-node-apollo-server-plugin/pull/205

bizob2828 commented 2 years ago

@philjt I'm trying to reproduce this error. do you mind providing me your code that you have to integrate the graphql-upload package into your apollo server? I want to make sure I'm replicating your setup

philjt commented 2 years ago

Hi Bob

This is a snippet of our code

const app = express();

  // add additional middleware
  app.use((req, _res, next) => {
    // set logger
    // Get the kong correlationId from the http headers
    const kongCorrelationId = req.headers['x-correlation-id'] as string |
undefined;
    const reqId = kongCorrelationId && kongCorrelationId.length > 0 ?
kongCorrelationId : uuid4();
    const logger = getCorrelatedLogger(reqId);

    req.app.locals.traceParent = reqId;
    req.app.locals.correlatedLogger = logger;
    req.app.locals.correlationId = reqId;

    next();
  });

  app.use(cookieParser());

  app.use(passport.initialize());
  passport.use(bearerStrategy);

  app.use(cors(corsOptions));

  app.use((req, res, next) => {
    ...
// auth
  });

  app.use(helmet(helmetOptions));

  // Add the 'graphql-upload' middleware
  app.use(graphqlUploadExpress({ maxFileSize: 12000000 }));

  app.use(bodyParser.json({ limit: jsonBodyLimit }));

  const schema = await createSchema(productApisOnly === 'true',
primaryLogger);
  const server = new ApolloServer({
    schema,
    debug: gqlDebugEnabled,
bizob2828 commented 2 years ago

Thanks @philjt. Here's a sample application that uses the graphql-upload package and the newrelic apollo server plugin: https://github.com/bizob2828/apollo-upload-app/blob/main/README.md. As you can see I'm not seeing the same crashes you are. Something else might be going on here. The PR you opened(#205) might be ok but we typically want integration tests that reproduce the errors.

You do say:

however for certain upload mutations we are receiving the error below which prevents the upload from succeeding

Does this mean that some mutations that are doing file uploads are working? Do you mind sharing the code around the upload mutation? If you don't feel comfortable posting it here you could always engage our technical support staff at support.newrelic.com. They will also ask to collect the necessary information which may or may not be sensitive (such as logs).

philjt commented 2 years ago

Hi @bizob2828 Sorry for not getting back to you sooner. Yes some mutation calls are working it seems to depend on how the request is formatted. As this is an API we cannot control how our clients are formatting the requests, so we need to ensure that the service doesn't fail.

For now we have had to remove the newrelic plugin as it was preventing requests due to it causing this unhandled exception.

philjt commented 2 years ago

@bizob2828 I have had another play with the code today and I can now replicate the issue running your example.

The key difference seems to be that the request fails when including an operationName in the request

This request succeeds curl --location --request POST 'http://localhost:29506/graphql' \ --form 'operations="{\"query\": \"mutation ($file: Upload!) { singleUpload(file: $file) { filename } }\", \"variables\": { \"file\": null } }"' \ --form 'map="{ \"0\": [\"variables.file\"] }"' \ --form '0=@"./Test Invoice.pdf"'

However this one fails: curl --location --request POST 'http://localhost:29506/graphql' \ --form 'operations="{\"operationName\":\"testUpload\", \"query\": \"mutation ($file: Upload!) { singleUpload(file: $file) { filename } }\", \"variables\": { \"file\": null } }"' \ --form 'map="{ \"0\": [\"variables.file\"] }"' \ --form '0=@"./Test Invoice.pdf"'

Note that the only difference is the inclusion of the operationName curl --location --request POST 'http://localhost:29506/graphql' \ --form 'operations="{\"operationName\":\"testUpload\", \"query\": \"mutation ($file: Upload!) { singleUpload(file: $file) { filename } }\", \"variables\": { \"file\": null } }"' \ --form 'map="{ \"0\": [\"variables.file\"] }"' \ --form '0=@"./Test Invoice - Copy (6).pdf"'

I hope this enables you also to replicate the issue.

Thanks

bizob2828 commented 2 years ago

It's worth noting this has nothing to do with the graphl-upload plugin. It's just that if you provide an operation name that's undefined to a query it'll fail. Our plugin had an assumption so the real error was never surfacing

Real error

{"errors":[{"message":"Unknown operation named \"testUpload\".","extensions":{"code":"INTERNAL_SERVER_ERROR","exception":{"stacktrace":["GraphQLError: Unknown operation named \"testUpload\".","    at buildExecutionContext (/Users/revans/code/graphql-upload-node-16/node_modules/graphql/execution/execute.js:264:9)","    at execute (/Users/revans/code/graphql-upload-node-16/node_modules/graphql/execution/execute.js:116:22)","    at execute (/Users/revans/code/graphql-upload-node-16/node_modules/apollo-server-core/dist/requestPipeline.js:205:48)","    at processGraphQLRequest (/Users/revans/code/graphql-upload-node-16/node_modules/apollo-server-core/dist/requestPipeline.js:148:34)","    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)","    at async processHTTPRequest (/Users/revans/code/graphql-upload-node-16/node_modules/apollo-server-core/dist/runHttpQuery.js:220:30)"]}}}]}