Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Add hook for logs #739

Merged
merged 2 commits into from
Apr 11, 2024
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
1 change: 1 addition & 0 deletions src/AppContext.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@ export class AppContext {
postInvocationHooks: HookCallback[] = [];
appStartHooks: HookCallback[] = [];
appTerminateHooks: HookCallback[] = [];
logHooks: HookCallback[] = [];
functions: { [id: string]: RegisteredFunction } = {};
legacyFunctions: { [id: string]: LegacyRegisteredFunction } = {};
workerIndexingLocked = false;
Expand Down
20 changes: 19 additions & 1 deletion src/WorkerContext.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,8 +4,10 @@
import { ProgrammingModel } from '@azure/functions-core';
import { AzureFunctionsRpcMessages as rpc } from '../azure-functions-language-worker-protobuf/src/rpc';
import { AppContext } from './AppContext';
import { fromCoreLogLevel } from './coreApi/converters/fromCoreStatusResult';
import { AzFuncSystemError } from './errors';
import { IEventStream } from './GrpcClient';
import { InvocationLogContext, LogHookContext } from './hooks/LogHookContext';

class WorkerContext {
app = new AppContext();
Expand Down Expand Up @@ -62,7 +64,23 @@ class WorkerContext {
* @param requestId gRPC message request id
* @param msg gRPC message content
*/
log(log: rpc.IRpcLog) {
log(log: rpc.IRpcLog, invocationLogCtx?: InvocationLogContext): void {
try {
const logContext = new LogHookContext(log, invocationLogCtx);
for (const callback of worker.app.logHooks) {
callback(logContext);
castrodd marked this conversation as resolved.
Show resolved Hide resolved
}

if (log.logCategory === rpc.RpcLog.RpcLogCategory.User) {
// let hooks change and filter these values, but only for user-generated logs
// system logs should always be sent as-is
log.message = logContext.message;
log.level = fromCoreLogLevel(logContext.level);
}
} catch {
// ignore so that user hooks can't prevent system logs
}

this.eventStream.write({
rpcLog: log,
});
Expand Down
2 changes: 1 addition & 1 deletion src/coreApi/converters/toCoreStatusResult.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ function toCoreLogs(data: rpc.IRpcLog[] | null | undefined): coreTypes.RpcLog[]
}
}

function toCoreLog(data: rpc.IRpcLog): coreTypes.RpcLog {
export function toCoreLog(data: rpc.IRpcLog): coreTypes.RpcLog {
const result = {
...data,
level: toCoreLogLevel(data.level),
Expand Down
20 changes: 13 additions & 7 deletions src/eventHandlers/InvocationHandler.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import { toCoreFunctionMetadata } from '../coreApi/converters/toCoreFunctionMeta
import { toCoreInvocationRequest } from '../coreApi/converters/toCoreInvocationRequest';
import { AzFuncSystemError, isError, ReadOnlyError } from '../errors';
import { executeHooks } from '../hooks/executeHooks';
import { InvocationLogContext } from '../hooks/LogHookContext';
import { getLegacyFunction } from '../LegacyFunctionLoader';
import { nonNullProp } from '../utils/nonNull';
import { worker } from '../WorkerContext';
Expand Down Expand Up @@ -70,6 +71,7 @@ export class InvocationHandler extends EventHandler<'invocationRequest', 'invoca

const hookData: HookData = {};
let { context, inputs } = await invocModel.getArguments();
coreCtx.logContext = { hookData, invocationContext: context };

const preInvocContext: PreInvocationContext = {
get hookData() {
Expand Down Expand Up @@ -157,6 +159,7 @@ class CoreInvocationContext implements coreTypes.CoreInvocationContext {
request: RpcInvocationRequest;
metadata: RpcFunctionMetadata;
state?: InvocationState;
logContext?: InvocationLogContext;
#msgCategory: string;

constructor(request: RpcInvocationRequest, metadata: RpcFunctionMetadata, msgCategory: string) {
Expand All @@ -167,12 +170,15 @@ class CoreInvocationContext implements coreTypes.CoreInvocationContext {
}

log(level: RpcLogLevel, logCategory: RpcLogCategory, message: string): void {
worker.log({
invocationId: this.request.invocationId,
category: this.#msgCategory,
message,
level: fromCoreLogLevel(level),
logCategory: fromCoreLogCategory(logCategory),
});
worker.log(
{
invocationId: this.request.invocationId,
category: this.#msgCategory,
message,
level: fromCoreLogLevel(level),
logCategory: fromCoreLogCategory(logCategory),
},
this.logContext
);
}
}
57 changes: 57 additions & 0 deletions src/hooks/LogHookContext.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the MIT License.

import { HookData, RpcLogCategory, RpcLogLevel } from '@azure/functions-core';
import * as coreTypes from '@azure/functions-core';
import { AzureFunctionsRpcMessages as rpc } from '../../azure-functions-language-worker-protobuf/src/rpc';
import { toCoreLog } from '../coreApi/converters/toCoreStatusResult';
import { ReadOnlyError } from '../errors';
import { nonNullProp } from '../utils/nonNull';
import { worker } from '../WorkerContext';

export interface InvocationLogContext {
hookData: HookData;
invocationContext: unknown;
}

export class LogHookContext implements coreTypes.LogHookContext {
level: RpcLogLevel;
message: string;
#hookData: HookData;
castrodd marked this conversation as resolved.
Show resolved Hide resolved
#category: RpcLogCategory;
#invocationContext: unknown;

constructor(log: rpc.IRpcLog, invocLogCtx: InvocationLogContext | undefined) {
this.#hookData = invocLogCtx?.hookData ?? {};
this.#invocationContext = invocLogCtx?.invocationContext;
const coreLog = toCoreLog(log);
this.level = nonNullProp(coreLog, 'level');
ejizba marked this conversation as resolved.
Show resolved Hide resolved
this.message = nonNullProp(coreLog, 'message');
this.#category = nonNullProp(coreLog, 'logCategory');
}

get hookData(): HookData {
return this.#hookData;
}
set hookData(_obj: HookData) {
throw new ReadOnlyError('hookData');
}
get category(): RpcLogCategory {
return this.#category;
}
set category(_obj: RpcLogCategory) {
throw new ReadOnlyError('category');
}
get appHookData(): HookData {
return worker.app.appHookData;
}
set appHookData(_obj: HookData) {
throw new ReadOnlyError('appHookData');
}
get invocationContext(): unknown {
return this.#invocationContext;
}
set invocationContext(_obj: unknown) {
throw new ReadOnlyError('invocationContext');
}
}
2 changes: 2 additions & 0 deletions src/hooks/getHooks.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@ export function getHooks(hookName: string): HookCallback[] {
return worker.app.appStartHooks;
case 'appTerminate':
return worker.app.appTerminateHooks;
case 'log':
return worker.app.logHooks;
default:
throw new AzFuncRangeError(`Unrecognized hook "${hookName}"`);
}
Expand Down
33 changes: 33 additions & 0 deletions test/eventHandlers/InvocationHandler.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1063,4 +1063,37 @@ describe('InvocationHandler', () => {
msg.invocation.response([])
);
});

it('log hook respects changes to value, only for user log', async () => {
coreApi.registerHook('log', (ctx) => {
ctx.message += 'UpdatedFromHook';
ctx.level = 'error';
});

registerV3Func(Binding.queue, async (invocContext: Context) => {
castrodd marked this conversation as resolved.
Show resolved Hide resolved
invocContext.log('testUserLog');
});
stream.addTestMessage(msg.invocation.request([InputData.http]));
await stream.assertCalledWith(
msg.invocation.receivedRequestLog,
msg.invocation.userLog('testUserLogUpdatedFromHook', LogLevel.Error),
msg.invocation.response([])
);
});

it('ignores log hook error', async () => {
coreApi.registerHook('log', (_ctx) => {
throw new Error('failed log hook');
});

registerV3Func(Binding.queue, async (invocContext: Context) => {
invocContext.log('testUserLog');
});
stream.addTestMessage(msg.invocation.request([InputData.http]));
await stream.assertCalledWith(
msg.invocation.receivedRequestLog,
msg.invocation.userLog(),
msg.invocation.response([])
);
});
});
4 changes: 2 additions & 2 deletions test/eventHandlers/msg.ts
Original file line number Diff line number Diff line change
Expand Up @@ -381,13 +381,13 @@ export namespace msg {
"Warning: Unexpected call to 'log' on the context object after function execution has completed. Please check for asynchronous calls that are not awaited or calls to 'done' made before function execution completes. Function name: testFuncName. Invocation Id: 1. Learn more: https://go.microsoft.com/fwlink/?linkid=2097909"
);

export function userLog(data = 'testUserLog'): TestMessage {
export function userLog(data = 'testUserLog', level = LogLevel.Information): TestMessage {
return {
rpcLog: {
category: 'testFuncName.Invocation',
invocationId: '1',
message: data,
level: LogLevel.Information,
level,
logCategory: LogCategory.User,
},
};
Expand Down
27 changes: 26 additions & 1 deletion types-core/index.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -58,13 +58,15 @@ declare module '@azure/functions-core' {
function registerHook(hookName: 'postInvocation', callback: PostInvocationCallback): Disposable;
function registerHook(hookName: 'appStart', callback: AppStartCallback): Disposable;
function registerHook(hookName: 'appTerminate', callback: AppTerminateCallback): Disposable;
function registerHook(hookName: 'log', callback: LogHookCallback): Disposable;
function registerHook(hookName: string, callback: HookCallback): Disposable;

type HookCallback = (context: HookContext) => void | Promise<void>;
type HookCallback = (context: HookContext) => unknown;
castrodd marked this conversation as resolved.
Show resolved Hide resolved
type PreInvocationCallback = (context: PreInvocationContext) => void | Promise<void>;
type PostInvocationCallback = (context: PostInvocationContext) => void | Promise<void>;
type AppStartCallback = (context: AppStartContext) => void | Promise<void>;
type AppTerminateCallback = (context: AppTerminateContext) => void | Promise<void>;
type LogHookCallback = (context: LogHookContext) => void;

type HookData = { [key: string]: any };

Expand Down Expand Up @@ -146,6 +148,29 @@ declare module '@azure/functions-core' {

type AppTerminateContext = HookContext;

interface LogHookContext extends HookContext {
/**
* If the log occurs during a function execution, the context object passed to the function handler.
* Otherwise, undefined.
*/
readonly invocationContext?: unknown;

/**
* 'system' if the log is generated by Azure Functions, 'user' if the log is generated by your own app.
*/
readonly category: RpcLogCategory;

/**
* Changes to this value _will_ affect the resulting log, but only for user-generated logs.
*/
level: RpcLogLevel;

/**
* Changes to this value _will_ affect the resulting log, but only for user-generated logs.
*/
message: string;
}

/**
* Represents a type which can release resources, such as event listening or a timer.
*/
Expand Down