Skip to content

Commit

Permalink
Add more logging during publishing
Browse files Browse the repository at this point in the history
  • Loading branch information
ecraig12345 committed Aug 30, 2023
1 parent 9ccc792 commit 1244c31
Show file tree
Hide file tree
Showing 5 changed files with 55 additions and 20 deletions.
7 changes: 7 additions & 0 deletions change/beachball-f146e707-ddd6-42bd-8918-391c07aaeabf.json
Original file line number Diff line number Diff line change
@@ -0,0 +1,7 @@
{
"type": "patch",
"comment": "Add more logging during publishing",
"packageName": "beachball",
"email": "[email protected]",
"dependentChangeType": "patch"
}
32 changes: 22 additions & 10 deletions src/__functional__/packageManager/packagePublish.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,13 @@ import { npm, NpmResult } from '../../packageManager/npm';
const testTag = 'testbeachballtag';
const testName = 'testbeachballpackage';
const testVersion = '0.6.0';
const testSpec = `${testName}@${testVersion}`;
const testPackage = { name: testName, version: testVersion };

// Some of these tests use an actual local npm registry, so they're slower to run.
// The rest mock npm calls for efficiency.
//
// (If there's ever a bug that could have been caught by testing against a real registry/npm,
// Some of these tests use an actual local npm registry, so they're slower to run.
// The rest mock npm calls for efficiency (but could potentially be updated to use real npm if
// a bug is found that would have been caught that way).
//
describe('packagePublish', () => {
let npmSpy: jest.SpiedFunction<typeof npm>;
Expand Down Expand Up @@ -86,7 +87,7 @@ describe('packagePublish', () => {
expect(npmSpy).toHaveBeenCalledTimes(1);

const allLogs = logs.getMockLines('all');
expect(allLogs).toMatch(`Publishing - ${testName}@${testVersion} with tag ${testTag}`);
expect(allLogs).toMatch(`Publishing - ${testSpec} with tag ${testTag}`);
expect(allLogs).toMatch('publish command:');
expect(allLogs).toMatch(`[log] Published!`);

Expand All @@ -113,7 +114,7 @@ describe('packagePublish', () => {
expect(npmSpy).toHaveBeenCalledTimes(2);

const logs2ndTry = logs.getMockLines('all');
expect(logs2ndTry).toMatch(`${testName}@${testVersion} already exists in the registry`);
expect(logs2ndTry).toMatch(`${testSpec} already exists in the registry`);
});

it('performs retries', async () => {
Expand All @@ -134,9 +135,9 @@ describe('packagePublish', () => {
expect(npmSpy).toHaveBeenCalledTimes(3);

const allLogs = logs.getMockLines('all');
expect(allLogs).toMatch(`[warn] Publishing ${testName} failed. Output:\n\nsome errors`);
expect(allLogs).toMatch(`[warn] Publishing ${testSpec} failed. Output:\n\nsome errors`);
expect(allLogs).toMatch('Retrying... (1/3)');
expect(allLogs).toMatch(`[warn] Publishing ${testName} failed (timed out). Output:\n\nsloooow`);
expect(allLogs).toMatch(`[warn] Publishing ${testSpec} failed (timed out). Output:\n\nsloooow`);
expect(allLogs).toMatch('Retrying... (2/3)');
expect(allLogs).toMatch(`[log] Published!`);
});
Expand All @@ -153,7 +154,7 @@ describe('packagePublish', () => {
expect(allLogs).toMatch('Retrying... (1/3)');
expect(allLogs).toMatch('Retrying... (2/3)');
expect(allLogs).toMatch('Retrying... (3/3)');
expect(allLogs).toMatch(`[error] Publishing ${testName} failed. Output:\n\nsome errors`);
expect(allLogs).toMatch(`[error] Publishing ${testSpec} failed. Output:\n\nsome errors`);
});

it('does not retry on auth error', async () => {
Expand All @@ -166,7 +167,7 @@ describe('packagePublish', () => {
expect(npmSpy).toHaveBeenCalledTimes(1);

expect(logs.getMockLines('error')).toMatch(
`Publishing ${testName} failed due to an auth error. Output:\n\nERR! code ENEEDAUTH`
`Publishing ${testSpec} failed due to an auth error. Output:\n\nERR! code ENEEDAUTH`
);
});

Expand All @@ -180,6 +181,17 @@ describe('packagePublish', () => {
expect(publishResult).toEqual(failedResult);
expect(npmSpy).toHaveBeenCalledTimes(1);

expect(logs.getMockLines('error')).toMatch(`Publishing ${testName} returned E404`);
expect(logs.getMockLines('error')).toMatch(`Publishing ${testSpec} failed with E404`);
});

it('does not retry on E403', async () => {
const testPackageInfo = getTestPackageInfo();
npmSpy.mockImplementation(() => Promise.resolve({ success: false, all: 'ERR! code E403' } as NpmResult));

const publishResult = await packagePublish(testPackageInfo, { registry: 'fake', retries: 3 });
expect(publishResult).toEqual(failedResult);
expect(npmSpy).toHaveBeenCalledTimes(1);

expect(logs.getMockLines('error')).toMatch(`Publishing ${testSpec} failed due to a 403 error`);
});
});
2 changes: 1 addition & 1 deletion src/packageManager/npmArgs.ts
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,7 @@ export function getNpmPublishArgs(packageInfo: PackageInfo, options: NpmOptions)
'--tag',
pkgCombinedOptions.tag || pkgCombinedOptions.defaultNpmTag || 'latest',
'--loglevel',
'warn',
options.verbose ? 'notice' : 'warn',
...getNpmAuthArgs(registry, token, authType),
];

Expand Down
32 changes: 24 additions & 8 deletions src/packageManager/packagePublish.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,11 +15,13 @@ export async function packagePublish(
): Promise<NpmResult> {
const publishArgs = getNpmPublishArgs(packageInfo, options);

const packageRoot = path.dirname(packageInfo.packageJsonPath);
const publishTag = publishArgs[publishArgs.indexOf('--tag') + 1];
const pkg = packageInfo.name;
console.log(`\nPublishing - ${pkg}@${packageInfo.version} with tag ${publishTag}`);
const packageSpec = `${packageInfo.name}@${packageInfo.version}`;
console.log(`\nPublishing - ${packageSpec} with tag ${publishTag}`);

console.log(` publish command: ${publishArgs.join(' ')}`);
console.log(` (cwd: ${packageRoot})`);

let result: NpmResult;

Expand All @@ -32,7 +34,7 @@ export async function packagePublish(

result = await npm(publishArgs, {
// Run npm publish in the package directory
cwd: path.dirname(packageInfo.packageJsonPath),
cwd: packageRoot,
timeout: options.timeout,
all: true,
});
Expand All @@ -42,24 +44,38 @@ export async function packagePublish(
return result;
}

console.log();
const output = `Output:\n\n${result.all}\n`;

// First check for specific cases where retries are unlikely to help
// First check the output for specific cases where retries are unlikely to help.
// NOTE: much of npm's output is localized, so it's best to only check for error codes.
if (result.all!.includes('EPUBLISHCONFLICT')) {
console.error(`${pkg}@${packageInfo.version} already exists in the registry. ${output}`);
console.error(`${packageSpec} already exists in the registry. ${output}`);
break;
}
if (result.all!.includes('code E403')) {
// This is apparently a less common variant of trying to publish over an existing version
// (not sure when this error is used vs. EPUBLISHCONFLICT). Keep the message generic since
// there may be other possible causes for 403 errors.
// npm ERR! code E403
// npm ERR! 403 403 Forbidden - PUT https://registry.npmjs.org/pkg-name - You cannot publish over the previously published versions: 0.1.6.
// npm ERR! 403 In most cases, you or one of your dependencies are requesting
// npm ERR! 403 a package version that is forbidden by your security policy, or
// npm ERR! 403 on a server you do not have access to.
console.error(`Publishing ${packageSpec} failed due to a 403 error. ${output}`);
break;
}
if (result.all!.includes('ENEEDAUTH')) {
// ENEEDAUTH only happens if no auth was attempted (no token/password provided).
console.error(`Publishing ${pkg} failed due to an auth error. ${output}`);
console.error(`Publishing ${packageSpec} failed due to an auth error. ${output}`);
break;
}
if (result.all!.includes('code E404')) {
// All types of invalid credentials appear to cause E404.
// validate() already checks for the most common ways invalid variable names might show up,
// so log a slightly more generic message instead of details about the token.
console.error(
`Publishing ${pkg} returned E404. Contrary to the output, this usually indicates an issue ` +
`Publishing ${packageSpec} failed with E404. Contrary to the output, this usually indicates an issue ` +
'with an auth token (expired, improper scopes, or incorrect variable name).'
);
// demote the output on this one due to the misleading message
Expand All @@ -69,7 +85,7 @@ export async function packagePublish(

const timedOutMessage = result.timedOut ? ' (timed out)' : '';
const log = retries < options.retries ? console.warn : console.error;
log(`Publishing ${pkg} failed${timedOutMessage}. ${output}`);
log(`Publishing ${packageSpec} failed${timedOutMessage}. ${output}`);
}

return result!;
Expand Down
2 changes: 1 addition & 1 deletion src/types/NpmOptions.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
import { BeachballOptions } from './BeachballOptions';

export type NpmOptions = Required<Pick<BeachballOptions, 'registry'>> &
Partial<Pick<BeachballOptions, 'token' | 'authType' | 'access' | 'timeout'>>;
Partial<Pick<BeachballOptions, 'token' | 'authType' | 'access' | 'timeout' | 'verbose'>>;

0 comments on commit 1244c31

Please sign in to comment.