niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #455
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDumpPathWriterError117=== CONT TestScriptTokenNoExpiryRerunsEveryCall118=== CONT TestDoWithRetry_BodyReplayedViaGetBody119=== CONT TestSetClientTLS120=== CONT TestStreamPushStopsWhenCanceled121=== CONT TestFileTokenEmpty122=== CONT TestClientSignaturesByStorePath123=== CONT TestFileTokenMissing124--- PASS: TestClientSignaturesByStorePath (0.00s)125=== CONT TestUploadMultipart_PartsInParallel126--- PASS: TestStreamPushStopsWhenCanceled (0.00s)127=== CONT TestStreamPushReportsSkippedPaths128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStreamPushReportsSignatures130=== CONT TestStaticToken131=== CONT TestDumpPathMatchesNix132=== CONT TestSetClientTLSErrors133=== CONT TestSupersededNARStillUploadsListing134=== CONT TestStreamPushGivesUpOnDeadServer135=== CONT TestStreamPushIsolatesFailures1362026/11/01 17:55:09 ERROR Upload failed error="connection refused" count=201372026/11/01 17:55:09 ERROR Server seems unavailable, giving up on batch untried=17138=== CONT TestStreamPushBatchesUnderLoad139=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false1402026/11/01 17:55:09 ERROR Upload failed error="bad path" count=3141=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false142=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true143=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true144=== CONT TestPartSizeForNAR145=== RUN TestPartSizeForNAR/zero_stays_at_minimum146=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica147=== CONT TestShellSplit148=== CONT TestUploadMultipart_FailedPartBufferNotReused1492026/11/01 17:55:09 ERROR Upload failed error=boom count=1150=== CONT TestCaseHackSuffix1512026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=server-test rate=5152=== CONT TestFilterOversizedClosures1532026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:36933154=== CONT TestDoWithRetry_FinalResponseBodyReadable155=== CONT TestRetryTimeoutOutlastsMaxRetries156--- PASS: TestFileTokenEmpty (0.00s)1572026/11/01 17:55:09 INFO Garbage collection started1582026/11/01 17:55:09 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=01592026/11/01 17:55:09 WARN Rate limiter backed off name=server-test rate=51602026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=server-test rate=51612026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:341491622026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:369331632026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34201164=== CONT TestStreamPushRequestLine1652026/11/01 17:55:09 WARN Rate limiter backed off name=server-test rate=5166=== CONT TestEncodeNixBase32WithRealHash167=== CONT TestConvertHashToNix32168=== RUN TestSupersededNARStillUploadsListing/small_NAR169=== CONT TestParsePathInfoJSON170=== CONT TestDumpPathSingleFile171=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun172=== RUN TestSetClientTLSErrors/missing_cert_file173=== CONT TestUploadMultipart_SupersededByPeer174=== CONT TestStreamPushReportsEveryPath1752026/11/01 17:55:09 ERROR Upload failed error=boom count=1176=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum177=== CONT TestRegisterUploadedObjectReusesConnections178=== CONT TestShellSplitErrors179=== CONT TestSetClientTLSDoesNotMutateDefaultTransport180=== RUN TestFilterOversizedClosures/no_limit_keeps_everything181--- PASS: TestStaticToken (0.00s)182=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry183=== CONT TestGetStorePathHash184=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything185=== RUN TestConvertHashToNix32/SRI_format_to_Nix32186=== RUN TestPartSizeForNAR/small_stays_at_minimum187=== PAUSE TestPartSizeForNAR/small_stays_at_minimum188=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum189=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum190=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts191=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts192=== RUN TestPartSizeForNAR/1_TiB193=== PAUSE TestPartSizeForNAR/1_TiB194=== RUN TestPartSizeForNAR/5_TiB_S3_max_object195=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object196=== RUN TestPartSizeForNAR/capped_at_5_GiB197=== PAUSE TestPartSizeForNAR/capped_at_5_GiB198--- PASS: TestFileTokenReadsAndCaches (0.00s)199--- PASS: TestFileTokenMissing (0.00s)200--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)201--- PASS: TestStreamPushIsolatesFailures (0.03s)202--- PASS: TestStreamPushReportsSkippedPaths (0.00s)203--- PASS: TestShellSplit (0.00s)204=== CONT TestRateLimiterFeedback205=== RUN TestRateLimiterFeedback/429_enables_limiter2062026/11/01 17:55:09 WARN Garbage collection finished on another replica. Its statistics are not available here207=== PAUSE TestRateLimiterFeedback/429_enables_limiter208=== RUN TestRateLimiterFeedback/503_enables_limiter209=== PAUSE TestRateLimiterFeedback/503_enables_limiter210=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter211=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter212=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter213=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter214--- PASS: TestStreamPushReportsSignatures (0.03s)215=== CONT TestEncodeNixBase32216=== RUN TestEncodeNixBase32/test_string_hash217=== PAUSE TestEncodeNixBase32/test_string_hash218=== RUN TestEncodeNixBase32/empty_input219=== PAUSE TestEncodeNixBase32/empty_input220=== CONT TestResolveStorePath2212026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34201222=== CONT TestScriptTokenEmptyToken223=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer2242026/11/01 17:55:09 INFO Garbage collection started2252026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=s3-test rate=52262026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:37801227=== CONT TestScriptTokenBadJSON2282026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:34201229--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)230--- PASS: TestDoServerRequestAttachesToken (0.06s)231=== PAUSE TestSupersededNARStillUploadsListing/small_NAR232=== RUN TestSupersededNARStillUploadsListing/dump_cut_short233=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short234=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails235=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails236--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.06s)237--- PASS: TestEncodeNixBase32WithRealHash (0.00s)238--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)239--- PASS: TestShellSplitErrors (0.00s)240--- PASS: TestStreamPushReportsEveryPath (0.00s)241--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)242--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)243--- PASS: TestResolveStorePath (0.00s)244=== CONT TestScriptTokenEmptyCommand245--- PASS: TestScriptTokenEmptyCommand (0.00s)246--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)247=== PAUSE TestSetClientTLSErrors/missing_cert_file248=== RUN TestSetClientTLSErrors/missing_key_file249=== PAUSE TestSetClientTLSErrors/missing_key_file250=== RUN TestSetClientTLSErrors/missing_ca_file251=== PAUSE TestSetClientTLSErrors/missing_ca_file252=== RUN TestSetClientTLSErrors/invalid_ca_file253=== PAUSE TestSetClientTLSErrors/invalid_ca_file254=== RUN TestUploadMultipart_SupersededByPeer/exists255=== PAUSE TestUploadMultipart_SupersededByPeer/exists256=== RUN TestUploadMultipart_SupersededByPeer/missing257=== PAUSE TestUploadMultipart_SupersededByPeer/missing258=== CONT TestPathInfoCACompatibility259=== RUN TestPathInfoCACompatibility/null_ca_field260=== PAUSE TestPathInfoCACompatibility/null_ca_field261=== RUN TestPathInfoCACompatibility/old_string_format_-_text262=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text263=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive264=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive265=== RUN TestPathInfoCACompatibility/new_structured_format_-_text266=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text267=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method268=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== CONT TestScriptTokenCachesUntilRefresh270=== CONT TestPartSizeForNAR/zero_stays_at_minimum271=== CONT TestPartSizeForNAR/1_TiB272=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts273=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum274=== CONT TestPartSizeForNAR/small_stays_at_minimum275=== CONT TestRateLimiterFeedback/429_enables_limiter2762026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:34201277=== CONT TestPathInfoHashCompatibility2782026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=server-test rate=5279=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2802026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:42383281=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)282=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon283=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon284=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI286=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512287=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess288=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped289=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32290--- PASS: TestScriptTokenEmptyToken (0.00s)291=== RUN TestParsePathInfoJSON/Nix_format292=== RUN TestSetClientTLS/rejects_connection_without_client_cert293=== CONT TestScriptTokenScriptFails294=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false295=== CONT TestParsePathInfoJSONMultiplePaths296=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths297=== RUN TestGetStorePathHash/valid_store_path298=== PAUSE TestGetStorePathHash/valid_store_path299=== RUN TestGetStorePathHash/basename_without_hyphen_should_error300=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error301=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error302=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error303=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error304=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error305=== PAUSE TestParsePathInfoJSON/Nix_format3062026/11/01 17:55:09 WARN Rate limiter backed off name=server-test rate=5307=== RUN TestParsePathInfoJSON/Lix_format308=== PAUSE TestParsePathInfoJSON/Lix_format309=== RUN TestParsePathInfoJSON/empty_input310=== CONT TestPartSizeForNAR/5_TiB_S3_max_object311=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3122026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:34201313=== RUN TestConvertHashToNix32/already_Nix32_format314=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true315=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped316=== RUN TestFilterOversizedClosures/all_closures_skipped317=== PAUSE TestFilterOversizedClosures/all_closures_skipped318=== CONT TestPartSizeForNAR/capped_at_5_GiB319=== CONT TestRateLimiterFeedback/503_enables_limiter320=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3212026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=server-test rate=5322=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths323=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths324=== PAUSE TestParsePathInfoJSON/empty_input325=== RUN TestParsePathInfoJSON/whitespace_only326=== PAUSE TestParsePathInfoJSON/whitespace_only327=== RUN TestParsePathInfoJSON/invalid_JSON328=== PAUSE TestParsePathInfoJSON/invalid_JSON329=== CONT TestSupersededNARStillUploadsListing/small_NAR330=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3312026/11/01 17:55:09 WARN Rate limiter enabled after throttle name=server-test rate=5332=== CONT TestSetClientTLSErrors/missing_cert_file3332026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46117334=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert3352026/11/01 17:55:09 INFO Uploading abc-hello (1.0GB)336--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)337=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5123382026/11/01 17:55:09 WARN Rate limiter backed off name=server-test rate=5339=== PAUSE TestConvertHashToNix32/already_Nix32_format340=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3412026/11/01 17:55:09 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:34201342=== CONT TestEncodeNixBase32/test_string_hash343=== CONT TestEncodeNixBase32/empty_input344=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails345=== CONT TestUploadMultipart_SupersededByPeer/exists346--- PASS: TestPartSizeForNAR (0.03s)347 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)348 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)349 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)350 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)351 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)352 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)353 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)354=== CONT TestPathInfoCACompatibility/null_ca_field355=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA356=== CONT TestSetClientTLSErrors/invalid_ca_file357=== CONT TestSetClientTLSErrors/missing_ca_file3582026/11/01 17:55:10 INFO Uploading abc-hello (1.0GB)359=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA3602026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:34201361=== RUN TestSetClientTLS/preserves_debug_logging_transport362=== PAUSE TestSetClientTLS/preserves_debug_logging_transport363--- PASS: TestScriptTokenBadJSON (0.00s)364--- PASS: TestScriptTokenScriptFails (0.00s)365=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error366=== CONT TestSetClientTLSErrors/missing_key_file367=== CONT TestUploadMultipart_SupersededByPeer/missing368=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method369=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive370=== CONT TestGetStorePathHash/basename_without_hyphen_should_error371=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3722026/11/01 17:55:10 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000373=== CONT TestParsePathInfoJSON/Nix_format374=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths375=== CONT TestParsePathInfoJSON/invalid_JSON376=== CONT TestParsePathInfoJSON/whitespace_only377=== CONT TestFilterOversizedClosures/all_closures_skipped3782026/11/01 17:55:10 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=50379=== CONT TestParsePathInfoJSON/Lix_format380=== CONT TestPathInfoCACompatibility/new_structured_format_-_text381=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512382=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon3832026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:34201384=== CONT TestSetClientTLS/rejects_connection_without_client_cert385=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths386=== CONT TestSetClientTLS/preserves_debug_logging_transport387=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI388=== CONT TestGetStorePathHash/valid_store_path389=== CONT TestPathInfoCACompatibility/old_string_format_-_text390=== CONT TestFilterOversizedClosures/no_limit_keeps_everything391=== RUN TestConvertHashToNix32/invalid_format392=== PAUSE TestConvertHashToNix32/invalid_format393=== CONT TestConvertHashToNix32/SRI_format_to_Nix32394=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error395--- PASS: TestRateLimiterFeedback (0.00s)396 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)397 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)398 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)399 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.17s)400--- PASS: TestEncodeNixBase32 (0.00s)401 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)402 --- PASS: TestEncodeNixBase32/empty_input (0.00s)4032026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:34201404=== CONT TestParsePathInfoJSON/empty_input405=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)406=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA407=== CONT TestConvertHashToNix32/already_Nix32_format408=== CONT TestConvertHashToNix32/invalid_format409--- PASS: TestDumpPathSingleFile (0.17s)410--- PASS: TestStreamPushBatchesUnderLoad (0.00s)411 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)412 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)413--- PASS: TestCaseHackSuffix (0.20s)414--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)415 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)416 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)417--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)418 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)419 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)420--- PASS: TestScriptTokenCachesUntilRefresh (0.17s)421--- PASS: TestStreamPushRequestLine (0.18s)422--- PASS: TestPathInfoCACompatibility (0.00s)423 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)424 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)425 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)426 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)427 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)428--- PASS: TestFilterOversizedClosures (0.03s)429 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)430 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)431 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)432--- PASS: TestGetStorePathHash (0.01s)433 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)434 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)435 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)436 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)437--- PASS: TestParsePathInfoJSON (0.01s)438 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)439 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)440 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)441 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)442 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)443--- PASS: TestPathInfoHashCompatibility (0.01s)444 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)445 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)446 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)447 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)448--- PASS: TestConvertHashToNix32 (0.18s)449 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)450 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)451 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)4522026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:34201453--- PASS: TestSetClientTLSErrors (0.06s)454 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.16s)455 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)456 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)457 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4582026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:342014592026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:342014602026/11/01 17:55:10 http: TLS handshake error from 127.0.0.1:45714: remote error: tls: bad certificate4612026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:34201462--- PASS: TestSetClientTLS (0.24s)463 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)464 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)465 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)4662026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:34201467--- PASS: TestRegisterUploadedObjectReusesConnections (0.19s)4682026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:342014692026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:342014702026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:342014712026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:342014722026/11/01 17:55:10 INFO Uploading abc-hello (1.0GB)473--- PASS: TestDumpPathWriterError (0.25s)4742026/11/01 17:55:10 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:34201475--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.22s)4762026/11/01 17:55:10 WARN Rate limiter enabled after throttle name=s3-test rate=54772026/11/01 17:55:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:38395/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:38395/part/2478--- PASS: TestDumpPathMatchesNix (0.30s)4792026/11/01 17:55:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:38395/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:38395/part/34802026/11/01 17:55:10 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"481--- PASS: TestSupersededNARStillUploadsListing (0.06s)482 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)483 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.17s)484 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.71s)485--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.78s)486--- PASS: TestUploadMultipart_PartsInParallel (0.84s)4872026/11/01 17:55:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41715/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41715/api/uploads/complete4882026/11/01 17:55:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4892026/11/01 17:55:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41715/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41715/api/uploads/complete4902026/11/01 17:55:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4912026/11/01 17:55:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:41715/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:41715/api/uploads/complete4922026/11/01 17:55:10 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"493--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)494--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)495PASS496Running server tests...497The files belonging to this database system will be owned by user "nixbld".498This user must also own the server process.499500The database cluster will be initialized with locale "C".501The default database encoding has accordingly been set to "SQL_ASCII".502The default text search configuration will be set to "english".503504Data page checksums are enabled.505506creating directory /build/postgres1719329762/data ... ok507creating subdirectories ... ok508selecting dynamic shared memory implementation ... posix509selecting default "max_connections" ... 100510selecting default "shared_buffers" ... 128MB511selecting default time zone ... UTC512creating configuration files ... ok513running bootstrap script ... ok514performing post-bootstrap initialization ... ok515syncing data to disk ... ok516517initdb: warning: enabling "trust" authentication for local connections518initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.519520Success. You can now start the database server using:521522 pg_ctl -D /build/postgres1719329762/data -l logfile start523524/build/postgres1719329762:5432 - no response5252026-11-01 17:55:11.728 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5262026-11-01 17:55:11.729 UTC [128] LOG: listening on Unix socket "/build/postgres1719329762/.s.PGSQL.5432"5272026-11-01 17:55:11.733 UTC [135] LOG: database system was shut down at 2026-11-01 17:55:11 UTC5282026-11-01 17:55:11.736 UTC [128] LOG: database system is ready to accept connections529/build/postgres1719329762:5432 - accepting connections530=== RUN TestService_AuthMiddleware531=== PAUSE TestService_AuthMiddleware532=== RUN TestService_AuthMiddleware_MTLSProxyHeader533=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader534=== RUN TestService_AuthMiddleware_MTLSBoundSubjects535=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects536=== RUN TestService_ReadAuthMiddleware537=== PAUSE TestService_ReadAuthMiddleware538=== RUN TestService_AuthMiddleware_OIDC539=== PAUSE TestService_AuthMiddleware_OIDC540=== RUN TestService_RequireScope_OIDC541=== PAUSE TestService_RequireScope_OIDC542=== RUN TestService_ReadScope_PublicByDefault543=== PAUSE TestService_ReadScope_PublicByDefault544=== RUN TestCacheConfigHandler545=== PAUSE TestCacheConfigHandler546=== RUN TestCacheStatsHandler547=== PAUSE TestCacheStatsHandler548=== RUN TestClientCADerivations549=== PAUSE TestClientCADerivations550=== RUN TestClientErrorHandling551=== PAUSE TestClientErrorHandling552=== RUN TestClientIntegration553=== PAUSE TestClientIntegration554=== RUN TestClientMultipleUploads555=== PAUSE TestClientMultipleUploads556=== RUN TestClientWithDependencies557=== PAUSE TestClientWithDependencies558=== RUN TestClientSharedPathCommittedMidPush559=== PAUSE TestClientSharedPathCommittedMidPush560=== RUN TestPinProtectsFromGC561=== PAUSE TestPinProtectsFromGC562=== RUN TestClientPushesUseOnePush563=== PAUSE TestClientPushesUseOnePush564=== RUN TestClientFallsBackToClosures565=== PAUSE TestClientFallsBackToClosures566=== RUN TestDeleteClosuresRacingPins567=== PAUSE TestDeleteClosuresRacingPins568=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock569=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== RUN TestResolveDBConnectionString571=== PAUSE TestResolveDBConnectionString572=== RUN TestConnectWaitsForAPeerMigration573=== PAUSE TestConnectWaitsForAPeerMigration574=== RUN TestLeadElectsOneAndHandsOver575=== PAUSE TestLeadElectsOneAndHandsOver576=== RUN TestLeadIncumbentWinsAfterRestart5772026/11/01 17:55:12 INFO lead: acquired remote=192.0.2.1:12345782026/11/01 17:55:12 INFO lead: released remote=192.0.2.1:12345792026/11/01 17:55:12 INFO lead: acquired remote=192.0.2.1:12345802026/11/01 17:55:13 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadIncumbentWinsAfterRestart (1.87s)582=== RUN TestLeadIncumbentAnnouncesAtOnce583=== PAUSE TestLeadIncumbentAnnouncesAtOnce584=== RUN TestLeadEndsOnShutdown585=== PAUSE TestLeadEndsOnShutdown586=== RUN TestLeadEndsWhenItsConnectionHangs5872026/11/01 17:55:14 INFO lead: acquired remote=192.0.2.1:12345882026-11-01 17:55:15.410 UTC [317] FATAL: terminating connection due to administrator command5892026/11/01 17:55:15 INFO lead: acquired remote=192.0.2.1:12345902026/11/01 17:55:16 WARN lead: lock connection lost error="timeout: context deadline exceeded"5912026/11/01 17:55:16 INFO lead: released remote=192.0.2.1:12345922026/11/01 17:55:16 INFO lead: released remote=192.0.2.1:1234593--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)594=== RUN TestGCAdvisoryLockBlocksConcurrentRun595=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun596=== RUN TestGCBugBareHashReferences597=== PAUSE TestGCBugBareHashReferences598=== RUN TestGCMetrics599=== PAUSE TestGCMetrics600=== RUN TestPushDedupSurvivesConcurrentGC601=== PAUSE TestPushDedupSurvivesConcurrentGC602=== RUN TestDeduplicatedObjectsRecordedAsPending603=== PAUSE TestDeduplicatedObjectsRecordedAsPending604=== RUN TestGCSweepSkipsPendingObjects605=== PAUSE TestGCSweepSkipsPendingObjects606=== RUN TestTombstonedObjectOfferedWithoutWaiting607=== PAUSE TestTombstonedObjectOfferedWithoutWaiting608=== RUN TestGCSweepDeliversEachKeyOnce609=== PAUSE TestGCSweepDeliversEachKeyOnce610=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection611=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== RUN TestForceGCDuringPushOffersSweptObject613=== PAUSE TestForceGCDuringPushOffersSweptObject614=== RUN TestFailedS3DeleteKeepsTombstone615=== PAUSE TestFailedS3DeleteKeepsTombstone616=== RUN TestSweepSkipsRowsLockedByPush617=== PAUSE TestSweepSkipsRowsLockedByPush618=== RUN TestRegisterCompletedObjectNeedsPendingRow619=== PAUSE TestRegisterCompletedObjectNeedsPendingRow620=== RUN TestGetExistingObjectsLocksRows621=== PAUSE TestGetExistingObjectsLocksRows622=== RUN TestSweepRechecksPendingAfterLocking623=== PAUSE TestSweepRechecksPendingAfterLocking624=== RUN TestPushWaitsForSweepHoldingRow625=== PAUSE TestPushWaitsForSweepHoldingRow626=== RUN TestCommitRacingPendingCleanupKeepsObjects627=== PAUSE TestCommitRacingPendingCleanupKeepsObjects628=== RUN TestGCEndsOnShutdown629=== PAUSE TestGCEndsOnShutdown630=== RUN TestGCTaskStore_StartNew631=== PAUSE TestGCTaskStore_StartNew632=== RUN TestGCTaskStore_DeduplicateSameParams633=== PAUSE TestGCTaskStore_DeduplicateSameParams634=== RUN TestGCTaskStore_ConflictDifferentParams635=== PAUSE TestGCTaskStore_ConflictDifferentParams636=== RUN TestGCTaskStore_GetEmpty637=== PAUSE TestGCTaskStore_GetEmpty638=== RUN TestGCTaskStore_GetReturnsLatest639=== PAUSE TestGCTaskStore_GetReturnsLatest640=== RUN TestGCTaskStore_CompletedAllowsNewTask641=== PAUSE TestGCTaskStore_CompletedAllowsNewTask642=== RUN TestGCTaskStore_PhaseUpdates643=== PAUSE TestGCTaskStore_PhaseUpdates644=== RUN TestGCTaskStore_Fail645=== PAUSE TestGCTaskStore_Fail646=== RUN TestGracefulShutdownDrainsInflight647=== PAUSE TestGracefulShutdownDrainsInflight648=== RUN TestService_healthCheckHandler649=== PAUSE TestService_healthCheckHandler650=== RUN TestService_readinessHandler651=== PAUSE TestService_readinessHandler652=== RUN TestGenerateLandingPage653=== PAUSE TestGenerateLandingPage654=== RUN TestCacheConfigHandlerMaxNarSize655=== PAUSE TestCacheConfigHandlerMaxNarSize656=== RUN TestCreatePendingClosureRejectsOversizedNAR657=== PAUSE TestCreatePendingClosureRejectsOversizedNAR658=== RUN TestNARDeduplicationMetadataUploadBug659=== PAUSE TestNARDeduplicationMetadataUploadBug660=== RUN TestMetricsInventory661=== PAUSE TestMetricsInventory662=== RUN TestMetricsCommit663=== PAUSE TestMetricsCommit664=== RUN TestService_NativeMTLS665=== PAUSE TestService_NativeMTLS666=== RUN TestServerTLSConfig667=== PAUSE TestServerTLSConfig668=== RUN TestMultipartCleanup669=== PAUSE TestMultipartCleanup670=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded671=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== RUN TestPendingCleanupUsesOneCutoff673=== PAUSE TestPendingCleanupUsesOneCutoff674=== RUN TestObjectStatsTrigger675=== PAUSE TestObjectStatsTrigger676=== RUN TestObjectStatsUpdatedOncePerCommit677=== PAUSE TestObjectStatsUpdatedOncePerCommit678=== RUN TestOrphanedObjectsGC679=== PAUSE TestOrphanedObjectsGC680=== RUN TestOrphanedObjectsGCStressTest681=== PAUSE TestOrphanedObjectsGCStressTest682=== RUN TestCreatePin_ReservedPins683=== PAUSE TestCreatePin_ReservedPins684=== RUN TestPresentReportsOnlyClosureRoots685=== PAUSE TestPresentReportsOnlyClosureRoots686=== RUN TestPresentRefreshesOnlyStaleClosures687=== PAUSE TestPresentRefreshesOnlyStaleClosures688=== RUN TestPresentNotReportedWhileGCDeletesClosure689=== PAUSE TestPresentNotReportedWhileGCDeletesClosure690=== RUN TestParseSingleRange691=== PAUSE TestParseSingleRange692=== RUN TestProxyHeadersOnlyTrustedOnSocket6932026/11/01 17:55:16 INFO Starting HTTP server address=proxy.sock6942026/11/01 17:55:16 INFO Starting HTTP server address=127.0.0.1:377936952026/11/01 17:55:16 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6962026/11/01 17:55:16 INFO Shutdown signal received, draining in-flight requests timeout=10s697--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)698=== RUN TestIsValidCachePath699=== PAUSE TestIsValidCachePath700=== RUN TestReadProxyNarinfo701=== PAUSE TestReadProxyNarinfo702=== RUN TestReadProxyNarinfoAlreadyDecompressed703=== PAUSE TestReadProxyNarinfoAlreadyDecompressed704=== RUN TestReadProxyContentNegotiation705=== PAUSE TestReadProxyContentNegotiation706=== RUN TestReadProxyNarStreaming707=== PAUSE TestReadProxyNarStreaming708=== RUN TestReadProxy404709=== PAUSE TestReadProxy404710=== RUN TestReadProxyInvalidPath711=== PAUSE TestReadProxyInvalidPath712=== RUN TestReadProxyHead713=== PAUSE TestReadProxyHead714=== RUN TestReadProxyOutlastsServerWriteTimeout715=== PAUSE TestReadProxyOutlastsServerWriteTimeout716=== RUN TestReadProxyConditionalGet717=== PAUSE TestReadProxyConditionalGet718=== RUN TestReadProxyRootRedirectsToIndexHTML719=== PAUSE TestReadProxyRootRedirectsToIndexHTML720=== RUN TestReadProxyDisabled721=== PAUSE TestReadProxyDisabled722=== RUN TestReadRedirectNar723=== PAUSE TestReadRedirectNar724=== RUN TestReadRedirectKeepsNarinfoProxied725=== PAUSE TestReadRedirectKeepsNarinfoProxied726=== RUN TestReadProxyRangeRequest727=== PAUSE TestReadProxyRangeRequest728=== RUN TestReadRedirectUsesPublicS3URL729=== PAUSE TestReadRedirectUsesPublicS3URL730=== RUN TestPush_OverlappingRootsStoreOneRowPerKey731=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey732=== RUN TestPush_CompleteCommitsEveryRoot733=== PAUSE TestPush_CompleteCommitsEveryRoot734=== RUN TestPush_RepeatedRootCommitsOnce735=== PAUSE TestPush_RepeatedRootCommitsOnce736=== RUN TestPush_CompleteWaitsForCleanupOfThePush737=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush738=== RUN TestPush_RootsAreLockedInByteOrder739=== PAUSE TestPush_RootsAreLockedInByteOrder740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/11/01 17:55:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/11/01 17:55:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/01 17:55:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"775--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)776=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== RUN TestProxyWriteTimeout779=== PAUSE TestProxyWriteTimeout780=== RUN TestPendingClosureWriteTimeout781=== PAUSE TestPendingClosureWriteTimeout782=== RUN TestIsValidUploadKey783=== PAUSE TestIsValidUploadKey784=== RUN TestUploadHandlersRejectInvalidKeys785=== PAUSE TestUploadHandlersRejectInvalidKeys786=== RUN TestUploadHandlersRejectOversizedBody787=== PAUSE TestUploadHandlersRejectOversizedBody788=== RUN TestService_cleanupPendingClosuresHandler789=== PAUSE TestService_cleanupPendingClosuresHandler790=== RUN TestService_createPendingClosureHandler791=== PAUSE TestService_createPendingClosureHandler792=== RUN TestService_verifyS3Integrity793=== PAUSE TestService_verifyS3Integrity794=== RUN TestService_verifyS3ReuploadsStaleNarinfo795=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo796=== RUN TestCompleteMultipartUnregistered797=== PAUSE TestCompleteMultipartUnregistered798=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT799=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestService_AuthMiddleware801=== CONT TestReadProxyRootRedirectsToIndexHTML802=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT803=== CONT TestCompleteMultipartUnregistered804=== CONT TestService_verifyS3ReuploadsStaleNarinfo805=== CONT TestService_verifyS3Integrity806=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed807=== CONT TestService_createPendingClosureHandler808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestUploadHandlersRejectInvalidKeys811=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info812=== CONT TestIsValidUploadKey813=== CONT TestPendingClosureWriteTimeout814=== CONT TestProxyWriteTimeout815=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle816=== CONT TestSkippedUploadsHandler817=== CONT TestParseSize818=== CONT TestService_Rustfstest819=== CONT TestPresignedUploadRegisteredBeforeCommit820=== CONT TestCompletedNarNotReofferedAcrossClosures821=== CONT TestCompleteMultipartUpload_ErrorButObjectExists822=== CONT TestRedundantMultipartUpload823=== CONT TestPush_SignsNarinfosOfItsPendingObjects824=== CONT TestPush_RejectsBadRequests825=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit826=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed827=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info828=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal829=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal830=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key831=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key8322026/11/01 17:55:17 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000833=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key834=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key835=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed836=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed837=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost838=== RUN TestIsValidUploadKey/narinfo839=== RUN TestProxyWriteTimeout/narinfo840--- PASS: TestParseSize (0.00s)841=== CONT TestPush_RootsAreLockedInByteOrder842=== CONT TestPush_CompleteWaitsForCleanupOfThePush843=== RUN TestPendingClosureWriteTimeout/empty844=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost845=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed846=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed847=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed848--- PASS: TestSkippedUploadsHandler (0.02s)849=== CONT TestPush_RepeatedRootCommitsOnce850=== PAUSE TestProxyWriteTimeout/narinfo851=== PAUSE TestPendingClosureWriteTimeout/empty852=== PAUSE TestIsValidUploadKey/narinfo853=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed854=== RUN TestProxyWriteTimeout/1_GiB_nar855=== RUN TestPendingClosureWriteTimeout/400_objects856=== RUN TestIsValidUploadKey/nar_zst857=== PAUSE TestIsValidUploadKey/nar_zst858=== RUN TestIsValidUploadKey/nar_xz859=== PAUSE TestIsValidUploadKey/nar_xz860=== RUN TestIsValidUploadKey/nar_plain861=== PAUSE TestIsValidUploadKey/nar_plain862=== RUN TestIsValidUploadKey/listing863=== PAUSE TestIsValidUploadKey/listing864=== RUN TestIsValidUploadKey/build_log865=== PAUSE TestIsValidUploadKey/build_log866=== RUN TestIsValidUploadKey/build_log_home-manager_file867=== PAUSE TestIsValidUploadKey/build_log_home-manager_file868=== CONT TestPush_CompleteCommitsEveryRoot869=== PAUSE TestProxyWriteTimeout/1_GiB_nar870=== RUN TestProxyWriteTimeout/10_GiB_nar871=== PAUSE TestProxyWriteTimeout/10_GiB_nar872=== RUN TestProxyWriteTimeout/unknown_size873=== PAUSE TestPendingClosureWriteTimeout/400_objects874=== RUN TestIsValidUploadKey/build_log_plus_in_name875=== PAUSE TestIsValidUploadKey/build_log_plus_in_name876=== RUN TestIsValidUploadKey/build_log_question_mark877=== PAUSE TestIsValidUploadKey/build_log_question_mark878=== RUN TestIsValidUploadKey/build_log_equals879=== PAUSE TestIsValidUploadKey/build_log_equals880=== RUN TestIsValidUploadKey/realisation881=== PAUSE TestIsValidUploadKey/realisation882=== RUN TestIsValidUploadKey/realisation_plus_in_output883=== PAUSE TestIsValidUploadKey/realisation_plus_in_output884=== PAUSE TestProxyWriteTimeout/unknown_size885=== RUN TestPendingClosureWriteTimeout/670k_objects886=== PAUSE TestPendingClosureWriteTimeout/670k_objects887=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline888=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline889=== RUN TestIsValidUploadKey/nix-cache-info890=== PAUSE TestIsValidUploadKey/nix-cache-info891=== RUN TestIsValidUploadKey/index.html892=== PAUSE TestIsValidUploadKey/index.html893=== RUN TestIsValidUploadKey/narinfo_key,_nar_type894=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type895=== RUN TestIsValidUploadKey/nar_key,_narinfo_type896=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type897=== RUN TestIsValidUploadKey/listing_key,_narinfo_type898=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type899=== RUN TestIsValidUploadKey/traversal900=== PAUSE TestIsValidUploadKey/traversal901=== RUN TestIsValidUploadKey/traversal_nar902=== PAUSE TestIsValidUploadKey/traversal_nar903=== RUN TestIsValidUploadKey/absolute904=== PAUSE TestIsValidUploadKey/absolute905=== RUN TestIsValidUploadKey/empty_key906=== PAUSE TestIsValidUploadKey/empty_key907=== RUN TestIsValidUploadKey/unknown_type908=== CONT TestPush_OverlappingRootsStoreOneRowPerKey909=== CONT TestReadRedirectUsesPublicS3URL910=== PAUSE TestIsValidUploadKey/unknown_type911=== CONT TestReadProxyRangeRequest912=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart913=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart914=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts915=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts916=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure917=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure918=== CONT TestReadRedirectKeepsNarinfoProxied9192026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9202026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9212026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9222026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures923--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.40s)924=== CONT TestReadRedirectNar9252026/11/01 17:55:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9262026/11/01 17:55:17 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst927--- PASS: TestCompleteMultipartUnregistered (0.41s)928=== CONT TestReadProxyDisabled9292026/11/01 17:55:17 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"930--- PASS: TestService_AuthMiddleware (0.43s)931=== CONT TestConnectWaitsForAPeerMigration9322026/11/01 17:55:17 INFO Received cleanup request method=DELETE path=/api/pending_closures9332026/11/01 17:55:17 INFO Aborted multipart uploads count=0 kept=09342026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9352026/11/01 17:55:17 INFO Received cleanup request method=DELETE path=/api/pending_closures9362026/11/01 17:55:17 INFO Aborted multipart uploads count=1 kept=09372026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9382026/11/01 17:55:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9392026-11-01 17:55:17.620 UTC [397] ERROR: Closure does not exist: id=19402026-11-01 17:55:17.620 UTC [397] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9412026-11-01 17:55:17.620 UTC [397] STATEMENT: -- name: CommitPendingClosure :one942 SELECT commit_pending_closure($1::bigint)::bigint943 944--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)945=== CONT TestCommitRacingPendingCleanupKeepsObjects946--- PASS: TestService_Rustfstest (0.49s)947=== CONT TestPushWaitsForSweepHoldingRow9482026/11/01 17:55:17 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9492026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures950--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.50s)951=== CONT TestSweepRechecksPendingAfterLocking9522026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures953--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.54s)954=== CONT TestGetExistingObjectsLocksRows955--- PASS: TestReadProxyRangeRequest (0.48s)956=== CONT TestRegisterCompletedObjectNeedsPendingRow9572026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes9582026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9592026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes9602026/11/01 17:55:17 INFO Received complete push request method=POST path=/api/pushes/1/complete9612026/11/01 17:55:17 INFO Completed push id=1 objects=4 duration=7.194048ms9622026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes9632026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes9642026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9652026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures9662026-11-01 17:55:17.835 UTC [458] ERROR: could not obtain lock on row in relation "closures"9672026-11-01 17:55:17.835 UTC [458] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9682026-11-01 17:55:17.836 UTC [458] ERROR: could not obtain lock on row in relation "closures"9692026-11-01 17:55:17.836 UTC [458] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9702026-11-01 17:55:17.836 UTC [458] ERROR: could not obtain lock on row in relation "closures"9712026-11-01 17:55:17.836 UTC [458] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9722026-11-01 17:55:17.836 UTC [458] ERROR: could not obtain lock on row in relation "closures"9732026-11-01 17:55:17.836 UTC [458] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9742026-11-01 17:55:17.836 UTC [458] ERROR: could not obtain lock on row in relation "closures"9752026-11-01 17:55:17.836 UTC [458] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT976--- PASS: TestPush_RootsAreLockedInByteOrder (0.69s)977=== CONT TestSweepSkipsRowsLockedByPush9782026/11/01 17:55:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9792026/11/01 17:55:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete980--- PASS: TestReadRedirectKeepsNarinfoProxied (0.55s)981=== CONT TestFailedS3DeleteKeepsTombstone9822026/11/01 17:55:17 INFO Aborted multipart uploads count=0 kept=09832026/11/01 17:55:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9842026/11/01 17:55:17 WARN Force mode enabled - objects will be deleted immediately without grace period9852026/11/01 17:55:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LmU5MjFiYjJiLTA5MDgtNGQxYi1iMWQ3LTFlNGI5MmZjYWZjZXgxNzkzNTU1NzE3NTAxOTE4Mzk5 parts=109862026/11/01 17:55:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9872026/11/01 17:55:17 INFO Completed upload id=1 objects=2 duration=4.228389ms9882026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures989=== RUN TestPush_RejectsBadRequests/no_roots990=== PAUSE TestPush_RejectsBadRequests/no_roots991=== RUN TestPush_RejectsBadRequests/no_objects992=== PAUSE TestPush_RejectsBadRequests/no_objects993=== RUN TestPush_RejectsBadRequests/bad_root994=== PAUSE TestPush_RejectsBadRequests/bad_root995=== RUN TestPush_RejectsBadRequests/root_not_in_objects996=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects997=== CONT TestForceGCDuringPushOffersSweptObject998=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows999=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1000=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1001=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1002=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10032026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures10042026/11/01 17:55:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=010052026/11/01 17:55:17 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjNkZDAxNGI2LTFhOTctNDBmNS04ODFhLThmZmE2ZGIyZDk0M3gxNzkzNTU1NzE3NTIyODQ4NTIz parts=1010062026/11/01 17:55:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10072026/11/01 17:55:17 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10082026/11/01 17:55:17 WARN Found objects in DB but missing from S3, will re-upload count=11009--- PASS: TestService_verifyS3Integrity (0.73s)1010=== CONT TestGCSweepDeliversEachKeyOnce10112026/11/01 17:55:17 INFO Vacuumed table table=pending_closures10122026/11/01 17:55:17 INFO Completed upload id=1 objects=2 duration=5.761618ms10132026/11/01 17:55:17 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010142026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures10152026/11/01 17:55:17 INFO Vacuumed table table=pending_objects10162026/11/01 17:55:17 INFO Vacuumed table table=multipart_uploads10172026/11/01 17:55:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures10182026/11/01 17:55:17 INFO Vacuumed table table=closures10192026/11/01 17:55:17 INFO Vacuumed table table=objects10202026/11/01 17:55:17 INFO Received complete push request method=POST path=/api/pushes/2/complete10212026/11/01 17:55:17 INFO Aborted multipart uploads count=0 kept=010222026/11/01 17:55:17 INFO Completed push id=2 objects=4 duration=3.209219ms10232026/11/01 17:55:17 INFO Received uploads request method=POST path=/api/pending_closures1024--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.75s)1025=== CONT TestTombstonedObjectOfferedWithoutWaiting10262026/11/01 17:55:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010272026/11/01 17:55:17 INFO Vacuumed table table=pending_closures10282026/11/01 17:55:17 INFO Vacuumed table table=pending_objects10292026/11/01 17:55:17 INFO Vacuumed table table=multipart_uploads10302026/11/01 17:55:17 INFO Vacuumed table table=closures10312026/11/01 17:55:17 INFO Vacuumed table table=objects10322026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes10332026/11/01 17:55:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10342026/11/01 17:55:17 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001035--- PASS: TestService_createPendingClosureHandler (0.79s)1036=== CONT TestGCSweepSkipsPendingObjects10372026/11/01 17:55:17 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LmM0MjFkNDZjLTdkMDgtNDljMy1iODQ4LWIyM2FlOWY3ZTE2ZngxNzkzNTU1NzE3OTA3NDY5MDQy10382026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10392026/11/01 17:55:17 INFO Signed narinfos id=1 count=110402026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10412026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10422026/11/01 17:55:17 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10432026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10442026/11/01 17:55:17 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10452026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10462026/11/01 17:55:17 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110472026/11/01 17:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10482026/11/01 17:55:17 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1049--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.80s)1050=== CONT TestDeduplicatedObjectsRecordedAsPending10512026/11/01 17:55:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LmM0MjFkNDZjLTdkMDgtNDljMy1iODQ4LWIyM2FlOWY3ZTE2ZngxNzkzNTU1NzE3OTA3NDY5MDQy parts=11052--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.80s)1053=== CONT TestPushDedupSurvivesConcurrentGC10542026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes10552026/11/01 17:55:17 INFO Received complete push request method=POST path=/api/pushes/1/complete10562026/11/01 17:55:17 INFO Completed push id=1 objects=4 duration=8.515828ms1057--- PASS: TestPush_RepeatedRootCommitsOnce (0.76s)1058=== CONT TestGCMetrics10592026/11/01 17:55:17 INFO Received push request method=POST path=/api/pushes10602026/11/01 17:55:18 INFO Received complete push request method=POST path=/api/pushes/1/complete10612026/11/01 17:55:18 INFO Completed push id=1 objects=6 duration=10.994346ms1062--- PASS: TestPush_CompleteCommitsEveryRoot (0.80s)1063=== CONT TestGCBugBareHashReferences10642026-11-01 17:55:18.033 UTC [440] ERROR: Push does not exist: id=110652026-11-01 17:55:18.033 UTC [440] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10662026-11-01 17:55:18.033 UTC [440] STATEMENT: SELECT commit_push($1)1067--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.88s)1068=== CONT TestGCAdvisoryLockBlocksConcurrentRun1069--- PASS: TestReadRedirectUsesPublicS3URL (0.81s)1070=== CONT TestLeadEndsOnShutdown10712026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures10722026/11/01 17:55:18 INFO Received push request method=POST path=/api/pushes1073--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.87s)1074=== CONT TestLeadIncumbentAnnouncesAtOnce1075--- PASS: TestReadRedirectNar (0.57s)1076=== CONT TestLeadElectsOneAndHandsOver1077--- PASS: TestReadProxyDisabled (0.58s)1078=== CONT TestGCEndsOnShutdown1079=== RUN TestGCEndsOnShutdown/before_the_run1080=== PAUSE TestGCEndsOnShutdown/before_the_run1081=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1082=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1083=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1084=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1085=== CONT TestClientIntegration10862026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures10872026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=010882026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period10892026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010902026/11/01 17:55:18 INFO Vacuumed table table=pending_closures10912026/11/01 17:55:18 INFO Vacuumed table table=pending_objects10922026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads10932026/11/01 17:55:18 INFO Vacuumed table table=closures10942026/11/01 17:55:18 INFO Vacuumed table table=objects1095--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.61s)1096=== CONT TestResolveDBConnectionString1097=== RUN TestResolveDBConnectionString/flag_wins1098=== PAUSE TestResolveDBConnectionString/flag_wins1099=== RUN TestResolveDBConnectionString/file_when_flag_empty1100=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1101=== RUN TestResolveDBConnectionString/missing_file_is_an_error1102=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1103=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1104=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1105=== RUN TestResolveDBConnectionString/nothing_configured1106=== PAUSE TestResolveDBConnectionString/nothing_configured1107=== CONT TestReadProxyConditionalGet11082026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011092026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011112026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11122026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11132026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11142026/11/01 17:55:18 INFO Vacuumed table table=closures1115--- PASS: TestGetExistingObjectsLocksRows (0.58s)1116=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11172026/11/01 17:55:18 INFO Vacuumed table table=objects1118--- PASS: TestSweepRechecksPendingAfterLocking (0.63s)1119=== CONT TestDeleteClosuresRacingPins1120--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.58s)1121=== CONT TestReadProxyOutlastsServerWriteTimeout11222026/11/01 17:55:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11242026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011252026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11262026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011272026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11282026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11292026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11302026/11/01 17:55:18 INFO Vacuumed table table=closures11312026/11/01 17:55:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjdiOWI4MTAwLTEwYTgtNGNmYi1hZTJjLWNkODkxNTRiNTJhOHgxNzkzNTU1NzE3ODI5NDAyNjg0 parts=1211322026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11332026/11/01 17:55:18 INFO Vacuumed table table=objects11342026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011352026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11362026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11372026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11382026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011392026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11402026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11412026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11422026/11/01 17:55:18 INFO Vacuumed table table=closures11432026/11/01 17:55:18 INFO Vacuumed table table=objects1144--- PASS: TestSweepSkipsRowsLockedByPush (0.54s)1145=== CONT TestClientFallsBackToClosures11462026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011472026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11482026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period1149--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.52s)1150=== CONT TestClientPushesUseOnePush11512026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011522026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11532026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11542026/11/01 17:55:18 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11552026/11/01 17:55:18 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1156--- PASS: TestFailedS3DeleteKeepsTombstone (0.59s)1157=== CONT TestReadProxyHead11582026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011592026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=011602026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11612026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11622026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11632026/11/01 17:55:18 INFO Vacuumed table table=closures11642026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11652026/11/01 17:55:18 INFO Vacuumed table table=objects1166--- PASS: TestGCSweepDeliversEachKeyOnce (0.58s)1167=== CONT TestPinProtectsFromGC11682026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011692026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11702026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11712026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11722026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11732026/11/01 17:55:18 INFO Vacuumed table table=closures11742026/11/01 17:55:18 INFO Vacuumed table table=objects1175--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.54s)1176=== CONT TestReadProxyInvalidPath1177--- PASS: TestGCSweepSkipsPendingObjects (0.55s)1178=== CONT TestClientSharedPathCommittedMidPush11792026/11/01 17:55:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11802026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11812026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=011822026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period11832026/11/01 17:55:18 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjY1MWU1ODRkLTZiMmYtNDkxZC1hNWFlLTIyNDg1MjRhMjY3ZXgxNzkzNTU1NzE4MDU1OTcxNTc5 parts=1211842026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures11852026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011862026/11/01 17:55:18 INFO Vacuumed table table=pending_closures11872026/11/01 17:55:18 INFO Vacuumed table table=pending_objects11882026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads11892026/11/01 17:55:18 INFO Vacuumed table table=closures11902026/11/01 17:55:18 INFO Vacuumed table table=objects1191--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.39s)1192=== CONT TestReadProxy4041193--- PASS: TestGCMetrics (0.55s)1194=== CONT TestClientWithDependencies1195--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.70s)1196=== CONT TestClientMultipleUploads11972026/11/01 17:55:18 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1198--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.54s)1199=== CONT TestReadProxyNarStreaming12002026/11/01 17:55:18 INFO lead: acquired remote=192.0.2.1:123412012026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=012022026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012032026/11/01 17:55:18 INFO lead: acquired remote=192.0.2.1:123412042026/11/01 17:55:18 INFO lead: released remote=192.0.2.1:12341205--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.51s)1206=== CONT TestService_NativeMTLS12072026/11/01 17:55:18 INFO Vacuumed table table=pending_closures12082026/11/01 17:55:18 INFO Vacuumed table table=pending_objects12092026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads12102026/11/01 17:55:18 INFO Vacuumed table table=closures12112026/11/01 17:55:18 INFO Vacuumed table table=objects12122026/11/01 17:55:18 INFO Aborted multipart uploads count=0 kept=012132026/11/01 17:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period12142026/11/01 17:55:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012152026/11/01 17:55:18 INFO lead: acquired remote=192.0.2.1:123412162026/11/01 17:55:18 INFO Vacuumed table table=pending_closures12172026/11/01 17:55:18 INFO Vacuumed table table=pending_objects12182026/11/01 17:55:18 INFO Vacuumed table table=multipart_uploads12192026/11/01 17:55:18 INFO Vacuumed table table=closures12202026/11/01 17:55:18 INFO Vacuumed table table=objects1221--- PASS: TestPushDedupSurvivesConcurrentGC (0.69s)1222=== CONT TestReadProxyContentNegotiation1223--- PASS: TestReadProxyConditionalGet (0.46s)1224=== CONT TestMetricsCommit1225=== NAME TestClientIntegration1226 client_integration_test.go:291: Created store path: /build/TestClientIntegration416331598/002/store/imhspb6a35jk8y7rw7m6gd28qy80vg5w-test-file.txt1227--- PASS: TestPushWaitsForSweepHoldingRow (1.07s)1228=== CONT TestReadProxyNarinfoAlreadyDecompressed12292026/11/01 17:55:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12302026/11/01 17:55:18 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LmFiOGJlMDBlLTAyZDEtNDNjYy05NGYwLWYwZGJhZGU4ODJlYXgxNzkzNTU1NzE4MzU1Nzc2NzYy error="Get \"http://127.0.0.1:1/bucket18/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12312026/11/01 17:55:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjNjMTVjYzBhLTVhMTYtNGQ0MC1iODUxLTNkODQ0ZjY4ODFlNXgxNzkzNTU1NzE4MzQ4NzAxMjQ0 parts=1212322026/11/01 17:55:18 INFO Received cleanup request method=DELETE path=/api/pending_closures12332026/11/01 17:55:18 INFO Aborted multipart uploads count=1 kept=01234--- PASS: TestRedundantMultipartUpload (1.60s)1235=== CONT TestReadProxyNarinfo12362026/11/01 17:55:18 INFO Received push request method=POST path=/api/pushes12372026/11/01 17:55:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12382026/11/01 17:55:18 INFO Uploading imhspb6a35jk8y7rw7m6gd28qy80vg5w-test-file.txt (152B)1239--- PASS: TestGCBugBareHashReferences (0.76s)1240=== CONT TestMetricsInventory12412026/11/01 17:55:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12422026/11/01 17:55:18 WARN Failed to register uploaded object key=imhspb6a35jk8y7rw7m6gd28qy80vg5w.ls error="server returned 404: 404 page not found\n"12432026/11/01 17:55:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12442026/11/01 17:55:18 INFO Signed narinfos id=1 count=112452026/11/01 17:55:18 INFO Uploading 1 narinfos12462026/11/01 17:55:18 INFO Received complete push request method=POST path=/api/pushes/1/complete12472026/11/01 17:55:18 WARN Failed to register uploaded object key=imhspb6a35jk8y7rw7m6gd28qy80vg5w.narinfo error="server returned 404: 404 page not found\n"12482026/11/01 17:55:18 INFO Completed push id=1 objects=3 duration=10.101997ms12492026/11/01 17:55:18 INFO Upload complete. (70ms)12502026/11/01 17:55:18 INFO All 1 paths already cached1251--- PASS: TestReadProxyHead (0.40s)1252=== CONT TestIsValidCachePath1253=== RUN TestIsValidCachePath/narinfo1254=== PAUSE TestIsValidCachePath/narinfo1255=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1256=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1257=== RUN TestIsValidCachePath/nar_zst1258=== PAUSE TestIsValidCachePath/nar_zst1259=== RUN TestIsValidCachePath/nar_xz1260=== NAME TestClientIntegration1261 client_integration_test.go:317: Retrieved narinfo from S3:1262 StorePath: /build/TestClientIntegration416331598/002/store/imhspb6a35jk8y7rw7m6gd28qy80vg5w-test-file.txt1263 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1264 Compression: zstd1265 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11266 NarSize: 1521267 References: 1268 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11269=== PAUSE TestIsValidCachePath/nar_xz1270=== RUN TestIsValidCachePath/nar_bz21271=== PAUSE TestIsValidCachePath/nar_bz21272=== RUN TestIsValidCachePath/nar_uncompressed1273=== PAUSE TestIsValidCachePath/nar_uncompressed1274=== RUN TestIsValidCachePath/ls1275=== PAUSE TestIsValidCachePath/ls1276=== RUN TestIsValidCachePath/log1277=== PAUSE TestIsValidCachePath/log1278=== RUN TestIsValidCachePath/realisation1279=== PAUSE TestIsValidCachePath/realisation1280=== RUN TestIsValidCachePath/nix-cache-info1281=== PAUSE TestIsValidCachePath/nix-cache-info1282=== RUN TestIsValidCachePath/index.html1283=== PAUSE TestIsValidCachePath/index.html1284=== RUN TestIsValidCachePath/traversal_parent1285=== PAUSE TestIsValidCachePath/traversal_parent1286=== RUN TestIsValidCachePath/traversal_in_middle1287=== PAUSE TestIsValidCachePath/traversal_in_middle1288=== RUN TestIsValidCachePath/invalid_char_e1289=== PAUSE TestIsValidCachePath/invalid_char_e1290=== RUN TestIsValidCachePath/invalid_char_u1291=== PAUSE TestIsValidCachePath/invalid_char_u1292=== RUN TestIsValidCachePath/random_path1293=== PAUSE TestIsValidCachePath/random_path1294=== RUN TestIsValidCachePath/empty1295=== PAUSE TestIsValidCachePath/empty1296=== RUN TestIsValidCachePath/leading_slash1297=== PAUSE TestIsValidCachePath/leading_slash1298=== RUN TestIsValidCachePath/wrong_extension1299=== PAUSE TestIsValidCachePath/wrong_extension1300=== RUN TestIsValidCachePath/short_hash1301=== PAUSE TestIsValidCachePath/short_hash1302=== CONT TestService_ReadScope_PublicByDefault1303=== NAME TestClientIntegration1304 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1305 client_integration_test.go:318: Decompressed .ls content (64 bytes):1306 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1307--- PASS: TestReadProxyInvalidPath (0.39s)1308=== CONT TestNARDeduplicationMetadataUploadBug13092026/11/01 17:55:18 INFO Received push request method=POST path=/api/pushes13102026/11/01 17:55:18 INFO Object in database but missing from S3 key=imhspb6a35jk8y7rw7m6gd28qy80vg5w.ls13112026/11/01 17:55:18 WARN Found objects in DB but missing from S3, will re-upload count=113122026/11/01 17:55:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13132026/11/01 17:55:18 INFO Received complete push request method=POST path=/api/pushes/2/complete13142026/11/01 17:55:18 WARN Failed to register uploaded object key=imhspb6a35jk8y7rw7m6gd28qy80vg5w.ls error="server returned 404: 404 page not found\n"13152026/11/01 17:55:18 INFO Completed push id=2 objects=3 duration=4.027129ms13162026/11/01 17:55:18 INFO Upload complete. (44ms)1317=== NAME TestPinProtectsFromGC1318 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC3480323634/001/store/vr6iywv7v2m2xifd5r7wfhm4k40ja44w-pinned-file.txt1319 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC3480323634/001/store/db56dbj24c7gpchq3r2mdlssy0hylik2-unpinned-file.txt1320=== NAME TestClientIntegration1321 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1322 client_integration_test.go:335: Decompressed .ls content (49 bytes):1323 {"version":1,"root":{"type":"regular","size":39}}1324--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.67s)1325=== CONT TestParseSingleRange1326=== RUN TestParseSingleRange/none1327=== PAUSE TestParseSingleRange/none1328=== RUN TestParseSingleRange/unknown_unit1329=== PAUSE TestParseSingleRange/unknown_unit1330=== RUN TestParseSingleRange/multi-range_ignored1331=== PAUSE TestParseSingleRange/multi-range_ignored1332=== RUN TestParseSingleRange/malformed_no_dash1333=== PAUSE TestParseSingleRange/malformed_no_dash1334=== RUN TestParseSingleRange/malformed_both_empty1335=== PAUSE TestParseSingleRange/malformed_both_empty1336=== RUN TestParseSingleRange/malformed_end_before_start1337=== PAUSE TestParseSingleRange/malformed_end_before_start1338=== RUN TestParseSingleRange/closed1339=== PAUSE TestParseSingleRange/closed1340=== RUN TestParseSingleRange/open-ended1341=== PAUSE TestParseSingleRange/open-ended1342=== RUN TestParseSingleRange/end_clamped_to_size1343=== PAUSE TestParseSingleRange/end_clamped_to_size1344=== RUN TestParseSingleRange/suffix1345=== PAUSE TestParseSingleRange/suffix1346=== RUN TestParseSingleRange/suffix_exceeds_size1347=== PAUSE TestParseSingleRange/suffix_exceeds_size1348=== RUN TestParseSingleRange/single_byte1349=== PAUSE TestParseSingleRange/single_byte1350=== RUN TestParseSingleRange/start_past_EOF1351=== PAUSE TestParseSingleRange/start_past_EOF1352=== RUN TestParseSingleRange/start_far_past_EOF1353=== PAUSE TestParseSingleRange/start_far_past_EOF1354=== CONT TestPresentNotReportedWhileGCDeletesClosure1355=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1356=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1357=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1358=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1359=== CONT TestCreatePendingClosureRejectsOversizedNAR13602026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures1361--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1362=== CONT TestPresentRefreshesOnlyStaleClosures13632026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures13642026/11/01 17:55:18 INFO Received uploads request method=POST path=/api/pending_closures13652026/11/01 17:55:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13662026/11/01 17:55:18 INFO Uploading kahfg85gfhwnmhz1vxpkzv87w813j7yq-b (216B)13672026/11/01 17:55:18 INFO Uploading 8q7x94zzmkqr8qm1638bd96kz2xh7w99-shared-dep (136B)13682026/11/01 17:55:18 WARN Failed to register uploaded object key=d8y0bjlxhijvyca76yj3msjyabijhkc5.ls error="server returned 404: 404 page not found\n"13692026/11/01 17:55:18 WARN Failed to register uploaded object key=kahfg85gfhwnmhz1vxpkzv87w813j7yq.ls error="server returned 404: 404 page not found\n"13702026/11/01 17:55:18 WARN Failed to register uploaded object key=nar/0qbbvb83a3vyv2asgmnkkzbzlhkyqhr0mwjhm47j49pd1784xn2j.nar.zst error="server returned 404: 404 page not found\n"13712026/11/01 17:55:18 WARN Failed to register uploaded object key=8q7x94zzmkqr8qm1638bd96kz2xh7w99.ls error="server returned 404: 404 page not found\n"13722026/11/01 17:55:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13732026/11/01 17:55:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13742026/11/01 17:55:18 INFO Signed narinfos id=1 count=213752026/11/01 17:55:18 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13762026/11/01 17:55:18 INFO Signed narinfos id=2 count=213772026/11/01 17:55:18 INFO Uploading 4 narinfos1378--- PASS: TestReadProxy404 (0.44s)1379=== CONT TestClientErrorHandling1380=== RUN TestClientErrorHandling/InvalidStorePath1381=== PAUSE TestClientErrorHandling/InvalidStorePath1382=== RUN TestClientErrorHandling/InvalidAuthToken1383=== PAUSE TestClientErrorHandling/InvalidAuthToken1384=== RUN TestClientErrorHandling/ServerNotAvailable1385=== PAUSE TestClientErrorHandling/ServerNotAvailable1386=== CONT TestCacheConfigHandlerMaxNarSize1387--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1388=== CONT TestClientCADerivations13892026/11/01 17:55:18 WARN Failed to register uploaded object key=d8y0bjlxhijvyca76yj3msjyabijhkc5.narinfo error="server returned 404: 404 page not found\n"13902026/11/01 17:55:18 WARN Failed to register uploaded object key=kahfg85gfhwnmhz1vxpkzv87w813j7yq.narinfo error="server returned 404: 404 page not found\n"13912026/11/01 17:55:18 WARN Failed to register uploaded object key=8q7x94zzmkqr8qm1638bd96kz2xh7w99.narinfo error="server returned 404: 404 page not found\n"13922026/11/01 17:55:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13932026/11/01 17:55:18 WARN Failed to register uploaded object key=8q7x94zzmkqr8qm1638bd96kz2xh7w99.narinfo error="server returned 404: 404 page not found\n"1394--- PASS: TestReadProxyNarStreaming (0.41s)1395=== CONT TestPresentReportsOnlyClosureRoots13962026/11/01 17:55:18 INFO Received push request method=POST path=/api/pushes13972026/11/01 17:55:18 INFO Completed upload id=1 objects=6 duration=4.627539ms13982026/11/01 17:55:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13992026/11/01 17:55:18 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14002026/11/01 17:55:18 INFO Uploading b2lwkqrrbm0yipp264lcg9hcbli9cfqr-a (216B)14012026/11/01 17:55:18 INFO Uploading siab1x5z7ni68lrs23kfqvr5mcvjcc07-shared-dep (136B)14022026/11/01 17:55:18 INFO Completed upload id=2 objects=6 duration=1.958689ms14032026/11/01 17:55:18 INFO Upload complete. (69ms)1404=== NAME TestClientFallsBackToClosures1405 client_pushes_test.go:112: Retrieved narinfo from S3:1406 StorePath: /build/TestClientFallsBackToClosures2362786648/001/store/8q7x94zzmkqr8qm1638bd96kz2xh7w99-shared-dep1407 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1408 Compression: zstd1409 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821410 NarSize: 1361411 References: 1412 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1413 client_pushes_test.go:112: Retrieved narinfo from S3:1414 StorePath: /build/TestClientFallsBackToClosures2362786648/001/store/d8y0bjlxhijvyca76yj3msjyabijhkc5-a1415 URL: nar/0qbbvb83a3vyv2asgmnkkzbzlhkyqhr0mwjhm47j49pd1784xn2j.nar.zst1416 Compression: zstd1417 NarHash: sha256:0qbbvb83a3vyv2asgmnkkzbzlhkyqhr0mwjhm47j49pd1784xn2j1418 NarSize: 2161419 References: /build/TestClientFallsBackToClosures2362786648/001/store/8q7x94zzmkqr8qm1638bd96kz2xh7w99-shared-dep1420 CA: text:sha256:1g1dggpfwmvy9j81qqmy5iirfplaypv4s7n2ki7bkfxvhd510hmq14212026/11/01 17:55:18 INFO Received push request method=POST path=/api/pushes14222026/11/01 17:55:18 WARN Failed to register uploaded object key=924h7lvf0r907dsv4d42j2f78bp1gybi.ls error="server returned 404: 404 page not found\n"14232026/11/01 17:55:18 WARN Failed to register uploaded object key=b2lwkqrrbm0yipp264lcg9hcbli9cfqr.ls error="server returned 404: 404 page not found\n"14242026/11/01 17:55:18 WARN Failed to register uploaded object key=siab1x5z7ni68lrs23kfqvr5mcvjcc07.ls error="server returned 404: 404 page not found\n"14252026/11/01 17:55:18 WARN Failed to register uploaded object key=nar/197hk55xdslzycg7xkmlbgdvpmbsv9flbmvwlnclcyvah1vkzk8j.nar.zst error="server returned 404: 404 page not found\n"14262026/11/01 17:55:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14272026/11/01 17:55:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1428 client_pushes_test.go:112: Retrieved narinfo from S3:1429 StorePath: /build/TestClientFallsBackToClosures2362786648/001/store/kahfg85gfhwnmhz1vxpkzv87w813j7yq-b1430 URL: nar/0qbbvb83a3vyv2asgmnkkzbzlhkyqhr0mwjhm47j49pd1784xn2j.nar.zst1431 Compression: zstd1432 NarHash: sha256:0qbbvb83a3vyv2asgmnkkzbzlhkyqhr0mwjhm47j49pd1784xn2j14332026/11/01 17:55:18 INFO Signed narinfos id=1 count=31434 NarSize: 2161435 References: /build/TestClientFallsBackToClosures2362786648/001/store/8q7x94zzmkqr8qm1638bd96kz2xh7w99-shared-dep1436 CA: text:sha256:1g1dggpfwmvy9j81qqmy5iirfplaypv4s7n2ki7bkfxvhd510hmq14372026/11/01 17:55:18 INFO Uploading 3 narinfos14382026/11/01 17:55:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/11/01 17:55:18 INFO Uploading vr6iywv7v2m2xifd5r7wfhm4k40ja44w-pinned-file.txt (128B)14402026/11/01 17:55:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14412026/11/01 17:55:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1442--- PASS: TestService_NativeMTLS (0.39s)1443=== CONT TestGenerateLandingPage1444=== NAME TestClientWithDependencies1445 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1516898833/001/store/7h7m6qgw6hz22y9i39ni42mnh11cy8wn-test-script14462026/11/01 17:55:18 WARN Failed to register uploaded object key=924h7lvf0r907dsv4d42j2f78bp1gybi.narinfo error="server returned 404: 404 page not found\n"1447--- PASS: TestClientFallsBackToClosures (0.62s)1448=== CONT TestCreatePin_ReservedPins14492026/11/01 17:55:18 WARN Failed to register uploaded object key=b2lwkqrrbm0yipp264lcg9hcbli9cfqr.narinfo error="server returned 404: 404 page not found\n"14502026/11/01 17:55:18 INFO Received complete push request method=POST path=/api/pushes/1/complete14512026/11/01 17:55:18 WARN Failed to register uploaded object key=siab1x5z7ni68lrs23kfqvr5mcvjcc07.narinfo error="server returned 404: 404 page not found\n"1452--- PASS: TestGenerateLandingPage (0.00s)1453=== CONT TestCacheStatsHandler1454=== NAME TestClientMultipleUploads1455 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads4201993111/001/store/1h92jb17cp5jlf96ingdmamidgadb2zp-test-file-0.txt14562026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14572026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14582026/11/01 17:55:19 WARN Failed to register uploaded object key=vr6iywv7v2m2xifd5r7wfhm4k40ja44w.ls error="server returned 404: 404 page not found\n"14592026/11/01 17:55:19 INFO Signed narinfos id=1 count=114602026/11/01 17:55:19 INFO Uploading 1 narinfos14612026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes14622026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14632026/11/01 17:55:19 WARN Failed to register uploaded object key=vr6iywv7v2m2xifd5r7wfhm4k40ja44w.narinfo error="server returned 404: 404 page not found\n"14642026/11/01 17:55:19 INFO Completed push id=1 objects=8 duration=6.851369ms14652026/11/01 17:55:19 INFO Upload complete. (54ms)1466=== NAME TestClientPushesUseOnePush1467 client_pushes_test.go:97: Retrieved narinfo from S3:1468 StorePath: /build/TestClientPushesUseOnePush3326388896/001/store/siab1x5z7ni68lrs23kfqvr5mcvjcc07-shared-dep1469 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1470 Compression: zstd1471 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821472 NarSize: 1361473 References: 1474 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1475 client_pushes_test.go:97: Retrieved narinfo from S3:1476 StorePath: /build/TestClientPushesUseOnePush3326388896/001/store/b2lwkqrrbm0yipp264lcg9hcbli9cfqr-a1477 URL: nar/197hk55xdslzycg7xkmlbgdvpmbsv9flbmvwlnclcyvah1vkzk8j.nar.zst1478 Compression: zstd1479 NarHash: sha256:197hk55xdslzycg7xkmlbgdvpmbsv9flbmvwlnclcyvah1vkzk8j1480 NarSize: 2161481 References: /build/TestClientPushesUseOnePush3326388896/001/store/siab1x5z7ni68lrs23kfqvr5mcvjcc07-shared-dep1482 CA: text:sha256:0120ld5y4y9j24prz72rlwfshpb78lz622j8nl4fhbrmnl1pnqri1483 client_pushes_test.go:97: Retrieved narinfo from S3:1484 StorePath: /build/TestClientPushesUseOnePush3326388896/001/store/924h7lvf0r907dsv4d42j2f78bp1gybi-b1485 URL: nar/197hk55xdslzycg7xkmlbgdvpmbsv9flbmvwlnclcyvah1vkzk8j.nar.zst1486 Compression: zstd1487 NarHash: sha256:197hk55xdslzycg7xkmlbgdvpmbsv9flbmvwlnclcyvah1vkzk8j1488 NarSize: 2161489 References: /build/TestClientPushesUseOnePush3326388896/001/store/siab1x5z7ni68lrs23kfqvr5mcvjcc07-shared-dep1490 CA: text:sha256:0120ld5y4y9j24prz72rlwfshpb78lz622j8nl4fhbrmnl1pnqri14912026/11/01 17:55:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14922026/11/01 17:55:19 INFO Completed push id=1 objects=3 duration=6.464458ms14932026/11/01 17:55:19 INFO Upload complete. (53ms)1494--- PASS: TestClientPushesUseOnePush (0.60s)1495=== CONT TestService_readinessHandler14962026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/3/complete14972026/11/01 17:55:19 WARN Failed to register uploaded object key=imhspb6a35jk8y7rw7m6gd28qy80vg5w.ls error="server returned 404: 404 page not found\n"14982026/11/01 17:55:19 INFO Completed push id=3 objects=3 duration=1.979999ms14992026/11/01 17:55:19 INFO Upload complete. (42ms)1500=== NAME TestClientIntegration1501 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1502 client_integration_test.go:352: Decompressed .ls content (49 bytes):1503 {"version":1,"root":{"type":"regular","size":39}}1504 client_integration_test.go:363: Testing garbage collection...15052026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1506=== NAME TestClientWithDependencies1507 client_integration_test.go:662: Found 1 dependencies (including self)1508=== NAME TestClientMultipleUploads1509 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads4201993111/001/store/207ja2yv4acrywrpdkafsvkgaccpgrcq-test-file-1.txt15102026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes15112026/11/01 17:55:19 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15122026/11/01 17:55:19 INFO Uploading 1np56645zqj7v6yxw2zkz0kbmz7iz6qx-top (224B)15132026/11/01 17:55:19 INFO Uploading 3qqgp1qh0c1pdyw9p7y87xrcc9gn874x-shared-dep (136B)15142026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/0ml2sc81dx1vjw9y69nja942zcx8pimzlifrm4qbg3hwlcmfbcic.nar.zst error="server returned 404: 404 page not found\n"15152026/11/01 17:55:19 WARN Failed to register uploaded object key=1np56645zqj7v6yxw2zkz0kbmz7iz6qx.ls error="server returned 404: 404 page not found\n"15162026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15172026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15182026/11/01 17:55:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures15192026/11/01 17:55:19 WARN Failed to register uploaded object key=3qqgp1qh0c1pdyw9p7y87xrcc9gn874x.ls error="server returned 404: 404 page not found\n"15202026/11/01 17:55:19 INFO Signed narinfos id=1 count=215212026/11/01 17:55:19 INFO Garbage collection started15222026/11/01 17:55:19 INFO Uploading 2 narinfos15232026/11/01 17:55:19 WARN Failed to register uploaded object key=1np56645zqj7v6yxw2zkz0kbmz7iz6qx.narinfo error="server returned 404: 404 page not found\n"15242026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15252026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15262026/11/01 17:55:19 WARN Failed to register uploaded object key=3qqgp1qh0c1pdyw9p7y87xrcc9gn874x.narinfo error="server returned 404: 404 page not found\n"15272026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=01528--- PASS: TestReadProxyContentNegotiation (0.41s)1529=== CONT TestCacheConfigHandler1530=== RUN TestCacheConfigHandler/full_config,_no_issuer1531=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1532=== RUN TestCacheConfigHandler/no_cache_url_configured1533=== PAUSE TestCacheConfigHandler/no_cache_url_configured1534=== RUN TestCacheConfigHandler/no_signing_keys1535=== PAUSE TestCacheConfigHandler/no_signing_keys1536=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1537=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1538=== CONT TestOrphanedObjectsGCStressTest15392026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period15402026/11/01 17:55:19 INFO Completed push id=1 objects=4 duration=8.073177ms15412026/11/01 17:55:19 INFO Completed push id=1 objects=6 duration=7.393037ms15422026/11/01 17:55:19 INFO Upload complete. (65ms)1543=== NAME TestClientSharedPathCommittedMidPush1544 client_integration_test.go:727: Retrieved narinfo from S3:1545 StorePath: /build/TestClientSharedPathCommittedMidPush2194773887/001/store/3qqgp1qh0c1pdyw9p7y87xrcc9gn874x-shared-dep1546 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1547 Compression: zstd1548 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821549 NarSize: 1361550 References: 1551 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15522026/11/01 17:55:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15532026/11/01 17:55:19 INFO Completed upload id=2 objects=2 duration=1.458839ms1554 client_integration_test.go:727: Retrieved narinfo from S3:1555 StorePath: /build/TestClientSharedPathCommittedMidPush2194773887/001/store/1np56645zqj7v6yxw2zkz0kbmz7iz6qx-top1556 URL: nar/0ml2sc81dx1vjw9y69nja942zcx8pimzlifrm4qbg3hwlcmfbcic.nar.zst1557 Compression: zstd1558 NarHash: sha256:0ml2sc81dx1vjw9y69nja942zcx8pimzlifrm4qbg3hwlcmfbcic1559 NarSize: 2241560 References: /build/TestClientSharedPathCommittedMidPush2194773887/001/store/3qqgp1qh0c1pdyw9p7y87xrcc9gn874x-shared-dep1561 CA: text:sha256:17i5nnkrqirlf60rl1sfav7k41jbs0kraxbzp1mqzvd0wfzkhi1v1562--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.36s)1563=== CONT TestService_healthCheckHandler1564=== NAME TestClientMultipleUploads1565 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads4201993111/001/store/3r9pr7fxbjq4d3b8gn6yya22924nmp5q-test-file-2.txt1566--- PASS: TestMetricsCommit (0.38s)1567=== CONT TestOrphanedObjectsGC1568--- PASS: TestClientSharedPathCommittedMidPush (0.59s)1569=== CONT TestGracefulShutdownDrainsInflight15702026/11/01 17:55:19 INFO Starting HTTP server address=127.0.0.1:4515115712026/11/01 17:55:19 INFO Shutdown signal received, draining in-flight requests timeout=10s15722026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes15732026/11/01 17:55:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15742026/11/01 17:55:19 INFO Uploading db56dbj24c7gpchq3r2mdlssy0hylik2-unpinned-file.txt (128B)15752026/11/01 17:55:19 WARN Failed to register uploaded object key=db56dbj24c7gpchq3r2mdlssy0hylik2.ls error="server returned 404: 404 page not found\n"15762026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15772026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15782026/11/01 17:55:19 INFO Signed narinfos id=2 count=115792026/11/01 17:55:19 INFO Uploading 1 narinfos15802026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/2/complete15812026/11/01 17:55:19 WARN Failed to register uploaded object key=db56dbj24c7gpchq3r2mdlssy0hylik2.narinfo error="server returned 404: 404 page not found\n"15822026/11/01 17:55:19 INFO Completed push id=2 objects=3 duration=3.628078ms15832026/11/01 17:55:19 INFO Upload complete. (49ms)15842026/11/01 17:55:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33021/oidc15852026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes15862026/11/01 17:55:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=015872026/11/01 17:55:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15882026/11/01 17:55:19 INFO Uploading 7h7m6qgw6hz22y9i39ni42mnh11cy8wn-test-script (136B)15892026/11/01 17:55:19 INFO Vacuumed table table=pending_closures15902026/11/01 17:55:19 WARN Failed to register uploaded object key=7h7m6qgw6hz22y9i39ni42mnh11cy8wn.ls error="server returned 404: 404 page not found\n"15912026/11/01 17:55:19 WARN Failed to register uploaded object key=log/8gg9vnxn9a4qqk95gmpqh3kvsnzl868y-test-script.drv error="server returned 404: 404 page not found\n"15922026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15932026/11/01 17:55:19 INFO Signed narinfos id=1 count=115942026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15952026/11/01 17:55:19 INFO Uploading 1 narinfos15962026/11/01 17:55:19 INFO Vacuumed table table=pending_objects15972026/11/01 17:55:19 INFO Vacuumed table table=multipart_uploads1598--- PASS: TestMetricsInventory (0.34s)1599=== CONT TestPendingCleanupUsesOneCutoff16002026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete16012026/11/01 17:55:19 WARN Failed to register uploaded object key=7h7m6qgw6hz22y9i39ni42mnh11cy8wn.narinfo error="server returned 404: 404 page not found\n"16022026/11/01 17:55:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures16032026/11/01 17:55:19 INFO Garbage collection started16042026/11/01 17:55:19 INFO Vacuumed table table=closures1605--- PASS: TestService_ReadScope_PublicByDefault (0.29s)1606=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16072026/11/01 17:55:19 INFO Vacuumed table table=objects16082026/11/01 17:55:19 INFO Completed push id=1 objects=4 duration=11.067146ms16092026/11/01 17:55:19 INFO Upload complete. (76ms)16102026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1611=== NAME TestClientWithDependencies1612 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1516898833/001/store) requires matching store prefix16132026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=01614--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1615=== CONT TestGCTaskStore_Fail1616--- PASS: TestGCTaskStore_Fail (0.00s)1617=== CONT TestObjectStatsUpdatedOncePerCommit16182026/11/01 17:55:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1619--- PASS: TestClientWithDependencies (0.60s)16202026/11/01 17:55:19 INFO Uploading 207ja2yv4acrywrpdkafsvkgaccpgrcq-test-file-1.txt (160B)1621=== CONT TestMultipartCleanup16222026/11/01 17:55:19 INFO Uploading 1h92jb17cp5jlf96ingdmamidgadb2zp-test-file-0.txt (160B)16232026/11/01 17:55:19 INFO Uploading 3r9pr7fxbjq4d3b8gn6yya22924nmp5q-test-file-2.txt (160B)16242026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period16252026/11/01 17:55:19 WARN Failed to register uploaded object key=207ja2yv4acrywrpdkafsvkgaccpgrcq.ls error="server returned 404: 404 page not found\n"16262026/11/01 17:55:19 WARN Failed to register uploaded object key=1h92jb17cp5jlf96ingdmamidgadb2zp.ls error="server returned 404: 404 page not found\n"16272026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16282026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16292026/11/01 17:55:19 WARN Failed to register uploaded object key=3r9pr7fxbjq4d3b8gn6yya22924nmp5q.ls error="server returned 404: 404 page not found\n"16302026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16312026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16322026/11/01 17:55:19 INFO Signed narinfos id=1 count=316332026/11/01 17:55:19 INFO Uploading 3 narinfos16342026/11/01 17:55:19 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1635--- PASS: TestReadProxyNarinfo (0.40s)1636=== CONT TestObjectStatsTrigger16372026/11/01 17:55:19 WARN Failed to register uploaded object key=1h92jb17cp5jlf96ingdmamidgadb2zp.narinfo error="server returned 404: 404 page not found\n"16382026/11/01 17:55:19 WARN Failed to register uploaded object key=3r9pr7fxbjq4d3b8gn6yya22924nmp5q.narinfo error="server returned 404: 404 page not found\n"16392026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete16402026/11/01 17:55:19 WARN Failed to register uploaded object key=207ja2yv4acrywrpdkafsvkgaccpgrcq.narinfo error="server returned 404: 404 page not found\n"16412026/11/01 17:55:19 INFO Completed push id=1 objects=9 duration=9.339917ms16422026/11/01 17:55:19 INFO Upload complete. (64ms)1643=== NAME TestClientMultipleUploads1644 client_integration_test.go:416: Uploaded 3 paths in 94.012753ms1645--- PASS: TestClientMultipleUploads (0.60s)1646=== CONT TestServerTLSConfig1647=== RUN TestServerTLSConfig/no_client_CA1648=== PAUSE TestServerTLSConfig/no_client_CA1649=== RUN TestServerTLSConfig/missing_CA_file1650=== PAUSE TestServerTLSConfig/missing_CA_file1651=== RUN TestServerTLSConfig/not_a_PEM_file1652=== PAUSE TestServerTLSConfig/not_a_PEM_file1653=== CONT TestGCTaskStore_PhaseUpdates1654--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1655=== CONT TestGCTaskStore_CompletedAllowsNewTask1656--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1657=== CONT TestGCTaskStore_ConflictDifferentParams1658--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1659=== CONT TestGCTaskStore_GetEmpty1660--- PASS: TestGCTaskStore_GetEmpty (0.00s)1661=== CONT TestGCTaskStore_DeduplicateSameParams1662--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1663=== CONT TestGCTaskStore_GetReturnsLatest1664--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1665=== CONT TestService_ReadAuthMiddleware16662026/11/01 17:55:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01667--- PASS: TestPresentRefreshesOnlyStaleClosures (0.25s)1668=== CONT TestGCTaskStore_StartNew1669--- PASS: TestGCTaskStore_StartNew (0.00s)1670=== CONT TestService_RequireScope_OIDC1671=== NAME TestNARDeduplicationMetadataUploadBug1672 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2364894383/001/store/mlzmx32gajm23bqplnfqir92f7nrg1g2-file1.txt16732026/11/01 17:55:19 INFO Vacuumed table table=pending_closures16742026/11/01 17:55:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42769/oidc16752026/11/01 17:55:19 INFO Vacuumed table table=pending_objects16762026/11/01 17:55:19 INFO Vacuumed table table=multipart_uploads16772026/11/01 17:55:19 INFO Vacuumed table table=closures16782026/11/01 17:55:19 INFO Vacuumed table table=objects1679--- PASS: TestPresentReportsOnlyClosureRoots (0.27s)1680=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1681--- PASS: TestCacheStatsHandler (0.26s)1682=== CONT TestService_AuthMiddleware_OIDC16832026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes16842026/11/01 17:55:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16852026/11/01 17:55:19 INFO Uploading mlzmx32gajm23bqplnfqir92f7nrg1g2-file1.txt (160B)16862026/11/01 17:55:19 WARN readiness check failed error="closed pool"1687--- PASS: TestService_readinessHandler (0.26s)1688=== CONT TestService_AuthMiddleware_MTLSProxyHeader16892026/11/01 17:55:19 WARN Failed to register uploaded object key=mlzmx32gajm23bqplnfqir92f7nrg1g2.ls error="server returned 404: 404 page not found\n"16902026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16912026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16922026/11/01 17:55:19 INFO Signed narinfos id=1 count=116932026/11/01 17:55:19 INFO Uploading 1 narinfos16942026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete16952026/11/01 17:55:19 WARN Failed to register uploaded object key=mlzmx32gajm23bqplnfqir92f7nrg1g2.narinfo error="server returned 404: 404 page not found\n"1696=== NAME TestClientCADerivations1697 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1335464827/001/store/fgip9sml014m2h7qr7pigpnhrkmamv8i-ca-test16982026/11/01 17:55:19 INFO Completed push id=1 objects=3 duration=9.484557ms16992026/11/01 17:55:19 INFO Upload complete. (64ms)1700=== NAME TestNARDeduplicationMetadataUploadBug1701 metadata_upload_test.go:54: Retrieved narinfo from S3:1702 StorePath: /build/TestNARDeduplicationMetadataUploadBug2364894383/001/store/mlzmx32gajm23bqplnfqir92f7nrg1g2-file1.txt1703 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1704 Compression: zstd1705 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1706 NarSize: 1601707 References: 1708 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1709 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1710 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1711 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1712=== NAME TestClientCADerivations1713 client_ca_test.go:139: Found 1 dependencies (including self)1714=== NAME TestNARDeduplicationMetadataUploadBug1715 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2364894383/001/store/plk9ikrrjab46glrlgf4gac05j3ymlx0-file2.txt17162026/11/01 17:55:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44309/oidc1717--- PASS: TestService_healthCheckHandler (0.28s)1718=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17192026/11/01 17:55:19 INFO Received uploads request method=POST path=/1720=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17212026/11/01 17:55:19 INFO Received uploads request method=POST path=/1722=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17232026/11/01 17:55:19 INFO Received complete multipart upload request method=POST path=/1724=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17252026/11/01 17:55:19 INFO Received request for more parts method=POST path=/1726--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1727 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1728 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1729 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1730 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1731=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed17322026/11/01 17:55:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17332026/11/01 17:55:19 WARN Refused reserved pin name=worker-x86_64-linux17342026/11/01 17:55:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17352026/11/01 17:55:19 INFO Received create pin request method=POST path=/api/pins/my-app17362026/11/01 17:55:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1737--- PASS: TestCreatePin_ReservedPins (0.39s)1738=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed17392026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes17402026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures17412026/11/01 17:55:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17422026/11/01 17:55:19 WARN Failed to register uploaded object key=plk9ikrrjab46glrlgf4gac05j3ymlx0.ls error="server returned 404: 404 page not found\n"17432026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17442026/11/01 17:55:19 INFO Signed narinfos id=2 count=117452026/11/01 17:55:19 INFO Uploading 1 narinfos17462026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/2/complete17472026/11/01 17:55:19 WARN Failed to register uploaded object key=plk9ikrrjab46glrlgf4gac05j3ymlx0.narinfo error="server returned 404: 404 page not found\n"17482026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures17492026/11/01 17:55:19 INFO Completed push id=2 objects=3 duration=1.877529ms17502026/11/01 17:55:19 INFO Upload complete. (46ms)1751=== NAME TestNARDeduplicationMetadataUploadBug1752 metadata_upload_test.go:76: Retrieved narinfo from S3:1753 StorePath: /build/TestNARDeduplicationMetadataUploadBug2364894383/001/store/plk9ikrrjab46glrlgf4gac05j3ymlx0-file2.txt1754 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1755 Compression: zstd1756 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1757 NarSize: 1601758 References: 1759 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17602026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1761 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1762 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1763 {"version":1,"root":{"type":"regular","size":44}}17642026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures1765--- PASS: TestNARDeduplicationMetadataUploadBug (0.54s)1766=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost17672026/11/01 17:55:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17682026/11/01 17:55:19 INFO Uploading fgip9sml014m2h7qr7pigpnhrkmamv8i-ca-test (144B)17692026/11/01 17:55:19 INFO Received cleanup request method=DELETE path=/api/pending_closures17702026/11/01 17:55:19 WARN Failed to register uploaded object key=fgip9sml014m2h7qr7pigpnhrkmamv8i.ls error="server returned 404: 404 page not found\n"17712026/11/01 17:55:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17722026/11/01 17:55:19 WARN Failed to register uploaded object key=log/g6rd77b6kpxfxismy3jbcb0hc3ngzz2y-ca-test.drv error="server returned 404: 404 page not found\n"17732026/11/01 17:55:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17742026/11/01 17:55:19 INFO Signed narinfos id=1 count=117752026/11/01 17:55:19 INFO Uploading 1 narinfos17762026/11/01 17:55:19 INFO Received complete push request method=POST path=/api/pushes/1/complete17772026/11/01 17:55:19 WARN Failed to register uploaded object key=fgip9sml014m2h7qr7pigpnhrkmamv8i.narinfo error="server returned 404: 404 page not found\n"1778--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.30s)1779=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed17802026/11/01 17:55:19 INFO Completed push id=1 objects=4 duration=11.137247ms17812026/11/01 17:55:19 INFO Upload complete. (92ms)1782=== NAME TestClientCADerivations1783 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1335464827/001/store/fgip9sml014m2h7qr7pigpnhrkmamv8i-ca-test1784 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1785 Compression: zstd1786 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1787 NarSize: 1441788 References: 1789 Deriver: /build/TestClientCADerivations1335464827/001/store/g6rd77b6kpxfxismy3jbcb0hc3ngzz2y-ca-test.drv1790 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1791 client_ca_test.go:185: Checking for realisation files in S3...1792 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1793 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1794--- PASS: TestObjectStatsTrigger (0.31s)1795=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed17962026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures1797--- PASS: TestObjectStatsUpdatedOncePerCommit (0.38s)1798=== CONT TestProxyWriteTimeout/narinfo1799=== CONT TestProxyWriteTimeout/unknown_size1800=== CONT TestProxyWriteTimeout/10_GiB_nar1801=== CONT TestProxyWriteTimeout/1_GiB_nar1802--- PASS: TestProxyWriteTimeout (0.07s)1803 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1804 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1805 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1806 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1807=== CONT TestPendingClosureWriteTimeout/empty1808=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1809--- PASS: TestService_ReadAuthMiddleware (0.35s)1810=== CONT TestPendingClosureWriteTimeout/670k_objects1811=== CONT TestPendingClosureWriteTimeout/400_objects1812=== CONT TestIsValidUploadKey/narinfo1813=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1814=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1815=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1816=== CONT TestIsValidUploadKey/index.html1817=== CONT TestIsValidUploadKey/nix-cache-info1818=== CONT TestIsValidUploadKey/realisation_plus_in_output1819=== CONT TestIsValidUploadKey/realisation1820=== CONT TestIsValidUploadKey/build_log_equals1821=== CONT TestIsValidUploadKey/build_log_question_mark1822=== CONT TestIsValidUploadKey/build_log_plus_in_name1823=== CONT TestIsValidUploadKey/build_log_home-manager_file1824=== CONT TestIsValidUploadKey/build_log1825=== CONT TestIsValidUploadKey/listing1826=== CONT TestIsValidUploadKey/nar_plain1827=== CONT TestIsValidUploadKey/nar_xz1828=== CONT TestIsValidUploadKey/nar_zst1829=== CONT TestIsValidUploadKey/absolute1830=== CONT TestIsValidUploadKey/unknown_type1831=== CONT TestIsValidUploadKey/empty_key1832=== CONT TestIsValidUploadKey/traversal_nar1833=== CONT TestIsValidUploadKey/traversal1834--- PASS: TestIsValidUploadKey (0.08s)1835 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1836 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1837 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1838 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1839 --- PASS: TestIsValidUploadKey/index.html (0.00s)1840 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1841 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1842 --- PASS: TestIsValidUploadKey/realisation (0.00s)1843 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1844 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1845 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1846 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1847 --- PASS: TestIsValidUploadKey/build_log (0.00s)1848 --- PASS: TestIsValidUploadKey/listing (0.00s)1849 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1850 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1851 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1852 --- PASS: TestIsValidUploadKey/absolute (0.00s)1853 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1854 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1855 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1856 --- PASS: TestIsValidUploadKey/traversal (0.00s)1857=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18582026/11/01 17:55:19 INFO Received complete multipart upload request method=POST path=/1859=== NAME TestClientCADerivations1860 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1861 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1862 error: binary cache 's3://bucket73?endpoint=http://localhost:34979®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1335464827/001/store'1863 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11864--- PASS: TestClientCADerivations (0.58s)1865=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18662026/11/01 17:55:19 INFO Received uploads request method=POST path=/1867=== RUN TestService_RequireScope_OIDC/builder_may_write1868=== PAUSE TestService_RequireScope_OIDC/builder_may_write1869=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1870=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1871=== RUN TestService_RequireScope_OIDC/ops_may_admin1872=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1873=== RUN TestService_RequireScope_OIDC/ops_may_not_write1874=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1875=== RUN TestService_RequireScope_OIDC/reader_may_not_write1876=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1877=== RUN TestService_RequireScope_OIDC/static_token_may_admin1878=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1879=== RUN TestService_RequireScope_OIDC/static_token_may_write1880=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1881=== RUN TestService_RequireScope_OIDC/reader_may_read1882=== PAUSE TestService_RequireScope_OIDC/reader_may_read1883=== RUN TestService_RequireScope_OIDC/writer_implies_read1884=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1885=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1886=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1887=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1888=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1889=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1890=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1891=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1892=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1893=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1894=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1895=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18962026/11/01 17:55:19 INFO Received request for more parts method=POST path=/18972026/11/01 17:55:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18982026/11/01 17:55:19 WARN mTLS auth: bound subjects configured but subject DN unavailable18992026/11/01 17:55:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1900--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1901=== CONT TestPush_RejectsBadRequests/no_roots19022026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1903=== CONT TestPush_RejectsBadRequests/bad_root19042026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1905=== CONT TestPush_RejectsBadRequests/root_not_in_objects19062026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1907=== CONT TestPush_RejectsBadRequests/no_objects19082026/11/01 17:55:19 INFO Received push request method=POST path=/api/pushes1909=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1910--- PASS: TestPush_RejectsBadRequests (0.72s)1911 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1912 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1913 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1914 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1915=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19162026/11/01 17:55:19 INFO Received cleanup request method=DELETE path=/api/pending_closures19172026/11/01 17:55:19 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket84/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""19182026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=119192026/11/01 17:55:19 INFO Received cleanup request method=DELETE path=/api/pending_closures19202026/11/01 17:55:19 INFO Aborted multipart uploads count=1 kept=01921--- PASS: TestMultipartCleanup (0.46s)1922=== CONT TestGCEndsOnShutdown/before_the_run1923--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.32s)1924=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1925=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1926=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1927=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1928=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1929=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1930=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1931=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1932=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1933=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1934=== CONT TestResolveDBConnectionString/flag_wins1935=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1936=== CONT TestResolveDBConnectionString/nothing_configured1937=== CONT TestResolveDBConnectionString/missing_file_is_an_error1938=== CONT TestResolveDBConnectionString/file_when_flag_empty1939=== CONT TestIsValidCachePath/narinfo1940=== CONT TestIsValidCachePath/index.html1941=== CONT TestIsValidCachePath/short_hash1942=== CONT TestIsValidCachePath/wrong_extension1943=== CONT TestIsValidCachePath/leading_slash1944=== CONT TestIsValidCachePath/empty1945=== CONT TestIsValidCachePath/random_path1946=== CONT TestIsValidCachePath/invalid_char_u1947=== CONT TestIsValidCachePath/invalid_char_e1948=== CONT TestIsValidCachePath/traversal_in_middle1949--- PASS: TestResolveDBConnectionString (0.00s)1950 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1951 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1952 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1953 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1954 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1955=== CONT TestIsValidCachePath/traversal_parent1956=== CONT TestIsValidCachePath/nar_uncompressed1957=== CONT TestIsValidCachePath/nix-cache-info1958=== CONT TestIsValidCachePath/realisation1959=== CONT TestIsValidCachePath/log1960=== CONT TestIsValidCachePath/ls1961=== CONT TestIsValidCachePath/nar_xz1962=== CONT TestIsValidCachePath/nar_bz21963=== CONT TestIsValidCachePath/nar_zst1964=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1965=== CONT TestParseSingleRange/none1966=== CONT TestParseSingleRange/open-ended1967--- PASS: TestIsValidCachePath (0.00s)1968 --- PASS: TestIsValidCachePath/narinfo (0.00s)1969 --- PASS: TestIsValidCachePath/index.html (0.00s)1970 --- PASS: TestIsValidCachePath/short_hash (0.00s)1971 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1972 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1973 --- PASS: TestIsValidCachePath/empty (0.00s)1974 --- PASS: TestIsValidCachePath/random_path (0.00s)1975 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1976 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1977 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1978 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1979 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1980 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1981 --- PASS: TestIsValidCachePath/realisation (0.00s)1982 --- PASS: TestIsValidCachePath/log (0.00s)1983 --- PASS: TestIsValidCachePath/ls (0.00s)1984 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1985 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1986 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1987 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1988=== CONT TestParseSingleRange/closed1989=== CONT TestParseSingleRange/malformed_end_before_start1990=== CONT TestParseSingleRange/malformed_both_empty1991=== CONT TestParseSingleRange/malformed_no_dash1992=== CONT TestParseSingleRange/multi-range_ignored1993=== CONT TestParseSingleRange/unknown_unit1994=== CONT TestParseSingleRange/start_past_EOF1995=== CONT TestParseSingleRange/end_clamped_to_size1996=== CONT TestParseSingleRange/single_byte1997=== CONT TestParseSingleRange/suffix_exceeds_size1998=== CONT TestParseSingleRange/suffix1999=== CONT TestParseSingleRange/start_far_past_EOF2000--- PASS: TestParseSingleRange (0.00s)2001 --- PASS: TestParseSingleRange/none (0.00s)2002 --- PASS: TestParseSingleRange/open-ended (0.00s)2003 --- PASS: TestParseSingleRange/closed (0.00s)2004 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2005 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2006 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2007 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2008 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2009 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2010 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2011 --- PASS: TestParseSingleRange/single_byte (0.00s)2012 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2013 --- PASS: TestParseSingleRange/suffix (0.00s)2014 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2015=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20162026/11/01 17:55:19 INFO lead: released remote=192.0.2.1:12342017--- PASS: TestLeadEndsOnShutdown (1.60s)2018=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh20192026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20202026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures2021=== NAME TestOrphanedObjectsGC2022 orphaned_objects_gc_test.go:287: GC Test Summary:2023 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2024 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2025 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2026 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2027 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2028--- PASS: TestOrphanedObjectsGC (0.64s)2029=== CONT TestClientErrorHandling/InvalidStorePath20302026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures2031--- PASS: TestDeleteClosuresRacingPins (1.44s)2032=== CONT TestClientErrorHandling/ServerNotAvailable20332026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20342026/11/01 17:55:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20352026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20362026/11/01 17:55:19 INFO lead: released remote=192.0.2.1:123420372026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20382026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20392026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=020402026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period20412026/11/01 17:55:19 INFO lead: acquired remote=192.0.2.1:123420422026/11/01 17:55:19 INFO Received uploads request method=POST path=/api/pending_closures20432026/11/01 17:55:19 WARN Request failed, retrying attempt=2 backoff=187.188166ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20442026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=020452026/11/01 17:55:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=020462026/11/01 17:55:19 INFO Vacuumed table table=pending_closures20472026/11/01 17:55:19 INFO Vacuumed table table=pending_objects20482026/11/01 17:55:19 INFO Vacuumed table table=multipart_uploads20492026/11/01 17:55:19 INFO Vacuumed table table=closures20502026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/11/01 17:55:19 INFO Vacuumed table table=objects20522026/11/01 17:55:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020532026/11/01 17:55:19 INFO Vacuumed table table=pending_closures20542026/11/01 17:55:19 INFO Vacuumed table table=pending_objects20552026/11/01 17:55:19 INFO Vacuumed table table=multipart_uploads20562026/11/01 17:55:19 INFO Vacuumed table table=closures20572026/11/01 17:55:19 INFO Vacuumed table table=objects2058=== CONT TestClientErrorHandling/InvalidAuthToken2059=== CONT TestCacheConfigHandler/full_config,_no_issuer2060=== CONT TestCacheConfigHandler/no_signing_keys2061=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2062=== CONT TestCacheConfigHandler/no_cache_url_configured2063--- PASS: TestCacheConfigHandler (0.00s)2064 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2065 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2066 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2067 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2068=== CONT TestServerTLSConfig/no_client_CA2069=== CONT TestServerTLSConfig/not_a_PEM_file2070--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2071 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)2072 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.35s)2073=== CONT TestServerTLSConfig/missing_CA_file2074=== CONT TestService_RequireScope_OIDC/builder_may_write2075--- PASS: TestServerTLSConfig (0.00s)2076 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2077 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2078 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2079=== CONT TestService_RequireScope_OIDC/reader_may_read2080=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2081=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2082=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2083=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20842026/11/01 17:55:19 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2085=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2086=== CONT TestService_RequireScope_OIDC/reader_may_not_write2087=== CONT TestService_RequireScope_OIDC/writer_implies_read2088=== CONT TestService_RequireScope_OIDC/static_token_may_admin2089=== CONT TestService_RequireScope_OIDC/ops_may_admin2090=== CONT TestService_RequireScope_OIDC/static_token_may_write2091=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2092=== CONT TestService_RequireScope_OIDC/ops_may_not_write2093=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2094=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20952026/11/01 17:55:19 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2096=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2097=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2098--- PASS: TestService_RequireScope_OIDC (0.38s)2099 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2103 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2104 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2105 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2106 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2107 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2108 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2109 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2110 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2111 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2112 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)21132026/11/01 17:55:19 WARN Authentication failed token_preview=eyJhbGciOi...tAsk35-yjw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2114--- PASS: TestService_AuthMiddleware_OIDC (0.36s)2115 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2116 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2117 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2118 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)21192026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=021202026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period21212026/11/01 17:55:19 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34979/bucket100/?delete=\": context canceled"21222026/11/01 17:55:19 INFO Aborted multipart uploads count=0 kept=021232026/11/01 17:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period2124--- PASS: TestGCEndsOnShutdown (0.00s)2125 --- PASS: TestGCEndsOnShutdown/before_the_run (0.33s)2126 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.35s)2127 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.42s)21282026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21292026/11/01 17:55:20 WARN Request failed, retrying attempt=3 backoff=420.721272ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21302026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjAzNTdhM2EyLWU1MzctNDdkOS1hMzVjLTk4MDI2NDNjOTA4Y3gxNzkzNTU1NzE5NjU2ODM1MDM1 parts=1021312026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21322026/11/01 17:55:20 INFO Completed upload id=1 objects=3 duration=1.64229ms21332026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21342026/11/01 17:55:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21352026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjZmNzA0OGExLWQ0YWEtNDA1Ni1iODZmLTRlNjBjZWI3Y2EwNHgxNzkzNTU1NzE5Njg2MTAxNTI3 parts=1021362026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21372026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21382026/11/01 17:55:20 INFO Completed upload id=1 objects=3 duration=3.036709ms21392026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21402026/11/01 17:55:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21412026/11/01 17:55:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21422026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21432026/11/01 17:55:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21442026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjM3YTdjNTkwLTJkNmUtNDE2Yi1iZmM1LTU1NWI0OGIzYTA2MHgxNzkzNTU1NzE5NzE1NzkxMDA4 parts=1021452026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21462026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21472026/11/01 17:55:20 INFO Completed upload id=1 objects=3 duration=2.949959ms21482026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21492026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjBjZjc4M2JmLTlmMzAtNDM5Ni1hOGIwLTZjOTMyYzdkMmZlNHgxNzkzNTU1NzE5NzgxMjI5OTIw parts=1021502026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21512026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21522026/11/01 17:55:20 INFO Completed upload id=1 objects=3 duration=2.944769ms21532026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21542026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjhlYjljMTQwLTAzYzctNGE2ZC04YmJhLTZlZDE4OThhMzVjZXgxNzkzNTU1NzE5ODExNzk2MjUx parts=1021552026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21562026/11/01 17:55:20 INFO Completed upload id=1 objects=3 duration=2.999349ms2157--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)2158 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2159 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2160 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.69s)21612026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21622026/11/01 17:55:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21632026/11/01 17:55:20 WARN Found objects in DB but missing from S3, will re-upload count=121642026/11/01 17:55:20 WARN Request failed, retrying attempt=4 backoff=753.962223ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2165--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2166 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.87s)2167 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.89s)21682026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21692026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LjhiMzdjNmU5LTQ2NjctNGFkYi1iZDA3LTZlOGYyOTg0Mzk0NHgxNzkzNTU1NzIwMTUyNzU4ODky parts=1021702026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21712026/11/01 17:55:20 INFO Completed upload id=2 objects=3 duration=1.36738ms21722026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21732026/11/01 17:55:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst21742026/11/01 17:55:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo21752026/11/01 17:55:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21762026/11/01 17:55:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MTFjYzgzYjgtODlkZS00ZDI0LThiZjUtM2YyMTdlZjgxZmE5LmVhMWE1ZDI5LWI1MjMtNDVhNC1hMjU3LTcwMWIwMjcxMWYxN3gxNzkzNTU1NzIwMTkzNjgxNDkx parts=1021772026/11/01 17:55:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2178--- PASS: TestPendingClosureWriteTimeout (0.07s)2179 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2180 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2181 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2182 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.11s)21832026/11/01 17:55:20 INFO Completed upload id=2 objects=3 duration=1.49507ms21842026/11/01 17:55:20 INFO Received uploads request method=POST path=/api/pending_closures21852026/11/01 17:55:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21862026/11/01 17:55:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2187--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.07s)2188 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.81s)2189 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.79s)2190 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.80s)2191 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.23s)2192 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.26s)21932026/11/01 17:55:20 INFO lead: released remote=192.0.2.1:12342194--- PASS: TestLeadElectsOneAndHandsOver (2.82s)2195=== NAME TestOrphanedObjectsGCStressTest2196 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2197 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21982026/11/01 17:55:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02199=== NAME TestClientIntegration2200 client_integration_test.go:370: Objects in database after GC:2201 client_integration_test.go:370: Successfully deleted all objects with GC --force2202--- PASS: TestClientIntegration (2.93s)22032026/11/01 17:55:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022042026/11/01 17:55:21 INFO Received create pin request method=POST path=/api/pins/myapp22052026/11/01 17:55:21 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3480323634/001/store/vr6iywv7v2m2xifd5r7wfhm4k40ja44w-pinned-file.txt narinfo_key=vr6iywv7v2m2xifd5r7wfhm4k40ja44w.narinfo22062026/11/01 17:55:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures22072026/11/01 17:55:21 INFO Garbage collection started22082026/11/01 17:55:21 INFO Aborted multipart uploads count=0 kept=022092026/11/01 17:55:21 WARN Force mode enabled - objects will be deleted immediately without grace period22102026/11/01 17:55:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022112026/11/01 17:55:21 INFO Vacuumed table table=pending_closures22122026/11/01 17:55:21 INFO Vacuumed table table=pending_objects22132026/11/01 17:55:21 INFO Vacuumed table table=multipart_uploads22142026/11/01 17:55:21 INFO Vacuumed table table=closures22152026/11/01 17:55:21 INFO Vacuumed table table=objects22162026/11/01 17:55:21 WARN Request failed, retrying attempt=5 backoff=1.471179608s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2217=== NAME TestOrphanedObjectsGCStressTest2218 orphaned_objects_gc_test.go:503: Stress test completed successfully:2219 orphaned_objects_gc_test.go:504: - Active objects preserved: 202220 orphaned_objects_gc_test.go:505: - Objects deleted: 2102221 orphaned_objects_gc_test.go:506: - Total GC'd: 2102222--- PASS: TestOrphanedObjectsGCStressTest (3.07s)2223--- PASS: TestConnectWaitsForAPeerMigration (5.15s)22242026/11/01 17:55:22 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/11/01 17:55:22 WARN Request failed, retrying attempt=2 backoff=198.653739ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2226--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.66s)22272026/11/01 17:55:22 WARN Rate limiter enabled after throttle name=s3-test rate=522282026/11/01 17:55:22 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2229=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2230 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102231 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002232--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.81s)22332026/11/01 17:55:23 WARN Request failed, retrying attempt=3 backoff=364.258686ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2234=== NAME TestPinProtectsFromGC2235 client_integration_test.go:887: Pin successfully protected closure from garbage collection2236--- PASS: TestPinProtectsFromGC (4.69s)22372026/11/01 17:55:23 WARN Request failed, retrying attempt=4 backoff=820.949658ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22382026/11/01 17:55:24 WARN Request failed, retrying attempt=5 backoff=1.501224239s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22392026/11/01 17:55:25 INFO Aborted multipart uploads count=1 kept=022402026/11/01 17:55:25 INFO Received cleanup request method=DELETE path=/api/pending_closures22412026/11/01 17:55:25 INFO Aborted multipart uploads count=1 kept=02242--- PASS: TestPendingCleanupUsesOneCutoff (6.31s)22432026/11/01 17:55:25 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22442026/11/01 17:55:25 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/11/01 17:55:25 WARN Request failed, retrying attempt=2 backoff=219.013251ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/11/01 17:55:26 WARN Request failed, retrying attempt=3 backoff=426.967058ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/11/01 17:55:26 WARN Request failed, retrying attempt=4 backoff=739.162591ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22482026/11/01 17:55:27 WARN Request failed, retrying attempt=5 backoff=1.678398301s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22492026/11/01 17:55:28 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22502026/11/01 17:55:29 WARN Request failed, retrying attempt=2 backoff=193.380162ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22512026/11/01 17:55:29 WARN Request failed, retrying attempt=3 backoff=413.166925ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22522026/11/01 17:55:29 WARN Request failed, retrying attempt=4 backoff=787.995325ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22532026/11/01 17:55:30 WARN Request failed, retrying attempt=5 backoff=1.457219224s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2254--- PASS: TestClientErrorHandling (0.00s)2255 --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)2256 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.25s)2257 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.19s)2258PASS2259{"timestamp":"2026-11-01T17:55:31.904953361Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55080","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(135)"}2260{"timestamp":"2026-11-01T17:55:31.905129461Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55630","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(137)"}2261{"timestamp":"2026-11-01T17:55:31.905339201Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56560","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(135)"}2262{"timestamp":"2026-11-01T17:55:31.905399191Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56578","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(140)"}2263{"timestamp":"2026-11-01T17:55:31.905461201Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56588","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(141)"}22642026-11-01 17:55:32.176 UTC [128] LOG: received smart shutdown request22652026-11-01 17:55:32.179 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 122662026-11-01 17:55:32.185 UTC [133] LOG: shutting down22672026-11-01 17:55:32.186 UTC [133] LOG: checkpoint starting: shutdown immediate22682026-11-01 17:55:34.025 UTC [133] LOG: checkpoint complete: wrote 11285 buffers (68.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.254 s, sync=1.526 s, total=1.840 s; sync files=35726, longest=0.002 s, average=0.001 s; distance=516917 kB, estimate=516917 kB; lsn=0/210331D8, redo lsn=0/210331D822692026-11-01 17:55:34.099 UTC [128] LOG: database system is shut down2270Running OIDC tests...2271=== RUN TestAudienceForIssuer2272=== PAUSE TestAudienceForIssuer2273=== RUN TestGlobMatch2274=== PAUSE TestGlobMatch2275=== RUN TestValidateToken_ValidToken2276=== PAUSE TestValidateToken_ValidToken2277=== RUN TestValidateToken_WrongAudience2278=== PAUSE TestValidateToken_WrongAudience2279=== RUN TestValidateToken_Expired2280=== PAUSE TestValidateToken_Expired2281=== RUN TestValidateToken_BoundClaimsMismatch2282=== PAUSE TestValidateToken_BoundClaimsMismatch2283=== RUN TestValidateToken_BoundSubjectMismatch2284=== PAUSE TestValidateToken_BoundSubjectMismatch2285=== RUN TestValidateToken_MultipleProviders2286=== PAUSE TestValidateToken_MultipleProviders2287=== RUN TestValidateToken_NoMatchingProvider2288=== PAUSE TestValidateToken_NoMatchingProvider2289=== RUN TestValidateToken_KubernetesServiceAccount2290=== PAUSE TestValidateToken_KubernetesServiceAccount2291=== RUN TestNewValidator_KubernetesRequiresCA2292=== PAUSE TestNewValidator_KubernetesRequiresCA2293=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2294=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2295=== RUN TestPins_ReservedForMatchingRule2296=== PAUSE TestPins_ReservedForMatchingRule2297=== RUN TestPins_TopLevelShorthand2298=== PAUSE TestPins_TopLevelShorthand2299=== RUN TestPins_ConfigValidation2300=== PAUSE TestPins_ConfigValidation2301=== RUN TestScopes_LegacyProviderDefaultsToWrite2302=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2303=== RUN TestScopes_Rules2304=== PAUSE TestScopes_Rules2305=== RUN TestScopes_ConfigValidation2306=== PAUSE TestScopes_ConfigValidation2307=== CONT TestAudienceForIssuer2308=== CONT TestValidateToken_KubernetesServiceAccount2309--- PASS: TestAudienceForIssuer (0.00s)2310=== CONT TestPins_ConfigValidation2311=== CONT TestValidateToken_Expired2312=== CONT TestValidateToken_WrongAudience2313=== CONT TestScopes_ConfigValidation2314=== CONT TestValidateToken_ValidToken2315=== CONT TestScopes_Rules2316--- PASS: TestScopes_ConfigValidation (0.00s)2317--- PASS: TestPins_ConfigValidation (0.00s)2318=== CONT TestGlobMatch2319=== CONT TestScopes_LegacyProviderDefaultsToWrite2320=== CONT TestValidateToken_MultipleProviders2321=== CONT TestValidateToken_NoMatchingProvider2322=== CONT TestValidateToken_BoundSubjectMismatch2323=== CONT TestPins_ReservedForMatchingRule2324=== CONT TestPins_TopLevelShorthand2325=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2326=== CONT TestNewValidator_KubernetesRequiresCA2327=== CONT TestValidateToken_BoundClaimsMismatch2328=== RUN TestGlobMatch/foo_foo2329=== PAUSE TestGlobMatch/foo_foo2330=== RUN TestGlobMatch/foo_bar2331=== PAUSE TestGlobMatch/foo_bar2332=== RUN TestGlobMatch/*_2333=== PAUSE TestGlobMatch/*_2334=== RUN TestGlobMatch/*_anything2335=== PAUSE TestGlobMatch/*_anything2336=== RUN TestGlobMatch/foo*_foo2337=== PAUSE TestGlobMatch/foo*_foo2338=== RUN TestGlobMatch/foo*_foobar2339=== PAUSE TestGlobMatch/foo*_foobar2340=== RUN TestGlobMatch/foo*_bar2341=== PAUSE TestGlobMatch/foo*_bar2342=== RUN TestGlobMatch/*bar_bar2343=== PAUSE TestGlobMatch/*bar_bar2344=== RUN TestGlobMatch/*bar_foobar2345=== PAUSE TestGlobMatch/*bar_foobar2346=== RUN TestGlobMatch/*bar_foo2347=== PAUSE TestGlobMatch/*bar_foo2348=== RUN TestGlobMatch/foo*bar_foobar2349=== PAUSE TestGlobMatch/foo*bar_foobar2350=== RUN TestGlobMatch/foo*bar_foo123bar2351=== PAUSE TestGlobMatch/foo*bar_foo123bar2352=== RUN TestGlobMatch/foo*bar_foobarbaz2353=== PAUSE TestGlobMatch/foo*bar_foobarbaz2354=== RUN TestGlobMatch/*/*_foo/bar2355=== PAUSE TestGlobMatch/*/*_foo/bar2356=== RUN TestGlobMatch/*/*_foo2357=== PAUSE TestGlobMatch/*/*_foo2358=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2359=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2360=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02362=== RUN TestGlobMatch/refs/*/main_refs/heads/main2363=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2364=== RUN TestGlobMatch/fo?_foo2365=== PAUSE TestGlobMatch/fo?_foo2366=== RUN TestGlobMatch/fo?_fo2367=== PAUSE TestGlobMatch/fo?_fo2368=== RUN TestGlobMatch/fo?_fooo2369=== PAUSE TestGlobMatch/fo?_fooo2370=== RUN TestGlobMatch/?oo_foo2371=== PAUSE TestGlobMatch/?oo_foo2372=== RUN TestGlobMatch/?oo_boo2373=== PAUSE TestGlobMatch/?oo_boo2374=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2375=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2376=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2378=== CONT TestGlobMatch/foo_foo2379=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2380=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2381=== CONT TestGlobMatch/?oo_boo2382=== CONT TestGlobMatch/?oo_foo2383=== CONT TestGlobMatch/fo?_fooo2384=== CONT TestGlobMatch/fo?_fo2385=== CONT TestGlobMatch/fo?_foo2386=== CONT TestGlobMatch/refs/*/main_refs/heads/main2387=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02388=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2389=== CONT TestGlobMatch/*/*_foo2390=== CONT TestGlobMatch/*/*_foo/bar2391=== CONT TestGlobMatch/foo*bar_foobarbaz2392=== CONT TestGlobMatch/foo*bar_foo123bar2393=== CONT TestGlobMatch/foo*bar_foobar2394=== CONT TestGlobMatch/*bar_foo2395=== CONT TestGlobMatch/*bar_foobar2396=== CONT TestGlobMatch/*bar_bar2397=== CONT TestGlobMatch/foo*_bar2398=== CONT TestGlobMatch/foo*_foobar2399=== CONT TestGlobMatch/foo*_foo2400=== CONT TestGlobMatch/*_anything2401=== CONT TestGlobMatch/*_2402=== CONT TestGlobMatch/foo_bar2403--- PASS: TestGlobMatch (0.00s)2404 --- PASS: TestGlobMatch/foo_foo (0.00s)2405 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2406 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2407 --- PASS: TestGlobMatch/?oo_boo (0.00s)2408 --- PASS: TestGlobMatch/?oo_foo (0.00s)2409 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2410 --- PASS: TestGlobMatch/fo?_fo (0.00s)2411 --- PASS: TestGlobMatch/fo?_foo (0.00s)2412 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2413 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2414 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2415 --- PASS: TestGlobMatch/*/*_foo (0.00s)2416 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2418 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2419 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/*bar_foo (0.00s)2421 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2422 --- PASS: TestGlobMatch/*bar_bar (0.00s)2423 --- PASS: TestGlobMatch/foo*_bar (0.00s)2424 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2425 --- PASS: TestGlobMatch/foo*_foo (0.00s)2426 --- PASS: TestGlobMatch/*_ (0.00s)2427 --- PASS: TestGlobMatch/foo_bar (0.00s)2428 --- PASS: TestGlobMatch/*_anything (0.00s)24292026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45767/oidc2430--- PASS: TestValidateToken_WrongAudience (0.03s)24312026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33419/oidc2432--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)24332026/11/01 17:55:36 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324342026/11/01 17:55:36 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3832124352026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33409/oidc24362026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40617/oidc2437--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2438--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)2439--- PASS: TestPins_TopLevelShorthand (0.04s)24402026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37911/oidc2441--- PASS: TestScopes_Rules (0.04s)2442--- PASS: TestPins_ReservedForMatchingRule (0.04s)24432026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44645/oidc2444--- PASS: TestValidateToken_ValidToken (0.05s)24452026/11/01 17:55:36 http: TLS handshake error from 127.0.0.1:32992: remote error: tls: bad certificate2446--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)24472026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41933/oidc2448--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24492026/11/01 17:55:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46443/oidc2450--- PASS: TestValidateToken_NoMatchingProvider (0.12s)24512026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36957/oidc2452--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)24532026/11/01 17:55:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37225/oidc2454--- PASS: TestValidateToken_Expired (0.20s)24552026/11/01 17:55:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46281/oidc24562026/11/01 17:55:36 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38659/oidc2457--- PASS: TestValidateToken_MultipleProviders (0.22s)2458PASS2459Running hook tests...2460=== RUN TestSendPathsEmpty2461=== PAUSE TestSendPathsEmpty2462=== RUN TestQueueEnqueueAndFetch2463=== PAUSE TestQueueEnqueueAndFetch2464=== RUN TestQueueDeduplication2465=== PAUSE TestQueueDeduplication2466=== RUN TestQueueRemove2467=== PAUSE TestQueueRemove2468=== RUN TestQueueFetchBatchLimit2469=== PAUSE TestQueueFetchBatchLimit2470=== RUN TestQueueRetryMovesToBack2471=== PAUSE TestQueueRetryMovesToBack2472=== RUN TestQueueFetchRemoveLifecycle2473=== PAUSE TestQueueFetchRemoveLifecycle2474=== RUN TestQueueConcurrentWriters2475=== PAUSE TestQueueConcurrentWriters2476=== RUN TestQueueRemoveLargeClosure2477=== PAUSE TestQueueRemoveLargeClosure2478=== RUN TestServerClientIntegration2479--- PASS: TestServerClientIntegration (0.00s)2480=== RUN TestServerQueueError24812026/11/01 17:55:36 ERROR Failed to queue paths error="permission denied" count=12482--- PASS: TestServerQueueError (0.00s)2483=== RUN TestGetListenerSocketActivation2484 server_test.go:218: === RUN TestGetListenerSocketActivation2485 --- PASS: TestGetListenerSocketActivation (0.00s)2486 PASS2487 2488--- PASS: TestGetListenerSocketActivation (0.01s)2489=== RUN TestServerStalledClientDoesNotBlockShutdown2490=== PAUSE TestServerStalledClientDoesNotBlockShutdown2491=== RUN TestServerBacksOffOnAcceptErrors2492=== PAUSE TestServerBacksOffOnAcceptErrors2493=== RUN TestDrainIsolatesPoisonPath2494=== PAUSE TestDrainIsolatesPoisonPath2495=== RUN TestRunNotBlockedByPoisonHead2496=== PAUSE TestRunNotBlockedByPoisonHead2497=== RUN TestDrainGivesUpWhenServerDown2498=== PAUSE TestDrainGivesUpWhenServerDown2499=== RUN TestFailedPathPrunedByLaterClosure2500=== PAUSE TestFailedPathPrunedByLaterClosure2501=== RUN TestWorkerUploadsAndRemoves2502=== PAUSE TestWorkerUploadsAndRemoves2503=== RUN TestWorkerSkipsGCdPaths2504=== PAUSE TestWorkerSkipsGCdPaths2505=== RUN TestWorkerPrunesClosureDeps2506=== PAUSE TestWorkerPrunesClosureDeps2507=== RUN TestDrainTimeout2508=== PAUSE TestDrainTimeout2509=== RUN TestWorkerRemoveFailureIsNotProgress2510=== PAUSE TestWorkerRemoveFailureIsNotProgress2511=== RUN TestWorkerKeepsPathItCannotStat2512=== PAUSE TestWorkerKeepsPathItCannotStat2513=== CONT TestSendPathsEmpty2514=== CONT TestWorkerUploadsAndRemoves2515--- PASS: TestSendPathsEmpty (0.00s)2516=== CONT TestWorkerKeepsPathItCannotStat2517=== CONT TestWorkerRemoveFailureIsNotProgress2518=== CONT TestDrainTimeout2519=== CONT TestWorkerPrunesClosureDeps2520=== CONT TestWorkerSkipsGCdPaths2521=== CONT TestDrainIsolatesPoisonPath2522=== CONT TestQueueRetryMovesToBack2523=== CONT TestQueueFetchRemoveLifecycle2524=== CONT TestQueueFetchBatchLimit2525=== CONT TestServerBacksOffOnAcceptErrors25262026/11/01 17:55:36 ERROR Accept failed error="too many open files"2527=== CONT TestServerStalledClientDoesNotBlockShutdown2528=== CONT TestQueueRemove2529=== CONT TestQueueDeduplication2530=== CONT TestQueueRemoveLargeClosure2531=== CONT TestQueueEnqueueAndFetch2532=== CONT TestQueueConcurrentWriters2533=== CONT TestDrainGivesUpWhenServerDown2534=== CONT TestFailedPathPrunedByLaterClosure2535=== CONT TestRunNotBlockedByPoisonHead25362026/11/01 17:55:36 ERROR Accept failed error="too many open files"25372026/11/01 17:55:36 INFO Upload queue status pending=225382026/11/01 17:55:36 INFO Upload queue status pending=225392026/11/01 17:55:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2387447570/002/nonexistent25402026/11/01 17:55:36 INFO Upload queue status pending=325412026/11/01 17:55:36 INFO Uploading batch count=225422026/11/01 17:55:36 INFO Uploading batch count=225432026/11/01 17:55:36 INFO Uploading batch count=425442026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=425452026/11/01 17:55:36 INFO Uploading batch count=125462026/11/01 17:55:36 INFO Uploading batch count=125472026/11/01 17:55:36 INFO Uploading batch count=125482026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=125492026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=125502026/11/01 17:55:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa: permission denied"25512026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4252401661/002/bbb25522026/11/01 17:55:36 INFO Uploading batch count=225532026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=225542026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/a2555--- PASS: TestQueueEnqueueAndFetch (0.01s)2556--- PASS: TestQueueDeduplication (0.01s)25572026/11/01 17:55:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa: permission denied"25582026/11/01 17:55:36 INFO Uploading batch count=12559--- PASS: TestQueueRetryMovesToBack (0.01s)25602026/11/01 17:55:36 INFO Upload queue status pending=225612026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/b25622026/11/01 17:55:36 INFO Uploading batch count=12563--- PASS: TestQueueRemove (0.01s)25642026/11/01 17:55:36 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat1188070087/002/locked/aaa: permission denied"2565--- PASS: TestQueueFetchBatchLimit (0.02s)2566--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25672026/11/01 17:55:36 ERROR Accept failed error="too many open files"25682026/11/01 17:55:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress144510868/002/nonexistent25692026/11/01 17:55:36 INFO Uploading batch count=125702026/11/01 17:55:36 INFO Uploading batch count=225712026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=225722026/11/01 17:55:36 ERROR Drain finished with paths left in queue remaining=125732026/11/01 17:55:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125742026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/c25752026/11/01 17:55:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress144510868/002/nonexistent25762026/11/01 17:55:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125772026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/d25782026/11/01 17:55:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress144510868/002/nonexistent25792026/11/01 17:55:36 INFO Uploading batch count=125802026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=125812026/11/01 17:55:36 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125822026/11/01 17:55:36 INFO Uploading batch count=225832026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=225842026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/e25852026/11/01 17:55:36 ERROR Drain finished with paths left in queue remaining=125862026/11/01 17:55:36 INFO Uploading batch count=125872026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=125882026/11/01 17:55:36 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3776366906/002/f2589--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25902026/11/01 17:55:36 INFO Uploading batch count=125912026/11/01 17:55:36 ERROR Upload failed error="upload failed" count=12592--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)2593--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25942026/11/01 17:55:36 ERROR Drain finished with paths left in queue remaining=1025952026/11/01 17:55:36 ERROR Drain finished with paths left in queue remaining=12596--- PASS: TestDrainIsolatesPoisonPath (0.02s)2597--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2598--- PASS: TestWorkerSkipsGCdPaths (0.03s)2599--- PASS: TestWorkerUploadsAndRemoves (0.03s)26002026/11/01 17:55:36 ERROR Accept failed error="too many open files"2601--- PASS: TestWorkerPrunesClosureDeps (0.04s)2602--- PASS: TestQueueRemoveLargeClosure (0.05s)26032026/11/01 17:55:36 ERROR Accept failed error="too many open files"26042026/11/01 17:55:36 ERROR Accept failed error="too many open files"2605--- PASS: TestQueueConcurrentWriters (0.18s)26062026/11/01 17:55:36 ERROR Failed to decode request error="read unix /build/hook3234088909/test.sock->@: i/o timeout"26072026/11/01 17:55:36 ERROR Failed to write response error="write unix /build/hook3234088909/test.sock->@: i/o timeout"2608--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26092026/11/01 17:55:36 ERROR Upload failed error="context deadline exceeded" count=226102026/11/01 17:55:36 ERROR Drain finished with paths left in queue remaining=42611--- PASS: TestDrainTimeout (0.22s)26122026/11/01 17:55:36 ERROR Accept failed error="too many open files"26132026/11/01 17:55:37 ERROR Accept failed error="too many open files"2614--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26152026/11/01 17:55:37 INFO Uploading batch count=126162026/11/01 17:55:37 INFO Uploading batch count=126172026/11/01 17:55:37 INFO Uploading batch count=126182026/11/01 17:55:37 ERROR Upload failed error="upload failed" count=126192026/11/01 17:55:37 INFO Uploading batch count=126202026/11/01 17:55:37 ERROR Upload failed error="upload failed" count=126212026/11/01 17:55:37 INFO Uploading batch count=126222026/11/01 17:55:37 ERROR Upload failed error="upload failed" count=126232026/11/01 17:55:37 INFO Uploading batch count=126242026/11/01 17:55:37 ERROR Upload failed error="upload failed" count=126252026/11/01 17:55:37 ERROR Drain finished with paths left in queue remaining=12626--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2627PASS2628Running signing tests...2629=== RUN TestExternalSigner2630=== PAUSE TestExternalSigner2631=== RUN TestExternalSignerWrongPublicKey2632=== PAUSE TestExternalSignerWrongPublicKey2633=== RUN TestExternalSignerErrors2634=== PAUSE TestExternalSignerErrors2635=== RUN TestExternalSignerRestartsAfterCrash2636=== PAUSE TestExternalSignerRestartsAfterCrash2637=== RUN TestExternalSignerProgramErrorKeepsProcess2638=== PAUSE TestExternalSignerProgramErrorKeepsProcess2639=== RUN TestExternalSignerClose2640=== PAUSE TestExternalSignerClose2641=== RUN TestExternalSignerRejectsInvalidPublicKey2642=== PAUSE TestExternalSignerRejectsInvalidPublicKey2643=== RUN TestExternalSignerCancellation2644=== PAUSE TestExternalSignerCancellation2645=== RUN TestGenerateFingerprint2646=== PAUSE TestGenerateFingerprint2647=== RUN TestParseSigningKey2648=== PAUSE TestParseSigningKey2649=== RUN TestSign2650=== PAUSE TestSign2651=== RUN TestSignBatch2652=== PAUSE TestSignBatch2653=== RUN TestNilKeyPublicKey2654=== PAUSE TestNilKeyPublicKey2655=== RUN TestSignErrors2656=== PAUSE TestSignErrors2657=== CONT TestExternalSigner2658=== CONT TestExternalSignerCancellation2659=== CONT TestSignBatch2660=== CONT TestSignErrors2661=== CONT TestNilKeyPublicKey2662=== CONT TestExternalSignerErrors2663=== CONT TestExternalSignerRestartsAfterCrash2664=== CONT TestExternalSignerRejectsInvalidPublicKey2665=== RUN TestExternalSignerRejectsInvalidPublicKey/#002666=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002667=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2668=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2669=== CONT TestExternalSignerWrongPublicKey2670=== CONT TestParseSigningKey2671=== CONT TestSign2672=== CONT TestGenerateFingerprint2673=== CONT TestExternalSignerClose2674=== CONT TestExternalSignerProgramErrorKeepsProcess2675--- PASS: TestNilKeyPublicKey (0.00s)2676=== RUN TestExternalSignerErrors/too_few_signatures2677=== PAUSE TestExternalSignerErrors/too_few_signatures2678=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2679=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2680=== RUN TestExternalSignerErrors/invalid_signature_base642681=== PAUSE TestExternalSignerErrors/invalid_signature_base642682=== RUN TestGenerateFingerprint/basic_with_references2683=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2684=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2685=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2686=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2687=== CONT TestExternalSignerRejectsInvalidPublicKey/#002688=== RUN TestParseSigningKey/valid_32-byte_key2689=== PAUSE TestParseSigningKey/valid_32-byte_key2690=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2691=== RUN TestExternalSignerErrors/invalid_JSON2692=== PAUSE TestExternalSignerErrors/invalid_JSON2693--- PASS: TestSign (0.00s)2694=== PAUSE TestGenerateFingerprint/basic_with_references2695=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2696=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2697=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2698=== RUN TestSignErrors/nil_key2699=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2700=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2701=== RUN TestParseSigningKey/no_colon2702=== PAUSE TestParseSigningKey/no_colon2703=== RUN TestParseSigningKey/empty_name2704=== PAUSE TestParseSigningKey/empty_name2705=== RUN TestParseSigningKey/invalid_base642706=== PAUSE TestParseSigningKey/invalid_base642707=== RUN TestExternalSignerErrors/wrong_shape2708=== PAUSE TestExternalSignerErrors/wrong_shape2709=== RUN TestExternalSignerErrors/null2710--- PASS: TestSignBatch (0.00s)2711=== RUN TestGenerateFingerprint/no_references2712=== PAUSE TestGenerateFingerprint/no_references2713=== PAUSE TestSignErrors/nil_key2714=== RUN TestParseSigningKey/wrong_length2715=== PAUSE TestParseSigningKey/wrong_length2716=== PAUSE TestExternalSignerErrors/null2717=== RUN TestExternalSignerErrors/wrong_id2718=== PAUSE TestExternalSignerErrors/wrong_id2719=== RUN TestExternalSignerErrors/null_signatures2720=== PAUSE TestExternalSignerErrors/null_signatures2721=== RUN TestExternalSignerErrors/unrequested_key2722--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2723 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2724 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2725 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2726 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2727 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2728=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2729=== RUN TestSignErrors/nil_narinfo2730=== PAUSE TestSignErrors/nil_narinfo2731=== RUN TestSignErrors/invalid_narinfo2732=== PAUSE TestSignErrors/invalid_narinfo2733=== CONT TestParseSigningKey/valid_32-byte_key2734=== CONT TestParseSigningKey/no_colon2735=== CONT TestParseSigningKey/empty_name2736=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2737=== CONT TestParseSigningKey/wrong_length2738=== CONT TestParseSigningKey/invalid_base642739--- PASS: TestParseSigningKey (0.00s)2740 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2741 --- PASS: TestParseSigningKey/no_colon (0.00s)2742 --- PASS: TestParseSigningKey/empty_name (0.00s)2743 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2744 --- PASS: TestParseSigningKey/wrong_length (0.00s)2745 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2746=== PAUSE TestExternalSignerErrors/unrequested_key2747=== RUN TestExternalSignerErrors/missing_signature_name2748=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2749=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2750=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2751=== RUN TestSignErrors/canceled2752=== PAUSE TestSignErrors/canceled2753=== CONT TestSignErrors/nil_key2754=== PAUSE TestExternalSignerErrors/missing_signature_name2755=== CONT TestSignErrors/canceled2756=== RUN TestGenerateFingerprint/invalid_nar_hash_length2757=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2758=== RUN TestGenerateFingerprint/invalid_store_path_prefix2759=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2760=== CONT TestSignErrors/invalid_narinfo2761=== RUN TestExternalSignerErrors/exit_at_startup2762=== CONT TestSignErrors/nil_narinfo2763--- PASS: TestSignErrors (0.00s)2764 --- PASS: TestSignErrors/nil_key (0.00s)2765 --- PASS: TestSignErrors/canceled (0.00s)2766 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2767 --- PASS: TestSignErrors/nil_narinfo (0.00s)2768=== RUN TestGenerateFingerprint/invalid_reference_prefix2769=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2770=== CONT TestGenerateFingerprint/basic_with_references2771=== CONT TestGenerateFingerprint/no_references2772=== PAUSE TestExternalSignerErrors/exit_at_startup2773=== RUN TestExternalSignerErrors/wrong_signature_name2774=== PAUSE TestExternalSignerErrors/wrong_signature_name2775=== RUN TestExternalSignerErrors/program_error2776=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2777=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2778=== CONT TestGenerateFingerprint/invalid_reference_prefix2779=== CONT TestGenerateFingerprint/invalid_nar_hash_length2780=== CONT TestGenerateFingerprint/invalid_store_path_prefix2781--- PASS: TestGenerateFingerprint (0.00s)2782 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2783 --- PASS: TestGenerateFingerprint/no_references (0.00s)2784 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2785 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2786 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2787 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2788 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2789=== PAUSE TestExternalSignerErrors/program_error2790=== RUN TestExternalSignerErrors/exit_on_request2791=== PAUSE TestExternalSignerErrors/exit_on_request2792=== RUN TestExternalSignerErrors/missing_signatures2793=== PAUSE TestExternalSignerErrors/missing_signatures2794=== RUN TestExternalSignerErrors/wrong_signatures_shape2795=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2796=== RUN TestExternalSignerErrors/wrong_signature_length2797=== PAUSE TestExternalSignerErrors/wrong_signature_length2798=== CONT TestExternalSignerErrors/too_few_signatures2799=== CONT TestExternalSignerErrors/missing_signatures2800=== CONT TestExternalSignerErrors/missing_signature_name2801=== CONT TestExternalSignerErrors/program_error2802=== CONT TestExternalSignerErrors/wrong_signatures_shape2803=== CONT TestExternalSignerErrors/exit_on_request2804=== CONT TestExternalSignerErrors/wrong_signature_name2805=== CONT TestExternalSignerErrors/exit_at_startup2806=== CONT TestExternalSignerErrors/invalid_JSON2807=== CONT TestExternalSignerErrors/wrong_shape2808=== CONT TestExternalSignerErrors/null_signatures2809=== CONT TestExternalSignerErrors/unrequested_key2810=== CONT TestExternalSignerErrors/invalid_signature_base642811=== CONT TestExternalSignerErrors/wrong_id2812=== CONT TestExternalSignerErrors/null2813=== CONT TestExternalSignerErrors/wrong_signature_length2814--- PASS: TestExternalSignerClose (0.00s)2815--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2816--- PASS: TestExternalSignerWrongPublicKey (0.00s)2817--- PASS: TestExternalSigner (0.01s)2818--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2819--- PASS: TestExternalSignerErrors (0.00s)2820 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2821 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2822 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2823 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2824 --- PASS: TestExternalSignerErrors/program_error (0.00s)2825 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2826 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2827 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2828 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2829 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2830 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2831 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2832 --- PASS: TestExternalSignerErrors/null (0.00s)2833 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2834 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2835 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2836--- PASS: TestExternalSignerCancellation (0.02s)2837PASS2838Running OpenBao signer tests...2839=== RUN TestSign2840=== PAUSE TestSign2841=== RUN TestSignErrors2842=== PAUSE TestSignErrors2843=== RUN TestServe2844=== PAUSE TestServe2845=== RUN TestServeRejectsGarbage2846=== PAUSE TestServeRejectsGarbage2847=== CONT TestSign2848=== CONT TestServe2849=== CONT TestServeRejectsGarbage2850=== CONT TestSignErrors2851--- PASS: TestServeRejectsGarbage (0.00s)2852=== RUN TestSignErrors/http_error2853=== PAUSE TestSignErrors/http_error2854=== RUN TestSignErrors/invalid_json2855=== PAUSE TestSignErrors/invalid_json2856=== RUN TestSignErrors/no_prefix2857=== PAUSE TestSignErrors/no_prefix2858=== RUN TestSignErrors/invalid_base642859=== PAUSE TestSignErrors/invalid_base642860=== CONT TestSignErrors/http_error2861=== CONT TestSignErrors/no_prefix2862=== CONT TestSignErrors/invalid_json2863=== CONT TestSignErrors/invalid_base642864--- PASS: TestServe (0.00s)2865--- PASS: TestSign (0.00s)2866--- PASS: TestSignErrors (0.00s)2867 --- PASS: TestSignErrors/invalid_base64 (0.00s)2868 --- PASS: TestSignErrors/invalid_json (0.00s)2869 --- PASS: TestSignErrors/http_error (0.00s)2870 --- PASS: TestSignErrors/no_prefix (0.00s)2871PASS