dotansimha / graphql-yoga

🧘 Rewrite of a fully-featured GraphQL Server with focus on easy setup, performance & great developer experience. The core of Yoga implements WHATWG Fetch API and can run/deploy on any JS environment.
https://the-guild.dev/graphql/yoga-server
MIT License
8.24k stars 569 forks source link

document the logger #1195

Closed n1ru4l closed 2 years ago

n1ru4l commented 2 years ago

We should add better docs on the logger customization.

  1. How to customize the logger
  2. How to use yoga with common log collecting tools
  3. ???
dthyresson commented 2 years ago

@n1ru4l This is a timely issue as I was recently using Yoga with RedwoodJS and there Pino logger and had a few observations:

  1. Yoga debug logging is enabled anytime a logger is provided (even a custom one) but there is no way to disable the Yoga log output. See: https://github.com/dotansimha/graphql-yoga/blob/a7834d676f3b45c6761d7f7e259f8c566fcd3994/packages/common/src/server.ts#L272
// Log events - useful for debugging purposes
      enableIf(
        logger !== false,
        useLogger({
          skipIntrospection: true,
          logFn: (eventName, events) => {
            switch (eventName) {
              case 'execute-start':
              case 'subscribe-start':
                this.logger.debug(titleBold('Execution start'))
                const {
                  query,
                  operationName,
                  variables,
                  extensions,
                }: YogaInitialContext = events.args.contextValue
                if (query) {
                  this.logger.debug(
                    '\n' + titleBold('Received GraphQL operation:') + '\n',
                    query,
                  )
                }
                if (operationName) {
                  this.logger.debug('\t operationName:', operationName)
                }
                if (variables) {
                  this.logger.debug('\t variables:', variables)
                }
                if (extensions) {
                  this.logger.debug('\t extensions:', extensions)
                }
                break
              case 'execute-end':
              case 'subscribe-end':
                this.logger.debug(titleBold('Execution end'))
                this.logger.debug('\t result:', events.result)
                break
            }
          },
        }),
  1. That means that it is not easy to turn off output like:
May 11, 06:04:01 PM: {"level":20,"time":1652306641686,"pid":9,"hostname":"xxx","msg":"Extracting GraphQL Parameters"}
May 11, 06:04:01 PM: {"level":20,"time":1652306641700,"pid":9,"hostname":"xx","msg":"Processing GraphQL Parameters"}
May 11, 06:04:01 PM: {"level":20,"time":1652306641721,"pid":9,"hostname":"xx,"msg":"\u001b[1mExecution start\u001b[0m"}
May 11, 06:04:01 PM: {"level":20,"time":1652306641724,"pid":9,"hostname":"xxx","msg":"\n\u001b[1mReceived GraphQL operation:\u001b[0m\n"}
May 11, 06:04:01 PM: {"level":20,"time":1652306641725,"pid":9,"hostname":"xx","msg":"\t operationName:"}
May 11, 06:04:01 PM: {"level":20,"time":1652306641725,"pid":9,"hostname":"xx,"msg":"\t variables:"}

In this case using the Pino logger to output NDJSON in a Netlify function

  1. Because Pino outputs NDJSON, the formatting with tabs and newlines and bolds are not necessarily needed.

This is a Redwood debug log from the GraphQL Server ... can see a few things: 1) redaction is enabled (we hide the title as en example of log redaction), 2) we have separate keys for data, operationName, query variables etc. 3) we add a name (Pino child logger) to distinguish itself from other logging/logs sent

May 11, 06:04:01 PM: {"level":20,"time":1652306641782,"pid":9,"hostname":"xx","name":"graphql-server","operationName":"BLOG_POSTS","query":{},"data":{"posts":[{"id":150,"title":"[Redacted]","body":"this is some text","createdAt":"2021-08-18T18:00:02.168Z","formattedDate":"6:00 pm on 18th August 2021","__typename":"Post"},{"id":2,"title":"[Redacted]","body":"The wind in the trees is whispering \\ Whispering low that I love her \\ She puts her hand over mine \\ Down in the lime tree arbour","createdAt":"2021-03-18T05:32:39.258Z","formattedDate":"5:32 am on 18th March 2021","__typename":"Post"},{"id":151,"title":"[Redacted]","body":"This is a tests","createdAt":"2022-01-03T15:17:30.505Z","formattedDate":"3:17 pm on 3rd January 2022","__typename":"Post"},{"id":9,"title":"[Redacted]","body":"Great success!","createdAt":"2021-08-06T16:44:22.248Z","formattedDate":"4:44 pm on 6th August 2021","__typename":"Post"},{"id":4,"title":"[Redacted]","body":"Souma Yergon, Sou Nou Yergon \\ We are shakin' the tree \\ Souma Yergon, Sou Nou Yergon \\ We are shakin' the tree","createdAt":"2021-03-18T05:32:39.502Z","formattedDate":"5:32 am on 18th March 2021","__typename":"Post"},{"id":109,"title":"[Redacted]","body":"there","createdAt":"2021-08-18T04:51:11.720Z","formattedDate":"4:51 am on 18th August 2021","__typename":"Post"}]},"msg":"GraphQL execution completed: BLOG_POSTS"}

Suggestions (and perhaps this is a separate issue):

  1. Configure Yoga logging separately
  2. Configure if the log messages should be "pretty" (tabs, newlines, bolds) or not
  3. Note: Redwood may want to setup the child logger earlier so its instance is the Yoga logger (and thus named)
dthyresson commented 2 years ago
  1. How to use yoga with common log collecting tools

Pino with their transports is an excellent way to send logs to tools like Datadog and LogFlare.

See: https://getpino.io/#/docs/transports

ardatan commented 2 years ago
n1ru4l commented 2 years ago

https://github.com/dotansimha/graphql-yoga/discussions/1625#discussioncomment-3441299

enisdenjo commented 2 years ago

1806