log server events to logFunction (#78)

* log server events to logFunction * update changelog
apollographql · Aug 5, 2016 · adf5727 · adf5727
1 parent ed00387
commit adf5727
Show file tree

Hide file tree

Showing 3 changed files with 55 additions and 0 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -1,5 +1,8 @@
 # Changelog
 
+### v0.2.2
+* Log server events such as request start etc. with logFunction ([@helfer](https://github.com/helfer) in [#78](https://github.com/apollostack/apollo-server/pull/78))
+
 ### v0.2.1
 * Complete refactor of Apollo Server using TypeScript. PR [#41](https://github.com/apollostack/apollo-server/pull/41)
 * Added HAPI integration ([@nnance](https://github.com/nnance) in [#46](https://github.com/apollostack/apollo-server/pull/46))

diff --git a/src/core/runQuery.test.ts b/src/core/runQuery.test.ts
@@ -169,4 +169,37 @@ describe('runQuery', () => {
  return expect(res.data).to.deep.equal(expected);
  });
  });
+
+ it('calls logFunction', () => {
+ const query = `
+ query Q1 {
+ testString
+ }`;
+ const logs = [];
+ const logFn = (...args) => {
+ logs.push(args);
+ };
+ const expected = {
+ testString: 'it works',
+ };
+ return runQuery({
+ schema: Schema,
+ query: query,
+ operationName: 'Q1',
+ variables: { test: 123 },
+ logFunction: logFn,
+ })
+ .then((res) => {
+ expect(res.data).to.deep.equal(expected);
+ expect(logs.length).to.equals(11);
+ expect(logs[0][0]).to.equals('request.start');
+ expect(logs[1][0]).to.equals('request.query');
+ expect(logs[1][1]).to.deep.equals(query);
+ expect(logs[2][0]).to.equals('request.variables');
+ expect(logs[2][1]).to.deep.equals({ test: 123 });
+ expect(logs[3][0]).to.equals('request.operationName');
+ expect(logs[3][1]).to.equals('Q1');
+ expect(logs[10][0]).to.equals('request.end');
+ });
+ });
 });
diff --git a/src/core/runQuery.ts b/src/core/runQuery.ts
@@ -3,6 +3,7 @@ import {
  GraphQLResult,
  Document,
  parse,
+ print,
  validate,
  execute,
  formatError,
@@ -34,6 +35,10 @@ export interface QueryOptions {
 function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  let documentAST: Document;
 
+ const logFunction = options.logFunction || function(){ return null; };
+
+ logFunction('request.start');
+
  function format(errors: Array<Error>): Array<Error> {
  // TODO: fix types! shouldn't have to cast.
  // the blocker is that the typings aren't right atm:
@@ -42,12 +47,19 @@ function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  return errors.map(options.formatError || formatError as any) as Array<Error>;
  }
 
+ logFunction('request.query', typeof options.query === 'string' ? options.query : print(options.query));
+ logFunction('request.variables', options.variables);
+ logFunction('request.operationName', options.operationName);
+
  // if query is already an AST, don't parse or validate
  if (typeof options.query === 'string') {
  try {
  // TODO: time this with log function
+ logFunction('parse.start');
  documentAST = parse(options.query as string);
+ logFunction('parse.end');
  } catch (syntaxError) {
+ logFunction('parse.end');
  return Promise.resolve({ errors: format([syntaxError]) });
  }
 
@@ -57,7 +69,9 @@ function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  if (options.validationRules) {
  rules = rules.concat(options.validationRules);
  }
+ logFunction('validation.start');
  const validationErrors = validate(options.schema, documentAST, rules);
+ logFunction('validation.end');
  if (validationErrors.length) {
  return Promise.resolve({ errors: format(validationErrors) });
  }
@@ -66,6 +80,7 @@ function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  }
 
  try {
+ logFunction('execution.start');
  return execute(
  options.schema,
  documentAST,
@@ -74,6 +89,7 @@ function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  options.variables,
  options.operationName
  ).then(gqlResponse => {
+ logFunction('execution.end');
  let response = {
  data: gqlResponse.data,
  };
@@ -83,9 +99,12 @@ function runQuery(options: QueryOptions): Promise<GraphQLResult> {
  if (options.formatResponse) {
  response = options.formatResponse(response);
  }
+ logFunction('request.end');
  return response;
  });
  } catch (executionError) {
+ logFunction('execution.end');
+ logFunction('request.end');
  return Promise.resolve({ errors: format([executionError]) });
  }
 }