Open
Description
Describe the bug
[22:36:15.758] 0ms error %@contra/contra-api: unhandledRejection
error:
code: ERR_HTTP_HEADERS_SENT
message: Cannot write headers after they are sent to the client
name: Error
stack:
"""
Error [ERR_HTTP_HEADERS_SENT]: Cannot write headers after they are sent to the client
at ServerResponse.writeHead (node:_http_server:345:11)
at safeWriteHead (/srv/node_modules/.pnpm/fastify@4.24.3/node_modules/fastify/lib/reply.js:556:9)
at onSendEnd (/srv/node_modules/.pnpm/fastify@4.24.3/node_modules/fastify/lib/reply.js:595:5)
at wrapOnSendEnd (/srv/node_modules/.pnpm/fastify@4.24.3/node_modules/fastify/lib/reply.js:549:5)
at next (/srv/node_modules/.pnpm/fastify@4.24.3/node_modules/fastify/lib/hooks.js:293:7)
at handleResolve (/srv/node_modules/.pnpm/fastify@4.24.3/node_modules/fastify/lib/hooks.js:310:5)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
"""
Added console.trace to try to catch it.
Trace: header
at Reply.header (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:247:11)
at Reply.headers (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:274:10)
at Object.handler (file:///srv/apps/contra-api/dist/contra-api/factories/createGraphqlPlugin.js:60:19)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Trace: header
at Reply.header (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:247:11)
at Reply.headers (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:274:10)
at Object.handler (file:///srv/apps/contra-api/dist/contra-api/factories/createGraphqlPlugin.js:60:19)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Trace: header
at Reply.header (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:247:11)
at Reply.headers (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:274:10)
at Object.handler (file:///srv/apps/contra-api/dist/contra-api/factories/createGraphqlPlugin.js:60:19)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Trace: send
at Reply.send (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:134:11)
at Object.handler (file:///srv/apps/contra-api/dist/contra-api/factories/createGraphqlPlugin.js:71:26)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Trace: header
at Reply.header (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:247:11)
at setCookies (/srv/node_modules/.pnpm/@fastify+cookie@9.1.0/node_modules/@fastify/cookie/plugin.js:80:15)
at Object.fastifyCookieOnSendHandler (/srv/node_modules/.pnpm/@fastify+cookie@9.1.0/node_modules/@fastify/cookie/plugin.js:109:5)
at next (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/hooks.js:299:30)
at onSendHookRunner (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/hooks.js:321:3)
at onSendHook (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:537:5)
at Reply.send (/srv/node_modules/.pnpm/fastify@4.24.3_patch_hash=lcbqiye6cxjewuoghmhivz2pjm/node_modules/fastify/lib/reply.js:161:7)
at Object.handler (file:///srv/apps/contra-api/dist/contra-api/factories/createGraphqlPlugin.js:71:26)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Our setup is pretty basic:
import { createContext } from './createContext.js';
import { AuthenticationError, ForbiddenError } from '@contra/errors';
import { type DatabasePool } from '@contra/slonik';
import { type Configuration } from '@contra/temporary-common/types.js';
import { useSchema } from '@envelop/core';
import { useParserCache } from '@envelop/parser-cache';
import { useValidationCache } from '@envelop/validation-cache';
import { renderGraphiQL } from '@graphql-yoga/render-graphiql';
import { FastifyReply, FastifyRequest } from 'fastify';
import { fastifyPlugin } from 'fastify-plugin';
import { GraphQLError, type GraphQLSchema } from 'graphql';
import { createYoga, maskError } from 'graphql-yoga';
import { type Redis } from 'ioredis';
import { randomUUID } from 'node:crypto';
import lru from 'tiny-lru';
export const createGraphqlPlugin = fastifyPlugin<{
configuration: Configuration;
pool: DatabasePool;
redis: Redis;
schema: GraphQLSchema;
}>(async (fastify, options) => {
const DAY = 24 * 60 * 60 * 1_000;
type ServerContext = {
reply: FastifyReply;
request: FastifyRequest;
};
const yoga = createYoga<ServerContext>({
context: ({ request }) => {
return createContext({
configuration: options.configuration,
pool: options.pool,
redis: options.redis,
request,
});
},
graphqlEndpoint: '/',
maskedErrors: options.configuration['error-masking']
? {
maskError: (error, message, isDevelopment) => {
// We don't know what this error, therefore using the default masking function
if (!(error instanceof GraphQLError)) {
return maskError(error, message, isDevelopment);
}
const originalError = error?.originalError as
| (Error & {
code?: string;
extensions?: Record<string, any>;
})
| undefined;
const uid = randomUUID();
// Authentication/authorization errors are expected, so we don't mask or report them either
if (
originalError instanceof AuthenticationError ||
originalError instanceof ForbiddenError
) {
return new GraphQLError(
originalError.message,
error.nodes,
error.source,
error.positions,
error.path,
null,
{ code: originalError.code, uid },
);
}
return maskError(error, message, isDevelopment);
},
}
: false,
plugins: [
useSchema(options.schema),
useParserCache({
documentCache: lru(10_000, DAY),
}),
useValidationCache({
cache: lru(10_000, DAY),
}),
],
renderGraphiQL,
schema: options.schema,
});
void fastify.route({
handler: async (request, reply) => {
const response = await yoga.handleNodeRequest(request, {
reply,
request,
});
reply.headers({
...Object.fromEntries(response.headers.entries()),
'x-contra-release-version':
options.configuration['release-version'] ?? 'n/a',
});
if (reply.sent) {
console.trace('already sent 1');
}
reply.status(response.status);
if (reply.sent) {
console.trace('already sent 2');
}
return reply.send(response.body);
},
method: ['GET', 'POST', 'OPTIONS'],
url: yoga.graphqlEndpoint,
});
});
This error appeared only after trying to migrate from Helix to Yoga.
Your Example Website or App
N/A
Steps to Reproduce the Bug or Issue
N/A
Expected behavior
N/A
Screenshots or Videos
No response
Platform
N/A
Additional context
No response
Metadata
Metadata
Assignees
Type
Projects
Milestone
Relationships
Development
No branches or pull requests
Participants
Activity
ardatan commentedon Nov 7, 2023
Could you disable your cookie plugin and try again?
gajus commentedon Nov 7, 2023
Not really, because the tests that are failing are for authorized user. So everything would fail even before it gets to it.
For what it is worth, we are just using
"@fastify/cookie": "^9.1.0",.I could patch the plugin if you see anything wrong with it.
For what it is worth, I looked at the plugin and nothing looks off.
https://github.com/fastify/fastify-cookie/blob/efea6715583149fdc7a591ca831047a84e3b80ce/plugin.js#L72
gajus commentedon Nov 7, 2023
I am not convinced that it is coming from the cookie plugin either. For instance, this crash does not refer to the cookie plugin.
ardatan commentedon Nov 7, 2023
Then could you help us to reproduce it because error stack traces look too cryptic for us to understand the problem?
gajus commentedon Nov 7, 2023
Annoyingly I was not able to replicate it locally yet, so cannot provide that or fix it. But I am working on it.
gajus commentedon Nov 7, 2023
I am still trying to understand what is happening here, but it looks like it happens after there is an unhandled rejection:
This is our error handler:
As seen from logs, it looks like Yoga attempted to send a reply even though it was handled by the
setErrorHandler, i.e.setErrorHandleralready sent a response. Trying to replicate this in a smaller example now.ardatan commentedon Nov 7, 2023
Sorry but this is not helpful enough for us to debug the issue. We need a proper reproduction like I said above.
gajus commentedon Nov 7, 2023
I don't know what the underlying issue is, but the issue is def with
graphql-yoga/ Fastify interoperability.I realized that Yoga response itself is a readable stream, and given that I don't use readable streams elsewhere, I tried to buffer the response. Turns out that fixes the issue, i.e.
Hope this helps others.
gajus commentedon Nov 8, 2023
Will leave this open since it is an issue with Yoga / Fastify compatibility.
ardatan commentedon Nov 9, 2023
Instead of
return reply.send, it should bereply.sendandreturn replylike here already;https://github.com/dotansimha/graphql-yoga/blob/main/examples/fastify/src/app.ts#L90
Urigo commentedon Nov 19, 2023
is there something we could add on the Yoga-Fastify docs to make sure people know how to use it properly?
kingston commentedon May 15, 2024
@gajus I encountered this issue in our E2E tests which were pretty bad since it pretty much triggered the entire Node server to crash on a premature close with @fastify/session. After a bit of digging, I figured out that using handleNodeRequestAndResponse instead of handleNodeRequest fixes this issue. It looks like this was released in Graphql Yoga 5.3.0.
gajus commentedon May 15, 2024
Thanks for this. Just deployed this change – so far looking really good!