diff --git a/package.json b/package.json index 678d6fb3..051e0c28 100644 --- a/package.json +++ b/package.json @@ -60,7 +60,7 @@ "presystem-test": "npm run compile", "samples-test": "cd samples/ && npm link ../ && npm test && cd ../", "system-test": "mocha build/system-test --timeout 600000", - "test": "nyc mocha build/test", + "test": "nyc mocha build/test build/test/middleware", "check": "gts check", "clean": "gts clean", "compile": "tsc -p .", @@ -72,8 +72,7 @@ "codecov": "nyc report --reporter=json && codecov -f .coverage/*.json" }, "dependencies": { - "@google-cloud/logging": "^4.0.1", - "@opencensus/propagation-stackdriver": "^0.0.6" + "@google-cloud/logging": "^4.1.0" }, "devDependencies": { "@google-cloud/nodejs-repo-tools": "^2.3.0", diff --git a/src/middleware/express.ts b/src/middleware/express.ts index 87cd6b98..ea15e3d1 100644 --- a/src/middleware/express.ts +++ b/src/middleware/express.ts @@ -13,25 +13,17 @@ * See the License for the specific language governing permissions and * limitations under the License. */ - -import * as context from '@opencensus/propagation-stackdriver'; +import {HttpRequest, middleware as commonMiddleware} from '@google-cloud/logging'; import * as bunyan from 'bunyan'; -import * as http from 'http'; - -export type Request = http.IncomingMessage; -export type Response = http.ServerResponse; -export type NextFunction = (err?: Error) => void; import {LOGGING_TRACE_KEY, LoggingBunyan} from '../index'; import * as types from '../types/core'; +export const APP_LOG_SUFFIX = 'applog'; + // @types/bunyan doesn't export Logger. Access it via ReturnType on // createLogger. -type Logger = ReturnType; - -export interface AnnotatedRequest extends Request { - log: Logger; -} +export type Logger = ReturnType; export interface MiddlewareOptions extends types.Options { level?: types.LogLevel; @@ -39,8 +31,7 @@ export interface MiddlewareOptions extends types.Options { export interface MiddlewareReturnType { logger: Logger; - // tslint:disable-next-line:no-any express middleware. - mw: (req: Request, res: Response, next: NextFunction) => any; + mw: ReturnType; } /** @@ -51,41 +42,28 @@ export async function middleware(options?: MiddlewareOptions): const defaultOptions = {logName: 'bunyan_log', level: 'info'}; options = Object.assign({}, defaultOptions, options); - const bunyan = require('bunyan'); - const loggingBunyan = new LoggingBunyan(options); - const projectId = - await loggingBunyan.stackdriverLog.logging.auth.getProjectId(); - // Failure to acquire projectId from auth would throw to the user. + // TODO: Create a http request logger unless we are running on GAE or GCF. + const loggingBunyanApp = new LoggingBunyan(Object.assign({}, options, { + // For request bundling to work, the parent (request) and child (app) logs + // need to have distinct names. For exact requirements see: + // https://cloud.google.com/appengine/articles/logging#linking_app_logs_and_requests + logName: `${options.logName}_${APP_LOG_SUFFIX}` + })); const logger = bunyan.createLogger({ - name: options.logName, - streams: [loggingBunyan.stream(options.level as types.LogLevel)] + name: `${options.logName}_${APP_LOG_SUFFIX}`, + streams: [loggingBunyanApp.stream(options.level as types.LogLevel)] }); + const projectId = + await loggingBunyanApp.stackdriverLog.logging.auth.getProjectId(); + return { logger, - mw: (req: Request, res: Response, next: NextFunction) => { - const wrapper = { - setHeader(name: string, value: string) { - req.headers[name] = value; - }, - getHeader(name: string) { - return req.headers[name]; - } - }; - - let spanContext = context.extract(wrapper); - if (!spanContext) { - // We were the first actor to detect lack of context. Establish context. - spanContext = context.generate(); - context.inject(wrapper, spanContext); - } - - const trace = `projects/${projectId}/traces/${spanContext.traceId}`; - - (req as AnnotatedRequest).log = - logger.child({[LOGGING_TRACE_KEY]: trace}, true /*simple child */); - next(); - } + mw: commonMiddleware.express.makeMiddleware(projectId, makeChildLogger) }; + + function makeChildLogger(trace: string) { + return logger.child({[LOGGING_TRACE_KEY]: trace}, true /* simple child */); + } } diff --git a/system-test/test-middleware-express.ts b/system-test/test-middleware-express.ts index 8fd523d3..5d0764ce 100644 --- a/system-test/test-middleware-express.ts +++ b/system-test/test-middleware-express.ts @@ -57,7 +57,7 @@ describe('express middleware', () => { const next = async () => { // At this point fakeRequest.log should have been installed. // tslint:disable-next-line:no-any - (fakeRequest as any as elb.AnnotatedRequest).log.info(LOG_MESSAGE); + (fakeRequest as any).log.info(LOG_MESSAGE); await delay(WRITE_CONSISTENCY_DELAY_MS); diff --git a/test/middleware/test-express.ts b/test/middleware/test-express.ts new file mode 100644 index 00000000..f10788f9 --- /dev/null +++ b/test/middleware/test-express.ts @@ -0,0 +1,96 @@ +/*! + * Copyright 2018 Google LLC + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import * as assert from 'assert'; +import * as proxyquire from 'proxyquire'; + +// types-only import. Actual require is done through proxyquire below. +import {MiddlewareOptions} from '../../src/middleware/express'; + +const FAKE_PROJECT_ID = 'project-🦄'; +const FAKE_GENERATED_MIDDLEWARE = () => {}; + +let passedOptions: MiddlewareOptions|undefined; + +class FakeLoggingBunyan { + // tslint:disable-next-line:no-any Doing "just enough" faking. + stackdriverLog: any; + constructor(options: MiddlewareOptions) { + passedOptions = options; + this.stackdriverLog = { + logging: { + auth: { + async getProjectId() { + return FAKE_PROJECT_ID; + } + } + } + }; + } + + // tslint:disable-next-line:no-any Doing "just enough" faking. + stream(level: any) { + return {level, type: 'raw', stream: this}; + } +} + +let passedProjectId: string|undefined; +function fakeMakeMiddleware( + projectId: string, makeChildLogger: Function): Function { + passedProjectId = projectId; + return FAKE_GENERATED_MIDDLEWARE; +} + +const {middleware, APP_LOG_SUFFIX} = + proxyquire('../../src/middleware/express', { + '../../src/index': {LoggingBunyan: FakeLoggingBunyan}, + '@google-cloud/logging': + {middleware: {express: {makeMiddleware: fakeMakeMiddleware}}} + }); + +describe('middleware/express', () => { + beforeEach(() => { + passedOptions = undefined; + passedProjectId = undefined; + }); + + it('should create and return a middleware', async () => { + const {mw} = await middleware(); + assert.strictEqual(mw, FAKE_GENERATED_MIDDLEWARE); + }); + + it('should use default logName and level', async () => { + await middleware(); + assert.ok(passedOptions); + assert.strictEqual(passedOptions!.logName, `bunyan_log_${APP_LOG_SUFFIX}`); + assert.strictEqual(passedOptions!.level, 'info'); + }); + + it('should prefer user-provided logName and level', async () => { + const LOGNAME = '㏒'; + const LEVEL = 'fatal'; + const OPTIONS = {logName: LOGNAME, level: LEVEL}; + await middleware(OPTIONS); + assert.ok(passedOptions); + assert.strictEqual(passedOptions!.logName, `${LOGNAME}_${APP_LOG_SUFFIX}`); + assert.strictEqual(passedOptions!.level, LEVEL); + }); + + it('should acquire the projectId and pass to makeMiddleware', async () => { + await middleware(); + assert.strictEqual(passedProjectId, FAKE_PROJECT_ID); + }); +}); \ No newline at end of file