Skip to content

Commit

Permalink
refactor: we can log objects now
Browse files Browse the repository at this point in the history
  • Loading branch information
@mshanemc
mshanemc committed Jul 21, 2023
1 parent cbe1090 commit c6bbeb5
Showing 1 changed file with 30 additions and 52 deletions.
82 changes: 30 additions & 52 deletions src/org/org.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -167,7 +167,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
private configAggregator!: ConfigAggregator;

// Initialized in create
private logger!: Logger;
private logger!: ReturnType<Logger['getRawLogger']>;
private connection!: Connection;

private options: Org.Options;
Expand Down Expand Up @@ -197,18 +197,16 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
interval: Duration.seconds(30),
}
): Promise<SandboxProcessObject> {
this.logger.debug(`CreateSandbox called with SandboxRequest: ${JSON.stringify(sandboxReq, undefined, 2)}`);
this.logger.debug(sandboxReq, 'CreateSandbox called with SandboxRequest');
const createResult = await this.connection.tooling.create('SandboxInfo', sandboxReq);
this.logger.debug(`Return from calling tooling.create: ${JSON.stringify(createResult, undefined, 2)}`);
this.logger.debug(createResult, 'Return from calling tooling.create');

if (Array.isArray(createResult) || !createResult.success) {
throw messages.createError('sandboxInfoCreateFailed', [JSON.stringify(createResult)]);
}

const sandboxCreationProgress = await this.querySandboxProcessBySandboxInfoId(createResult.id);
this.logger.debug(
`Return from calling singleRecordQuery with tooling: ${JSON.stringify(sandboxCreationProgress, undefined, 2)}`
);
this.logger.debug(sandboxCreationProgress, 'Return from calling singleRecordQuery with tooling');

const isAsync = !!options.async;

Expand All @@ -219,11 +217,8 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
}
const [wait, pollInterval] = this.validateWaitOptions(options);
this.logger.debug(
`create - pollStatusAndAuth sandboxProcessObj ${JSON.stringify(
sandboxCreationProgress,
undefined,
2
)}, max wait time of ${wait.minutes} minutes`
sandboxCreationProgress,
`create - pollStatusAndAuth sandboxProcessObj, max wait time of ${wait.minutes} minutes`
);
return this.pollStatusAndAuth({
sandboxProcessObj: sandboxCreationProgress,
Expand All @@ -245,7 +240,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
options: { wait?: Duration; interval?: Duration }
): Promise<SandboxProcessObject> {
sandboxReq.SourceId = (await this.querySandboxProcessBySandboxName(sourceSandboxName)).SandboxInfoId;
this.logger.debug('Clone sandbox sourceId %s', sandboxReq.SourceId);
this.logger.debug(`Clone sandbox sourceId ${sandboxReq.SourceId}`);
return this.createSandbox(sandboxReq, options);
}

Expand All @@ -265,9 +260,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
interval: Duration.seconds(30),
}
): Promise<SandboxProcessObject> {
this.logger.debug(
`ResumeSandbox called with ResumeSandboxRequest: ${JSON.stringify(resumeSandboxRequest, undefined, 2)}`
);
this.logger.debug(resumeSandboxRequest, 'ResumeSandbox called with ResumeSandboxRequest');
let sandboxCreationProgress: SandboxProcessObject;
// seed the sandboxCreationProgress via the resumeSandboxRequest options
if (resumeSandboxRequest.SandboxName) {
Expand All @@ -279,9 +272,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
resumeSandboxRequest.SandboxName ?? resumeSandboxRequest.SandboxProcessObjId,
]);
}
this.logger.debug(
`Return from calling singleRecordQuery with tooling: ${JSON.stringify(sandboxCreationProgress, undefined, 2)}`
);
this.logger.debug(sandboxCreationProgress, 'Return from calling singleRecordQuery with tooling');

if (!sandboxIsResumable(sandboxCreationProgress.Status)) {
throw messages.createError('sandboxNotResumable', [
Expand All @@ -301,7 +292,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
if (sandboxInfo) {
await Lifecycle.getInstance().emit(SandboxEvents.EVENT_AUTH, sandboxInfo);
try {
this.logger.debug(`sandbox signup complete with ${JSON.stringify(sandboxInfo, undefined, 2)}`);
this.logger.debug(sandboxInfo, 'sandbox signup complete');
await this.writeSandboxAuthFile(sandboxCreationProgress, sandboxInfo);
return sandboxCreationProgress;
} catch (err) {
Expand All @@ -314,11 +305,8 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
}

this.logger.debug(
`resume - pollStatusAndAuth sandboxProcessObj ${JSON.stringify(
sandboxCreationProgress,
undefined,
2
)}, max wait time of ${wait.minutes} minutes`
sandboxCreationProgress,
`resume - pollStatusAndAuth sandboxProcessObj, max wait time of ${wait.minutes} minutes`
);
return this.pollStatusAndAuth({
sandboxProcessObj: sandboxCreationProgress,
Expand Down Expand Up @@ -949,7 +937,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
*/
protected async init(): Promise<void> {
const stateAggregator = await StateAggregator.getInstance();
this.logger = await Logger.child('Org');
this.logger = (await Logger.child('Org')).getRawLogger();

this.configAggregator = this.options.aggregator ? this.options.aggregator : await ConfigAggregator.create();

Expand Down Expand Up @@ -1018,11 +1006,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
}
): Promise<SandboxProcessObject> {
const [wait, pollInterval] = this.validateWaitOptions(options);
this.logger.debug(
`AuthWithRetries sandboxProcessObj ${JSON.stringify(sandboxProcessObj, undefined, 2)}, max wait time of ${
wait.minutes
} minutes`
);
this.logger.debug(sandboxProcessObj, `AuthWithRetries sandboxProcessObj, max wait time of ${wait.minutes} minutes`);
return this.pollStatusAndAuth({
sandboxProcessObj,
wait,
Expand All @@ -1038,11 +1022,11 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
*/
private async queryLatestSandboxProcessBySandboxName(sandboxNameIn: string): Promise<SandboxProcessObject> {
const { tooling } = this.getConnection();
this.logger.debug('QueryLatestSandboxProcessBySandboxName called with SandboxName: %s ', sandboxNameIn);
this.logger.debug(`QueryLatestSandboxProcessBySandboxName called with SandboxName: ${sandboxNameIn}`);
const queryStr = `SELECT Id, Status, SandboxName, SandboxInfoId, LicenseType, CreatedDate, CopyProgress, SandboxOrganization, SourceId, Description, EndDate FROM SandboxProcess WHERE SandboxName='${sandboxNameIn}' AND Status != 'D' ORDER BY CreatedDate DESC LIMIT 1`;

const queryResult = await tooling.query(queryStr);
this.logger.debug('Return from calling queryToolingApi: %s ', queryResult);
this.logger.debug(queryResult, 'Return from calling queryToolingApi');
if (queryResult?.records?.length === 1) {
return queryResult.records[0] as SandboxProcessObject;
} else if (queryResult.records && queryResult.records.length > 1) {
Expand Down Expand Up @@ -1116,7 +1100,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {

if (sandboxInfoId) {
const deleteResult = await this.destroySandbox(prodOrg, sandboxInfoId);
this.logger.debug('Return from calling tooling.delete: ', deleteResult);
this.logger.debug(deleteResult, 'Return from calling tooling.delete');
}
// cleanup remaining artifacts
await this.remove();
Expand Down Expand Up @@ -1260,14 +1244,11 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
sandboxProcessObj: SandboxProcessObject,
sandboxRes: SandboxUserAuthResponse
): Promise<void> {
this.logger.debug(
`writeSandboxAuthFile sandboxProcessObj: ${JSON.stringify(sandboxProcessObj)}, sandboxRes: ${JSON.stringify(
sandboxRes
)}`
);
this.logger.debug(sandboxProcessObj, 'writeSandboxAuthFile sandboxProcessObj');
this.logger.debug(sandboxRes, 'writeSandboxAuthFile sandboxRes');
if (sandboxRes.authUserName) {
const productionAuthFields = this.connection.getAuthInfoFields();
this.logger.debug('Result from getAuthInfoFields: AuthFields', productionAuthFields);
this.logger.debug(productionAuthFields, 'Result from getAuthInfoFields: AuthFields');

// let's do headless auth via jwt (if we have privateKey) or web auth
const oauth2Options: AuthFields & {
Expand All @@ -1294,10 +1275,12 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
});

this.logger.debug(
'Creating AuthInfo for sandbox',
sandboxRes.authUserName,
productionAuthFields.username,
oauth2Options
{
sandboxResAuthUsername: sandboxRes.authUserName,
productionAuthFieldsUsername: productionAuthFields.username,
...oauth2Options,
},
'Creating AuthInfo for sandbox'
);
// save auth info for new sandbox
await authInfo.save();
Expand Down Expand Up @@ -1336,12 +1319,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
wait: Duration;
pollInterval: Duration;
}): Promise<SandboxProcessObject> {
this.logger.debug(
'PollStatusAndAuth called with SandboxProcessObject',
options.sandboxProcessObj,
options.wait.minutes,
options.pollInterval.seconds
);
this.logger.debug(options, 'PollStatusAndAuth called with SandboxProcessObject');
let remainingWait = options.wait;
let waitingOnAuth = false;
const pollingClient = await PollingClient.create({
Expand All @@ -1354,7 +1332,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
if (sandboxInfo) {
await Lifecycle.getInstance().emit(SandboxEvents.EVENT_AUTH, sandboxInfo);
try {
this.logger.debug('sandbox signup complete with', sandboxInfo);
this.logger.debug(sandboxInfo, 'sandbox signup complete with');
await this.writeSandboxAuthFile(sandboxProcessObj, sandboxInfo);
return { completed: true, payload: sandboxProcessObj };
} catch (err) {
Expand Down Expand Up @@ -1422,7 +1400,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {
callbackUrl,
};

this.logger.debug('Calling sandboxAuth with SandboxUserAuthRequest', sandboxReq);
this.logger.debug(sandboxReq, 'Calling sandboxAuth with SandboxUserAuthRequest');

// eslint-disable-next-line no-underscore-dangle
const url = `${this.connection.tooling._baseUrl()}/sandboxAuth`;
Expand All @@ -1435,7 +1413,7 @@ export class Org extends AsyncOptionalCreatable<Org.Options> {

const result: SandboxUserAuthResponse = await this.connection.tooling.request(params);

this.logger.debug('Result of calling sandboxAuth', result);
this.logger.debug(result, 'Result of calling sandboxAuth');
return result;
} catch (err) {
const error = err as Error;
Expand Down

4 comments on commit c6bbeb5

@svc-cli-bot
Copy link
Contributor

Choose a reason for hiding this comment

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

Logger Benchmarks - ubuntu-latest

Benchmark suite Current: c6bbeb5 Previous: 568e9e8 Ratio
Child logger creation 463774 ops/sec (±6.07%) 15155 ops/sec (±0.68%) 0.03267755415353168
Logging a string on root logger 563802 ops/sec (±12.44%) 71281 ops/sec (±0.07%) 0.13
Logging an object on root logger 434982 ops/sec (±10.22%) 60606 ops/sec (±0.08%) 0.14
Logging an object with a message on root logger 264881 ops/sec (±12.53%) 28843 ops/sec (±0.10%) 0.11
Logging an object with a redacted prop on root logger 9028 ops/sec (±199.09%) 54766 ops/sec (±0.07%) 6.07
Logging a nested 3-level object on root logger 223616 ops/sec (±20.69%) 49531 ops/sec (±0.13%) 0.22

This comment was automatically generated by workflow using github-action-benchmark.

@svc-cli-bot
Copy link
Contributor

Choose a reason for hiding this comment

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

⚠️ Performance Alert ⚠️

Possible performance regression was detected for benchmark 'Logger Benchmarks - ubuntu-latest'.
Benchmark result of this commit is worse than the previous benchmark result exceeding threshold 2.

Benchmark suite Current: c6bbeb5 Previous: 568e9e8 Ratio
Logging an object with a redacted prop on root logger 9028 ops/sec (±199.09%) 54766 ops/sec (±0.07%) 6.07

This comment was automatically generated by workflow using github-action-benchmark.

@svc-cli-bot
Copy link
Contributor

Choose a reason for hiding this comment

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

Logger Benchmarks - windows-latest

Benchmark suite Current: c6bbeb5 Previous: 568e9e8 Ratio
Child logger creation 442948 ops/sec (±4.60%) 4713 ops/sec (±9.71%) 0.010640075132972718
Logging a string on root logger 652135 ops/sec (±9.92%) 58738 ops/sec (±0.56%) 0.09007030752834919
Logging an object on root logger 533590 ops/sec (±19.23%) 48896 ops/sec (±0.88%) 0.09163590022301767
Logging an object with a message on root logger 239711 ops/sec (±18.28%) 23078 ops/sec (±1.20%) 0.09627426359240919
Logging an object with a redacted prop on root logger 6639 ops/sec (±206.97%) 45025 ops/sec (±0.82%) 6.78
Logging a nested 3-level object on root logger 285999 ops/sec (±18.67%) 39048 ops/sec (±12.07%) 0.14

This comment was automatically generated by workflow using github-action-benchmark.

@svc-cli-bot
Copy link
Contributor

Choose a reason for hiding this comment

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

⚠️ Performance Alert ⚠️

Possible performance regression was detected for benchmark 'Logger Benchmarks - windows-latest'.
Benchmark result of this commit is worse than the previous benchmark result exceeding threshold 2.

Benchmark suite Current: c6bbeb5 Previous: 568e9e8 Ratio
Logging an object with a redacted prop on root logger 6639 ops/sec (±206.97%) 45025 ops/sec (±0.82%) 6.78

This comment was automatically generated by workflow using github-action-benchmark.

Please sign in to comment.