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

feat: add debug logging support #1898

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 3 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
1 change: 1 addition & 0 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
"ecdsa-sig-formatter": "^1.0.11",
"gaxios": "^6.1.1",
"gcp-metadata": "^6.1.0",
"google-logging-utils": "next",
"gtoken": "^7.0.0",
"jws": "^4.0.0"
},
Expand Down
28 changes: 23 additions & 5 deletions src/auth/baseexternalclient.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@ import {
GaxiosResponse,
} from 'gaxios';
import * as stream from 'stream';
import {log as makeLog} from 'google-logging-utils';
const log = makeLog('auth');
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it may be cleaner and flexible to add this to the base AuthClient class and have it as a member or static method.

This will allow:

  • Customers to change/modify the log functionality (if they want)
  • Dedupe the import statements across the files

Additionally, in the next major we're planning to unify the Transporter instance into AuthClient via this PR:

It would be an even smaller migration after that has landed as we could extend the GaxiosOptions interface with a Symbol (which would note the type of log) and use log.info on every request (as all requests would use that _request method).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the quick review. I'll make that change tomorrow.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A lot of the logging can be done through AuthClient now, good call. There are a few objects that don't seem to derive ultimately from AuthClient, so I moved makeLog() into the class itself to make it cleaner. (makeLog caches the loggers by name, so there's little harm in calling it multiple times.)


import {Credentials} from './credentials';
import {AuthClient, AuthClientOptions} from './authclient';
Expand Down Expand Up @@ -478,13 +480,19 @@ export abstract class BaseExternalAccountClient extends AuthClient {
} else if (projectNumber) {
// Preferable not to use request() to avoid retrial policies.
const headers = await this.getRequestHeaders();
const url = `${this.cloudResourceManagerURL.toString()}${projectNumber}`;
const request = {
headers,
url,
};
log.info('getProjectId %j', request);
const response = await this.transporter.request<ProjectInfo>({
...request,
...BaseExternalAccountClient.RETRY_CONFIG,
headers,
url: `${this.cloudResourceManagerURL.toString()}${projectNumber}`,
responseType: 'json',
});
this.projectId = response.data.projectId;
log.info('getProjectId, id %s', this.projectId);
return this.projectId;
}
return null;
Expand Down Expand Up @@ -665,10 +673,8 @@ export abstract class BaseExternalAccountClient extends AuthClient {
private async getImpersonatedAccessToken(
token: string
): Promise<CredentialsWithResponse> {
const opts: GaxiosOptions = {
...BaseExternalAccountClient.RETRY_CONFIG,
const request = {
url: this.serviceAccountImpersonationUrl!,
method: 'POST',
headers: {
'Content-Type': 'application/json',
Authorization: `Bearer ${token}`,
Expand All @@ -677,11 +683,23 @@ export abstract class BaseExternalAccountClient extends AuthClient {
scope: this.getScopesArray(),
lifetime: this.serviceAccountImpersonationLifetime + 's',
},
};
log.info('getImpersonatedAccessToken %j', request);
const opts: GaxiosOptions = {
...request,
...BaseExternalAccountClient.RETRY_CONFIG,
method: 'POST',
responseType: 'json',
};
const response =
await this.transporter.request<IamGenerateAccessTokenResponse>(opts);
const successResponse = response.data;
log.info(
'getImpersonatedAccessToken success: %s, %s, %s',
successResponse.accessToken,
successResponse.expireTime,
response
);
return {
access_token: successResponse.accessToken,
// Convert from ISO format to timestamp.
Expand Down
39 changes: 31 additions & 8 deletions src/auth/defaultawssecuritycredentialssupplier.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@
// See the License for the specific language governing permissions and
// limitations under the License.

import {log as makeLog} from 'google-logging-utils';
const log = makeLog('auth');

import {ExternalAccountSupplierContext} from './baseexternalclient';
import {Gaxios, GaxiosOptions} from 'gaxios';
import {Transporter} from '../transporters';
Expand Down Expand Up @@ -122,14 +125,19 @@ export class DefaultAwsSecurityCredentialsSupplier
'"options.credential_source.region_url"'
);
}
const request = {
url: this.regionUrl,
headers: metadataHeaders,
};
log.info('getAwsRegion %j', request);
const opts: GaxiosOptions = {
...request,
...this.additionalGaxiosOptions,
url: this.regionUrl,
method: 'GET',
responseType: 'text',
headers: metadataHeaders,
};
const response = await context.transporter.request<string>(opts);
log.info('getAwsRegion is %s', response.data);
// Remove last character. For example, if us-east-2b is returned,
// the region would be us-east-2.
return response.data.substr(0, response.data.length - 1);
Expand Down Expand Up @@ -186,14 +194,19 @@ export class DefaultAwsSecurityCredentialsSupplier
async #getImdsV2SessionToken(
transporter: Transporter | Gaxios
): Promise<string> {
const request = {
url: this.imdsV2SessionTokenUrl,
headers: {'x-aws-ec2-metadata-token-ttl-seconds': '300'},
};
const opts: GaxiosOptions = {
...request,
...this.additionalGaxiosOptions,
url: this.imdsV2SessionTokenUrl,
method: 'PUT',
responseType: 'text',
headers: {'x-aws-ec2-metadata-token-ttl-seconds': '300'},
};
log.info('#getImdsV2SessionToken %j', request);
const response = await transporter.request<string>(opts);
log.info('#getImdsV2SessionToken is %s', response.data);
return response.data;
}

Expand All @@ -213,14 +226,19 @@ export class DefaultAwsSecurityCredentialsSupplier
'"options.credential_source.url"'
);
}
const request = {
url: this.securityCredentialsUrl,
headers: headers,
};
log.info('#getAwsRoleName %j', request);
const opts: GaxiosOptions = {
...request,
...this.additionalGaxiosOptions,
url: this.securityCredentialsUrl,
method: 'GET',
responseType: 'text',
headers: headers,
};
const response = await transporter.request<string>(opts);
log.info('#getAwsRoleName name is %s', response.data);
return response.data;
}

Expand All @@ -238,12 +256,17 @@ export class DefaultAwsSecurityCredentialsSupplier
headers: Headers,
transporter: Transporter | Gaxios
): Promise<AwsSecurityCredentialsResponse> {
const request = {
url: `${this.securityCredentialsUrl}/${roleName}`,
headers: headers,
};
log.info('#retrieveAwsSecurityCredentials %j', request);
const response = await transporter.request<AwsSecurityCredentialsResponse>({
...request,
...this.additionalGaxiosOptions,
url: `${this.securityCredentialsUrl}/${roleName}`,
responseType: 'json',
headers: headers,
});
log.info('#retrieveAwsSecurityCredentials %s', response.data);
return response.data;
}

Expand Down
11 changes: 11 additions & 0 deletions src/auth/externalAccountAuthorizedUserClient.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@
// See the License for the specific language governing permissions and
// limitations under the License.

import {log as makeLog} from 'google-logging-utils';
const log = makeLog('auth');

import {AuthClient, AuthClientOptions} from './authclient';
import {Headers} from './oauth2client';
import {
Expand Down Expand Up @@ -124,16 +127,24 @@ class ExternalAccountAuthorizedUserHandler extends OAuthClientAuthHandler {
// Apply OAuth client authentication.
this.applyClientAuthenticationOptions(opts);

log.info('refreshToken %j', {
url: opts.url,
headers: opts.headers,
data: opts.data,
});

try {
const response =
await this.transporter.request<TokenRefreshResponse>(opts);
// Successful response.
const tokenRefreshResponse = response.data;
tokenRefreshResponse.res = response;
log.info('refreshToken response %j', tokenRefreshResponse);
return tokenRefreshResponse;
} catch (error) {
// Translate error to OAuthError.
if (error instanceof GaxiosError && error.response) {
log.error('refreshToken failed %j', error.response?.data);
throw getErrorFromOAuthErrorResponse(
error.response.data as OAuthErrorResponse,
// Preserve other fields from the original error.
Expand Down
60 changes: 47 additions & 13 deletions src/auth/oauth2client.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,8 @@ import {
import * as querystring from 'querystring';
import * as stream from 'stream';
import * as formatEcdsa from 'ecdsa-sig-formatter';
import {log as makeLog} from 'google-logging-utils';
const log = makeLog('auth');

import {createCrypto, JwkCertificate, hasBrowserCrypto} from '../crypto/crypto';
import {BodyResponseCallback} from '../transporters';
Expand Down Expand Up @@ -708,14 +710,21 @@ export class OAuth2Client extends AuthClient {
if (this.clientAuthentication === ClientAuthentication.ClientSecretPost) {
values.client_secret = this._clientSecret;
}
const res = await this.transporter.request<CredentialRequest>({
...OAuth2Client.RETRY_CONFIG,
method: 'POST',

const request = {
url,
data: querystring.stringify(values),
headers,
};
log.info('getTokenAsync %j', request);

const res = await this.transporter.request<CredentialRequest>({
...request,
...OAuth2Client.RETRY_CONFIG,
method: 'POST',
});
const tokens = res.data as Credentials;
log.info('getTokenAsync success %j', tokens);
if (res.data && res.data.expires_in) {
tokens.expiry_date = new Date().getTime() + res.data.expires_in * 1000;
delete (tokens as CredentialRequest).expires_in;
Expand Down Expand Up @@ -769,18 +778,24 @@ export class OAuth2Client extends AuthClient {
grant_type: 'refresh_token',
};

const request = {
url,
data: querystring.stringify(data),
headers: {'Content-Type': 'application/x-www-form-urlencoded'},
};
log.info('refreshTokenNoCache %j', request);

let res: GaxiosResponse<CredentialRequest>;

try {
// request for new token
res = await this.transporter.request<CredentialRequest>({
...request,
...OAuth2Client.RETRY_CONFIG,
method: 'POST',
url,
data: querystring.stringify(data),
headers: {'Content-Type': 'application/x-www-form-urlencoded'},
});
} catch (e) {
} catch (exc) {
const e = exc as Error;
if (
e instanceof GaxiosError &&
e.message === 'invalid_grant' &&
Expand All @@ -789,11 +804,13 @@ export class OAuth2Client extends AuthClient {
) {
e.message = JSON.stringify(e.response.data);
}
log.error('refreshTokenNoCache failure %j', e.message);

throw e;
}

const tokens = res.data as Credentials;
log.info('refreshTokenNoCache success %j', tokens);
// TODO: de-duplicate this code from a few spots
if (res.data && res.data.expires_in) {
tokens.expiry_date = new Date().getTime() + res.data.expires_in * 1000;
Expand Down Expand Up @@ -1002,12 +1019,17 @@ export class OAuth2Client extends AuthClient {
url: this.getRevokeTokenURL(token).toString(),
method: 'POST',
};
log.info('revokeToken %s', opts.url);
if (callback) {
this.transporter
.request<RevokeCredentialsResult>(opts)
.then(r => callback(null, r), callback);
this.transporter.request<RevokeCredentialsResult>(opts).then(r => {
log.info('revokeToken success %s', r.data ?? '');
callback(null, r);
}, callback);
} else {
return this.transporter.request<RevokeCredentialsResult>(opts);
return this.transporter.request<RevokeCredentialsResult>(opts).then(r => {
log.info('revokeToken success %j', r.data);
return r;
});
}
}

Expand Down Expand Up @@ -1271,14 +1293,22 @@ export class OAuth2Client extends AuthClient {
throw new Error(`Unsupported certificate format ${format}`);
}
try {
log.info('getFederatedSignonCertsAsync %s', url);
res = await this.transporter.request({
...OAuth2Client.RETRY_CONFIG,
url,
});
} catch (e) {
log.info(
'getFederatedSignonCertsAsync success %j %j',
res?.data,
res?.headers
);
} catch (err) {
const e = err as Error;
if (e instanceof Error) {
e.message = `Failed to retrieve verification certificates: ${e.message}`;
}
log.error('getFederatedSignonCertsAsync failed', e?.message);

throw e;
}
Expand Down Expand Up @@ -1342,14 +1372,18 @@ export class OAuth2Client extends AuthClient {
const url = this.endpoints.oauth2IapPublicKeyUrl.toString();

try {
log.info('getIapPublicKeysAsync %s', url);
res = await this.transporter.request({
...OAuth2Client.RETRY_CONFIG,
url,
});
} catch (e) {
log.info('getIapPublicKeysAsync success %j', res.data);
} catch (err) {
const e = err as Error;
if (e instanceof Error) {
e.message = `Failed to retrieve verification certificates: ${e.message}`;
}
log.error('getIapPublicKeysAsync failed', e?.message);

throw e;
}
Expand Down
15 changes: 12 additions & 3 deletions src/auth/refreshclient.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@ import {
OAuth2ClientOptions,
} from './oauth2client';
import {stringify} from 'querystring';
import {log as makeLog} from 'google-logging-utils';
const log = makeLog('auth');

export const USER_REFRESH_ACCOUNT_TYPE = 'authorized_user';

Expand Down Expand Up @@ -80,22 +82,29 @@ export class UserRefreshClient extends OAuth2Client {
}

async fetchIdToken(targetAudience: string): Promise<string> {
const res = await this.transporter.request<CredentialRequest>({
...UserRefreshClient.RETRY_CONFIG,
const request = {
url: this.endpoints.oauth2TokenUrl,
headers: {
'Content-Type': 'application/x-www-form-urlencoded',
},
method: 'POST',
data: stringify({
client_id: this._clientId,
client_secret: this._clientSecret,
grant_type: 'refresh_token',
refresh_token: this._refreshToken,
target_audience: targetAudience,
}),
};
log.info('fetchIdToken %j', request);

const res = await this.transporter.request<CredentialRequest>({
...request,
...UserRefreshClient.RETRY_CONFIG,
method: 'POST',
});

log.info('fetchIdToken success %s', res?.data?.id_token);

return res.data.id_token!;
}

Expand Down
Loading
Loading