Skip to content

Commit

Permalink
feat: gRPC transport logging (#209)
Browse files Browse the repository at this point in the history
DH-18086: gRPC transport logging

### Testing
I tested this using a local http1 proxy on a Grizzly dev server to see
errors logged via gRPC transport. I was able to see the following when
creating new Core+ workers:
```
[NodeHttp2gRPCTransport] ERROR: Session error Error: Protocol error
    at Http2Session.onSessionInternalError (node:internal/http2/core:793:26)
    at Http2Session.callbackTrampoline (node:internal/async_hooks:130:17)
```

I also tested without the proxy and can see debug messages for gRPC
transport communication. This is easy to test by connecting a server and
looking at the Output -> Deephaven Debug panel and looking for
[NodeHttp2gRPCTransport] messages.
  • Loading branch information
bmingles authored Jan 27, 2025
1 parent 833f59c commit a20013a
Show file tree
Hide file tree
Showing 9 changed files with 160 additions and 31 deletions.
46 changes: 23 additions & 23 deletions package-lock.json

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

2 changes: 1 addition & 1 deletion package.json
Original file line number Diff line number Diff line change
Expand Up @@ -870,7 +870,7 @@
"dependencies": {
"@deephaven-enterprise/auth-nodejs": "^1.20240723.124-beta",
"@deephaven-enterprise/query-utils": "^1.20240723.124-beta",
"@deephaven/jsapi-nodejs": "^0.103.0",
"@deephaven/jsapi-nodejs": "^0.104.0",
"nanoid": "^5.0.7"
},
"devDependencies": {
Expand Down
2 changes: 2 additions & 0 deletions src/common/constants.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,8 @@ export const CONFIG_KEY = {
enterpriseServers: 'enterpriseServers',
} as const;

export const CENSORED_TEXT = '********' as const;

export const DEFAULT_CONSOLE_TYPE = 'python' as const;
// export const DHFS_SCHEME = 'dhfs';

Expand Down
11 changes: 11 additions & 0 deletions src/controllers/ExtensionController.ts
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ import {
isSupportedLanguageId,
Logger,
OutputChannelWithHistory,
sanitizeGRPCLogMessageArgs,
Toaster,
} from '../util';
import {
Expand Down Expand Up @@ -107,6 +108,8 @@ export class ExtensionController implements Disposable {
this.initializeWebViews();
this.initializeServerUpdates();

this._context.subscriptions.push(NodeHttp2gRPCTransport);

logger.info(
'Congratulations, your extension "vscode-deephaven" is now active!'
);
Expand Down Expand Up @@ -317,6 +320,14 @@ export class ExtensionController implements Disposable {
Logger.addConsoleHandler();
Logger.addOutputChannelHandler(this._outputChannelDebug);

const gRPCOutputChannelHandler = Logger.createOutputChannelHandler(
this._outputChannelDebug
);
NodeHttp2gRPCTransport.onLogMessage((logLevel, ...args: unknown[]) => {
args = sanitizeGRPCLogMessageArgs(args);
gRPCOutputChannelHandler(logLevel)('[NodeHttp2gRPCTransport]', ...args);
});

this._toaster = new Toaster();

this._context.subscriptions.push(
Expand Down
12 changes: 11 additions & 1 deletion src/controllers/PanelController.ts
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ import {
} from '../util';
import { DhcService } from '../services';
import {
CENSORED_TEXT,
DEEPHAVEN_POST_MSG,
DH_PANEL_VIEW_TYPE,
OPEN_VARIABLE_PANELS_CMD,
Expand Down Expand Up @@ -161,7 +162,16 @@ export class PanelController extends ControllerBase {
workerInfo,
});

logger.debug('Posting LoginOptions response:', response);
logger.debug('Posting LoginOptions response:', {
...response,
payload: {
...response.payload,
payload: {
...response.payload.payload,
token: CENSORED_TEXT,
},
},
});

postResponseMessage(response);

Expand Down
43 changes: 37 additions & 6 deletions src/util/Logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -41,19 +41,50 @@ export class Logger {
});
};

/**
* Stringify an argument for logging.
* @param arg The argument to stringify.
* @returns The stringified argument.
*/
static stringifyArg = (arg: unknown): string => {
if (arg instanceof Error) {
return arg.stack ?? arg.message;
}

if (typeof arg === 'string') {
return arg;
}

try {
return JSON.stringify(arg);
} catch {
return String(arg);
}
};

/**
* Create a log handler that logs to a `vscode.OutputChannel`.
* @param outputChannel The output channel to log to.
* @returns A log handler that logs to the output channel.
*/
static createOutputChannelHandler = (
outputChannel: vscode.OutputChannel
): ((level: LogLevel) => LogLevelHandler) => {
return (level: LogLevel): LogLevelHandler =>
(label, ...args) =>
outputChannel.appendLine(
`${label} ${level.toUpperCase()}: ${args.map(Logger.stringifyArg).join(' ')}`
);
};

/**
* Register a log handler that logs to a `vscode.OutputChannel`.
* @param outputChannel
*/
static addOutputChannelHandler = (
outputChannel: vscode.OutputChannel
): void => {
const createHandler =
(level: LogLevel): LogLevelHandler =>
(label, ...args) =>
outputChannel.appendLine(
`${label} ${level.toUpperCase()}: ${args.map(a => (a instanceof Error ? (a.stack ?? a.message) : a)).join(' ')}`
);
const createHandler = Logger.createOutputChannelHandler(outputChannel);

Logger.handlers.add({
error: createHandler('error'),
Expand Down
13 changes: 13 additions & 0 deletions src/util/dataUtils.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,18 @@
import type { NonEmptyArray } from '../types';

/**
* Type guard to determine if an object has a property.
* @param obj The object to check.
* @param prop The property to check for.
* @returns true if the property exists, false otherwise.
*/
export function hasProperty<TProp extends string>(
obj: unknown,
prop: TProp
): obj is Record<TProp, unknown> {
return obj != null && typeof obj === 'object' && prop in obj;
}

/**
* Type guard to check if an array is non-empty.
* @param array
Expand Down
1 change: 1 addition & 0 deletions src/util/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ export * from './Logger';
export * from './OutputChannelWithHistory';
export * from './panelUtils';
export * from './promiseUtils';
export * from './sanitizeUtils';
export * from './selectionUtils';
export * from './serverUtils';
export * from './testUtils';
Expand Down
61 changes: 61 additions & 0 deletions src/util/sanitizeUtils.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,61 @@
import { CENSORED_TEXT } from '../common';
import { hasProperty } from './dataUtils';

/**
* Sanitize an auth header value.
* @param authHeaderValue Sanitize secret portion of known auth headers. If
* unrecognized, replace the whole thing.
* @returns The sanitized auth header value.
*/
export function sanitizeAuthHeaderValue(authHeaderValue: string): string {
if (
authHeaderValue.startsWith('io.deephaven.proto.auth.Token') ||
authHeaderValue.startsWith('Bearer')
) {
return authHeaderValue.replace(/ \S+$/, ` ${CENSORED_TEXT}`);
}

return CENSORED_TEXT;
}

/**
* Sanitize an auth header.
* @param authorization The authorization header value. This can be a string
* or an array of strings. Any other data types will be treated as an empty
* string.
* @returns The sanitized auth header value.
*/
export function sanitizeAuthHeader(authorization: unknown): string | string[] {
if (typeof authorization === 'string') {
return sanitizeAuthHeaderValue(authorization);
}

if (Array.isArray(authorization)) {
return authorization.map(sanitizeAuthHeaderValue);
}

return CENSORED_TEXT;
}

/**
* Sanitize auth headers in a gRPC log message.
* @param args The arguments to sanitize.
* @returns The sanitized arguments.
*/
export function sanitizeGRPCLogMessageArgs([
arg0,
arg1,
...args
]: unknown[]): unknown[] {
if (arg0 === 'start' && hasProperty(arg1, 'authorization')) {
return [
arg0,
{
...arg1,
authorization: sanitizeAuthHeader(arg1.authorization),
},
];
}

return [arg0, arg1, ...args];
}

0 comments on commit a20013a

Please sign in to comment.