Skip to content

Commit c2ab56e

Browse files
authored
Stabilize buffered file writer tests (#45)
1 parent 2cc09d3 commit c2ab56e

2 files changed

Lines changed: 405 additions & 68 deletions

File tree

packages/chirp/test/rotating_file_writer_test.dart

Lines changed: 85 additions & 68 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import 'package:test/test.dart';
1313

1414
import 'fake_async_with_drain.dart';
1515
import 'test_log_record.dart';
16+
import 'tracking_io_overrides.dart';
1617

1718
void main() {
1819
group('SimpleFileFormatter', () {
@@ -1664,39 +1665,46 @@ void main() {
16641665
});
16651666

16661667
test('timer resets after flush, next write starts new timer', () async {
1667-
await fakeAsyncWithDrain((async) async {
1668-
final tempDir = createTempDir();
1669-
final logPath = '${tempDir.path}/app.log';
1670-
final writer = RotatingFileWriter(
1671-
baseFilePathProvider: () => logPath,
1672-
flushStrategy: FlushStrategy.buffered,
1673-
);
1668+
final io = TrackingIoOverrides();
1669+
await io.run(() async {
1670+
await fakeAsyncWithDrain((async) async {
1671+
final tempDir = createTempDir();
1672+
final logPath = '${tempDir.path}/app.log';
1673+
final writer = RotatingFileWriter(
1674+
baseFilePathProvider: () => logPath,
1675+
flushStrategy: FlushStrategy.buffered,
1676+
);
16741677

1675-
// First batch
1676-
writer.write(testRecord(message: 'Batch 1'));
1677-
async.elapse(const Duration(seconds: 1));
1678-
await drainEvent();
1678+
// First batch
1679+
writer.write(testRecord(message: 'Batch 1'));
1680+
final firstFlush = io.trapFlush();
1681+
async.elapse(const Duration(seconds: 1));
1682+
await firstFlush.wait();
1683+
async.flushMicrotasks();
16791684

1680-
final content = File(logPath).readAsStringSync();
1681-
expect(content, contains('Batch 1'));
1682-
expect(content, isNot(contains('Batch 2')));
1685+
final content = File(logPath).readAsStringSync();
1686+
expect(content, contains('Batch 1'));
1687+
expect(content, isNot(contains('Batch 2')));
16831688

1684-
// Second batch - starts new timer
1685-
writer.write(testRecord(message: 'Batch 2'));
1689+
// Second batch - starts new timer
1690+
writer.write(testRecord(message: 'Batch 2'));
16861691

1687-
// Immediately, batch 2 not flushed yet
1688-
expect(File(logPath).readAsStringSync(), isNot(contains('Batch 2')),
1689-
reason: 'Batch 2 not yet flushed');
1692+
// Immediately, batch 2 not flushed yet
1693+
expect(File(logPath).readAsStringSync(), isNot(contains('Batch 2')),
1694+
reason: 'Batch 2 not yet flushed');
16901695

1691-
async.elapse(const Duration(seconds: 1));
1692-
await drainEvent();
1696+
final secondFlush = io.trapFlush();
1697+
async.elapse(const Duration(seconds: 1));
1698+
await secondFlush.wait();
1699+
async.flushMicrotasks();
16931700

1694-
final content2 = File(logPath).readAsStringSync();
1695-
expect(content2, contains('Batch 1'));
1696-
expect(content2, contains('Batch 2'));
1701+
final content2 = File(logPath).readAsStringSync();
1702+
expect(content2, contains('Batch 1'));
1703+
expect(content2, contains('Batch 2'));
16971704

1698-
await writer.close();
1699-
await drainEvent();
1705+
await writer.close();
1706+
await drainEvent();
1707+
});
17001708
});
17011709
});
17021710

@@ -1891,50 +1899,59 @@ void main() {
18911899
});
18921900

18931901
test('sustained logging: each flush resets timer for next batch', () async {
1894-
await fakeAsyncWithDrain((async) async {
1895-
final tempDir = createTempDir();
1896-
final logPath = '${tempDir.path}/app.log';
1897-
final writer = RotatingFileWriter(
1898-
baseFilePathProvider: () => logPath,
1899-
flushStrategy: FlushStrategy.buffered,
1900-
);
1901-
1902-
// Batch 1
1903-
writer.write(testRecord(message: 'Batch 1 - Msg 1'));
1904-
writer.write(testRecord(message: 'Batch 1 - Msg 2'));
1905-
async.elapse(const Duration(seconds: 1));
1906-
await drainEvent();
1907-
1908-
var content = File(logPath).readAsStringSync();
1909-
expect(content, contains('Batch 1 - Msg 1'));
1910-
expect(content, contains('Batch 1 - Msg 2'));
1911-
1912-
// Batch 2
1913-
writer.write(testRecord(message: 'Batch 2 - Msg 1'));
1914-
async.elapse(const Duration(seconds: 1));
1915-
await drainEvent();
1916-
1917-
content = File(logPath).readAsStringSync();
1918-
expect(content, contains('Batch 2 - Msg 1'));
1919-
1920-
// Batch 3
1921-
writer.write(testRecord(message: 'Batch 3 - Msg 1'));
1922-
writer.write(testRecord(message: 'Batch 3 - Msg 2'));
1923-
writer.write(testRecord(message: 'Batch 3 - Msg 3'));
1924-
async.elapse(const Duration(seconds: 1));
1925-
await drainEvent();
1902+
final io = TrackingIoOverrides();
1903+
await io.run(() async {
1904+
await fakeAsyncWithDrain((async) async {
1905+
final tempDir = createTempDir();
1906+
final logPath = '${tempDir.path}/app.log';
1907+
final writer = RotatingFileWriter(
1908+
baseFilePathProvider: () => logPath,
1909+
flushStrategy: FlushStrategy.buffered,
1910+
);
19261911

1927-
// All batches flushed
1928-
content = File(logPath).readAsStringSync();
1929-
expect(content, contains('Batch 1 - Msg 1'));
1930-
expect(content, contains('Batch 1 - Msg 2'));
1931-
expect(content, contains('Batch 2 - Msg 1'));
1932-
expect(content, contains('Batch 3 - Msg 1'));
1933-
expect(content, contains('Batch 3 - Msg 2'));
1934-
expect(content, contains('Batch 3 - Msg 3'));
1912+
// Batch 1
1913+
writer.write(testRecord(message: 'Batch 1 - Msg 1'));
1914+
writer.write(testRecord(message: 'Batch 1 - Msg 2'));
1915+
final firstFlush = io.trapFlush();
1916+
async.elapse(const Duration(seconds: 1));
1917+
await firstFlush.wait();
1918+
async.flushMicrotasks();
1919+
1920+
var content = File(logPath).readAsStringSync();
1921+
expect(content, contains('Batch 1 - Msg 1'));
1922+
expect(content, contains('Batch 1 - Msg 2'));
1923+
1924+
// Batch 2
1925+
writer.write(testRecord(message: 'Batch 2 - Msg 1'));
1926+
final secondFlush = io.trapFlush();
1927+
async.elapse(const Duration(seconds: 1));
1928+
await secondFlush.wait();
1929+
async.flushMicrotasks();
1930+
1931+
content = File(logPath).readAsStringSync();
1932+
expect(content, contains('Batch 2 - Msg 1'));
1933+
1934+
// Batch 3
1935+
writer.write(testRecord(message: 'Batch 3 - Msg 1'));
1936+
writer.write(testRecord(message: 'Batch 3 - Msg 2'));
1937+
writer.write(testRecord(message: 'Batch 3 - Msg 3'));
1938+
final thirdFlush = io.trapFlush();
1939+
async.elapse(const Duration(seconds: 1));
1940+
await thirdFlush.wait();
1941+
async.flushMicrotasks();
1942+
1943+
// All batches flushed
1944+
content = File(logPath).readAsStringSync();
1945+
expect(content, contains('Batch 1 - Msg 1'));
1946+
expect(content, contains('Batch 1 - Msg 2'));
1947+
expect(content, contains('Batch 2 - Msg 1'));
1948+
expect(content, contains('Batch 3 - Msg 1'));
1949+
expect(content, contains('Batch 3 - Msg 2'));
1950+
expect(content, contains('Batch 3 - Msg 3'));
19351951

1936-
await writer.close();
1937-
await drainEvent();
1952+
await writer.close();
1953+
await drainEvent();
1954+
});
19381955
});
19391956
});
19401957

0 commit comments

Comments
 (0)