Performance issue?!

[Warxcell]

Hello, I'm debugging slow responses from API, and it seems like GraphQL Mesh is the bottleneck.

In this particular request there are 2 queries sent.

I've added following logger in mesh:

const logger: Plugin<Context> = {
  onExecute({args}) {
    const startedAt = new Date()

    return {
      onExecuteDone: () => {
        const now = new Date()
        const self = now.getTime() - startedAt.getTime()
        console.log('OPERATION', args.operationName, 'TOTAL TIME', self)
      },
    };
  },
};

First request:
How client see response time: 318ms
GraphQL Mesh see response time: 287ms
Backend answered in 37ms

Second request:

How client see response time: 583ms
GraphQL Mesh see response time: 528ms
Backend answered in 211ms

So there is constant latency of ~200-300ms inside Mesh - which seems insane, given that it only parses query and routes the requests (and it does that in async fashion) - and that is way slower than the backends which also parses queries but also processes all the data (in non-async fashion) ?

Backend is GraphQL.

Here is profile from the request. Seems like the issue is coming @graphql-tools/delegate/cjs/delegateToSchema.js
which internally calls several times @graphql-tools/delegate/cjs/Transformer.js 20ms.

What could be done in order to achieve better performance ?!

[Urigo]

can you share a repo we could look at?

[Warxcell]

and btw this is SINGLE request concurrently. So they are not overlapping whatsoever and the node is not under any load.

[Warxcell]

seems like there is deviation between requests after fetch from subschemas. Sometimes it takes 5ms, sometimes it takes 700ms - for same request. Not that parsing and preparing queries are fast...

[Warxcell]

even after upgrade to latest versions

OPERATION init: (2024-07-24T19:57:42.945Z): total: 220ms, self: 220ms - Before fetch
OPERATION init: (2024-07-24T19:57:43.034Z): total: 309ms, self: 89ms - Fetched
OPERATION init: (2024-07-24T19:57:43.594Z): total: 869ms, self: 560ms - Operation finish

Huuge delay. Total 780 ms total latency because of graphql mesh in this request.

[enisdenjo]

hey @Warxcell, thanks for reporting this! we'd like to investigate further and therefore ask for more info in order to expedite the process: how are you running mesh serve (docker,npx,tsx,node)? what are your sources (just graphql or a combination)? ideally, a repro, or at least the config, would be perfect!

[Warxcell]

I'm running it inside docker with mesh start command. This is the dockerfile which builds the image:

ARG NODE_VERSION=20
ARG NODE_ENV=production

FROM node:${NODE_VERSION}-slim AS base

WORKDIR /app

EXPOSE 4000

ENTRYPOINT ["yarn"]

FROM base AS builder

RUN apt-get update && apt-get install --assume-yes python3 python3-dev libcurl4-openssl-dev make g++

COPY --link package.json yarn.lock ./

RUN yarn install --frozen-lockfile

COPY --link .meshrc.ts ./
COPY --link src ./src/
COPY --link tsconfig.json ./

ARG DEBUG=false

RUN yarn build && yarn tsc-lint

RUN yarn install --production --frozen-lockfile

FROM base AS prod

ARG NODE_ENV
ENV NODE_ENV=$NODE_ENV
ENV TS_NODE_TRANSPILE_ONLY="true"
ENV SENTRY_PROFILER_LOGGING_MODE="lazy"

COPY --link --from=builder /app/package.json ./package.json
COPY --link --from=builder /app/yarn.lock ./yarn.lock
COPY --link --from=builder /app/.meshrc.ts ./.meshrc.ts
COPY --link --from=builder /app/src ./src
COPY --link --from=builder /app/.mesh ./.mesh
COPY --link --from=builder /app/node_modules ./node_modules

CMD ["start"]

I have 3 sources - 2 remote GraphQLs and one local graphql. (makeExecutableSchema + "source": "schema.ts").

The query fetches 6 fields from one of Remote GraphQL and 8 fields from local GraphQL (so total of 14 Query fields), with quite a bit of query (~1000 lines)

I will try to create simple reproducible repo.