Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

feat: Logging provider for Cloud Functions that outputs structured logs to process.stdout #605

Merged
merged 2 commits into from
Mar 21, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 23 additions & 0 deletions .readme-partials.yml
Original file line number Diff line number Diff line change
Expand Up @@ -153,3 +153,26 @@ body: |-
},
});
```

### Alternative way to ingest logs in Google Cloud managed environments
If you use this library with the Cloud Logging Agent, you can configure the handler to output logs to `process.stdout` using
the [structured logging Json format](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields).
To do this, add `redirectToStdout: true` parameter to the `LoggingBunyan` constructor as in sample below.
You can use this parameter when running applications in Google Cloud managed environments such as AppEngine, Cloud Run,
Cloud Function or GKE. The logger agent installed on these environments can capture `process.stdout` and ingest it into Cloud Logging.
The agent can parse structured logs printed to `process.stdout` and capture additional log metadata beside the log payload.
It is recommended to set `redirectToStdout: true` in serverless environments like Cloud Functions since it could
decrease logging record loss upon execution termination - since all logs are written to `process.stdout` those
would be picked up by the Cloud Logging Agent running in Google Cloud managed environment.

```js
// Imports the Google Cloud client library for Bunyan
const {LoggingBunyan} = require('@google-cloud/logging-bunyan');

// Creates a client
const loggingBunyan = new LoggingBunyan({
projectId: 'your-project-id',
keyFilename: '/path/to/key.json',
redirectToStdout: true,
});
```
23 changes: 23 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -236,6 +236,29 @@ const loggingBunyan = new LoggingBunyan({
});
```

### Alternative way to ingest logs in Google Cloud managed environments
If you use this library with the Cloud Logging Agent, you can configure the handler to output logs to `process.stdout` using
the [structured logging Json format](https://cloud.google.com/logging/docs/structured-logging#special-payload-fields).
To do this, add `redirectToStdout: true` parameter to the `LoggingBunyan` constructor as in sample below.
You can use this parameter when running applications in Google Cloud managed environments such as AppEngine, Cloud Run,
Cloud Function or GKE. The logger agent installed on these environments can capture `process.stdout` and ingest it into Cloud Logging.
The agent can parse structured logs printed to `process.stdout` and capture additional log metadata beside the log payload.
It is recommended to set `redirectToStdout: true` in serverless environments like Cloud Functions since it could
decrease logging record loss upon execution termination - since all logs are written to `process.stdout` those
would be picked up by the Cloud Logging Agent running in Google Cloud managed environment.

```js
// Imports the Google Cloud client library for Bunyan
const {LoggingBunyan} = require('@google-cloud/logging-bunyan');

// Creates a client
const loggingBunyan = new LoggingBunyan({
projectId: 'your-project-id',
keyFilename: '/path/to/key.json',
redirectToStdout: true,
});
```


## Samples

Expand Down
85 changes: 71 additions & 14 deletions src/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,11 +20,18 @@ import * as express from './middleware/express';
// Export the express middleware as 'express'.
export {express};

import {Logging, detectServiceContext} from '@google-cloud/logging';
import {
Logging,
detectServiceContext,
Log,
LogSync,
Entry,
} from '@google-cloud/logging';

import * as types from './types/core';

import {ApiResponseCallback} from '@google-cloud/logging/build/src/log';
import {LogSeverityFunctions} from '@google-cloud/logging/build/src/utils/log-common';

// Map of Stackdriver logging levels.
const BUNYAN_TO_STACKDRIVER: Map<number, string> = new Map([
Expand Down Expand Up @@ -160,23 +167,28 @@ export class LoggingBunyan extends Writable {
private resource: types.MonitoredResource | undefined;
private serviceContext?: types.ServiceContext;
private defaultCallback?: ApiResponseCallback;
stackdriverLog: types.StackdriverLog; // TODO: add type for @google-cloud/logging
cloudLog: LogSeverityFunctions;
redirectToStdout: boolean;
constructor(options?: types.Options) {
options = options || {};
super({objectMode: true});
this.logName = options.logName || 'bunyan_log';
this.resource = options.resource;
this.serviceContext = options.serviceContext;
this.defaultCallback = options.defaultCallback;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
this.stackdriverLog = new Logging(options as any).log(this.logName, {
removeCircular: true,
// See: https://cloud.google.com/logging/quotas, a log size of
// 250,000 has been chosen to keep us comfortably within the
// 256,000 limit.
maxEntrySize: options.maxEntrySize || 250000,
this.redirectToStdout = options.redirectToStdout ?? false;
if (!this.redirectToStdout) {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
}) as any;
this.cloudLog = new Logging(options).log(this.logName, {
removeCircular: true,
// See: https://cloud.google.com/logging/quotas, a log size of
// 250,000 has been chosen to keep us comfortably within the
// 256,000 limit.
maxEntrySize: options.maxEntrySize || 250000,
});
} else {
this.cloudLog = new Logging(options).logSync(this.logName);
}

// serviceContext.service is required by the Error Reporting
// API. Without it, errors that are logged with level 'error'
Expand All @@ -194,7 +206,8 @@ export class LoggingBunyan extends Writable {

/* Asynchrnously attempt to discover the service context. */
if (!this.serviceContext) {
detectServiceContext(this.stackdriverLog.logging.auth).then(
// eslint-disable-next-line @typescript-eslint/no-explicit-any
detectServiceContext((this.cloudLog as any).logging.auth).then(
serviceContext => {
this.serviceContext = serviceContext!;
},
Expand Down Expand Up @@ -283,7 +296,15 @@ export class LoggingBunyan extends Writable {
delete record[LOGGING_SAMPLED_KEY];
}

return this.stackdriverLog.entry(entryMetadata, record);
return (
(
this.redirectToStdout
? (this.cloudLog as LogSync)
: (this.cloudLog as Log)
)
// eslint-disable-next-line @typescript-eslint/no-explicit-any
.entry(entryMetadata as any, record)
);
}

// eslint-disable-next-line @typescript-eslint/no-explicit-any
Expand Down Expand Up @@ -350,7 +371,7 @@ export class LoggingBunyan extends Writable {
*/
_write(record: types.BunyanLogRecord, encoding: string, callback: Function) {
const entry = this.formatEntry_(record);
this.stackdriverLog.write(entry, this.defaultCallback ?? callback);
this._writeCall(entry, callback);
}

/**
Expand All @@ -375,8 +396,44 @@ export class LoggingBunyan extends Writable {
return this.formatEntry_(request.chunk);
}
);
this._writeCall(entries, callback);
}

this.stackdriverLog.write(entries, this.defaultCallback ?? callback);
/**
* Creates a combined callback which calls the this.defaultCallback and the Writable.write supplied callback
* @param callback The callback function provided by Writable
* @returns Combined callback which executes both, this.defaultCallback and one supplied by Writable.write
*/
generateCallback(callback: Function): ApiResponseCallback {
// Make sure that both callbacks are called in case if provided
const newCallback: ApiResponseCallback = (
err: Error | null,
apiResponse?: {}
) => {
if (callback) {
callback(err, apiResponse);
}
if (this.defaultCallback) {
this.defaultCallback(err, apiResponse);
}
};
return newCallback;
}

/**
* A helper function to make a write call
* @param entries The entries to be written
* @param callback The callback supplied by Writable.write
*/
_writeCall(entries: Entry | Entry[], callback: Function) {
if (this.redirectToStdout) {
(this.cloudLog as LogSync).write(entries);
// The LogSync class does not supports callback. However if callback provided and
// if this.defaultCallback exists, we should call it
this.generateCallback(callback)(null, undefined);
} else {
(this.cloudLog as Log).write(entries, this.generateCallback(callback));
}
}
}

Expand Down
4 changes: 2 additions & 2 deletions src/middleware/express.ts
Original file line number Diff line number Diff line change
Expand Up @@ -64,8 +64,8 @@ export async function middleware(
name: `${options.logName}_${APP_LOG_SUFFIX}`,
streams: [loggingBunyanApp.stream(options.level as types.LogLevel)],
});

const auth = loggingBunyanApp.stackdriverLog.logging.auth;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
const auth = (loggingBunyanApp.cloudLog as any).logging.auth;
const [env, projectId] = await Promise.all([
auth.getEnv(),
auth.getProjectId(),
Expand Down
9 changes: 8 additions & 1 deletion src/types/core.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -79,11 +79,18 @@ export interface Options {
*/
apiEndpoint?: string;
// An attempt will be made to truncate messages larger than maxEntrySize.
// Please note that this parameter is ignored when redirectToStdout is set.
maxEntrySize?: number;

// A default global callback to be used for {@link LoggingBunyan} write calls
// when callback is not supplied by caller in function parameters
defaultCallback?: ApiResponseCallback;
/**
* Boolen flag that opts-in redirecting the output to STDOUT instead of ingesting logs to Cloud
* Logging using Logging API. Defaults to {@code false}. Redirecting logs can be used in
* Google Cloud environments with installed logging agent to delegate log ingestions to the
* agent. Redirected logs are formatted as one line Json string following the structured logging guidelines.
*/
redirectToStdout?: boolean;
}

export interface MonitoredResource {
Expand Down
10 changes: 9 additions & 1 deletion system-test/logging-bunyan.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ import * as bunyan from 'bunyan';
import * as uuid from 'uuid';
import * as types from '../src/types/core';
import {ErrorsApiTransport} from './errors-transport';
import {Logging} from '@google-cloud/logging';
import {Logging, LogSync} from '@google-cloud/logging';

const logging = new Logging();
import {LoggingBunyan} from '../src/index';
Expand All @@ -47,6 +47,14 @@ describe('LoggingBunyan', function () {
streams: [loggingBunyan.stream('info')],
});

it('should create LoggingBunyan with LogSync', () => {
const loggingBunyan = new LoggingBunyan({
logName: LOG_NAME,
redirectToStdout: true,
});
assert.ok(loggingBunyan.cloudLog instanceof LogSync);
});

it('should properly write log entries', async function () {
this.retries(3);
const timestamp = new Date();
Expand Down
35 changes: 16 additions & 19 deletions test/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -264,7 +264,7 @@ describe('logging-bunyan', () => {
});

it('should properly create an entry', done => {
loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: types.StackdriverEntryMetadata
) => {
Expand All @@ -284,7 +284,7 @@ describe('logging-bunyan', () => {
const recordWithMsg = Object.assign({msg: 'msg'}, RECORD);
const recordWithMessage = Object.assign({message: 'msg'}, RECORD);

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: types.StackdriverEntryMetadata
) => {
Expand Down Expand Up @@ -317,7 +317,7 @@ describe('logging-bunyan', () => {
RECORD
);

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record_: types.StackdriverEntryMetadata
) => {
Expand All @@ -340,7 +340,7 @@ describe('logging-bunyan', () => {
RECORD
);

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record_: types.StackdriverEntryMetadata
) => {
Expand All @@ -362,7 +362,7 @@ describe('logging-bunyan', () => {
RECORD
);

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: string | types.BunyanLogRecord
) => {
Expand All @@ -382,7 +382,7 @@ describe('logging-bunyan', () => {
it('should promote properly formatted labels to metadata', done => {
const labels = {key: 'value', 0: 'value2'};
const recordWithLabels = {...RECORD, labels};
loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: string | types.BunyanLogRecord
) => {
Expand All @@ -396,7 +396,7 @@ describe('logging-bunyan', () => {
it('should not promote ill-formatted labels to metadata', done => {
const labels = {key: -1}; // values must be strings.
const recordWithLabels = {...RECORD, labels};
loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: string | types.BunyanLogRecord
) => {
Expand All @@ -417,7 +417,7 @@ describe('logging-bunyan', () => {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
(recordWithTrace as any)[loggingBunyanLib.LOGGING_SAMPLED_KEY] = true;

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: string | types.BunyanLogRecord
) => {
Expand All @@ -441,7 +441,7 @@ describe('logging-bunyan', () => {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
(recordWithTrace as any)[loggingBunyanLib.LOGGING_SAMPLED_KEY] = false;

loggingBunyan.stackdriverLog.entry = (
loggingBunyan.cloudLog.entry = (
entryMetadata: types.StackdriverEntryMetadata,
record: string | types.BunyanLogRecord
) => {
Expand Down Expand Up @@ -630,11 +630,11 @@ describe('logging-bunyan', () => {
it('should write the record to the log instance', done => {
const entry = {};

loggingBunyan.stackdriverLog.entry = () => {
loggingBunyan.cloudLog.entry = () => {
return entry;
};

loggingBunyan.stackdriverLog.write =
loggingBunyan.cloudLog.write =
// Writable.write used 'any' in function signature.
// eslint-disable-next-line @typescript-eslint/no-explicit-any
(entries: any, callback: Function) => {
Expand All @@ -647,22 +647,19 @@ describe('logging-bunyan', () => {

it('should write the record and call default callback', done => {
let isCallbackCalled = false;
loggingBunyan.stackdriverLog.entry = () => {
loggingBunyan.cloudLog.entry = () => {
return {};
};
loggingBunyan.defaultCallback = () => {
isCallbackCalled = true;
};
loggingBunyan.stackdriverLog.write =
loggingBunyan.cloudLog.write =
// Writable.write used 'any' in function signature.
// eslint-disable-next-line @typescript-eslint/no-explicit-any
(entries: any, callback: Function) => {
callback();
};

loggingBunyan._write(RECORD, '', () => {
throw Error('Should never be called!');
});
loggingBunyan._write(RECORD, '', () => {});
assert.strictEqual(isCallbackCalled, true);
done();
});
Expand Down Expand Up @@ -690,11 +687,11 @@ describe('logging-bunyan', () => {
it('should write the records to the log instance', done => {
const entry = {};

loggingBunyan.stackdriverLog.entry = () => {
loggingBunyan.cloudLog.entry = () => {
return entry;
};

loggingBunyan.stackdriverLog.write =
loggingBunyan.cloudLog.write =
// Writable.write used 'any' in function signature.
// eslint-disable-next-line @typescript-eslint/no-explicit-any
(entries: any, callback: Function) => {
Expand Down
4 changes: 2 additions & 2 deletions test/middleware/test-express.ts
Original file line number Diff line number Diff line change
Expand Up @@ -32,10 +32,10 @@ let passedOptions: Array<MiddlewareOptions | undefined>;

class FakeLoggingBunyan {
// eslint-disable-next-line @typescript-eslint/no-explicit-any
stackdriverLog: any;
cloudLog: any;
constructor(options: MiddlewareOptions) {
passedOptions.push(options);
this.stackdriverLog = {
this.cloudLog = {
logging: {
auth: {
async getProjectId() {
Expand Down