From 7bcb404fa88592079571149c4b4224f97798f47d Mon Sep 17 00:00:00 2001 From: Phil Adams Date: Tue, 3 Sep 2024 11:04:41 -0500 Subject: [PATCH] fix(logging): improve node core's debug logging (#286) This commit includes the following changes: 1. some additional debug logging in various components 2. HTTP message tracing was improved by adding specific interceptors to display request/response messages much the same way the Go and Java cores do. Signed-off-by: Phil Adams --- .secrets.baseline | 30 ++-- auth/authenticators/basic-authenticator.ts | 4 +- .../bearer-token-authenticator.ts | 2 + .../token-request-based-authenticator.ts | 2 + auth/token-managers/cp4d-token-manager.ts | 7 +- .../iam-request-based-token-manager.ts | 6 +- auth/token-managers/mcsp-token-manager.ts | 7 +- auth/token-managers/token-manager.ts | 11 +- .../vpc-instance-token-manager.ts | 6 +- auth/utils/read-external-sources.ts | 3 + lib/base-service.ts | 3 + lib/private-helpers.ts | 65 ++++++++ lib/request-wrapper.ts | 149 ++++++++++++++++-- package-lock.json | 20 +-- package.json | 5 +- sdk-test-utilities/package-lock.json | 13 +- sdk-test-utilities/package.json | 3 + test/unit/container-token-manager.test.js | 29 +++- test/unit/cp4d-token-manager.test.js | 41 ++++- .../iam-request-based-token-manager.test.js | 12 +- test/unit/iam-token-manager.test.js | 19 +-- test/unit/jwt-token-manager.test.js | 4 +- test/unit/mcsp-token-manager.test.js | 35 +++- test/unit/redact-secrets.test.js | 79 ++++++++++ ...token-request-based-authenticator.test.js} | 4 +- test/unit/vpc-instance-token-manager.test.js | 9 +- 26 files changed, 469 insertions(+), 99 deletions(-) create mode 100644 lib/private-helpers.ts create mode 100644 test/unit/redact-secrets.test.js rename test/unit/{request-token-based-authenticator.test.js => token-request-based-authenticator.test.js} (96%) diff --git a/.secrets.baseline b/.secrets.baseline index d0a1b49b7..3f8ed82c0 100644 --- a/.secrets.baseline +++ b/.secrets.baseline @@ -3,7 +3,7 @@ "files": "package-lock.json|^.secrets.baseline$", "lines": null }, - "generated_at": "2024-06-06T19:22:54Z", + "generated_at": "2024-08-29T14:54:57Z", "plugins_used": [ { "name": "AWSKeyDetector" @@ -96,7 +96,7 @@ "hashed_secret": "bc2f74c22f98f7b6ffbc2f67453dbfa99bce9a32", "is_secret": false, "is_verified": false, - "line_number": 174, + "line_number": 207, "type": "Secret Keyword", "verified_result": null } @@ -106,7 +106,7 @@ "hashed_secret": "32e8612d8ca77c7ea8374aa7918db8e5df9252ed", "is_secret": false, "is_verified": false, - "line_number": 63, + "line_number": 62, "type": "Secret Keyword", "verified_result": null } @@ -126,7 +126,7 @@ "hashed_secret": "bbccdf2efb33b52e6c9d0a14dd70b2d415fbea6e", "is_secret": false, "is_verified": false, - "line_number": 52, + "line_number": 53, "type": "Secret Keyword", "verified_result": null } @@ -210,7 +210,7 @@ "hashed_secret": "d5ff02fa48e492fac0a245ad63d1ae608e705c05", "is_secret": false, "is_verified": false, - "line_number": 98, + "line_number": 99, "type": "Secret Keyword", "verified_result": null }, @@ -218,7 +218,7 @@ "hashed_secret": "8f4bfc22c4fd7cb884f94ec175ff4a3284a174a1", "is_secret": false, "is_verified": false, - "line_number": 99, + "line_number": 100, "type": "Secret Keyword", "verified_result": null }, @@ -226,7 +226,7 @@ "hashed_secret": "45a15668db917c293f16e8add0f5d801889e5923", "is_secret": false, "is_verified": false, - "line_number": 116, + "line_number": 117, "type": "Secret Keyword", "verified_result": null }, @@ -234,7 +234,7 @@ "hashed_secret": "65e622227634e8876cfa733000233fb80c6f0473", "is_secret": false, "is_verified": false, - "line_number": 117, + "line_number": 118, "type": "Secret Keyword", "verified_result": null } @@ -296,7 +296,7 @@ "hashed_secret": "8f4bfc22c4fd7cb884f94ec175ff4a3284a174a1", "is_secret": false, "is_verified": false, - "line_number": 79, + "line_number": 80, "type": "Secret Keyword", "verified_result": null }, @@ -304,7 +304,7 @@ "hashed_secret": "65e622227634e8876cfa733000233fb80c6f0473", "is_secret": false, "is_verified": false, - "line_number": 95, + "line_number": 96, "type": "Secret Keyword", "verified_result": null } @@ -442,7 +442,7 @@ "hashed_secret": "1572bd30ac06678a82df42b5913e5e52e27f9a12", "is_secret": false, "is_verified": false, - "line_number": 27, + "line_number": 32, "type": "Secret Keyword", "verified_result": null }, @@ -450,7 +450,7 @@ "hashed_secret": "16856d955c788df03735a24feb2e3ffefd91f3dc", "is_secret": false, "is_verified": false, - "line_number": 28, + "line_number": 33, "type": "Secret Keyword", "verified_result": null } @@ -522,7 +522,7 @@ "hashed_secret": "a7ef1be18bb8d37af79f3d87761a203378bf26a2", "is_secret": false, "is_verified": false, - "line_number": 169, + "line_number": 158, "type": "Secret Keyword", "verified_result": null } @@ -542,7 +542,7 @@ "hashed_secret": "f2e7745f43b0ef0e2c2faf61d6c6a28be2965750", "is_secret": false, "is_verified": false, - "line_number": 26, + "line_number": 31, "type": "Secret Keyword", "verified_result": null } @@ -582,7 +582,7 @@ } ] }, - "version": "0.13.1+ibm.56.dss", + "version": "0.13.1+ibm.62.dss", "word_list": { "file": null, "hash": null diff --git a/auth/authenticators/basic-authenticator.ts b/auth/authenticators/basic-authenticator.ts index 25b5621f5..aef1c20ee 100644 --- a/auth/authenticators/basic-authenticator.ts +++ b/auth/authenticators/basic-authenticator.ts @@ -1,5 +1,5 @@ /** - * (C) Copyright IBM Corp. 2019, 2023. + * (C) Copyright IBM Corp. 2019, 2024. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -18,6 +18,7 @@ import extend from 'extend'; import { computeBasicAuthHeader, validateInput } from '../utils/helpers'; import { Authenticator } from './authenticator'; import { AuthenticateOptions } from './authenticator-interface'; +import logger from '../../lib/logger'; /** Configuration options for basic authentication. */ export type Options = { @@ -72,6 +73,7 @@ export class BasicAuthenticator extends Authenticator { public authenticate(requestOptions: AuthenticateOptions): Promise { return new Promise((resolve) => { requestOptions.headers = extend(true, {}, requestOptions.headers, this.authHeader); + logger.debug(`Authenticated outbound request (type=${this.authenticationType()})`); resolve(); }); } diff --git a/auth/authenticators/bearer-token-authenticator.ts b/auth/authenticators/bearer-token-authenticator.ts index 04022a65d..4fe2faa95 100644 --- a/auth/authenticators/bearer-token-authenticator.ts +++ b/auth/authenticators/bearer-token-authenticator.ts @@ -18,6 +18,7 @@ import extend from 'extend'; import { validateInput } from '../utils/helpers'; import { Authenticator } from './authenticator'; import { AuthenticateOptions } from './authenticator-interface'; +import logger from '../../lib/logger'; /** Configuration options for bearer authentication. */ export type Options = { @@ -76,6 +77,7 @@ export class BearerTokenAuthenticator extends Authenticator { return new Promise((resolve) => { const authHeader = { Authorization: `Bearer ${this.bearerToken}` }; requestOptions.headers = extend(true, {}, requestOptions.headers, authHeader); + logger.debug(`Authenticated outbound request (type=${this.authenticationType()})`); resolve(); }); } diff --git a/auth/authenticators/token-request-based-authenticator.ts b/auth/authenticators/token-request-based-authenticator.ts index c27f019e2..d001e9cce 100644 --- a/auth/authenticators/token-request-based-authenticator.ts +++ b/auth/authenticators/token-request-based-authenticator.ts @@ -19,6 +19,7 @@ import { OutgoingHttpHeaders } from 'http'; import { JwtTokenManager } from '../token-managers/jwt-token-manager'; import { Authenticator } from './authenticator'; import { AuthenticateOptions } from './authenticator-interface'; +import logger from '../../lib/logger'; /** Configuration options for token-based authentication. */ export type BaseOptions = { @@ -118,6 +119,7 @@ export class TokenRequestBasedAuthenticator extends Authenticator { return this.tokenManager.getToken().then((token) => { const authHeader = { Authorization: `Bearer ${token}` }; requestOptions.headers = extend(true, {}, requestOptions.headers, authHeader); + logger.debug(`Authenticated outbound request (type=${this.authenticationType()})`); }); } } diff --git a/auth/token-managers/cp4d-token-manager.ts b/auth/token-managers/cp4d-token-manager.ts index 381f84e5e..5f90bdd2c 100644 --- a/auth/token-managers/cp4d-token-manager.ts +++ b/auth/token-managers/cp4d-token-manager.ts @@ -18,6 +18,7 @@ import extend from 'extend'; import { validateInput } from '../utils/helpers'; import { buildUserAgent } from '../../lib/build-user-agent'; import { JwtTokenManager, JwtTokenManagerOptions } from './jwt-token-manager'; +import logger from '../../lib/logger'; /** Configuration options for CP4D token retrieval. */ interface Options extends JwtTokenManagerOptions { @@ -121,6 +122,10 @@ export class Cp4dTokenManager extends JwtTokenManager { rejectUnauthorized: !this.disableSslVerification, }, }; - return this.requestWrapperInstance.sendRequest(parameters); + logger.debug(`Invoking CP4D token service operation: ${parameters.options.url}`); + return this.requestWrapperInstance.sendRequest(parameters).then((response) => { + logger.debug('Returned from CP4D token service operation'); + return response; + }); } } diff --git a/auth/token-managers/iam-request-based-token-manager.ts b/auth/token-managers/iam-request-based-token-manager.ts index 405679de7..52e53ab1c 100644 --- a/auth/token-managers/iam-request-based-token-manager.ts +++ b/auth/token-managers/iam-request-based-token-manager.ts @@ -180,7 +180,11 @@ export class IamRequestBasedTokenManager extends JwtTokenManager { }, }; - return this.requestWrapperInstance.sendRequest(parameters); + logger.debug(`Invoking IAM get_token operation: ${parameters.options.url}`); + return this.requestWrapperInstance.sendRequest(parameters).then((response) => { + logger.debug('Returned from IAM get_token operation'); + return response; + }); } /** diff --git a/auth/token-managers/mcsp-token-manager.ts b/auth/token-managers/mcsp-token-manager.ts index a1645918b..096fe9709 100644 --- a/auth/token-managers/mcsp-token-manager.ts +++ b/auth/token-managers/mcsp-token-manager.ts @@ -18,6 +18,7 @@ import extend from 'extend'; import { validateInput } from '../utils/helpers'; import { buildUserAgent } from '../../lib/build-user-agent'; import { JwtTokenManager, JwtTokenManagerOptions } from './jwt-token-manager'; +import logger from '../../lib/logger'; /** * Configuration options for MCSP token retrieval. @@ -99,6 +100,10 @@ export class McspTokenManager extends JwtTokenManager { rejectUnauthorized: !this.disableSslVerification, }, }; - return this.requestWrapperInstance.sendRequest(parameters); + logger.debug(`Invoking MCSP token service operation: ${parameters.options.url}`); + return this.requestWrapperInstance.sendRequest(parameters).then((response) => { + logger.debug('Returned from MCSP token service operation'); + return response; + }); } } diff --git a/auth/token-managers/token-manager.ts b/auth/token-managers/token-manager.ts index bf7c15784..e13444383 100644 --- a/auth/token-managers/token-manager.ts +++ b/auth/token-managers/token-manager.ts @@ -101,11 +101,14 @@ export class TokenManager { */ public getToken(): Promise { if (!this.accessToken || this.isTokenExpired()) { - // 1. request a new token + // 1. Need a new token. + logger.debug('Performing synchronous token refresh'); return this.pacedRequestToken().then(() => this.accessToken); } - // If refresh needed, kick one off + if (this.tokenNeedsRefresh()) { + // 2. Need to refresh the current (valid) token. + logger.debug('Performing background asynchronous token fetch'); this.requestToken().then( (tokenResponse) => { this.saveTokenInfo(tokenResponse); @@ -122,8 +125,10 @@ export class TokenManager { logger.debug(err); } ); + } else { + logger.debug('Using cached access token'); } - // 2. use valid, managed token + return Promise.resolve(this.accessToken); } diff --git a/auth/token-managers/vpc-instance-token-manager.ts b/auth/token-managers/vpc-instance-token-manager.ts index a3fda8d63..f435eac80 100644 --- a/auth/token-managers/vpc-instance-token-manager.ts +++ b/auth/token-managers/vpc-instance-token-manager.ts @@ -141,8 +141,10 @@ export class VpcInstanceTokenManager extends JwtTokenManager { }; logger.debug(`Invoking VPC 'create_iam_token' operation: ${parameters.options.url}`); - - return this.requestWrapperInstance.sendRequest(parameters); + return this.requestWrapperInstance.sendRequest(parameters).then((response) => { + logger.debug(`Returned from VPC 'create_iam_token' operation`); + return response; + }); } private async getInstanceIdentityToken(): Promise { diff --git a/auth/utils/read-external-sources.ts b/auth/utils/read-external-sources.ts index cde21aaff..6caf1e476 100644 --- a/auth/utils/read-external-sources.ts +++ b/auth/utils/read-external-sources.ts @@ -48,6 +48,8 @@ function getProperties(serviceName: string): any { // only get properties from one source, return null if none found let properties = null; + logger.debug(`Retrieving config properties for service '${serviceName}'`); + properties = filterPropertiesByServiceName(readCredentialsFile(), serviceName); if (isEmptyObject(properties)) { @@ -58,6 +60,7 @@ function getProperties(serviceName: string): any { properties = getPropertiesFromVCAP(serviceName); } + logger.debug(`Retrieved ${Object.keys(properties).length} properties`); return properties; } diff --git a/lib/base-service.ts b/lib/base-service.ts index 135276d90..515ce2e71 100644 --- a/lib/base-service.ts +++ b/lib/base-service.ts @@ -156,6 +156,7 @@ export class BaseService { public setServiceUrl(url: string): void { if (url) { this.baseOptions.serviceUrl = stripTrailingSlash(url); + logger.debug(`Set service URL: ${this.baseOptions.serviceUrl}`); } } @@ -238,6 +239,8 @@ export class BaseService { * configuration. */ protected configureService(serviceName: string): void { + logger.debug(`Configuring BaseService instance with service name: ${serviceName}`); + if (!serviceName) { const err = 'Error configuring service. Service name is required.'; logger.error(err); diff --git a/lib/private-helpers.ts b/lib/private-helpers.ts new file mode 100644 index 000000000..370759b14 --- /dev/null +++ b/lib/private-helpers.ts @@ -0,0 +1,65 @@ +/** + * (C) Copyright IBM Corp. 2024. + * + * 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. + */ + +// Keywords that should be redacted. +const redactedKeywords = [ + 'apikey', + 'api_key', + 'passcode', + 'password', + 'token', + + 'aadClientId', + 'aadClientSecret', + 'auth', + 'auth_provider_x509_cert_url', + 'auth_uri', + 'client_email', + 'client_id', + 'client_x509_cert_url', + 'key', + 'project_id', + 'secret', + 'subscriptionId', + 'tenantId', + 'thumbprint', + 'token_uri', +]; + +const redactedTokens = redactedKeywords.join('|'); + +// Pre-compiled regular expressions used by redactSecrets(). +const reAuthHeader = new RegExp(`^(Authorization|X-Auth\\S*): .*$`, 'gim'); +const rePropertySetting = new RegExp(`(${redactedTokens})=[^&]*(&|$)`, 'gi'); +const reJsonField = new RegExp(`"([^"]*(${redactedTokens})[^"_]*)":\\s*"[^\\,]*"`, 'gi'); + +// RedactSecrets() returns the input string with secrets redacted. +/** + * Redacts secrets found in "input" so that the resulting string + * is suitable for debug logging. + * @param input - the string that potentially contains secrets + * @returns the input string with secrets replaced with "[redacted]" + */ +export function redactSecrets(input: string): string { + const redacted = '[redacted]'; + + let redactedString = input; + redactedString = redactedString.replace(reAuthHeader, `$1: ${redacted}`); + redactedString = redactedString.replace(rePropertySetting, `$1=${redacted}$2`); + redactedString = redactedString.replace(reJsonField, `"$1":"${redacted}"`); + + return redactedString; +} diff --git a/lib/request-wrapper.ts b/lib/request-wrapper.ts index 34b1379ea..b05d097c9 100644 --- a/lib/request-wrapper.ts +++ b/lib/request-wrapper.ts @@ -1,7 +1,7 @@ /* eslint-disable class-methods-use-this */ /** - * (C) Copyright IBM Corp. 2014, 2023. + * (C) Copyright IBM Corp. 2014, 2024. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -16,7 +16,13 @@ * limitations under the License. */ -import axios, { AxiosInstance, AxiosRequestConfig } from 'axios'; +import axios, { + AxiosInstance, + AxiosError, + AxiosRequestConfig, + AxiosResponse, + InternalAxiosRequestConfig, +} from 'axios'; import * as rax from 'retry-axios'; import extend from 'extend'; import FormData from 'form-data'; @@ -33,6 +39,7 @@ import { isJsonMimeType, stripTrailingSlash, } from './helper'; +import { redactSecrets } from './private-helpers'; import logger from './logger'; import { streamToPromise } from './stream-to-promise'; import { createCookieInterceptor } from './cookie-support'; @@ -118,36 +125,111 @@ export class RequestWrapper { this.enableRetries(retryOptions); } - // set debug interceptors - if (process.env.NODE_DEBUG === 'axios' || process.env.DEBUG) { + // If debug logging is requested, set up interceptors to log http request/response messages. + if (logger.debug.enabled || process.env.NODE_DEBUG === 'axios') { this.axiosInstance.interceptors.request.use( - (config) => { - logger.debug('Request:'); - logger.debug(config); - return config; + (request) => { + logger.debug(`--> HTTP Request:\n${this.formatAxiosRequest(request)}`); + return request; }, (error) => { - logger.error('Error: '); - logger.error(error); + logger.debug(`<-- HTTP Error:\n${this.formatAxiosError(error)}`); return Promise.reject(error); } ); - this.axiosInstance.interceptors.response.use( (response) => { - logger.debug('Response:'); - logger.debug(response); + logger.debug(`<-- HTTP Response:\n${this.formatAxiosResponse(response)}`); return response; }, (error) => { - logger.error('Error: '); - logger.error(error); + logger.debug(`<-- HTTP Error:\n${this.formatAxiosError(error)}`); return Promise.reject(error); } ); } } + /** + * Formats the specified Axios request for debug logging. + * @param request - the request to be logged + * @returns the string representation of the request + */ + private formatAxiosRequest(request: InternalAxiosRequestConfig): string { + const { method, url, data, headers } = request; + + const headersOutput = this.formatAxiosHeaders(headers); + const body = this.formatAxiosBody(data); + const output = `${(method || '??').toUpperCase()} ${url || '??'}\n${headersOutput}\n${body}`; + return redactSecrets(output); + } + + /** + * Formats the specified Axios response for debug logging. + * @param response - the response to be logged + * @returns the string representation of the response + */ + private formatAxiosResponse(response: AxiosResponse): string { + const { status, statusText, headers, data } = response; + const headersOutput = this.formatAxiosHeaders(headers); + const body = this.formatAxiosBody(data); + const statusMsg = statusText || `status_code_${status}`; + const output = `${status} ${statusMsg}\n${headersOutput}\n${body}`; + return redactSecrets(output); + } + + /** + * Formats the specified Axios error for debug logging. + * @param error - the error to be logged + * @returns the string representation of the error + */ + private formatAxiosError(error: AxiosError): string { + const { response } = error; + + let output = `HTTP error message=${error.message || ''}, code=${error.code || ''}`; + if (response) { + output = this.formatAxiosResponse(response); + } + return output; + } + + /** + * Formats 'headers' to be included in the debug output + * like this: + * Accept: application/json + * Content-Type: application/json + * My-Header: my-value + * ... + * @param headers - the headers associated with an Axios request or response + * @returns the formatted output to be included in the HTTP message traces + */ + private formatAxiosHeaders(headers: any): string { + let output = ''; + if (headers) { + const lines = []; + Object.keys(headers).forEach((key) => { + lines.push(`${key}: ${headers[key]}`); + }); + output = lines.join('\n'); + } + + return output; + } + + /** + * Formats 'body' (either a string or object/array) to be included in the debug output + * + * @param body - a string, object or array that contains the request or response body + * @returns the formatted output to be included in the HTTP message traces + */ + private formatAxiosBody(body: any): string { + let output = ''; + if (body) { + output = typeof body === 'string' ? body : JSON.stringify(body); + } + return output; + } + public setCompressRequestData(setting: boolean) { this.compressRequestData = setting; } @@ -368,6 +450,7 @@ export class RequestWrapper { backoffType: 'exponential', checkRetryAfter: true, // use Retry-After header first maxRetryDelay: 30 * 1000, // default to 30 sec max delay + shouldRetry: this.retryPolicy, }; if (retryOptions) { @@ -391,6 +474,9 @@ export class RequestWrapper { } this.raxConfig = RequestWrapper.getRaxConfig(this.axiosInstance, retryOptions); this.retryInterceptorId = rax.attach(this.axiosInstance); + logger.debug( + `Enabled retries; maxRetries=${this.raxConfig.retry}, maxRetryInterval=${this.raxConfig.maxRetryDelay}` + ); } public disableRetries(): void { @@ -398,9 +484,42 @@ export class RequestWrapper { rax.detach(this.retryInterceptorId, this.axiosInstance); delete this.retryInterceptorId; delete this.raxConfig; + logger.debug('Disabled retries'); } } + /** + * Returns true iff the previously-failed request contained in "error" should be retried. + * @param error - an AxiosError instance that contains a previously-failed request + * @returns true iff the request should be retried + */ + private static retryPolicy(error: AxiosError) { + if (logger.debug.enabled) { + const details = []; + if (error.response) { + const statusText = error.response.statusText || ``; + details.push(`status_code=${error.response.status} (${statusText})`); + } + if (error.config) { + if (error.config.method) { + details.push(`method=${error.config.method.toUpperCase()}`); + } + if (error.config.url) { + details.push(`url=${error.config.url}`); + } + } + + logger.debug(`Considering retry attempt; ${details.join(', ')}`); + } + + // Delegate to the default function defined by retry-axios. + const shouldRetry = rax.shouldRetryRequest(error); + + logger.debug(`Retry will ${shouldRetry ? '' : 'not '}be attempted`); + + return shouldRetry; + } + private async gzipRequestBody(data: any, headers: OutgoingHttpHeaders): Promise { // skip compression if user has set the encoding header to gzip const contentSetToGzip = diff --git a/package-lock.json b/package-lock.json index a35efc485..6a6200c6b 100644 --- a/package-lock.json +++ b/package-lock.json @@ -9689,30 +9689,18 @@ } }, "node_modules/micromatch": { - "version": "4.0.6", - "resolved": "https://registry.npmjs.org/micromatch/-/micromatch-4.0.6.tgz", - "integrity": "sha512-Y4Ypn3oujJYxJcMacVgcs92wofTHxp9FzfDpQON4msDefoC0lb3ETvQLOdLcbhSwU1bz8HrL/1sygfBIHudrkQ==", + "version": "4.0.8", + "resolved": "https://registry.npmjs.org/micromatch/-/micromatch-4.0.8.tgz", + "integrity": "sha512-PXwfBhYu0hBCPw8Dn0E+WDYb7af3dSLVWKi3HGv84IdF4TyFoC0ysxFd0Goxw7nSv4T/PzEJQxsYsEiFCKo2BA==", "dev": true, "dependencies": { "braces": "^3.0.3", - "picomatch": "^4.0.2" + "picomatch": "^2.3.1" }, "engines": { "node": ">=8.6" } }, - "node_modules/micromatch/node_modules/picomatch": { - "version": "4.0.2", - "resolved": "https://registry.npmjs.org/picomatch/-/picomatch-4.0.2.tgz", - "integrity": "sha512-M7BAV6Rlcy5u+m6oPhAPFgJTzAioX/6B0DxyvDlo9l8+T3nLKbrczg2WLUyzd45L8RqfUMyGPzekbMvX2Ldkwg==", - "dev": true, - "engines": { - "node": ">=12" - }, - "funding": { - "url": "https://github.com/sponsors/jonschlinkert" - } - }, "node_modules/mime": { "version": "4.0.1", "resolved": "https://registry.npmjs.org/mime/-/mime-4.0.1.tgz", diff --git a/package.json b/package.json index 9fc4d9c5e..c4529fe86 100644 --- a/package.json +++ b/package.json @@ -82,7 +82,8 @@ "tough-cookie": "^4.1.3" }, "overrides": { - "semver": "^7.5.3" + "semver": "^7.5.3", + "micromatch": "4.0.8" }, "browser": { "./auth/utils/read-credentials-file": "./auth/utils/read-credentials-file.browser" @@ -91,7 +92,7 @@ "node": ">=18" }, "scripts": { - "clean": "rm -fr node_modules", + "clean": "rm -fr node_modules sdk-test-utilities/node_modules", "commitmsg": "commitlint -E GIT_PARAMS", "eslint:config": "eslint --print-config .eslintrc.js | eslint-config-prettier-check", "eslint:fix": "eslint . --fix", diff --git a/sdk-test-utilities/package-lock.json b/sdk-test-utilities/package-lock.json index 18a9a1336..a829fb54c 100644 --- a/sdk-test-utilities/package-lock.json +++ b/sdk-test-utilities/package-lock.json @@ -1,15 +1,18 @@ { "name": "@ibm-cloud/sdk-test-utilities", - "version": "0.0.1", + "version": "1.0.0", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "@ibm-cloud/sdk-test-utilities", - "version": "0.0.1", + "version": "1.0.0", "license": "Apache-2.0", "dependencies": { "expect": "^29.7.0" + }, + "engines": { + "node": ">=18" } }, "node_modules/@babel/code-frame": { @@ -410,9 +413,9 @@ "integrity": "sha512-RdJUflcE3cUzKiMqQgsCu06FPu9UdIJO0beYbPhHN4k6apgJtifcoCtT9bcxOpYBtpD2kCM6Sbzg4CausW/PKQ==" }, "node_modules/micromatch": { - "version": "4.0.7", - "resolved": "https://registry.npmjs.org/micromatch/-/micromatch-4.0.7.tgz", - "integrity": "sha512-LPP/3KorzCwBxfeUuZmaR6bG2kdeHSbe0P2tY3FLRU4vYrjYz5hI4QZwV0njUx3jeuKe67YukQ1LSPZBKDqO/Q==", + "version": "4.0.8", + "resolved": "https://registry.npmjs.org/micromatch/-/micromatch-4.0.8.tgz", + "integrity": "sha512-PXwfBhYu0hBCPw8Dn0E+WDYb7af3dSLVWKi3HGv84IdF4TyFoC0ysxFd0Goxw7nSv4T/PzEJQxsYsEiFCKo2BA==", "dependencies": { "braces": "^3.0.3", "picomatch": "^2.3.1" diff --git a/sdk-test-utilities/package.json b/sdk-test-utilities/package.json index a231f0280..4aa069505 100644 --- a/sdk-test-utilities/package.json +++ b/sdk-test-utilities/package.json @@ -11,6 +11,9 @@ "dependencies": { "expect": "^29.7.0" }, + "overrides": { + "micromatch": "4.0.8" + }, "engines": { "node": ">=18" } diff --git a/test/unit/container-token-manager.test.js b/test/unit/container-token-manager.test.js index d8f58db09..f3f9a1e5f 100644 --- a/test/unit/container-token-manager.test.js +++ b/test/unit/container-token-manager.test.js @@ -16,10 +16,16 @@ * limitations under the License. */ +jest.mock('jsonwebtoken/decode'); +const decode = require('jsonwebtoken/decode'); + +decode.mockImplementation(() => ({ exp: 100, iat: 100 })); + const path = require('path'); const { ContainerTokenManager } = require('../../dist/auth'); const { RequestWrapper } = require('../../dist/lib/request-wrapper'); const { getRequestOptions } = require('./utils'); +const { getCurrentTime } = require('../../dist/auth/utils/helpers'); const logger = require('../../dist/lib/logger').default; // make sure no actual requests are sent @@ -28,13 +34,23 @@ jest.mock('../../dist/lib/request-wrapper'); const CR_TOKEN_FILENAME = '/path/to/file'; const IAM_PROFILE_NAME = 'some-name'; const IAM_PROFILE_ID = 'some-id'; +const ACCESS_TOKEN = 'access-token'; +const IAM_RESPONSE = { + result: { + access_token: ACCESS_TOKEN, + token_type: 'Bearer', + expires_in: 3600, + expiration: getCurrentTime() + 3600, + }, + status: 200, +}; describe('Container Token Manager', () => { const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue(IAM_RESPONSE); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); - afterAll(() => { sendRequestMock.mockRestore(); }); @@ -150,5 +166,16 @@ describe('Container Token Manager', () => { /^ibm-node-sdk-core\/container-authenticator.*$/ ); }); + + it('use getToken to invoke requestToken', async () => { + const instance = new ContainerTokenManager({ + crTokenFilename: pathToTestToken, + iamProfileName: IAM_PROFILE_NAME, + }); + + const accessToken = await instance.getToken(); + + expect(accessToken).toBe(ACCESS_TOKEN); + }); }); }); diff --git a/test/unit/cp4d-token-manager.test.js b/test/unit/cp4d-token-manager.test.js index 05cf94a54..aa5b17a19 100644 --- a/test/unit/cp4d-token-manager.test.js +++ b/test/unit/cp4d-token-manager.test.js @@ -16,6 +16,11 @@ * limitations under the License. */ +jest.mock('jsonwebtoken/decode'); +const decode = require('jsonwebtoken/decode'); + +decode.mockImplementation(() => ({ exp: 100, iat: 100 })); + const { Cp4dTokenManager } = require('../../dist/auth'); // mock sendRequest @@ -28,12 +33,23 @@ const PASSWORD = 'holmes'; const APIKEY = '221b-b4k3r'; const URL = 'tokenservice.com'; const FULL_URL = 'tokenservice.com/v1/authorize'; +const ACCESS_TOKEN = 'access-token'; +const CP4D_RESPONSE = { + result: { + token: ACCESS_TOKEN, + }, + status: 200, +}; describe('CP4D Token Manager', () => { const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue(CP4D_RESPONSE); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); + afterEach(() => { + sendRequestMock.mockClear(); + }); describe('constructor', () => { it('should initialize base variables - password edition', () => { @@ -130,18 +146,15 @@ describe('CP4D Token Manager', () => { }); describe('requestToken', () => { - afterEach(() => { - sendRequestMock.mockClear(); - }); - - it('should call sendRequest with all request options - password edition', () => { + it('should call sendRequest with all request options - password edition', async () => { const instance = new Cp4dTokenManager({ url: URL, username: USERNAME, password: PASSWORD, }); - instance.requestToken(); + const response = await instance.requestToken(); + expect(response).toBe(CP4D_RESPONSE); const requestOptions = getRequestOptions(sendRequestMock); expect(requestOptions.url).toBe(FULL_URL); @@ -155,14 +168,15 @@ describe('CP4D Token Manager', () => { expect(requestOptions.body.api_key).toBeUndefined(); }); - it('should call sendRequest with all request options - API key edition', () => { + it('should call sendRequest with all request options - API key edition', async () => { const instance = new Cp4dTokenManager({ url: URL, username: USERNAME, apikey: APIKEY, }); - instance.requestToken(); + const response = await instance.requestToken(); + expect(response).toBe(CP4D_RESPONSE); const requestOptions = getRequestOptions(sendRequestMock); expect(sendRequestMock).toHaveBeenCalled(); @@ -174,6 +188,7 @@ describe('CP4D Token Manager', () => { expect(requestOptions.headers['Content-Type']).toBe('application/json'); expect(requestOptions.body).toBeDefined(); expect(requestOptions.body.username).toBe(USERNAME); + expect(requestOptions.body.api_key).toBe(APIKEY); expect(requestOptions.body.password).toBeUndefined(); }); @@ -192,5 +207,15 @@ describe('CP4D Token Manager', () => { /^ibm-node-sdk-core\/cp4d-authenticator.*$/ ); }); + it('use getToken to exercise requestToken', async () => { + const instance = new Cp4dTokenManager({ + url: URL, + username: USERNAME, + apikey: APIKEY, + }); + + const token = await instance.getToken(); + expect(token).toBe(ACCESS_TOKEN); + }); }); }); diff --git a/test/unit/iam-request-based-token-manager.test.js b/test/unit/iam-request-based-token-manager.test.js index b44c81a26..af1be9d02 100644 --- a/test/unit/iam-request-based-token-manager.test.js +++ b/test/unit/iam-request-based-token-manager.test.js @@ -36,18 +36,24 @@ describe('IAM Request Based Token Manager', () => { jest.spyOn(logger, 'warn').mockImplementation(() => {}); const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue({ + data: { access_token: 'Hello world!' }, + status: 200, + }); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); beforeEach(() => { logger.warn.mockClear(); - sendRequestMock.mockReset(); }); afterAll(() => { logger.warn.mockRestore(); - sendRequestMock.mockRestore(); + }); + + afterEach(() => { + sendRequestMock.mockClear(); }); describe('constructor', () => { @@ -169,7 +175,7 @@ describe('IAM Request Based Token Manager', () => { }); }); - describe('request token', () => { + describe('requestToken', () => { it('should set required headers by default', async () => { const instance = new IamRequestBasedTokenManager(); diff --git a/test/unit/iam-token-manager.test.js b/test/unit/iam-token-manager.test.js index 27e9b0f02..cead8e698 100644 --- a/test/unit/iam-token-manager.test.js +++ b/test/unit/iam-token-manager.test.js @@ -43,16 +43,12 @@ const IAM_RESPONSE = { describe('IAM Token Manager', () => { const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue(IAM_RESPONSE); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); - - beforeEach(() => { - sendRequestMock.mockReset(); - }); - - afterAll(() => { - sendRequestMock.mockRestore(); + afterEach(() => { + sendRequestMock.mockClear(); }); it('should throw an error if apikey is not provided', () => { @@ -77,8 +73,6 @@ describe('IAM Token Manager', () => { apikey: 'abcd-1234', }); - sendRequestMock.mockImplementation((parameters) => Promise.resolve(IAM_RESPONSE)); - await instance.getToken(); expect(instance.refreshToken).toBe(REFRESH_TOKEN); @@ -91,8 +85,6 @@ describe('IAM Token Manager', () => { it('should turn an iam apikey into an access token', async () => { const instance = new IamTokenManager({ apikey: 'abcd-1234' }); - sendRequestMock.mockImplementation((parameters) => Promise.resolve(IAM_RESPONSE)); - const token = await instance.getToken(); expect(token).toBe(ACCESS_TOKEN); @@ -113,8 +105,7 @@ describe('IAM Token Manager', () => { // Set the expiration time so that we'll consider the first token expired. instance.expireTime = getCurrentTime() + EXPIRATION_WINDOW; - // Set up our second mock response, then call getToken() and make sure we got the second access token. - sendRequestMock.mockImplementation((parameters) => Promise.resolve(IAM_RESPONSE)); + // Call getToken() and make sure we got the second access token. token = await instance.getToken(); expect(token).toBe(ACCESS_TOKEN); expect(requestMock).toHaveBeenCalled(); @@ -137,8 +128,6 @@ describe('IAM Token Manager', () => { .spyOn(instance, 'requestToken') .mockImplementation(() => Promise.resolve({ result: { access_token: ACCESS_TOKEN } })); - sendRequestMock.mockImplementation((parameters) => Promise.resolve(IAM_RESPONSE)); - const token = await instance.getToken(); expect(token).toBe(CURRENT_ACCESS_TOKEN); expect(requestMock).toHaveBeenCalled(); diff --git a/test/unit/jwt-token-manager.test.js b/test/unit/jwt-token-manager.test.js index fbce2858f..093f77e02 100644 --- a/test/unit/jwt-token-manager.test.js +++ b/test/unit/jwt-token-manager.test.js @@ -1,7 +1,7 @@ /* eslint-disable no-alert, no-console */ /** - * (C) Copyright IBM Corp. 2019, 2021. + * (C) Copyright IBM Corp. 2019, 2024. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -215,7 +215,7 @@ describe('JWT Token Manager', () => { ); expect(debugLogSpy).toHaveBeenCalled(); - const debugArg = debugLogSpy.mock.calls[0][0]; + const debugArg = debugLogSpy.mock.calls[1][0]; expect(debugArg).toBeInstanceOf(Error); expect(debugArg.stack).toMatch(/Error: Connection Refused\n.*at JwtTokenManager/); diff --git a/test/unit/mcsp-token-manager.test.js b/test/unit/mcsp-token-manager.test.js index 5b41b08e1..a1c545787 100644 --- a/test/unit/mcsp-token-manager.test.js +++ b/test/unit/mcsp-token-manager.test.js @@ -16,16 +16,31 @@ * limitations under the License. */ +jest.mock('jsonwebtoken/decode'); +const decode = require('jsonwebtoken/decode'); + +decode.mockImplementation(() => ({ exp: 100, iat: 100 })); const { McspTokenManager } = require('../../dist/auth'); // mock sendRequest jest.mock('../../dist/lib/request-wrapper'); const { RequestWrapper } = require('../../dist/lib/request-wrapper'); const { getRequestOptions } = require('./utils'); +const { getCurrentTime } = require('../../dist/auth/utils/helpers'); const APIKEY = 'my-api-key'; const URL = 'https://mcsp.ibm.com'; const FULL_URL = `${URL}/siusermgr/api/1.0/apikeys/token`; +const ACCESS_TOKEN = 'access-token'; +const IAM_RESPONSE = { + result: { + token: ACCESS_TOKEN, + token_type: 'Bearer', + expires_in: 3600, + expiration: getCurrentTime() + 3600, + }, + status: 200, +}; describe('MCSP Token Manager', () => { describe('constructor', () => { @@ -71,21 +86,22 @@ describe('MCSP Token Manager', () => { describe('requestToken', () => { const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue(IAM_RESPONSE); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); - afterEach(() => { sendRequestMock.mockClear(); }); - it('should call sendRequest with all request options', () => { + it('should call sendRequest with all request options', async () => { const instance = new McspTokenManager({ url: URL, apikey: APIKEY, }); - instance.requestToken(); + const response = await instance.requestToken(); + expect(response).toBe(IAM_RESPONSE); const requestOptions = getRequestOptions(sendRequestMock); expect(requestOptions.url).toBe(FULL_URL); @@ -104,7 +120,8 @@ describe('MCSP Token Manager', () => { apikey: APIKEY, }); - await instance.requestToken(); + const response = await instance.requestToken(); + expect(response).toBe(IAM_RESPONSE); const requestOptions = getRequestOptions(sendRequestMock); expect(requestOptions.headers).toBeDefined(); @@ -112,5 +129,15 @@ describe('MCSP Token Manager', () => { /^ibm-node-sdk-core\/mcsp-authenticator.*$/ ); }); + + it('use getToken to invoke requestToken', async () => { + const instance = new McspTokenManager({ + url: URL, + apikey: APIKEY, + }); + + const accessToken = await instance.getToken(); + expect(accessToken).toBe(ACCESS_TOKEN); + }); }); }); diff --git a/test/unit/redact-secrets.test.js b/test/unit/redact-secrets.test.js new file mode 100644 index 000000000..71915f1a9 --- /dev/null +++ b/test/unit/redact-secrets.test.js @@ -0,0 +1,79 @@ +/** + * (C) Copyright IBM Corp. 2024. + * + * 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. + */ + +const { redactSecrets } = require('../../dist/lib/private-helpers'); + +describe('redactSecrets()', () => { + it('misc. tests', async () => { + const inputStrings = [ + 'Authorization: Bearer secret', + 'Authorization: secret\nX-Author: secret', + 'apikey=81KiI5Zm2kjOWnrSglhtnDJn3u0kfv&grant_type=apikey&response_type=cloud_iam', + `{"apikey":"secret"}`, + 'apikey=secret&project_id=secret&api_key=secret&passcode=secret&password=secret&token=secret&response_type=not_a_secret', + '{"aadClientId":"secret", "auth":"secret", "key":"secret", "secret":"foo", "token_uri":"secret", "client_id":"secret", "tenantId":"secret"}', + ]; + const outputStrings = [ + 'Authorization: [redacted]', + 'Authorization: [redacted]\nX-Author: [redacted]', + 'apikey=[redacted]&grant_type=apikey&response_type=cloud_iam', + `{"apikey":"[redacted]"}`, + 'apikey=[redacted]&project_id=[redacted]&api_key=[redacted]&passcode=[redacted]&password=[redacted]&token=[redacted]&response_type=not_a_secret', + '{"aadClientId":"[redacted]", "auth":"[redacted]", "key":"[redacted]", "secret":"[redacted]", "token_uri":"[redacted]", "client_id":"[redacted]", "tenantId":"[redacted]"}', + ]; + + for (let i = 0; i < inputStrings.length; i++) { + expect(redactSecrets(inputStrings[i])).toBe(outputStrings[i]); + } + }); + it('test debug output', async () => { + const input = ` +POST https://iam.cloud.ibm.com/identity/token +Accept: application/json, text/plain, */* +Content-Type: application/x-www-form-urlencoded +Authorization: Bearer secret +User-Agent: ibm-node-sdk-core/iam-authenticator-5.0.1 os.name=linux os.version=6.10.5-100.fc39.x86_64 node.version=v20.12.2 +apikey=secret&grant_type=urn%3Aibm%3Aparams%3Aoauth%3Agrant-type%3Aapikey&response_type=cloud_iam +transaction-id: cXpoZmY-262c12615bae4b6e92d10faf37033ad4 +content-type: application/json +content-language: en-US +strict-transport-security: max-age=31536000; includeSubDomains +vary: Accept-Encoding +content-length: 986 +connection: keep-alive +{"access_token":"secret","refresh_token":"secret","token_type":"Bearer","expires_in":3600,"expiration":1724788046,"scope":"ibm openid"} +`; + + const output = ` +POST https://iam.cloud.ibm.com/identity/token +Accept: application/json, text/plain, */* +Content-Type: application/x-www-form-urlencoded +Authorization: [redacted] +User-Agent: ibm-node-sdk-core/iam-authenticator-5.0.1 os.name=linux os.version=6.10.5-100.fc39.x86_64 node.version=v20.12.2 +apikey=[redacted]&grant_type=urn%3Aibm%3Aparams%3Aoauth%3Agrant-type%3Aapikey&response_type=cloud_iam +transaction-id: cXpoZmY-262c12615bae4b6e92d10faf37033ad4 +content-type: application/json +content-language: en-US +strict-transport-security: max-age=31536000; includeSubDomains +vary: Accept-Encoding +content-length: 986 +connection: keep-alive +{"access_token":"[redacted]","refresh_token":"[redacted]","token_type":"Bearer","expires_in":3600,"expiration":1724788046,"scope":"ibm openid"} +`; + + expect(redactSecrets(input)).toBe(output); + }); +}); diff --git a/test/unit/request-token-based-authenticator.test.js b/test/unit/token-request-based-authenticator.test.js similarity index 96% rename from test/unit/request-token-based-authenticator.test.js rename to test/unit/token-request-based-authenticator.test.js index 548b8a4eb..e12c921f6 100644 --- a/test/unit/request-token-based-authenticator.test.js +++ b/test/unit/token-request-based-authenticator.test.js @@ -1,5 +1,5 @@ /** - * (C) Copyright IBM Corp. 2019, 2021. + * (C) Copyright IBM Corp. 2019, 2024. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -17,7 +17,7 @@ const { TokenRequestBasedAuthenticator } = require('../../dist/auth'); const { JwtTokenManager } = require('../../dist/auth'); -describe('Request Based Token Authenticator', () => { +describe('Token Request Based Authenticator', () => { const config = { url: 'auth.com', disableSslVerification: true, diff --git a/test/unit/vpc-instance-token-manager.test.js b/test/unit/vpc-instance-token-manager.test.js index 9ebcd179e..4b3cd64d0 100644 --- a/test/unit/vpc-instance-token-manager.test.js +++ b/test/unit/vpc-instance-token-manager.test.js @@ -39,7 +39,11 @@ const IAM_PROFILE_ID = 'some-id'; const EXPIRATION_WINDOW = 10; describe('VPC Instance Token Manager', () => { - const sendRequestMock = jest.fn().mockImplementation(() => ({ result: { access_token: TOKEN } })); + const sendRequestMock = jest.fn(); + sendRequestMock.mockResolvedValue({ + result: { access_token: TOKEN }, + status: 200, + }); RequestWrapper.mockImplementation(() => ({ sendRequest: sendRequestMock, })); @@ -108,7 +112,8 @@ describe('VPC Instance Token Manager', () => { describe('getInstanceIdentityToken', () => { it('should correctly construct headers and request parameters', async () => { const instance = new VpcInstanceTokenManager({ url: '123.345.567' }); - await instance.getInstanceIdentityToken(); + const token = await instance.getInstanceIdentityToken(); + expect(token).toBe(TOKEN); const requestOptions = getRequestOptions(sendRequestMock); expect(requestOptions.url).toBe('123.345.567/instance_identity/v1/token');