Skip to content

Commit

Permalink
chore: chalk breaking logging tests (#32393)
Browse files Browse the repository at this point in the history
### Reason for this change

logging tests would break when running `npx jest` but not when running `yarn test` as npx jest was not pulling out the ansi codes which were failing the string comparisons.

### Description of changes

Removed all the ansi codes from stdout in logging and log-monitor tests

### Description of how you validated changes

ran `npx jest` and `yarn test` as well as rebuilt the package

### Checklist
- [x] My code adheres to the [CONTRIBUTING GUIDE](https://github.com/aws/aws-cdk/blob/main/CONTRIBUTING.md) and [DESIGN GUIDELINES](https://github.com/aws/aws-cdk/blob/main/docs/DESIGN_GUIDELINES.md)

----

*By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license*
  • Loading branch information
HBobertz authored Dec 7, 2024
1 parent 3fe229d commit 609faba
Show file tree
Hide file tree
Showing 2 changed files with 45 additions and 30 deletions.
Original file line number Diff line number Diff line change
@@ -1,10 +1,16 @@
import { LogLevel, log, setLogLevel, setCI, data, print, error, warning, success, debug, trace, prefix, withCorkedLogging } from '../lib/logging';
import { LogLevel, log, setLogLevel, setCI, data, print, error, warning, success, debug, trace, prefix, withCorkedLogging } from '../../../lib/logging';

describe('logging', () => {
// Mock streams to capture output
let mockStdout: jest.Mock;
let mockStderr: jest.Mock;

// Helper function to strip ANSI codes
const stripAnsi = (str: string): string => {
const ansiRegex = /\u001b\[[0-9;]*[a-zA-Z]/g;
return str.replace(ansiRegex, '');
};

beforeEach(() => {
// Reset log level before each test
setLogLevel(LogLevel.INFO);
Expand All @@ -14,44 +20,45 @@ describe('logging', () => {
mockStdout = jest.fn();
mockStderr = jest.fn();

// Mock the write methods directly
// Mock the write methods directly and strip ANSI codes
jest.spyOn(process.stdout, 'write').mockImplementation((chunk: any) => {
mockStdout(chunk.toString());
mockStdout(stripAnsi(chunk.toString()));
return true;
});

jest.spyOn(process.stderr, 'write').mockImplementation((chunk: any) => {
mockStderr(chunk.toString());
mockStderr(stripAnsi(chunk.toString()));
return true;
});
});

afterEach(() => {
jest.restoreAllMocks();
});

describe('stream selection', () => {
test('data() always writes to stdout', () => {
data('test message');
expect(mockStdout).toHaveBeenCalledWith(expect.stringContaining('test message\n'));
expect(mockStdout).toHaveBeenCalledWith('test message\n');
expect(mockStderr).not.toHaveBeenCalled();
});

test('error() always writes to stderr', () => {
error('test error');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('test error\n'));
expect(mockStderr).toHaveBeenCalledWith('test error\n');
expect(mockStdout).not.toHaveBeenCalled();
});

test('print() writes to stderr by default', () => {
print('test print');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('test print\n'));
expect(mockStderr).toHaveBeenCalledWith('test print\n');
expect(mockStdout).not.toHaveBeenCalled();
});

test('print() writes to stdout in CI mode', () => {
setCI(true);
print('test print');
expect(mockStdout).toHaveBeenCalledWith(expect.stringContaining('test print\n'));
expect(mockStdout).toHaveBeenCalledWith('test print\n');
expect(mockStderr).not.toHaveBeenCalled();
});
});
Expand All @@ -62,9 +69,9 @@ describe('logging', () => {
error('error message');
warning('warning message');
print('print message');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('error message\n'));
expect(mockStderr).not.toHaveBeenCalledWith(expect.stringContaining('warning message\n'));
expect(mockStderr).not.toHaveBeenCalledWith(expect.stringContaining('print message\n'));
expect(mockStderr).toHaveBeenCalledWith('error message\n');
expect(mockStderr).not.toHaveBeenCalledWith('warning message\n');
expect(mockStderr).not.toHaveBeenCalledWith('print message\n');
});

test('debug messages only show at debug level', () => {
Expand All @@ -74,7 +81,7 @@ describe('logging', () => {

setLogLevel(LogLevel.DEBUG);
debug('debug message');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('debug message\n'));
expect(mockStderr).toHaveBeenCalledWith('debug message\n');
});

test('trace messages only show at trace level', () => {
Expand All @@ -84,26 +91,25 @@ describe('logging', () => {

setLogLevel(LogLevel.TRACE);
trace('trace message');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('trace message\n'));
expect(mockStderr).toHaveBeenCalledWith('trace message\n');
});
});

describe('message formatting', () => {
test('formats messages with multiple arguments', () => {
print('Value: %d, String: %s', 42, 'test');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('Value: 42, String: test\n'));
expect(mockStderr).toHaveBeenCalledWith('Value: 42, String: test\n');
});

test('handles prefix correctly', () => {
const prefixedLog = prefix('PREFIX');
prefixedLog('test message');
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('PREFIX test message\n'));
expect(mockStderr).toHaveBeenCalledWith('PREFIX test message\n');
});

test('handles custom styles', () => {
success('success message');
// Note: actual styling will depend on chalk, but we can verify the message is there
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('success message\n'));
expect(mockStderr).toHaveBeenCalledWith('success message\n');
});
});

Expand All @@ -115,8 +121,8 @@ describe('logging', () => {
expect(mockStderr).not.toHaveBeenCalled();
});

expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('message 1\n'));
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('message 2\n'));
expect(mockStderr).toHaveBeenCalledWith('message 1\n');
expect(mockStderr).toHaveBeenCalledWith('message 2\n');
});

test('handles nested corking correctly', async () => {
Expand All @@ -130,9 +136,9 @@ describe('logging', () => {
});

expect(mockStderr).toHaveBeenCalledTimes(3);
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('outer 1\n'));
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('inner\n'));
expect(mockStderr).toHaveBeenCalledWith(expect.stringContaining('outer 2\n'));
expect(mockStderr).toHaveBeenCalledWith('outer 1\n');
expect(mockStderr).toHaveBeenCalledWith('inner\n');
expect(mockStderr).toHaveBeenCalledWith('outer 2\n');
});
});

Expand All @@ -145,7 +151,7 @@ describe('logging', () => {
prefix: 'PREFIX',
});
expect(mockStderr).toHaveBeenCalledWith(
expect.stringMatching(/PREFIX \[\d{2}:\d{2}:\d{2}\] test message\n/),
expect.stringMatching(/^PREFIX \[\d{2}:\d{2}:\d{2}\] test message\n$/),
);
});
});
Expand Down
23 changes: 16 additions & 7 deletions packages/aws-cdk/test/api/logs/logs-monitor.test.ts
Original file line number Diff line number Diff line change
@@ -1,16 +1,25 @@
import { FilterLogEventsCommand, type FilteredLogEvent } from '@aws-sdk/client-cloudwatch-logs';
import { blue, yellow } from 'chalk';
import { CloudWatchLogEventMonitor } from '../../../lib/api/logs/logs-monitor';
import { sleep } from '../../util';
import { MockSdk, mockCloudWatchClient } from '../../util/mock-sdk';

// Helper function to strip ANSI codes
const stripAnsi = (str: string): string => {
const ansiRegex = /\u001b\[[0-9;]*[a-zA-Z]/g;
return str.replace(ansiRegex, '');
};

let sdk: MockSdk;
let stderrMock: jest.SpyInstance;
let monitor: CloudWatchLogEventMonitor;
beforeEach(() => {
monitor = new CloudWatchLogEventMonitor(new Date(T100));
stderrMock = jest.spyOn(process.stderr, 'write').mockImplementation(() => {
return true;
stderrMock = jest.spyOn(process.stderr, 'write').mockImplementation((chunk: any) => {
// Strip ANSI codes when capturing output
if (typeof chunk === 'string') {
return stripAnsi(chunk) as unknown as boolean;
}
return stripAnsi(chunk.toString()) as unknown as boolean;
});
sdk = new MockSdk();
});
Expand Down Expand Up @@ -44,7 +53,7 @@ test('process events', async () => {
// THEN
const expectedLocaleTimeString = eventDate.toLocaleTimeString();
expect(stderrMock).toHaveBeenCalledTimes(1);
expect(stderrMock.mock.calls[0][0]).toContain(`[${blue('loggroup')}] ${yellow(expectedLocaleTimeString)} message`);
expect(stripAnsi(stderrMock.mock.calls[0][0])).toContain(`[loggroup] ${expectedLocaleTimeString} message`);
});

test('process truncated events', async () => {
Expand Down Expand Up @@ -76,9 +85,9 @@ test('process truncated events', async () => {
// THEN
const expectedLocaleTimeString = eventDate.toLocaleTimeString();
expect(stderrMock).toHaveBeenCalledTimes(101);
expect(stderrMock.mock.calls[0][0]).toContain(`[${blue('loggroup')}] ${yellow(expectedLocaleTimeString)} message`);
expect(stderrMock.mock.calls[100][0]).toContain(
`[${blue('loggroup')}] ${yellow(expectedLocaleTimeString)} >>> \`watch\` shows only the first 100 log messages - the rest have been truncated...`,
expect(stripAnsi(stderrMock.mock.calls[0][0])).toContain(`[loggroup] ${expectedLocaleTimeString} message0`);
expect(stripAnsi(stderrMock.mock.calls[100][0])).toContain(
`[loggroup] ${expectedLocaleTimeString} >>> \`watch\` shows only the first 100 log messages - the rest have been truncated...`,
);
});

Expand Down

0 comments on commit 609faba

Please sign in to comment.