diff --git a/app/test/admin/exported_api_sync_test.dart b/app/test/admin/exported_api_sync_test.dart index 0d68a5f87a..12f6800ab9 100644 --- a/app/test/admin/exported_api_sync_test.dart +++ b/app/test/admin/exported_api_sync_test.dart @@ -99,7 +99,10 @@ void main() { }); }); - testWithProfile('deleted files + full sync', fn: () async { + testWithProfile('deleted files + full sync', expectedLogMessages: [ + // TODO: review why we have unhandled errors here + RegExp(r'^SEVERE Unhandled error in API handler \(incidentId: .*\)'), + ], fn: () async { await syncExportedApi(); final oldRoot = await listExportedApi(); diff --git a/app/test/admin/moderate_package_test.dart b/app/test/admin/moderate_package_test.dart index a4e2148360..d1ca5c95cb 100644 --- a/app/test/admin/moderate_package_test.dart +++ b/app/test/admin/moderate_package_test.dart @@ -62,7 +62,11 @@ void main() { ); } - testWithProfile('update state', fn: () async { + testWithProfile('update state', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc = await _report('neon'); await expectModerationActions(mc.caseId, actions: []); @@ -104,7 +108,11 @@ void main() { ); }); - testWithProfile('clear moderation flag', fn: () async { + testWithProfile('clear moderation flag', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc = await _report('oxygen'); await expectModerationActions(mc.caseId, actions: []); final r1 = await _moderate('oxygen', caseId: mc.caseId); @@ -189,7 +197,11 @@ void main() { }); }); - testWithProfile('API endpoints return not found', fn: () async { + testWithProfile('API endpoints return not found', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final jsonUrls = [ '/api/packages/oxygen', '/api/packages/oxygen/versions/1.0.0', @@ -215,7 +227,11 @@ void main() { }); testWithProfile('public pages are displaying moderation notice', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final htmlUrls = [ '/packages/oxygen', '/packages/oxygen/changelog', @@ -256,7 +272,11 @@ void main() { actions: [ModerationAction.apply, ModerationAction.revert]); }); - testWithProfile('not included in search', fn: () async { + testWithProfile('not included in search', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { await searchBackend.doCreateAndUpdateSnapshot( FakeGlobalLockClaim(clock.now().add(Duration(seconds: 3))), concurrency: 2, @@ -295,7 +315,12 @@ void main() { expect(docs3!.where((d) => d.package == 'oxygen'), isNotEmpty); }); - testWithProfile('archives are removed from public buckets', fn: () async { + testWithProfile('archives are removed from public buckets', + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final publicUrls = [ '${activeConfiguration.storageBaseUrl}' '/${activeConfiguration.publicPackagesBucketName}' @@ -339,6 +364,11 @@ void main() { testWithProfile( 'analysis results are cleared', processJobsWithFakeRunners: true, + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final score1 = await scoreCardBackend.getScoreCardData('oxygen', '1.2.0'); @@ -386,7 +416,10 @@ void main() { testWithProfile( 'cleanup deletes datastore entities and canonical archive file', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { // delete old version await accountBackend.withBearerToken(siteAdminToken, () async { await adminBackend.removePackageVersion('oxygen', '1.0.0'); diff --git a/app/test/admin/moderate_package_version_test.dart b/app/test/admin/moderate_package_version_test.dart index a5a1de7c1c..44120cf8e2 100644 --- a/app/test/admin/moderate_package_version_test.dart +++ b/app/test/admin/moderate_package_version_test.dart @@ -64,7 +64,9 @@ void main() { ); } - testWithProfile('update state', fn: () async { + testWithProfile('update state', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { final mc = await _report('oxygen', '1.0.0'); final r1 = await _moderate('oxygen', '1.0.0'); expect(r1.output, { @@ -109,7 +111,9 @@ void main() { expect(mc2!.getActionLog().entries, hasLength(1)); }); - testWithProfile('clear moderation flag', fn: () async { + testWithProfile('clear moderation flag', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { final r1 = await _moderate('oxygen', '1.0.0', state: true); expect(r1.output, { 'package': 'oxygen', @@ -143,7 +147,11 @@ void main() { expect(optionsUpdates.isRetracted, true); }); - testWithProfile('cannot moderate last visible version', fn: () async { + testWithProfile('cannot moderate last visible version', + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { await _moderate('oxygen', '1.2.0', state: true); final p1 = await packageBackend.lookupPackage('oxygen'); expect(p1!.latestVersion, '1.0.0'); @@ -164,7 +172,9 @@ void main() { ); }); - testWithProfile('can publish new version', fn: () async { + testWithProfile('can publish new version', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { await _moderate('oxygen', '1.0.0', state: true); final pubspecContent = generatePubspecYaml('oxygen', '3.0.0'); @@ -174,7 +184,10 @@ void main() { expect(message.success.message, contains('Successfully uploaded')); }); - testWithProfile('cannot re-publish moderated version', fn: () async { + testWithProfile('cannot re-publish moderated version', + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { await _moderate('oxygen', '1.0.0', state: true); final pubspecContent = generatePubspecYaml('oxygen', '1.0.0'); @@ -189,7 +202,9 @@ void main() { }); testWithProfile('archive file is removed from public buckets', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { Future expectStatusCode(int statusCode, {String version = '1.0.0'}) async { final publicUrls = [ @@ -232,7 +247,9 @@ void main() { }); testWithProfile('versions file is updated in exported bucket', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { Future expectIncluded(String version, bool isIncluded) async { final prefixes = ['latest', runtimeVersion]; for (final prefix in prefixes) { @@ -257,7 +274,9 @@ void main() { await expectIncluded('1.0.0', true); }); - testWithProfile('search is updated with new version', fn: () async { + testWithProfile('search is updated with new version', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + ], fn: () async { await searchBackend.doCreateAndUpdateSnapshot( FakeGlobalLockClaim(clock.now().add(Duration(seconds: 3))), concurrency: 2, @@ -298,7 +317,10 @@ void main() { testWithProfile( 'moderated version is not visible in API (other version is)', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + ], fn: () async { await _moderate('oxygen', '1.0.0', state: true); final rs1 = await packageBackend.listVersionsCached('oxygen'); expect(rs1.latest.version, '1.2.0'); @@ -325,7 +347,9 @@ void main() { }); testWithProfile('moderated versions are not displayed on versions tab', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + ], fn: () async { await _moderate('oxygen', '1.2.0', state: true); await expectHtmlResponse( await issueGet('/packages/oxygen/versions'), @@ -339,7 +363,10 @@ void main() { ); }); - testWithProfile('moderated version pages are not displayed', fn: () async { + testWithProfile('moderated version pages are not displayed', + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + ], fn: () async { List pagePaths(String version) { return [ '/packages/oxygen/versions/$version', @@ -415,6 +442,9 @@ void main() { testWithProfile( 'moderated version trigger new analysis', processJobsWithFakeRunners: true, + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + ], fn: () async { final score1 = await scoreCardBackend.getScoreCardData('oxygen', '1.2.0'); @@ -468,7 +498,9 @@ void main() { testWithProfile( 'cleanup deletes datastore entities and canonical archive file', - fn: () async { + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + ], fn: () async { // canonical file is present expect( await packageBackend.tarballStorage diff --git a/app/test/admin/moderation_case_resolve_test.dart b/app/test/admin/moderation_case_resolve_test.dart index da7889af38..7921b1b169 100644 --- a/app/test/admin/moderation_case_resolve_test.dart +++ b/app/test/admin/moderation_case_resolve_test.dart @@ -76,7 +76,11 @@ void main() { expect(await _close(mc.caseId), 'no-action'); }); - testWithProfile('notification: apply moderation', fn: () async { + testWithProfile('notification: apply moderation', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc = await _prepare(apply: true); expect( await _close( @@ -87,7 +91,11 @@ void main() { ); }); - testWithProfile('appeal no action: revert', fn: () async { + testWithProfile('appeal no action: revert', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc1 = await _prepare(apply: null); await _close(mc1.caseId); @@ -108,7 +116,11 @@ void main() { expect(await _close(mc.caseId), 'no-action-upheld'); }); - testWithProfile('appeal moderation: revert', fn: () async { + testWithProfile('appeal moderation: revert', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc1 = await _prepare(apply: true); await _close( mc1.caseId, @@ -119,7 +131,11 @@ void main() { expect(await _close(mc.caseId), 'moderation-reverted'); }); - testWithProfile('appeal moderation: upheld', fn: () async { + testWithProfile('appeal moderation: upheld', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc1 = await _prepare(apply: true); await _close( mc1.caseId, diff --git a/app/test/admin/moderation_transparency_metrics_test.dart b/app/test/admin/moderation_transparency_metrics_test.dart index 8983c67afd..2d83394efb 100644 --- a/app/test/admin/moderation_transparency_metrics_test.dart +++ b/app/test/admin/moderation_transparency_metrics_test.dart @@ -125,7 +125,11 @@ void main() { expect(text, contains('Total number of actions taken,0\r\n')); }); - testWithProfile('moderated package', fn: () async { + testWithProfile('moderated package', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc = await _report('oxygen'); await _moderatePkg('oxygen', caseId: mc.caseId, state: true); await _resolve( @@ -222,7 +226,11 @@ void main() { ])); }); - testWithProfile('appeal', fn: () async { + testWithProfile('appeal', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final mc = await _report('oxygen'); await _moderatePkg('oxygen', caseId: mc.caseId, state: true); await _resolve( diff --git a/app/test/package/api_export/api_exporter_test.dart b/app/test/package/api_export/api_exporter_test.dart index 9548638cc6..850a178871 100644 --- a/app/test/package/api_export/api_exporter_test.dart +++ b/app/test/package/api_export/api_exporter_test.dart @@ -43,8 +43,12 @@ final _testProfile = TestProfile( ); void main() { - testWithFakeTime('synchronizeExportedApi()', testProfile: _testProfile, - (fakeTime) async { + testWithFakeTime('synchronizeExportedApi()', + testProfile: _testProfile, + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/bar-2.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/bar-3.0.0.tar.gz".', + ], (fakeTime) async { await storageService.createBucket('bucket'); final bucket = storageService.bucket('bucket'); final apiExporter = @@ -59,6 +63,10 @@ void main() { testWithFakeTime( 'apiExporter.start()', + expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/bar-2.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/bar-3.0.0.tar.gz".', + ], testProfile: _testProfile, (fakeTime) async { await storageService.createBucket('bucket'); diff --git a/app/test/package/update_public_bucket_test.dart b/app/test/package/update_public_bucket_test.dart index 79147131ba..63b755dcaa 100644 --- a/app/test/package/update_public_bucket_test.dart +++ b/app/test/package/update_public_bucket_test.dart @@ -80,7 +80,11 @@ void main() { expect(changes3.archivesDeleted, 0); }); - testWithProfile('extra file - without package filter', fn: () async { + testWithProfile('extra file - without package filter', + expectedLogMessages: [ + 'SHOUT Object from public bucket will be deleted: "packages/oxygen-0.0.99.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-0.0.99.tar.gz".', + ], fn: () async { final bucket = storageService.bucket(activeConfiguration.publicPackagesBucketName!); await bucket.writeBytes('packages/oxygen-0.0.99.tar.gz', [1]); @@ -109,7 +113,11 @@ void main() { expect(changes3.isAllZero, isTrue); }); - testWithProfile('extra file - with matching package filter', fn: () async { + testWithProfile('extra file - with matching package filter', + expectedLogMessages: [ + 'SHOUT Object from public bucket will be deleted: "packages/oxygen-0.0.99.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-0.0.99.tar.gz".', + ], fn: () async { final bucket = storageService.bucket(activeConfiguration.publicPackagesBucketName!); await bucket.writeBytes('packages/oxygen-0.0.99.tar.gz', [1]); @@ -143,7 +151,10 @@ void main() { expect(changes4.isAllZero, isTrue); }); - testWithProfile('extra file - with different package filter', fn: () async { + testWithProfile('extra file - with different package filter', + expectedLogMessages: [ + 'SHOUT Object from public bucket will be deleted: "packages/oxygen-0.0.99.tar.gz".', + ], fn: () async { final bucket = storageService.bucket(activeConfiguration.publicPackagesBucketName!); await bucket.writeBytes('packages/oxygen-0.0.99.tar.gz', [1]); diff --git a/app/test/service/download_counts/download_counts_test.dart b/app/test/service/download_counts/download_counts_test.dart index 50aa30d6d4..28b922d433 100644 --- a/app/test/service/download_counts/download_counts_test.dart +++ b/app/test/service/download_counts/download_counts_test.dart @@ -15,7 +15,7 @@ import 'package:test/test.dart'; import '../../shared/test_services.dart'; void main() { - group('', () { + group('download counts', () { testWithProfile('Ingest download counts', fn: () async { final pkg = 'test'; final downloadCounts = @@ -465,7 +465,11 @@ void main() { }); testWithProfile('Sync download counts several data files - success & failure', - fn: () async { + expectedLogMessages: [ + RegExp(r'SEVERE daily_download_counts/.*.jsonl is empty.$'), + RegExp( + r'SHOUT Download counts sync was partial. The following files failed:\n.*$'), + ], fn: () async { final today = clock.now(); for (int i = defaultNumberOfSyncDays; i > 0; i--) { @@ -531,7 +535,11 @@ void main() { ); }); testWithProfile('Sync download counts several data files - failure', - fn: () async { + expectedLogMessages: [ + RegExp(r'SEVERE daily_download_counts/.*.jsonl is empty.$'), + RegExp( + r'SHOUT Download counts sync was partial. The following files failed:\n.*$'), + ], fn: () async { final today = clock.now(); final goodDate = today.addCalendarDays(-2); diff --git a/app/test/service/security_advisory/security_advisory_test.dart b/app/test/service/security_advisory/security_advisory_test.dart index 49ce5dd19f..457328e661 100644 --- a/app/test/service/security_advisory/security_advisory_test.dart +++ b/app/test/service/security_advisory/security_advisory_test.dart @@ -71,7 +71,10 @@ void main() { } }); - testWithProfile('Ingest invalid advisory', fn: () async { + testWithProfile('Ingest invalid advisory', expectedLogMessages: [ + 'SHOUT Package a not found, while ingesting advisory 123.', + 'SHOUT [advisory-malformed] ID: 456: Invalid modified date, cannot be a future date.', + ], fn: () async { final firstTime = DateTime(2022).toIso8601String(); final futureTime = clock.now().add(Duration(days: 1)).toIso8601String(); final affectedA = Affected( @@ -107,7 +110,11 @@ void main() { expect(adv2, isNull); }); - testWithProfile('List all advisories and delete advisory', fn: () async { + testWithProfile('List all advisories and delete advisory', + expectedLogMessages: [ + 'SHOUT Package a not found, while ingesting advisory 123.', + 'SHOUT Package a not found, while ingesting advisory 456.', + ], fn: () async { final firstTime = DateTime(2022).toIso8601String(); final affectedA = Affected( package: Package(ecosystem: 'pub', name: 'a'), @@ -158,7 +165,11 @@ void main() { expect(advisory, isNull); }); - testWithProfile('Insert, lookup and update advisory', fn: () async { + testWithProfile('Insert, lookup and update advisory', expectedLogMessages: [ + 'SHOUT Package a not found, while ingesting advisory 123.', + 'SHOUT Package b not found, while ingesting advisory 123.', + 'SHOUT Package c not found, while ingesting advisory 123.', + ], fn: () async { final firstTime = DateTime(2022).toIso8601String(); final affectedA = Affected( package: Package(ecosystem: 'pub', name: 'a'), @@ -249,7 +260,9 @@ void main() { testWithProfile( 'Only include affected packages with "Pub" as specified ecosystem.', - fn: () async { + expectedLogMessages: [ + 'SHOUT Package a not found, while ingesting advisory GHSA-0123-4567-8910.', + ], fn: () async { final firstTime = DateTime(2022).toIso8601String(); final id = 'GHSA-0123-4567-8910'; @@ -477,7 +490,13 @@ void main() { expect(neonRes.advisoriesUpdated, isNull); }); - testWithProfile('display url', fn: () async { + testWithProfile('display url', expectedLogMessages: [ + 'SHOUT Package a not found, while ingesting advisory GHSA-0123-4567-8910.', + 'SHOUT Package a not found, while ingesting advisory CVE-0123-4567-8910.', + 'SHOUT Package a not found, while ingesting advisory ABCD-EFGH-IJKL-1234.', + 'SHOUT Package a not found, while ingesting advisory ABCD-EFGH-IJKL-1235.', + 'SHOUT Package a not found, while ingesting advisory ABCD-EFGH-IJKL-1236.', + ], fn: () async { final firstTime = DateTime(2022).toIso8601String(); final affectedA = Affected( package: Package(ecosystem: 'pub', name: 'a'), diff --git a/app/test/service/security_advisory/sync_security_advisories_test.dart b/app/test/service/security_advisory/sync_security_advisories_test.dart index dc00659b8d..d2f6a4dd96 100644 --- a/app/test/service/security_advisory/sync_security_advisories_test.dart +++ b/app/test/service/security_advisory/sync_security_advisories_test.dart @@ -52,7 +52,9 @@ void main() { expect(adv, isNull); }); - testWithProfile('Sync with partial success', fn: () async { + testWithProfile('Sync with partial success', expectedLogMessages: [ + 'SHOUT [advisory-malformed] ID: GHSA-5678-5678-5678: Invalid modified date, cannot be a future date.', + ], fn: () async { // This directory contains 4 json files. One is with invalid json. // One contains invalid osv. The final two are valid security advisories. final dataDir3 = Directory(path.join(Directory.current.path, 'test', @@ -66,7 +68,10 @@ void main() { expect(list.length, 2); }); - testWithProfile('LatestAdvisory field gets updated on sync', fn: () async { + testWithProfile('LatestAdvisory field gets updated on sync', + expectedLogMessages: [ + 'SHOUT [advisory-malformed] ID: GHSA-5678-5678-5678: Invalid modified date, cannot be a future date.', + ], fn: () async { var pkg = await packageBackend.lookupPackage('oxygen'); expect(pkg!.latestAdvisory, isNull); diff --git a/app/test/shared/test_services.dart b/app/test/shared/test_services.dart index 382300a862..dc008c832a 100644 --- a/app/test/shared/test_services.dart +++ b/app/test/shared/test_services.dart @@ -164,6 +164,7 @@ void testWithProfile( Timeout? timeout, bool processJobsWithFakeRunners = false, Pattern? integrityProblem, + Iterable? expectedLogMessages, dynamic skip, }) { final env = FakeAppengineEnv(); @@ -180,6 +181,7 @@ void testWithProfile( integrityProblem: integrityProblem, ); }, + expectedLogMessages: expectedLogMessages, timeout: timeout, skip: skip, ); @@ -193,8 +195,9 @@ void testWithFakeTime( TestProfile? testProfile, ImportSource? importSource, Pattern? integrityProblem, + Iterable? expectedLogMessages, }) { - scopedTest(name, () async { + scopedTest(name, expectedLogMessages: expectedLogMessages, () async { await FakeTime.run((fakeTime) async { setupDebugEnvBasedLogging(); await withFakeServices( diff --git a/app/test/shared/utils.dart b/app/test/shared/utils.dart index 1931e58d91..fca4e60751 100644 --- a/app/test/shared/utils.dart +++ b/app/test/shared/utils.dart @@ -7,6 +7,7 @@ import 'dart:async'; import 'package:gcloud/service_scope.dart'; import 'package:html/dom.dart'; import 'package:html/parser.dart'; +import 'package:logging/logging.dart'; import 'package:pub_dev/frontend/dom/dom.dart' show isSelfClosing; import 'package:pub_dev/service/announcement/backend.dart'; import 'package:pub_dev/shared/configuration.dart'; @@ -24,14 +25,48 @@ void scopedTest( Function() func, { Timeout? timeout, dynamic skip, + Iterable? expectedLogMessages, }) { - test(name, () { - return fork(() async { - // double fork to allow further override - registerActiveConfiguration(Configuration.test()); - registerAnnouncementBackend(AnnouncementBackend()); - return await fork(() async => func()); - }); + test(name, () async { + final logMessages = {}; + final logSubscription = Logger.root.onRecord + .where((r) => r.level.value >= Level.SEVERE.value) + .listen((r) => logMessages.add('${r.level} ${r.message}')); + try { + await fork(() async { + // double fork to allow further override + registerActiveConfiguration(Configuration.test()); + registerAnnouncementBackend(AnnouncementBackend()); + return await fork(() async => func()); + }); + } finally { + await logSubscription.cancel(); + } + final allMatchedMessages = {}; + for (final p in expectedLogMessages ?? const []) { + final matchedMessages = + logMessages.where((m) => p.matchAsPrefix(m) != null).toList(); + if (matchedMessages.isEmpty) { + throw AssertionError( + 'Expected log message pattern "$p", but was absent.'); + } + allMatchedMessages.addAll(matchedMessages); + } + // remove known messages that can be ignored for now + // TODO: investigate why these messages are flaky + logMessages.removeWhere((m) => + allMatchedMessages.contains(m) || + m.startsWith('SEVERE failed to delete task-worker ') || + m.startsWith('SHOUT Download counts sync was partial.') || + (m.startsWith('SEVERE Failed to proccess line') && + m.contains('daily_download_counts')) || + m.contains( + 'appeared in download counts data for file daily_download_counts') || + (m.startsWith('SEVERE daily_download_counts') && + m.endsWith('.jsonl is empty.')) || + m.startsWith( + 'SEVERE [pub-search-not-working] Search is temporarily impaired')); + expect(logMessages, isEmpty); }, timeout: timeout, skip: skip); } diff --git a/app/test/tool/maintenance/migrate_isblocked_test.dart b/app/test/tool/maintenance/migrate_isblocked_test.dart index 7b0c3f7ba6..aa271890ae 100644 --- a/app/test/tool/maintenance/migrate_isblocked_test.dart +++ b/app/test/tool/maintenance/migrate_isblocked_test.dart @@ -14,7 +14,11 @@ import '../../shared/test_services.dart'; void main() { group('Migrate isBlocked', () { - testWithProfile('package', fn: () async { + testWithProfile('package', expectedLogMessages: [ + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.0.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-1.2.0.tar.gz".', + 'SHOUT Deleting object from public bucket: "packages/oxygen-2.0.0-dev.tar.gz".', + ], fn: () async { final p1 = await packageBackend.lookupPackage('oxygen'); await dbService.commit(inserts: [ p1! diff --git a/app/test/tool/maintenance/remove_orphaned_likes_test.dart b/app/test/tool/maintenance/remove_orphaned_likes_test.dart index 13ad7c32aa..4bfe2534b8 100644 --- a/app/test/tool/maintenance/remove_orphaned_likes_test.dart +++ b/app/test/tool/maintenance/remove_orphaned_likes_test.dart @@ -24,6 +24,9 @@ void main() { testWithProfile( 'finds like without package', + expectedLogMessages: [ + 'SHOUT ### [FAILED] neat-periodic-task: "sync-public-bucket-from-canonical-bucket"', + ], fn: () async { final client = await createFakeAuthPubApiClient(email: userAtPubDevEmail);