Allow a user-provided logger for Server, Gateway and AER (#3894)

* Switch multi-argument `logger` pattern to single parameter invocations.

Will consider supporting this if I can confirm all loggers support it.

* Decompose `GatewayConfigBase` into types in preparation for `logger`.

The `logger` will be mutually exclusive to the `debug` property, which means
we'll need to (essentially) XOR them in the types with `never` types, which
cannot be done with an `interface`.

* gateway: Introduce `Logger` type and expose on `logger` config.

This is a mutually exclusive option to `debug` which enables logging of our
default logger when one is not provided by the user.

* tests: test various popular loggers: log4js, winston, bunyan, loglevel.

* Add optional `logger` to `GraphQLServiceContext` and `GraphQLRequestContext`.

A follow-up commit will make these required!

* Introduce optional `logger` property for `apollo-engine-reporting`.

This is a more granular part of a larger project to introduce the concept of
a `logger` to various parts of the Apollo Server stack - including
`ApolloGateway` and `ApolloServer`.

Since this extension is most always initiated by `ApolloServer` itself, this
will generally be a property that is inherited by the configuration that
`ApolloServer` provides.

The intention is: if someone provides a `logger` at the `ApolloServer`
level, we will propagate it down to various sub-components, including the
`apollo-engine-reporting` extension.

* Introduce optional `logger` for `ApolloServer` class.

In general, Apollo Server itself does very little outputting of messages
(either informational or otherwise) to its console.  Historically, Apollo
Server has simply used various `console` facilities (i.e. `console.log`) to
output such messages.

Using `console` methods does get the point across quite well in development,
though it's less ideal for production environments which often demand a more
structured approach to capturing their log messages across various stacks.
For example, in containerized environments logs are often siphoned into
various centralized log facilities and/or third party log providers (e.g.
Datadog, Loggly, etc.).

Many users are already using existing loggers (like [`winston`], [`log4js`],
[`bunyan`] and more) to report messages from their resolvers by exposing
those logger implementations on their "context" using the `context` property
to the `ApolloServer` constructor options.  However, exposing a logger on
the `context` doesn't allow Apollo Server to use it for its own important
messaging and users should be able to opt into getting Apollo's own messages
in the same log facilities.

Apollo Server will continue to be relatively quiet for now, but various
sub-components (e.g. Gateway, Engine Reporting) are already outputting more
and more important messages and warnings which deserve to get attention.

Therefore, this introduces a relatively generic `logger` property to
`ApolloServer` which will be made available on the `GraphQLRequestContext`
that is already passed around in many places internally, received by various
Gateway compoments, and also exposed to plugins, allowing well-considered
plugins to utilize the same centralized log sink.

This should also allow granular logging at various levels, including scoped
or tagged logging, since the request pipeline could be used to create a
sub-instance of a logger.  For example, different components can accept
their own `logger` property which, when set, will override any more-parent
`logger` and allow logs to be sorted according to user preference.  Apollo
Engine will be the first-subcomponent to get this treatment.

Similarly, for logger implementations that support the notion of creating a
sub-logger from an existing logger, the plugin life-cycle hooks can be used
to create a user-specific logger in the `requestDidStart` life-cycle.  This
can be helpful in applying a user-id tag to all log messages which happened
within the scope of a particular request.  If the same logger should be made
available to resolvers via exposure on the `context, such plugin
implementation on `requestDidStart` should also augment the already-created
`context` with the scoped-logger.

* To support Node.js 6, use older version of `log4js` for testing.

We're only testing the interface compatibility here, so the latest version
isn't really necessary.  Though this would be great to update!

* ResponseCache: when available, use `requestContext.logger` to log.

* gateway: when set, log using `requestContext.logger` in `executeQueryPlan`.

* Make `logger` required on `GraphQLServiceContext` + `GraphQLRequestContext`.

As promised in 62e99d76.

* Fix all the spelling mistakes.

You'd think I dictated these using Siri or something.

Thanks, @trevor-scheer.

Co-Authored-By: Trevor Scheer <trevor@apollographql.com>

* Add CHANGELOG for #3894.

* docs: Explain `logger` on `ApolloServer` and `EngineReportingOptions`.

* Kinda revert "Decompose `GatewayConfigBase` into types in prep..."

This reverts the decomposition introduced by commit
8a19ecc, but also maintains the bit that
was added right after it in 780d7f4.

Specifically, I misjudged with the direction I was headed.  While my intent
was to have `debug` and `logger` be mutually exclusive, it turns out that in
order to preserve the existing behavior, I need to make sure that `debug:
true` is the thing that puts the default logger (`loglevel`) into the
appropriate level where it still prints out various legacy messages.

cc @trevor-scheer

* docs: Explain `logger` on `ApolloGateway` in the API reference.

* Apply counter-intuitive severity to `debugPrintReports` messages.

In terms of verbosity, and as the name of this option suggests, the output
when `debugPrintReports` is enabled is is either an "info" or a "debug"
level message.

However, we are using `warn` here for compatibility reasons since the
`debugPrintReports` flag pre-dated the existence of log-levels and changing
this to also require `debug: true` (in addition to `debugPrintReports`) just
to reach the level of verbosity to produce the output would be a breaking
change.  The "warn" level is on by default.  There is a similar theory and
comment applied below.

cc @trevor-scheer

* docs: Note presence of `logger` in plugins' lifecycle  hooks.

Co-authored-by: Trevor Scheer <trevor@apollographql.com>

Author: abernix

CHANGELOG.md

@@ -5,6 +5,10 @@ The version headers in this history reflect the versions of Apollo Server itself
 - [__CHANGELOG for `@apollo/gateway`__](https://github.com/apollographql/apollo-server/blob/master/packages/apollo-gateway/CHANGELOG.md)
 - [__CHANGELOG for `@apollo/federation`__](https://github.com/apollographql/apollo-server/blob/master/packages/apollo-federation/CHANGELOG.md)
 
+### v2.13.0
+
+- `apollo-server-core`: Support providing a custom logger implementation (e.g. [`winston`](https://npm.im/winston), [`bunyan`](https://npm.im/bunyan), etc.) to capture server console messages.  Though there has historically been limited output from Apollo Server, some messages are important to capture in the larger context of production logging facilities or can benefit from using more advanced structure, like JSON-based logging.  This also introduces a `logger` property to the `GraphQLRequestContext` that is exposed to plugins, making it possible for plugins to leverage the same server-level logger, and allowing implementors to create request-specific log contexts, if desired.  When not provided, these will still output to `console`. [PR #3894](https://github.com/apollographql/apollo-server/pull/3894)
+
 ### v2.12.0
 
 - `apollo-server-core`: When operating in gateway mode using the `gateway` property of the Apollo Server constructor options, the failure to initialize a schema during initial start-up, e.g. connectivity problems, will no longer result in the federated executor from being assigned when the schema eventually becomes available.  This precludes a state where the gateway may never become available to serve federated requests, even when failure conditions are no longer present. [PR #3811](https://github.com/apollographql/apollo-server/pull/3811)

docs/source/api/apollo-gateway.mdx

@@ -99,13 +99,20 @@ example of using `ApolloGateway`, see [The gateway](/federation/gateway/).
     });
     ```
 
+  * `logger`: `Logger`
+
+    A logging implementation to be used in place of `console`.  The implementation must provide the methods which satisfy the requirements of [the `Logger` interface](https://github.com/apollographql/apollo-server/blob/80a12d89ea1ae9a0892f4a81d9213eddf95ca965/packages/apollo-server-types/src/index.ts#L114-L121) (i.e. it must provide `debug`, `info`, `warn` and `error` methods).  When a custom logger is provided, it will receive all levels of logging and it is up to the logger itself to determine how it wishes to handle each level.  When a custom logger is _not_ provided, Gateway will default to outputting `warn` and `error` levels unless `debug: true` is specified,  in which case it will output all log levels (i.e. `debug` through `error`).
+
+    Additionally, this `logger` will be made available on the `GraphQLRequestContext` and available to plugins.  This allows a plugin to, e.g., augment the logger on a per-request basis within the `requestDidStart` life-cycle hook.
+
+
   * `debug`: `Boolean`
 
     If `true`, the gateway logs startup messages, along with the query plan for
     each incoming request. The default value is `false`.
-    
+
   * `fetcher`: `typeof fetch`
-  
+
     When specified, overrides the default
     [Fetch API](https://fetch.spec.whatwg.org/#fetch-api) implementation
     which is used when communicating with downstream services.  By default,

docs/source/api/apollo-server.md

@@ -68,6 +68,12 @@ new ApolloServer({
     | AWS Lambda | <code>{<br/>&nbsp;&nbsp;event: [`APIGatewayProxyEvent`](https://github.com/DefinitelyTyped/DefinitelyTyped/blob/50adc95acf873e714256074311353232fcc1b5ed/types/aws-lambda/index.d.ts#L78-L92),<br/>&nbsp;&nbsp;context: [`LambdaContext`](https://github.com/DefinitelyTyped/DefinitelyTyped/blob/50adc95acf873e714256074311353232fcc1b5ed/types/aws-lambda/index.d.ts#L510-L534)<br/>}</code> |
     | Micro | <code>{ req: [`MicroRequest`](https://github.com/apollographql/apollo-server/blob/c356bcf3f2864b8d2fcca0add455071e0606ef46/packages/apollo-server-micro/src/types.ts#L3-L5), res: [`ServerResponse`](https://github.com/DefinitelyTyped/DefinitelyTyped/blob/50adc95acf873e714256074311353232fcc1b5ed/types/node/v10/http.d.ts#L145-L158) }</code> |
 
+  * `logger`: `Logger`
+
+    A logging implementation to be used in place of `console`.  The implementation must provide the methods which satisfy the requirements of [the `Logger` interface](https://github.com/apollographql/apollo-server/blob/80a12d89ea1ae9a0892f4a81d9213eddf95ca965/packages/apollo-server-types/src/index.ts#L114-L121) (i.e. it must provide `debug`, `info`, `warn` and `error` methods).  When a custom logger is provided, it will receive all levels of logging and it is up to the logger itself to determine how it wishes to handle each level.  When a custom logger is _not_ provided, Apollo Server will default to outputting `warn` and `error` levels unless `debug: true` is specified,  in which case it will output all log levels (i.e. `debug` through `error`).
+
+    Additionally, this `logger` will be made available on the `GraphQLRequestContext` and available to plugins.  This allows a plugin to, e.g., augment the logger on a per-request basis within the `requestDidStart` life-cycle hook.
+
   * `rootValue`: <`Any`> | <`Function`>
 
     A value or function called with the parsed `Document`, creating the root value passed to the graphql executor. The function is useful if you wish to provide a different root value based on the query operation type.
@@ -337,6 +343,10 @@ addMockFunctionsToSchema({
   a service. You can also specify an API key with the `ENGINE_API_KEY`
   environment variable, although the `apiKey` option takes precedence.
 
+* `logger`: `Logger`
+
+  By default, this will inherit from the `logger` provided to `ApolloServer` which defaults to `console` when not provided.  If specified within the `EngineReportingOptions` it can be used to send engine reporting to a separate logger.  If provided, the implementation must provide the methods which satisfy the requirements of [the `Logger` interface](https://github.com/apollographql/apollo-server/blob/80a12d89ea1ae9a0892f4a81d9213eddf95ca965/packages/apollo-server-types/src/index.ts#L114-L121) (i.e. it must provide `debug`, `info`, `warn` and `error` methods).
+
 *  `calculateSignature`: (ast: DocumentNode, operationName: string) => string
 
    Specify the function for creating a signature for a query.

docs/source/integrations/plugins.md

@@ -269,6 +269,15 @@ const server = new ApolloServer({
 
 The `requestDidStart` event fires whenever Apollo Server begins fulfilling a GraphQL request.
 
+```typescript
+requestDidStart?(
+  requestContext: WithRequired<
+    GraphQLRequestContext<TContext>,
+    'request' | 'context' | 'logger'
+  >
+): GraphQLRequestListener<TContext> | void;
+```
+
 This function can optionally return an object that includes functions for responding
 to request lifecycle events that might follow `requestDidStart`.
 
@@ -318,7 +327,7 @@ does not occur.
 parsingDidStart?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source'
+    'metrics' | 'source' | 'logger'
   >,
 ): (err?: Error) => void | void;
 ```
@@ -338,7 +347,7 @@ available at this stage, because parsing must succeed for validation to occur.
 validationDidStart?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source' | 'document'
+    'metrics' | 'source' | 'document' | 'logger'
   >,
 ): (err?: ReadonlyArray<Error>) => void | void;
 ```
@@ -355,7 +364,7 @@ both the `operationName` string and `operation` AST are available.
 didResolveOperation?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source' | 'document' | 'operationName' | 'operation'
+    'metrics' | 'source' | 'document' | 'operationName' | 'operation' | 'logger'
   >,
 ): ValueOrPromise<void>;
 ```
@@ -371,7 +380,7 @@ are invoked in series, and the first non-null response is used.
 responseForOperation?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source' | 'document' | 'operationName' | 'operation'
+    'metrics' | 'source' | 'document' | 'operationName' | 'operation' | 'logger'
   >,
 ): ValueOrPromise<GraphQLResponse | null>;
 ```
@@ -385,7 +394,7 @@ GraphQL operation specified by a request's `document` AST.
 executionDidStart?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source' | 'document' | 'operationName' | 'operation'
+    'metrics' | 'source' | 'document' | 'operationName' | 'operation' | 'logger'
   >,
 ): (err?: Error) => void | void;
 ```
@@ -399,7 +408,7 @@ parsing, validating, or executing a GraphQL operation.
 didEncounterErrors?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'source' | 'errors'
+    'metrics' | 'source' | 'errors' | 'logger'
   >,
 ): ValueOrPromise<void>;
 ```
@@ -414,7 +423,7 @@ if the GraphQL operation encounters one or more errors.
 willSendResponse?(
   requestContext: WithRequired<
     GraphQLRequestContext<TContext>,
-    'metrics' | 'response'
+    'metrics' | 'response' | 'logger'
   >,
 ): ValueOrPromise<void>;
 ```