niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #348
· 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 TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.64s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.03s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry129=== CONT TestScriptTokenCachesUntilRefresh130=== CONT TestDumpPathSingleFile131=== CONT TestCompletePendingClosure_NotFoundWithoutKey132=== CONT TestParsePathInfoJSONMultiplePaths133=== CONT TestDumpPathWriterError134=== CONT TestDoWithRetry_BodyReplayedViaGetBody135=== CONT TestScriptTokenEmptyCommand136=== CONT TestScriptTokenDoesNotWaitForItsChildren137=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs138=== CONT TestScriptTokenBadJSON139=== CONT TestParsePathInfoJSON140=== RUN TestParsePathInfoJSON/Nix_format141=== CONT TestScriptTokenScriptFails142=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer143=== CONT TestGetStorePathHash144=== CONT TestPathInfoCACompatibility145=== CONT TestPathInfoHashCompatibility146=== CONT TestResolveStorePath147=== CONT TestEncodeNixBase32WithRealHash148=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess149=== CONT TestEncodeNixBase32150=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent151=== CONT TestConvertHashToNix32152=== CONT TestStreamPushReportsSignatures153=== CONT TestRateLimiterFeedback154=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155--- PASS: TestScriptTokenEmptyCommand (0.00s)156=== CONT TestFileTokenReadsAndCaches157=== CONT TestSetClientTLS158=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs159=== RUN TestRateLimiterFeedback/429_enables_limiter160=== PAUSE TestParsePathInfoJSON/Nix_format161=== RUN TestGetStorePathHash/valid_store_path162=== RUN TestPathInfoCACompatibility/null_ca_field163=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== RUN TestConvertHashToNix32/SRI_format_to_Nix32165--- PASS: TestEncodeNixBase32WithRealHash (0.00s)166=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier167=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout168=== RUN TestEncodeNixBase32/test_string_hash169=== RUN TestParsePathInfoJSON/Lix_format170=== CONT TestScriptTokenEmptyToken171=== PAUSE TestEncodeNixBase32/test_string_hash172=== PAUSE TestParsePathInfoJSON/Lix_format173=== RUN TestEncodeNixBase32/empty_input174=== PAUSE TestGetStorePathHash/valid_store_path175=== PAUSE TestPathInfoCACompatibility/null_ca_field176=== PAUSE TestRateLimiterFeedback/429_enables_limiter177=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32178--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.02s)179=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180=== RUN TestConvertHashToNix32/already_Nix32_format181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon182=== CONT TestSetClientTLSErrors183=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier184=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout185=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths186=== RUN TestGetStorePathHash/basename_without_hyphen_should_error187=== CONT TestUploadMultipart_SupersededByPeer188=== PAUSE TestEncodeNixBase32/empty_input189=== RUN TestPathInfoCACompatibility/old_string_format_-_text190=== CONT TestDumpPathMatchesNix191=== RUN TestParsePathInfoJSON/empty_input192=== RUN TestRateLimiterFeedback/503_enables_limiter193--- PASS: TestScriptTokenScriptFails (0.01s)194=== PAUSE TestConvertHashToNix32/already_Nix32_format195=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== CONT TestUploadMultipart_FailedPartBufferNotReused199=== CONT TestFilterOversizedClosures200=== RUN TestUploadMultipart_SupersededByPeer/exists201=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica202=== CONT TestClientSignaturesByStorePath203=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error204=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text205=== PAUSE TestParsePathInfoJSON/empty_input206--- PASS: TestScriptTokenBadJSON (0.01s)207=== PAUSE TestRateLimiterFeedback/503_enables_limiter208=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up209=== CONT TestStreamPushRequestLine210=== CONT TestStreamPushGivesUpOnDeadServer211=== RUN TestConvertHashToNix32/invalid_format212=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths213=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI214=== RUN TestFilterOversizedClosures/no_limit_keeps_everything215=== RUN TestSetClientTLSErrors/missing_cert_file216=== PAUSE TestUploadMultipart_SupersededByPeer/exists217--- PASS: TestResolveStorePath (0.01s)218=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error219=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== CONT TestStreamPushIsolatesFailures222=== CONT TestSupersededNARStillUploadsListing223=== RUN TestParsePathInfoJSON/whitespace_only224=== CONT TestDoServerRequestAttachesToken225=== PAUSE TestConvertHashToNix32/invalid_format226=== CONT TestScriptTokenNoExpiryRerunsEveryCall227=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI228=== CONT TestFileTokenEmpty229=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230=== PAUSE TestSetClientTLSErrors/missing_cert_file231=== RUN TestUploadMultipart_SupersededByPeer/missing232--- PASS: TestStreamPushReportsSignatures (0.01s)233=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error234=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter235=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== RUN TestSupersededNARStillUploadsListing/small_NAR237=== PAUSE TestParsePathInfoJSON/whitespace_only238=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512239=== PAUSE TestSupersededNARStillUploadsListing/small_NAR240=== CONT TestSetClientTLSDoesNotMutateDefaultTransport241=== CONT TestUploadMultipart_PartsInParallel242=== RUN TestSetClientTLS/rejects_connection_without_client_cert243=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped244=== RUN TestSetClientTLSErrors/missing_key_file245=== PAUSE TestUploadMultipart_SupersededByPeer/missing246=== PAUSE TestSetClientTLSErrors/missing_key_file247=== CONT TestPartSizeForNAR248=== RUN TestSetClientTLSErrors/missing_ca_file249--- PASS: TestFileTokenReadsAndCaches (0.02s)250=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error251=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter252=== RUN TestPathInfoCACompatibility/new_structured_format_-_text253=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512254=== RUN TestParsePathInfoJSON/invalid_JSON255=== CONT TestStreamPushStopsOnCancel256=== RUN TestSupersededNARStillUploadsListing/dump_cut_short257=== CONT TestStaticToken258=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert259=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped260=== RUN TestPartSizeForNAR/zero_stays_at_minimum261--- PASS: TestClientSignaturesByStorePath (0.00s)262=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error263--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)264=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text265=== PAUSE TestSetClientTLSErrors/missing_ca_file266=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter267=== PAUSE TestParsePathInfoJSON/invalid_JSON268=== CONT TestFileTokenMissing269=== RUN TestStreamPushStopsOnCancel/waiting_for_input270=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short271=== CONT TestTruncatedNARDumpIsNotCompleted272=== CONT TestCaseHackSuffix273=== CONT TestRegisterUploadedObjectReusesConnections274=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA275=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA276=== RUN TestFilterOversizedClosures/all_closures_skipped277=== PAUSE TestFilterOversizedClosures/all_closures_skipped278=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum279=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun280--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)281=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== RUN TestSetClientTLSErrors/invalid_ca_file283=== CONT TestStreamPushReportsEveryPath284=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure285=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input286=== CONT TestDoWithRetry_FinalResponseBodyReadable287=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails288=== RUN TestSetClientTLS/preserves_debug_logging_transport289=== PAUSE TestSetClientTLS/preserves_debug_logging_transport290=== CONT TestStreamPushBatchesUnderLoad291=== RUN TestStreamPushBatchesUnderLoad/together292=== CONT TestShellSplitErrors293=== RUN TestPartSizeForNAR/small_stays_at_minimum294=== CONT TestUploadMultipart_ProducerErrorIsNotEOF295=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== CONT TestShellSplit297=== PAUSE TestPartSizeForNAR/small_stays_at_minimum298=== PAUSE TestStreamPushBatchesUnderLoad/together299=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum300=== PAUSE TestSetClientTLSErrors/invalid_ca_file301=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time302=== CONT TestEncodeNixBase32/test_string_hash303=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time304=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum305=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout306=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot307=== CONT TestEncodeNixBase32/empty_input308=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot309--- PASS: TestScriptTokenEmptyToken (0.02s)310=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot311=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part312=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot313=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot314=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part315=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs316=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths317--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.04s)318--- PASS: TestStreamPushIsolatesFailures (0.00s)319--- PASS: TestFileTokenEmpty (0.00s)320--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)321--- PASS: TestDumpPathSingleFile (0.04s)322--- PASS: TestStaticToken (0.00s)323=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary324=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary325--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)326--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)327=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts328=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts329=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths330=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails331=== CONT TestConvertHashToNix32/already_Nix32_format332=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot333=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier334=== CONT TestConvertHashToNix32/SRI_format_to_Nix32335=== CONT TestConvertHashToNix32/invalid_format336=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon337=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot338=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)339--- PASS: TestDoServerRequestAttachesToken (0.01s)340=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI341--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)342=== CONT TestGetStorePathHash/valid_store_path343=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter344=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error345=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot346=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken347=== CONT TestGetStorePathHash/basename_without_hyphen_should_error348=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken349--- PASS: TestFileTokenMissing (0.00s)350=== CONT TestUploadMultipart_SupersededByPeer/missing351=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512352=== RUN TestPartSizeForNAR/1_TiB353=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error354=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up355=== CONT TestUploadMultipart_SupersededByPeer/exists356=== CONT TestRateLimiterFeedback/503_enables_limiter357=== CONT TestRateLimiterFeedback/429_enables_limiter358=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter359=== PAUSE TestPartSizeForNAR/1_TiB360--- PASS: TestShellSplitErrors (0.00s)361=== CONT TestParsePathInfoJSON/invalid_JSON362=== CONT TestParsePathInfoJSON/Nix_format363=== CONT TestParsePathInfoJSON/whitespace_only364=== CONT TestParsePathInfoJSON/Lix_format365=== CONT TestParsePathInfoJSON/empty_input366=== RUN TestPartSizeForNAR/5_TiB_S3_max_object367--- PASS: TestStreamPushReportsEveryPath (0.00s)368=== CONT TestFilterOversizedClosures/no_limit_keeps_everything369=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped370=== CONT TestFilterOversizedClosures/all_closures_skipped371=== CONT TestSetClientTLS/preserves_debug_logging_transport372=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive373=== CONT TestPathInfoCACompatibility/old_string_format_-_text374=== CONT TestSetClientTLSErrors/invalid_ca_file375=== CONT TestSetClientTLSErrors/missing_ca_file376=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part379=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary380--- PASS: TestShellSplit (0.00s)381=== CONT TestPathInfoCACompatibility/new_structured_format_-_text382=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA383=== CONT TestPathInfoCACompatibility/null_ca_field384=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails385=== CONT TestSetClientTLSErrors/missing_cert_file386=== CONT TestSetClientTLSErrors/missing_key_file387=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object388--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)389=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time390=== CONT TestSupersededNARStillUploadsListing/small_NAR391=== CONT TestSupersededNARStillUploadsListing/dump_cut_short392=== CONT TestStreamPushBatchesUnderLoad/together393=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot394=== RUN TestPartSizeForNAR/capped_at_5_GiB395--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)396=== PAUSE TestPartSizeForNAR/capped_at_5_GiB397--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)398 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)399 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)400=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken401=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot402=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot403--- PASS: TestEncodeNixBase32 (0.02s)404 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)405 --- PASS: TestEncodeNixBase32/empty_input (0.00s)406--- PASS: TestCaseHackSuffix (0.15s)407--- PASS: TestConvertHashToNix32 (0.03s)408 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)409 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)410 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)411--- PASS: TestPathInfoHashCompatibility (0.03s)412 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)416--- PASS: TestGetStorePathHash (0.04s)417 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)418 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)419 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)420 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)421--- PASS: TestParsePathInfoJSON (0.04s)422 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)423 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)424 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)425 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)426 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)427--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)428 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)429 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)430--- PASS: TestRateLimiterFeedback (0.04s)431 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)432 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)433 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)434 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)435--- PASS: TestFilterOversizedClosures (0.02s)436 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)437 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)438 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)439--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)440 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)441 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.14s)442--- PASS: TestPathInfoCACompatibility (0.04s)443 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)444 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)445 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)446 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)447 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)448--- PASS: TestStreamPushBatchesUnderLoad (0.00s)449 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)450 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)451--- PASS: TestSetClientTLSErrors (0.03s)452 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)453 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)454 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)455 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)456=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot457=== CONT TestStreamPushStopsOnCancel/waiting_for_input458=== CONT TestPartSizeForNAR/zero_stays_at_minimum459=== CONT TestPartSizeForNAR/capped_at_5_GiB460=== CONT TestPartSizeForNAR/5_TiB_S3_max_object461=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts462=== CONT TestPartSizeForNAR/1_TiB463=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum464=== CONT TestPartSizeForNAR/small_stays_at_minimum465--- PASS: TestPartSizeForNAR (0.16s)466 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)467 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)468 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)469 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)470 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)471 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)472 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)473--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.68s)474--- PASS: TestDumpPathWriterError (0.74s)475--- PASS: TestStreamPushStopsOnCancel (0.02s)476 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.52s)477 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.51s)478 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.52s)479 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.51s)480 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)482--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)483 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.69s)484 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.73s)485--- PASS: TestSetClientTLS (0.04s)486 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.30s)487 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.52s)488 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.76s)489--- PASS: TestRegisterUploadedObjectReusesConnections (0.84s)490--- PASS: TestStreamPushRequestLine (0.87s)491--- PASS: TestDumpPathMatchesNix (0.93s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)493--- PASS: TestTruncatedNARDumpIsNotCompleted (1.53s)494--- PASS: TestUploadMultipart_PartsInParallel (1.57s)495--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.63s)496--- PASS: TestSupersededNARStillUploadsListing (0.01s)497 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.54s)498 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.55s)499 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.55s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.67s)504PASS505Running server tests...506The files belonging to this database system will be owned by user "nixbld".507This user must also own the server process.508509The database cluster will be initialized with locale "C".510The default database encoding has accordingly been set to "SQL_ASCII".511The default text search configuration will be set to "english".512513Data page checksums are enabled.514515creating directory /build/postgres2020223493/data ... ok516creating subdirectories ... ok517selecting dynamic shared memory implementation ... posix518selecting default "max_connections" ... 100519selecting default "shared_buffers" ... 128MB520selecting default time zone ... UTC521creating configuration files ... ok522running bootstrap script ... ok523performing post-bootstrap initialization ... ok524syncing data to disk ... ok525526initdb: warning: enabling "trust" authentication for local connections527initdb: 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.528529Success. You can now start the database server using:530531 pg_ctl -D /build/postgres2020223493/data -l logfile start532533/build/postgres2020223493:5432 - no response5342026-10-02 20:37:54.629 UTC [172] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-02 20:37:54.629 UTC [172] LOG: listening on Unix socket "/build/postgres2020223493/.s.PGSQL.5432"5362026-10-02 20:37:54.634 UTC [179] LOG: database system was shut down at 2026-10-02 20:37:54 UTC5372026-10-02 20:37:54.638 UTC [172] LOG: database system is ready to accept connections538/build/postgres2020223493:5432 - accepting connections539{"timestamp":"2026-10-02T20:37:54.943577139Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"511c24f6-5c10-4d08-8e87-59ca3c8be948","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}540=== RUN TestService_AuthMiddleware541=== PAUSE TestService_AuthMiddleware542=== RUN TestService_AuthMiddleware_MTLSProxyHeader543=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader544=== RUN TestService_AuthMiddleware_MTLSBoundSubjects545=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects546=== RUN TestService_ReadAuthMiddleware547=== PAUSE TestService_ReadAuthMiddleware548=== RUN TestService_AuthMiddleware_OIDC549=== PAUSE TestService_AuthMiddleware_OIDC550=== RUN TestService_RequireScope_OIDC551=== PAUSE TestService_RequireScope_OIDC552=== RUN TestService_ReadScope_PublicByDefault553=== PAUSE TestService_ReadScope_PublicByDefault554=== RUN TestCacheConfigHandler555=== PAUSE TestCacheConfigHandler556=== RUN TestCacheStatsHandler557=== PAUSE TestCacheStatsHandler558=== RUN TestClientCADerivations559=== PAUSE TestClientCADerivations560=== RUN TestClientErrorHandling561=== PAUSE TestClientErrorHandling562=== RUN TestClientIntegration563=== PAUSE TestClientIntegration564=== RUN TestClientMultipleUploads565=== PAUSE TestClientMultipleUploads566=== RUN TestClientWithDependencies567=== PAUSE TestClientWithDependencies568=== RUN TestClientSharedPathCommittedMidPush569=== PAUSE TestClientSharedPathCommittedMidPush570=== RUN TestPinProtectsFromGC571=== PAUSE TestPinProtectsFromGC572=== RUN TestClientPushesUseOnePush573=== PAUSE TestClientPushesUseOnePush574=== RUN TestClientFallsBackToClosures575=== PAUSE TestClientFallsBackToClosures576=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock578=== RUN TestResolveDBConnectionString579=== PAUSE TestResolveDBConnectionString580=== RUN TestConnectWaitsForAPeerMigration581=== PAUSE TestConnectWaitsForAPeerMigration582=== RUN TestConnectSerialisesConcurrentMigrations583=== PAUSE TestConnectSerialisesConcurrentMigrations584=== RUN TestLeadElectsOneAndHandsOver585=== PAUSE TestLeadElectsOneAndHandsOver586=== RUN TestLeadIncumbentWinsAfterRestart5872026/10/02 20:37:55 INFO lead: acquired remote=192.0.2.1:12345882026/10/02 20:37:56 INFO lead: released remote=192.0.2.1:12345892026/10/02 20:37:56 INFO lead: acquired remote=192.0.2.1:12345902026/10/02 20:37:57 INFO lead: released remote=192.0.2.1:1234591--- PASS: TestLeadIncumbentWinsAfterRestart (2.34s)592=== RUN TestLeadEndsOnShutdown593=== PAUSE TestLeadEndsOnShutdown594=== RUN TestLeadEndsWhenItsConnectionHangs5952026/10/02 20:37:57 INFO lead: acquired remote=192.0.2.1:12345962026-10-02 20:37:58.961 UTC [624] FATAL: terminating connection due to administrator command5972026/10/02 20:37:59 INFO lead: acquired remote=192.0.2.1:12345982026/10/02 20:38:00 WARN lead: lock connection lost error="timeout: context deadline exceeded"5992026/10/02 20:38:00 INFO lead: released remote=192.0.2.1:12346002026/10/02 20:38:00 INFO lead: released remote=192.0.2.1:1234601--- PASS: TestLeadEndsWhenItsConnectionHangs (2.99s)602=== RUN TestGCAdvisoryLockBlocksConcurrentRun603=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun604=== RUN TestGCBugBareHashReferences605=== PAUSE TestGCBugBareHashReferences606=== RUN TestGCMetrics607=== PAUSE TestGCMetrics608=== RUN TestPushDedupSurvivesConcurrentGC609=== PAUSE TestPushDedupSurvivesConcurrentGC610=== RUN TestDeduplicatedObjectsRecordedAsPending611=== PAUSE TestDeduplicatedObjectsRecordedAsPending612=== RUN TestGCSweepSkipsPendingObjects613=== PAUSE TestGCSweepSkipsPendingObjects614=== RUN TestTombstonedObjectOfferedWithoutWaiting615=== PAUSE TestTombstonedObjectOfferedWithoutWaiting616=== RUN TestGCSweepDeliversEachKeyOnce617=== PAUSE TestGCSweepDeliversEachKeyOnce618=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== RUN TestForceGCDuringPushOffersSweptObject621=== PAUSE TestForceGCDuringPushOffersSweptObject622=== RUN TestFailedS3DeleteKeepsTombstone623=== PAUSE TestFailedS3DeleteKeepsTombstone624=== RUN TestSweepSkipsRowsLockedByPush625=== PAUSE TestSweepSkipsRowsLockedByPush626=== RUN TestRegisterCompletedObjectNeedsPendingRow627=== PAUSE TestRegisterCompletedObjectNeedsPendingRow628=== RUN TestGetExistingObjectsLocksRows629=== PAUSE TestGetExistingObjectsLocksRows630=== RUN TestSweepRechecksPendingAfterLocking631=== PAUSE TestSweepRechecksPendingAfterLocking632=== RUN TestPushWaitsForSweepHoldingRow633=== PAUSE TestPushWaitsForSweepHoldingRow634=== RUN TestCommitRacingPendingCleanupKeepsObjects635=== PAUSE TestCommitRacingPendingCleanupKeepsObjects636=== RUN TestGCEndsOnShutdown637=== PAUSE TestGCEndsOnShutdown638=== RUN TestGCTaskStore_StartNew639=== PAUSE TestGCTaskStore_StartNew640=== RUN TestGCTaskStore_DeduplicateSameParams641=== PAUSE TestGCTaskStore_DeduplicateSameParams642=== RUN TestGCTaskStore_ConflictDifferentParams643=== PAUSE TestGCTaskStore_ConflictDifferentParams644=== RUN TestGCTaskStore_GetEmpty645=== PAUSE TestGCTaskStore_GetEmpty646=== RUN TestGCTaskStore_GetReturnsLatest647=== PAUSE TestGCTaskStore_GetReturnsLatest648=== RUN TestGCTaskStore_CompletedAllowsNewTask649=== PAUSE TestGCTaskStore_CompletedAllowsNewTask650=== RUN TestGCTaskStore_PhaseUpdates651=== PAUSE TestGCTaskStore_PhaseUpdates652=== RUN TestGCTaskStore_Fail653=== PAUSE TestGCTaskStore_Fail654=== RUN TestGracefulShutdownDrainsInflight655=== PAUSE TestGracefulShutdownDrainsInflight656=== RUN TestService_healthCheckHandler657=== PAUSE TestService_healthCheckHandler658=== RUN TestService_readinessHandler659=== PAUSE TestService_readinessHandler660=== RUN TestGenerateLandingPage661=== PAUSE TestGenerateLandingPage662=== RUN TestCacheConfigHandlerMaxNarSize663=== PAUSE TestCacheConfigHandlerMaxNarSize664=== RUN TestCreatePendingClosureRejectsOversizedNAR665=== PAUSE TestCreatePendingClosureRejectsOversizedNAR666=== RUN TestNARDeduplicationMetadataUploadBug667=== PAUSE TestNARDeduplicationMetadataUploadBug668=== RUN TestMetricsInventory669=== PAUSE TestMetricsInventory670=== RUN TestService_NativeMTLS671=== PAUSE TestService_NativeMTLS672=== RUN TestServerTLSConfig673=== PAUSE TestServerTLSConfig674=== RUN TestMultipartCleanup675=== PAUSE TestMultipartCleanup676=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded677=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded678=== RUN TestPendingCleanupUsesOneCutoff679=== PAUSE TestPendingCleanupUsesOneCutoff680=== RUN TestPendingClosureFailureTracksEveryUpload681=== PAUSE TestPendingClosureFailureTracksEveryUpload682=== RUN TestPendingClosureFailureAbortsItsUploads683=== PAUSE TestPendingClosureFailureAbortsItsUploads684=== RUN TestObjectStatsTrigger685=== PAUSE TestObjectStatsTrigger686=== RUN TestReconnectLeavesObjectsUnlocked687=== PAUSE TestReconnectLeavesObjectsUnlocked688=== RUN TestOrphanedObjectsGC689=== PAUSE TestOrphanedObjectsGC690=== RUN TestOrphanedObjectsGCStressTest691=== PAUSE TestOrphanedObjectsGCStressTest692=== RUN TestCreatePin_ReservedPins693=== PAUSE TestCreatePin_ReservedPins694=== RUN TestConcurrentPinUpdatesAgree695=== PAUSE TestConcurrentPinUpdatesAgree696=== RUN TestCreatePinRejectsBadInput697=== PAUSE TestCreatePinRejectsBadInput698=== RUN TestDeletePinKeepsRowWhenS3Fails699=== PAUSE TestDeletePinKeepsRowWhenS3Fails700=== RUN TestPresentReportsOnlyClosureRoots701=== PAUSE TestPresentReportsOnlyClosureRoots702=== RUN TestPresentNotReportedWhileGCDeletesClosure703=== PAUSE TestPresentNotReportedWhileGCDeletesClosure704=== RUN TestParseSingleRange705=== PAUSE TestParseSingleRange706=== RUN TestProxyHeadersOnlyTrustedOnSocket707=== PAUSE TestProxyHeadersOnlyTrustedOnSocket708=== RUN TestIsValidCachePath709=== PAUSE TestIsValidCachePath710=== RUN TestReadProxyNarinfo711=== PAUSE TestReadProxyNarinfo712=== RUN TestReadProxyNarinfoAlreadyDecompressed713=== PAUSE TestReadProxyNarinfoAlreadyDecompressed714=== RUN TestReadProxyNarStreaming715=== PAUSE TestReadProxyNarStreaming716=== RUN TestReadProxy404717=== PAUSE TestReadProxy404718=== RUN TestReadProxyInvalidPath719=== PAUSE TestReadProxyInvalidPath720=== RUN TestReadProxyHead721=== PAUSE TestReadProxyHead722=== RUN TestReadProxyOutlastsServerWriteTimeout723=== PAUSE TestReadProxyOutlastsServerWriteTimeout724=== RUN TestReadProxyConditionalGet725=== PAUSE TestReadProxyConditionalGet726=== RUN TestReadProxyRootRedirectsToIndexHTML727=== PAUSE TestReadProxyRootRedirectsToIndexHTML728=== RUN TestReadProxyDisabled729=== PAUSE TestReadProxyDisabled730=== RUN TestReadRedirectNar731=== PAUSE TestReadRedirectNar732=== RUN TestReadRedirectKeepsNarinfoProxied733=== PAUSE TestReadRedirectKeepsNarinfoProxied734=== RUN TestReadProxyRangeRequest735=== PAUSE TestReadProxyRangeRequest736=== RUN TestReadRedirectUsesPublicS3URL737=== PAUSE TestReadRedirectUsesPublicS3URL738=== RUN TestPush_OverlappingRootsStoreOneRowPerKey739=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey740=== RUN TestPush_CompleteCommitsEveryRoot741=== PAUSE TestPush_CompleteCommitsEveryRoot742=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit743=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit744=== RUN TestPush_RejectsBadRequests745=== PAUSE TestPush_RejectsBadRequests746=== RUN TestPush_SignsNarinfosOfItsPendingObjects747=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects748=== RUN TestRedundantMultipartUpload749=== PAUSE TestRedundantMultipartUpload750=== RUN TestCompleteMultipartUpload_ErrorButObjectExists751=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists752=== RUN TestCompletedNarNotReofferedAcrossClosures753=== PAUSE TestCompletedNarNotReofferedAcrossClosures754=== RUN TestPresignedUploadRegisteredBeforeCommit755=== PAUSE TestPresignedUploadRegisteredBeforeCommit756=== RUN TestService_Rustfstest757=== PAUSE TestService_Rustfstest758=== RUN TestParseSize759=== PAUSE TestParseSize760=== RUN TestSkippedUploadsHandler761=== PAUSE TestSkippedUploadsHandler762=== RUN TestSystemdListenerNotActivated763--- PASS: TestSystemdListenerNotActivated (0.00s)764=== RUN TestWatchdogBeatsWhenHealthy765--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)766=== RUN TestWatchdogSkipsWhenUnhealthy7672026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"777--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)778=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== RUN TestProxyWriteTimeout781=== PAUSE TestProxyWriteTimeout782=== RUN TestPendingClosureWriteTimeout783=== PAUSE TestPendingClosureWriteTimeout784=== RUN TestIsValidUploadKey785=== PAUSE TestIsValidUploadKey786=== RUN TestUploadHandlersRejectInvalidKeys787=== PAUSE TestUploadHandlersRejectInvalidKeys788=== RUN TestUploadHandlersRejectOversizedBody789=== PAUSE TestUploadHandlersRejectOversizedBody790=== RUN TestService_cleanupPendingClosuresHandler791=== PAUSE TestService_cleanupPendingClosuresHandler792=== RUN TestService_createPendingClosureHandler793=== PAUSE TestService_createPendingClosureHandler794=== RUN TestService_verifyS3Integrity795=== PAUSE TestService_verifyS3Integrity796=== RUN TestCompleteMultipartUnregistered797=== PAUSE TestCompleteMultipartUnregistered798=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT799=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestService_AuthMiddleware_MTLSProxyHeader801=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle802=== CONT TestDeletePinKeepsRowWhenS3Fails803=== CONT TestReadProxyRangeRequest804=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT805=== CONT TestService_verifyS3Integrity806=== CONT TestService_createPendingClosureHandler807=== CONT TestService_cleanupPendingClosuresHandler808=== CONT TestUploadHandlersRejectOversizedBody809=== CONT TestCompleteMultipartUnregistered810=== CONT TestUploadHandlersRejectInvalidKeys811=== CONT TestPendingClosureWriteTimeout812=== CONT TestProxyWriteTimeout813=== CONT TestSkippedUploadsHandler814=== CONT TestIsValidUploadKey815=== CONT TestService_Rustfstest816=== CONT TestParseSize817=== CONT TestPresignedUploadRegisteredBeforeCommit818--- PASS: TestParseSize (0.00s)819=== CONT TestPush_CompleteCommitsEveryRoot820=== CONT TestCompletedNarNotReofferedAcrossClosures821=== CONT TestRedundantMultipartUpload822=== CONT TestPush_SignsNarinfosOfItsPendingObjects823=== CONT TestPush_RejectsBadRequests824=== CONT TestCompleteMultipartUpload_ErrorButObjectExists825=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit826=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info827=== RUN TestPendingClosureWriteTimeout/empty828=== RUN TestProxyWriteTimeout/narinfo8292026/10/02 20:38:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000830=== RUN TestIsValidUploadKey/narinfo831=== PAUSE TestPendingClosureWriteTimeout/empty832=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info833=== PAUSE TestIsValidUploadKey/narinfo834=== RUN TestPendingClosureWriteTimeout/400_objects835=== PAUSE TestProxyWriteTimeout/narinfo836=== RUN TestProxyWriteTimeout/1_GiB_nar837=== PAUSE TestPendingClosureWriteTimeout/400_objects838=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal839=== RUN TestIsValidUploadKey/nar_zst840=== PAUSE TestProxyWriteTimeout/1_GiB_nar841=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal842=== RUN TestPendingClosureWriteTimeout/670k_objects843=== PAUSE TestIsValidUploadKey/nar_zst844=== RUN TestProxyWriteTimeout/10_GiB_nar845=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key846=== PAUSE TestPendingClosureWriteTimeout/670k_objects847=== RUN TestIsValidUploadKey/nar_xz848=== PAUSE TestIsValidUploadKey/nar_xz849=== PAUSE TestProxyWriteTimeout/10_GiB_nar850=== RUN TestIsValidUploadKey/nar_plain851=== RUN TestProxyWriteTimeout/unknown_size852=== PAUSE TestIsValidUploadKey/nar_plain853=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline854=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key855=== PAUSE TestProxyWriteTimeout/unknown_size856=== RUN TestIsValidUploadKey/listing857=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key858=== PAUSE TestIsValidUploadKey/listing859=== CONT TestReadProxyInvalidPath860=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline861=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key862=== RUN TestIsValidUploadKey/build_log863=== CONT TestReadRedirectUsesPublicS3URL864=== PAUSE TestIsValidUploadKey/build_log865=== CONT TestReadProxyDisabled866=== RUN TestIsValidUploadKey/build_log_home-manager_file867=== PAUSE TestIsValidUploadKey/build_log_home-manager_file868=== RUN TestIsValidUploadKey/build_log_plus_in_name869=== PAUSE TestIsValidUploadKey/build_log_plus_in_name870=== RUN TestIsValidUploadKey/build_log_question_mark871=== PAUSE TestIsValidUploadKey/build_log_question_mark872=== RUN TestIsValidUploadKey/build_log_equals873=== PAUSE TestIsValidUploadKey/build_log_equals874=== RUN TestIsValidUploadKey/realisation875=== PAUSE TestIsValidUploadKey/realisation876=== RUN TestIsValidUploadKey/realisation_plus_in_output877=== PAUSE TestIsValidUploadKey/realisation_plus_in_output878=== RUN TestIsValidUploadKey/nix-cache-info879=== PAUSE TestIsValidUploadKey/nix-cache-info880=== RUN TestIsValidUploadKey/index.html881=== PAUSE TestIsValidUploadKey/index.html882=== RUN TestIsValidUploadKey/narinfo_key,_nar_type883=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type884=== RUN TestIsValidUploadKey/nar_key,_narinfo_type885=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type886=== RUN TestIsValidUploadKey/listing_key,_narinfo_type887=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type888=== RUN TestIsValidUploadKey/traversal889=== PAUSE TestIsValidUploadKey/traversal890=== RUN TestIsValidUploadKey/traversal_nar891=== PAUSE TestIsValidUploadKey/traversal_nar892=== RUN TestIsValidUploadKey/absolute893=== PAUSE TestIsValidUploadKey/absolute894=== RUN TestIsValidUploadKey/empty_key895=== PAUSE TestIsValidUploadKey/empty_key896=== RUN TestIsValidUploadKey/unknown_type897=== PAUSE TestIsValidUploadKey/unknown_type898=== CONT TestReadRedirectKeepsNarinfoProxied899--- PASS: TestSkippedUploadsHandler (0.03s)900=== CONT TestReadProxyRootRedirectsToIndexHTML9012026/10/02 20:38:00 INFO Received uploads request method=POST path=/api/pending_closures9022026/10/02 20:38:00 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/02 20:38:00 INFO Received uploads request method=POST path=/api/pending_closures9042026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/app9052026/10/02 20:38:01 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9062026/10/02 20:38:01 INFO Received delete pin request method=DELETE path=/api/pins/app9072026/10/02 20:38:01 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket5/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9082026/10/02 20:38:01 INFO Received delete pin request method=DELETE path=/api/pins/app9092026/10/02 20:38:01 INFO Deleted pin name=app910--- PASS: TestReadProxyRangeRequest (0.45s)911=== CONT TestReadProxyOutlastsServerWriteTimeout9122026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures913=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure914=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure915=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart916=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart917=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts918=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts919=== CONT TestReadProxy404920--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.67s)921=== CONT TestReadProxyHead922=== CONT TestPush_OverlappingRootsStoreOneRowPerKey923--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.69s)9242026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/02 20:38:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9262026/10/02 20:38:01 INFO Aborted multipart uploads count=0 kept=09272026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/02 20:38:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9292026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/02 20:38:01 INFO Aborted multipart uploads count=1 kept=09312026/10/02 20:38:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9322026-10-02 20:38:01.394 UTC [694] ERROR: Closure does not exist: id=19332026-10-02 20:38:01.394 UTC [694] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9342026-10-02 20:38:01.394 UTC [694] STATEMENT: -- name: CommitPendingClosure :exec935 SELECT commit_pending_closure($1::bigint)936 9372026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestService_cleanupPendingClosuresHandler (0.79s)939=== CONT TestRegisterCompletedObjectNeedsPendingRow9402026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete941--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.82s)942=== CONT TestReadRedirectNar9432026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes9442026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9462026/10/02 20:38:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmQ5ZjJmNjUxLWJmOTgtNDQ4OC05YTRjLWQxMWI1NWU1Nzg1NXgxNzkwOTczNDgxNDMxNjA5OTk09472026/10/02 20:38:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9482026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures949--- PASS: TestService_Rustfstest (0.90s)950=== CONT TestReadProxyConditionalGet9512026/10/02 20:38:01 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmQ5ZjJmNjUxLWJmOTgtNDQ4OC05YTRjLWQxMWI1NWU1Nzg1NXgxNzkwOTczNDgxNDMxNjA5OTk0 error="Delete \"http://localhost:38517/bucket11/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmQ5ZjJmNjUxLWJmOTgtNDQ4OC05YTRjLWQxMWI1NWU1Nzg1NXgxNzkwOTczNDgxNDMxNjA5OTk0\": injected: abort refused"952--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.90s)953=== CONT TestPresentNotReportedWhileGCDeletesClosure9542026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9552026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/02 20:38:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmQ5ZjJmNjUxLWJmOTgtNDQ4OC05YTRjLWQxMWI1NWU1Nzg1NXgxNzkwOTczNDgxNDMxNjA5OTk09572026/10/02 20:38:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmQ5ZjJmNjUxLWJmOTgtNDQ4OC05YTRjLWQxMWI1NWU1Nzg1NXgxNzkwOTczNDgxNDMxNjA5OTk0 parts=1958--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.95s)959=== CONT TestClientCADerivations9602026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes9612026/10/02 20:38:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9622026/10/02 20:38:01 INFO Signed narinfos id=1 count=1963--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.02s)964=== CONT TestSweepSkipsRowsLockedByPush965--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.00s)966=== CONT TestOrphanedObjectsGCStressTest9672026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures969=== RUN TestPush_RejectsBadRequests/no_objects970=== PAUSE TestPush_RejectsBadRequests/no_objects971=== RUN TestPush_RejectsBadRequests/bad_root972=== PAUSE TestPush_RejectsBadRequests/bad_root973=== RUN TestPush_RejectsBadRequests/root_not_in_objects974=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects975=== RUN TestPush_RejectsBadRequests/no_roots976=== PAUSE TestPush_RejectsBadRequests/no_roots977=== CONT TestClientPushesUseOnePush978--- PASS: TestReadRedirectUsesPublicS3URL (1.08s)979=== CONT TestFailedS3DeleteKeepsTombstone980--- PASS: TestReadProxyInvalidPath (1.14s)981=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock982--- PASS: TestReadProxyDisabled (1.17s)983=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9842026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9852026/10/02 20:38:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst986--- PASS: TestCompleteMultipartUnregistered (1.22s)987=== CONT TestPinProtectsFromGC9882026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes9892026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9902026/10/02 20:38:01 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmY0NDA0NDlmLWVhMTEtNDkwNy04YTljLWY1N2VkOWE4OGU2YngxNzkwOTczNDgxMDA5MDE4MzU3 parts=109912026/10/02 20:38:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9922026/10/02 20:38:01 INFO Completed upload id=19932026/10/02 20:38:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009942026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/02 20:38:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures9962026/10/02 20:38:01 INFO Aborted multipart uploads count=0 kept=0997=== CONT TestGCSweepDeliversEachKeyOnce998--- PASS: TestReadRedirectKeepsNarinfoProxied (1.26s)9992026/10/02 20:38:01 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=010002026/10/02 20:38:01 INFO Vacuumed table table=pending_closures10012026/10/02 20:38:01 INFO Vacuumed table table=pending_objects10022026/10/02 20:38:01 INFO Vacuumed table table=multipart_uploads10032026/10/02 20:38:01 INFO Vacuumed table table=closures10042026/10/02 20:38:01 INFO Vacuumed table table=objects10052026/10/02 20:38:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001006=== CONT TestClientSharedPathCommittedMidPush1007--- PASS: TestService_createPendingClosureHandler (1.35s)10082026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes10092026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1010--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.63s)1011=== CONT TestTombstonedObjectOfferedWithoutWaiting10122026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmMxNGYzMzM0LTM1ODctNGIzNy04MmMwLWQxZjc0YjUzNmExMHgxNzkwOTczNDgxMzM2MjYzODEz parts=1010132026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10142026/10/02 20:38:02 INFO Completed upload id=11015--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.75s)1016=== CONT TestResolveDBConnectionString1017=== RUN TestResolveDBConnectionString/flag_wins1018=== PAUSE TestResolveDBConnectionString/flag_wins1019=== RUN TestResolveDBConnectionString/file_when_flag_empty1020=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1021=== RUN TestResolveDBConnectionString/missing_file_is_an_error1022=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1023=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1024=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1025=== RUN TestResolveDBConnectionString/nothing_configured1026=== PAUSE TestResolveDBConnectionString/nothing_configured1027=== CONT TestPendingClosureFailureAbortsItsUploads10282026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/02 20:38:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10312026/10/02 20:38:02 WARN Found objects in DB but missing from S3, will re-upload count=110322026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10332026/10/02 20:38:02 INFO Completed upload id=31034--- PASS: TestReadRedirectNar (0.67s)1035=== CONT TestReadProxyNarinfo1036--- PASS: TestService_verifyS3Integrity (1.51s)1037=== CONT TestGracefulShutdownDrainsInflight1038--- PASS: TestReadProxyHead (0.85s)1039=== CONT TestGetExistingObjectsLocksRows10402026/10/02 20:38:02 INFO Starting HTTP server address=127.0.0.1:3821910412026/10/02 20:38:02 INFO Shutdown signal received, draining in-flight requests timeout=10s10422026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10432026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjA0MzQ1MjMzLTI1NTAtNDkxZS04MGQyLWJlNDQwM2Q2NGE4OHgxNzkwOTczNDgxNDg4ODA2NDc2 parts=101044--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1045=== CONT TestService_AuthMiddleware10462026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=010472026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period10482026/10/02 20:38:02 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=010492026/10/02 20:38:02 INFO Vacuumed table table=pending_closures10502026/10/02 20:38:02 INFO Vacuumed table table=pending_objects10512026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads10522026/10/02 20:38:02 INFO Vacuumed table table=closures10532026/10/02 20:38:02 INFO Vacuumed table table=objects10542026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=01055=== NAME TestClientCADerivations1056 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2579105167/001/store/c0izvmmy1370vvrclw3q1xa5kqy1plzw-ca-test10572026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period10582026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/02 20:38:02 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=010602026/10/02 20:38:02 INFO Vacuumed table table=pending_closures10612026/10/02 20:38:02 INFO Vacuumed table table=pending_objects10622026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads10632026/10/02 20:38:02 INFO Vacuumed table table=closures10642026/10/02 20:38:02 INFO Vacuumed table table=objects1065 client_ca_test.go:139: Found 1 dependencies (including self)1066--- PASS: TestSweepSkipsRowsLockedByPush (0.66s)1067=== CONT TestConcurrentPinUpdatesAgree10682026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10692026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1070=== CONT TestReconnectLeavesObjectsUnlocked1071--- PASS: TestReadProxyConditionalGet (0.82s)10722026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmUzN2U2ZDU0LTBiNTAtNDZiNC04OGI1LTA4MWExN2JjYjJhZHgxNzkwOTczNDgxNTYzMjA4MjYz parts=1210732026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures10742026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=010752026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period10762026/10/02 20:38:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10772026/10/02 20:38:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1078--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.77s)1079=== CONT TestCacheConfigHandlerMaxNarSize1080=== CONT TestClientFallsBackToClosures1081--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1082=== CONT TestForceGCDuringPushOffersSweptObject1083--- PASS: TestFailedS3DeleteKeepsTombstone (0.69s)1084=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1085=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1086=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1087=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1088=== CONT TestService_healthCheckHandler10892026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes10902026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10912026/10/02 20:38:02 INFO Uploading c0izvmmy1370vvrclw3q1xa5kqy1plzw-ca-test (144B)1092=== NAME TestPinProtectsFromGC1093 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1249170871/001/store/0xm15744wzqrj6hnv0p7hlzsqd9r8wn1-pinned-file.txt1094 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1249170871/001/store/p6b27js6fv2gfvwmjl9hsj6a4ni8bnjh-unpinned-file.txt10952026/10/02 20:38:02 WARN Rate limiter enabled after throttle name=s3-test rate=510962026/10/02 20:38:02 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."10972026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10982026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=010992026/10/02 20:38:02 WARN Failed to register uploaded object key=log/01gk4y86yl2s8wj6356mxmw59iwf3i7v-ca-test.drv error="server returned 404: 404 page not found\n"11002026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period11012026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes11022026/10/02 20:38:02 WARN Failed to register uploaded object key=c0izvmmy1370vvrclw3q1xa5kqy1plzw.ls error="server returned 404: 404 page not found\n"11032026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11042026/10/02 20:38:02 INFO Signed narinfos id=1 count=111052026/10/02 20:38:02 INFO Uploading 1 narinfos11062026/10/02 20:38:02 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=011072026/10/02 20:38:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11082026/10/02 20:38:02 INFO Uploading z2bbriqd69qr2g2kjj95sa7607k92gr5-a (208B)11092026/10/02 20:38:02 INFO Uploading nbkkjsqaxiqnlh5d2w978jahjnl2pz4y-shared-dep (136B)11102026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11122026/10/02 20:38:02 INFO Vacuumed table table=pending_closures11132026/10/02 20:38:02 INFO Vacuumed table table=pending_objects11142026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads11152026/10/02 20:38:02 INFO Vacuumed table table=closures11162026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete11172026/10/02 20:38:02 WARN Failed to register uploaded object key=c0izvmmy1370vvrclw3q1xa5kqy1plzw.narinfo error="server returned 404: 404 page not found\n"11182026/10/02 20:38:02 WARN Failed to register uploaded object key=sxprd0zsni3ik86d5w1zvk05dsz78706.ls error="server returned 404: 404 page not found\n"11192026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11202026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/07s8r6yg9q3hxjdq1v2ivlbsvvavfpbxpsdr0ybn9fiywyr69b0i.nar.zst error="server returned 404: 404 page not found\n"11212026/10/02 20:38:02 INFO Upload complete. (169ms)11222026/10/02 20:38:02 WARN Failed to register uploaded object key=z2bbriqd69qr2g2kjj95sa7607k92gr5.ls error="server returned 404: 404 page not found\n"11232026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11242026/10/02 20:38:02 WARN Failed to register uploaded object key=nbkkjsqaxiqnlh5d2w978jahjnl2pz4y.ls error="server returned 404: 404 page not found\n"11252026/10/02 20:38:02 INFO Vacuumed table table=objects11262026/10/02 20:38:02 INFO Signed narinfos id=1 count=311272026/10/02 20:38:02 INFO Uploading 3 narinfos11282026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1129=== NAME TestClientCADerivations1130 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2579105167/001/store/c0izvmmy1370vvrclw3q1xa5kqy1plzw-ca-test1131 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1132 Compression: zstd1133 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1134 NarSize: 1441135 References: 11362026/10/02 20:38:02 WARN Failed to register uploaded object key=nbkkjsqaxiqnlh5d2w978jahjnl2pz4y.narinfo error="server returned 404: 404 page not found\n"1137 Deriver: /build/TestClientCADerivations2579105167/001/store/01gk4y86yl2s8wj6356mxmw59iwf3i7v-ca-test.drv1138 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1139 client_ca_test.go:185: Checking for realisation files in S3...11402026/10/02 20:38:02 WARN Failed to register uploaded object key=z2bbriqd69qr2g2kjj95sa7607k92gr5.narinfo error="server returned 404: 404 page not found\n"11412026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjA4NDg3NDQ0LTYxNGYtNDk1Zi1hODc5LWNmMjAyNTM3MDU4NHgxNzkwOTczNDgxNjgwMzIwODU1 parts=121142 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1143 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache11442026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete11462026/10/02 20:38:02 WARN Failed to register uploaded object key=sxprd0zsni3ik86d5w1zvk05dsz78706.narinfo error="server returned 404: 404 page not found\n"11472026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes1148--- PASS: TestGCSweepDeliversEachKeyOnce (0.62s)1149=== CONT TestCreatePin_ReservedPins1150=== CONT TestProxyHeadersOnlyTrustedOnSocket1151--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)11522026/10/02 20:38:02 INFO Upload complete. (100ms)11532026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11542026/10/02 20:38:02 INFO Uploading 0xm15744wzqrj6hnv0p7hlzsqd9r8wn1-pinned-file.txt (128B)11552026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1156=== NAME TestClientPushesUseOnePush1157 client_pushes_test.go:97: Retrieved narinfo from S3:1158 StorePath: /build/TestClientPushesUseOnePush911472428/001/store/nbkkjsqaxiqnlh5d2w978jahjnl2pz4y-shared-dep1159 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1160 Compression: zstd1161 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821162 NarSize: 1361163 References: 1164 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1165 client_pushes_test.go:97: Retrieved narinfo from S3:1166 StorePath: /build/TestClientPushesUseOnePush911472428/001/store/z2bbriqd69qr2g2kjj95sa7607k92gr5-a1167 URL: nar/07s8r6yg9q3hxjdq1v2ivlbsvvavfpbxpsdr0ybn9fiywyr69b0i.nar.zst1168 Compression: zstd1169 NarHash: sha256:07s8r6yg9q3hxjdq1v2ivlbsvvavfpbxpsdr0ybn9fiywyr69b0i1170 NarSize: 2081171 References: /build/TestClientPushesUseOnePush911472428/001/store/nbkkjsqaxiqnlh5d2w978jahjnl2pz4y-shared-dep1172 CA: text:sha256:1il74fhs9vr47p9rcnjv74mymhcprvcqy02hdqdzlhycvhmf8m2s11732026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1174 client_pushes_test.go:97: Retrieved narinfo from S3:1175 StorePath: /build/TestClientPushesUseOnePush911472428/001/store/sxprd0zsni3ik86d5w1zvk05dsz78706-b1176 URL: nar/07s8r6yg9q3hxjdq1v2ivlbsvvavfpbxpsdr0ybn9fiywyr69b0i.nar.zst1177 Compression: zstd1178 NarHash: sha256:07s8r6yg9q3hxjdq1v2ivlbsvvavfpbxpsdr0ybn9fiywyr69b0i1179 NarSize: 2081180 References: /build/TestClientPushesUseOnePush911472428/001/store/nbkkjsqaxiqnlh5d2w978jahjnl2pz4y-shared-dep1181 CA: text:sha256:1il74fhs9vr47p9rcnjv74mymhcprvcqy02hdqdzlhycvhmf8m2s11822026/10/02 20:38:02 WARN Rate limiter backed off name=s3-test rate=511832026/10/02 20:38:02 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."11842026/10/02 20:38:02 WARN Failed to register uploaded object key=0xm15744wzqrj6hnv0p7hlzsqd9r8wn1.ls error="server returned 404: 404 page not found\n"11852026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11862026/10/02 20:38:02 INFO Signed narinfos id=1 count=111872026/10/02 20:38:02 INFO Uploading 1 narinfos11882026/10/02 20:38:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34265/oidc1189--- PASS: TestPendingClosureFailureAbortsItsUploads (0.52s)1190=== CONT TestIsValidCachePath1191=== RUN TestIsValidCachePath/narinfo1192=== PAUSE TestIsValidCachePath/narinfo1193=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1194=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1195=== RUN TestIsValidCachePath/nar_zst1196=== PAUSE TestIsValidCachePath/nar_zst1197=== RUN TestIsValidCachePath/nar_xz1198=== PAUSE TestIsValidCachePath/nar_xz1199=== RUN TestIsValidCachePath/nar_bz21200=== PAUSE TestIsValidCachePath/nar_bz21201=== RUN TestIsValidCachePath/nar_uncompressed1202=== PAUSE TestIsValidCachePath/nar_uncompressed1203=== RUN TestIsValidCachePath/ls1204=== PAUSE TestIsValidCachePath/ls1205=== RUN TestIsValidCachePath/log1206=== PAUSE TestIsValidCachePath/log1207=== RUN TestIsValidCachePath/realisation1208=== PAUSE TestIsValidCachePath/realisation1209=== RUN TestIsValidCachePath/nix-cache-info12102026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1211=== PAUSE TestIsValidCachePath/nix-cache-info1212=== RUN TestIsValidCachePath/index.html1213=== PAUSE TestIsValidCachePath/index.html12142026/10/02 20:38:02 WARN Failed to register uploaded object key=0xm15744wzqrj6hnv0p7hlzsqd9r8wn1.narinfo error="server returned 404: 404 page not found\n"1215=== RUN TestIsValidCachePath/traversal_parent1216=== PAUSE TestIsValidCachePath/traversal_parent1217=== RUN TestIsValidCachePath/traversal_in_middle1218=== PAUSE TestIsValidCachePath/traversal_in_middle1219=== RUN TestIsValidCachePath/invalid_char_e1220=== PAUSE TestIsValidCachePath/invalid_char_e1221=== RUN TestIsValidCachePath/invalid_char_u1222=== PAUSE TestIsValidCachePath/invalid_char_u1223=== RUN TestIsValidCachePath/random_path1224=== PAUSE TestIsValidCachePath/random_path1225=== RUN TestIsValidCachePath/empty1226=== PAUSE TestIsValidCachePath/empty1227=== RUN TestIsValidCachePath/leading_slash1228=== PAUSE TestIsValidCachePath/leading_slash1229=== RUN TestIsValidCachePath/wrong_extension1230=== PAUSE TestIsValidCachePath/wrong_extension1231=== CONT TestOrphanedObjectsGC1232=== RUN TestIsValidCachePath/short_hash1233=== PAUSE TestIsValidCachePath/short_hash1234--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.77s)1235=== CONT TestClientMultipleUploads12362026/10/02 20:38:02 INFO Upload complete. (105ms)1237--- PASS: TestReadProxy404 (1.32s)1238=== CONT TestParseSingleRange1239=== RUN TestParseSingleRange/none1240=== PAUSE TestParseSingleRange/none1241=== RUN TestParseSingleRange/unknown_unit12422026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1243=== PAUSE TestParseSingleRange/unknown_unit1244=== RUN TestParseSingleRange/multi-range_ignored1245=== PAUSE TestParseSingleRange/multi-range_ignored1246=== RUN TestParseSingleRange/malformed_no_dash1247=== PAUSE TestParseSingleRange/malformed_no_dash1248=== RUN TestParseSingleRange/malformed_both_empty1249=== PAUSE TestParseSingleRange/malformed_both_empty1250=== RUN TestParseSingleRange/malformed_end_before_start1251=== PAUSE TestParseSingleRange/malformed_end_before_start1252=== RUN TestParseSingleRange/closed1253=== PAUSE TestParseSingleRange/closed1254=== RUN TestParseSingleRange/open-ended1255=== PAUSE TestParseSingleRange/open-ended1256=== RUN TestParseSingleRange/end_clamped_to_size1257=== PAUSE TestParseSingleRange/end_clamped_to_size1258=== RUN TestParseSingleRange/suffix1259=== PAUSE TestParseSingleRange/suffix1260=== RUN TestParseSingleRange/suffix_exceeds_size1261=== PAUSE TestParseSingleRange/suffix_exceeds_size1262=== RUN TestParseSingleRange/single_byte1263=== PAUSE TestParseSingleRange/single_byte1264=== RUN TestParseSingleRange/start_past_EOF1265=== PAUSE TestParseSingleRange/start_past_EOF1266=== RUN TestParseSingleRange/start_far_past_EOF1267=== PAUSE TestParseSingleRange/start_far_past_EOF1268=== CONT TestClientWithDependencies1269--- PASS: TestClientPushesUseOnePush (0.91s)1270=== CONT TestDeduplicatedObjectsRecordedAsPending12712026/10/02 20:38:02 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1272--- PASS: TestGetExistingObjectsLocksRows (0.48s)1273=== CONT TestPendingClosureFailureTracksEveryUpload1274--- PASS: TestService_AuthMiddleware (0.41s)1275=== CONT TestClientIntegration12762026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes12772026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/app12782026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjcxN2Q4NjU4LWJkNTEtNGQ4Ny05ZWVmLTUwZjdkNDlmM2M0OHgxNzkwOTczNDgxODc0NjczMjEz parts=1012792026/10/02 20:38:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12802026/10/02 20:38:02 INFO Uploading iw0wx20plgnhk5y4y1f23jzjnjb8p3ng-shared-dep (136B)12812026/10/02 20:38:02 INFO Uploading 83z0c4k0wq04hiwr4mhz1az2pbv33cjn-top (224B)1282=== NAME TestClientCADerivations1283 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1284 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1285 error: binary cache 's3://bucket34?endpoint=http://localhost:38517®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2579105167/001/store'1286 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 112872026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/app12882026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1289=== CONT TestCreatePinRejectsBadInput1290--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.14s)12912026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1n9gfxvi4vva7lqshnhzxddl1q37kmijrahd8aiiv44ads6s5z8r.nar.zst error="server returned 404: 404 page not found\n"12922026/10/02 20:38:02 WARN Failed to register uploaded object key=iw0wx20plgnhk5y4y1f23jzjnjb8p3ng.ls error="server returned 404: 404 page not found\n"12932026/10/02 20:38:02 WARN Failed to register uploaded object key=83z0c4k0wq04hiwr4mhz1az2pbv33cjn.ls error="server returned 404: 404 page not found\n"12942026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12952026/10/02 20:38:02 INFO Signed narinfos id=1 count=212962026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes12972026/10/02 20:38:02 INFO Uploading 2 narinfos12982026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12992026/10/02 20:38:02 WARN Failed to register uploaded object key=iw0wx20plgnhk5y4y1f23jzjnjb8p3ng.narinfo error="server returned 404: 404 page not found\n"13002026/10/02 20:38:02 INFO Uploading p6b27js6fv2gfvwmjl9hsj6a4ni8bnjh-unpinned-file.txt (128B)1301--- PASS: TestClientCADerivations (1.11s)1302=== CONT TestPushWaitsForSweepHoldingRow13032026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13042026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete13052026/10/02 20:38:02 WARN Failed to register uploaded object key=83z0c4k0wq04hiwr4mhz1az2pbv33cjn.narinfo error="server returned 404: 404 page not found\n"13062026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13072026/10/02 20:38:02 WARN Failed to register uploaded object key=p6b27js6fv2gfvwmjl9hsj6a4ni8bnjh.ls error="server returned 404: 404 page not found\n"13082026/10/02 20:38:02 INFO Signed narinfos id=2 count=113092026/10/02 20:38:02 INFO Uploading 1 narinfos13102026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/2/complete13112026/10/02 20:38:02 INFO Upload complete. (134ms)13122026/10/02 20:38:02 WARN Failed to register uploaded object key=p6b27js6fv2gfvwmjl9hsj6a4ni8bnjh.narinfo error="server returned 404: 404 page not found\n"1313=== NAME TestClientSharedPathCommittedMidPush1314 client_integration_test.go:816: Retrieved narinfo from S3:1315 StorePath: /build/TestClientSharedPathCommittedMidPush1058659824/001/store/iw0wx20plgnhk5y4y1f23jzjnjb8p3ng-shared-dep1316 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1317 Compression: zstd1318 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821319 NarSize: 1361320 References: 1321 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13222026/10/02 20:38:02 INFO Upload complete. (84ms)1323 client_integration_test.go:816: Retrieved narinfo from S3:1324 StorePath: /build/TestClientSharedPathCommittedMidPush1058659824/001/store/83z0c4k0wq04hiwr4mhz1az2pbv33cjn-top1325 URL: nar/1n9gfxvi4vva7lqshnhzxddl1q37kmijrahd8aiiv44ads6s5z8r.nar.zst1326 Compression: zstd1327 NarHash: sha256:1n9gfxvi4vva7lqshnhzxddl1q37kmijrahd8aiiv44ads6s5z8r1328 NarSize: 2241329 References: /build/TestClientSharedPathCommittedMidPush1058659824/001/store/iw0wx20plgnhk5y4y1f23jzjnjb8p3ng-shared-dep1330 CA: text:sha256:0pk90kzxpnimp6cmszfx14hpiv22n8by3x48scvv1idngwb2q7dd1331--- PASS: TestReconnectLeavesObjectsUnlocked (0.38s)1332=== CONT TestObjectStatsTrigger1333=== CONT TestPendingCleanupUsesOneCutoff1334--- PASS: TestService_healthCheckHandler (0.33s)13352026/10/02 20:38:02 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1918922598/001/proxy.sock13362026/10/02 20:38:02 INFO Starting HTTP server address=127.0.0.1:4148513372026/10/02 20:38:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"13382026/10/02 20:38:02 INFO Shutdown signal received, draining in-flight requests timeout=10s13392026/10/02 20:38:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures13402026/10/02 20:38:02 INFO Garbage collection started1341--- PASS: TestClientSharedPathCommittedMidPush (0.79s)1342=== CONT TestService_AuthMiddleware_OIDC13432026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=01344--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.25s)1345=== CONT TestMultipartCleanup13462026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period13472026/10/02 20:38:02 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=013482026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13492026/10/02 20:38:02 WARN Refused reserved pin name=worker-x86_64-linux13502026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13512026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/my-app13522026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13532026/10/02 20:38:02 INFO Vacuumed table table=pending_closures13542026/10/02 20:38:02 INFO Vacuumed table table=pending_objects13552026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads13562026/10/02 20:38:02 INFO Vacuumed table table=closures13572026/10/02 20:38:02 INFO Vacuumed table table=objects1358--- PASS: TestCreatePin_ReservedPins (0.31s)1359=== CONT TestGCSweepSkipsPendingObjects13602026/10/02 20:38:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38701/oidc13612026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1362=== NAME TestClientMultipleUploads1363 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2739120766/001/store/9nmy4277prfb38g0sy6yhypdqjg5iqyp-test-file-0.txt13642026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13652026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1366--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.30s)1367=== CONT TestClientErrorHandling1368=== RUN TestClientErrorHandling/InvalidStorePath1369=== PAUSE TestClientErrorHandling/InvalidStorePath1370=== RUN TestClientErrorHandling/InvalidAuthToken1371=== PAUSE TestClientErrorHandling/InvalidAuthToken1372=== RUN TestClientErrorHandling/ServerNotAvailable1373=== PAUSE TestClientErrorHandling/ServerNotAvailable1374=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13752026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjNkZDVmZWMzLTczODQtNDVlNC04YThhLTRkN2FhOTYzZmM1NXgxNzkwOTczNDgxNDkwMTAyNzY1 parts=1013762026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1378=== NAME TestClientMultipleUploads1379 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2739120766/001/store/6bg1dw2r8cb1ffdykws16lwj0hfc8c4p-test-file-1.txt13802026/10/02 20:38:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13812026/10/02 20:38:02 INFO Uploading bgznisb89s4rw3s59j2a9n0121ikvj90-b (216B)13822026/10/02 20:38:02 INFO Uploading 9np51vv0p2s19sj9hfj9x0dbxfbf63zf-shared-dep (136B)13832026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/0awx4fb14l77pdsb95w3cj9fpaf5li4fkbjl387cdii9aaf8pw18.nar.zst error="server returned 404: 404 page not found\n"13842026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13852026/10/02 20:38:02 WARN Failed to register uploaded object key=5r1xmb240lf6rric60dgw812ry12w6kw.ls error="server returned 404: 404 page not found\n"13862026/10/02 20:38:02 WARN Failed to register uploaded object key=bgznisb89s4rw3s59j2a9n0121ikvj90.ls error="server returned 404: 404 page not found\n"13872026/10/02 20:38:02 WARN Failed to register uploaded object key=9np51vv0p2s19sj9hfj9x0dbxfbf63zf.ls error="server returned 404: 404 page not found\n"13882026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13892026/10/02 20:38:03 INFO Signed narinfos id=1 count=213902026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13912026/10/02 20:38:03 INFO Signed narinfos id=2 count=213922026/10/02 20:38:03 INFO Uploading 4 narinfos1393 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2739120766/001/store/4jrv6yzryx7jhabvmm7jnqg1swyfdryy-test-file-2.txt13942026/10/02 20:38:03 WARN Failed to register uploaded object key=9np51vv0p2s19sj9hfj9x0dbxfbf63zf.narinfo error="server returned 404: 404 page not found\n"13952026/10/02 20:38:03 WARN Failed to register uploaded object key=bgznisb89s4rw3s59j2a9n0121ikvj90.narinfo error="server returned 404: 404 page not found\n"13962026/10/02 20:38:03 WARN Failed to register uploaded object key=5r1xmb240lf6rric60dgw812ry12w6kw.narinfo error="server returned 404: 404 page not found\n"13972026/10/02 20:38:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13982026/10/02 20:38:03 WARN Failed to register uploaded object key=9np51vv0p2s19sj9hfj9x0dbxfbf63zf.narinfo error="server returned 404: 404 page not found\n"13992026/10/02 20:38:03 INFO Completed upload id=214002026/10/02 20:38:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14012026/10/02 20:38:03 INFO Completed upload id=114022026/10/02 20:38:03 INFO Upload complete. (157ms)1403=== NAME TestClientFallsBackToClosures1404 client_pushes_test.go:112: Retrieved narinfo from S3:1405 StorePath: /build/TestClientFallsBackToClosures1494549039/001/store/9np51vv0p2s19sj9hfj9x0dbxfbf63zf-shared-dep1406 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1407 Compression: zstd1408 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821409 NarSize: 1361410 References: 1411 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1412 client_pushes_test.go:112: Retrieved narinfo from S3:1413 StorePath: /build/TestClientFallsBackToClosures1494549039/001/store/5r1xmb240lf6rric60dgw812ry12w6kw-a1414 URL: nar/0awx4fb14l77pdsb95w3cj9fpaf5li4fkbjl387cdii9aaf8pw18.nar.zst1415 Compression: zstd1416 NarHash: sha256:0awx4fb14l77pdsb95w3cj9fpaf5li4fkbjl387cdii9aaf8pw181417 NarSize: 2161418 References: /build/TestClientFallsBackToClosures1494549039/001/store/9np51vv0p2s19sj9hfj9x0dbxfbf63zf-shared-dep1419 CA: text:sha256:0i7infagncf093c4gm1lld8adszfjsnfy4p4fqfpnd8cw1v14hma1420 client_pushes_test.go:112: Retrieved narinfo from S3:1421 StorePath: /build/TestClientFallsBackToClosures1494549039/001/store/bgznisb89s4rw3s59j2a9n0121ikvj90-b1422 URL: nar/0awx4fb14l77pdsb95w3cj9fpaf5li4fkbjl387cdii9aaf8pw18.nar.zst1423 Compression: zstd1424 NarHash: sha256:0awx4fb14l77pdsb95w3cj9fpaf5li4fkbjl387cdii9aaf8pw181425 NarSize: 2161426 References: /build/TestClientFallsBackToClosures1494549039/001/store/9np51vv0p2s19sj9hfj9x0dbxfbf63zf-shared-dep1427 CA: text:sha256:0i7infagncf093c4gm1lld8adszfjsnfy4p4fqfpnd8cw1v14hma1428=== NAME TestClientIntegration1429 client_integration_test.go:334: Created store path: /build/TestClientIntegration1884379502/002/store/dd93y9d8nxqwnrbyfs92rxnsvl6whqz1-test-file.txt14302026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14312026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14322026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14332026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14342026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14352026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14362026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14372026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14382026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes14392026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1440--- PASS: TestClientFallsBackToClosures (0.69s)1441=== CONT TestReadProxyNarinfoAlreadyDecompressed14422026/10/02 20:38:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14432026/10/02 20:38:03 INFO Uploading 6bg1dw2r8cb1ffdykws16lwj0hfc8c4p-test-file-1.txt (160B)14442026/10/02 20:38:03 INFO Uploading 9nmy4277prfb38g0sy6yhypdqjg5iqyp-test-file-0.txt (160B)14452026/10/02 20:38:03 INFO Uploading 4jrv6yzryx7jhabvmm7jnqg1swyfdryy-test-file-2.txt (160B)14462026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14472026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14482026/10/02 20:38:03 WARN Failed to register uploaded object key=4jrv6yzryx7jhabvmm7jnqg1swyfdryy.ls error="server returned 404: 404 page not found\n"14492026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14502026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes14512026/10/02 20:38:03 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"14522026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy14532026/10/02 20:38:03 WARN Failed to register uploaded object key=9nmy4277prfb38g0sy6yhypdqjg5iqyp.ls error="server returned 404: 404 page not found\n"14542026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14552026/10/02 20:38:03 INFO Uploading dd93y9d8nxqwnrbyfs92rxnsvl6whqz1-test-file.txt (152B)14562026/10/02 20:38:03 WARN Failed to register uploaded object key=6bg1dw2r8cb1ffdykws16lwj0hfc8c4p.ls error="server returned 404: 404 page not found\n"14572026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14582026/10/02 20:38:03 INFO Signed narinfos id=1 count=314592026/10/02 20:38:03 INFO Uploading 3 narinfos1460=== NAME TestClientWithDependencies1461 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies509586096/001/store/qfc94rj7igih8jkzx4xhhxwy5ql2qg3n-test-script14622026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/02 20:38:03 WARN Failed to register uploaded object key=6bg1dw2r8cb1ffdykws16lwj0hfc8c4p.narinfo error="server returned 404: 404 page not found\n"14642026/10/02 20:38:03 WARN Failed to register uploaded object key=9nmy4277prfb38g0sy6yhypdqjg5iqyp.narinfo error="server returned 404: 404 page not found\n"14652026/10/02 20:38:03 WARN Failed to register uploaded object key=dd93y9d8nxqwnrbyfs92rxnsvl6whqz1.ls error="server returned 404: 404 page not found\n"14662026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14672026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14682026/10/02 20:38:03 INFO Signed narinfos id=1 count=114692026/10/02 20:38:03 INFO Uploading 1 narinfos14702026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14712026/10/02 20:38:03 WARN Failed to register uploaded object key=4jrv6yzryx7jhabvmm7jnqg1swyfdryy.narinfo error="server returned 404: 404 page not found\n"1472--- PASS: TestObjectStatsTrigger (0.43s)1473=== CONT TestCacheStatsHandler14742026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/02 20:38:03 WARN Failed to register uploaded object key=dd93y9d8nxqwnrbyfs92rxnsvl6whqz1.narinfo error="server returned 404: 404 page not found\n"14762026/10/02 20:38:03 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo14772026/10/02 20:38:03 INFO Upload complete. (122ms)1478=== NAME TestClientMultipleUploads1479 client_integration_test.go:491: Uploaded 3 paths in 158.807197ms14802026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures14812026/10/02 20:38:03 INFO Upload complete. (81ms)14822026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures14832026/10/02 20:38:03 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1484=== NAME TestClientWithDependencies1485 client_integration_test.go:737: Found 1 dependencies (including self)14862026/10/02 20:38:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1487--- PASS: TestConcurrentPinUpdatesAgree (0.89s)1488=== CONT TestPushDedupSurvivesConcurrentGC14892026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1490--- PASS: TestClientMultipleUploads (0.62s)1491=== CONT TestService_ReadScope_PublicByDefault14922026/10/02 20:38:03 INFO All 1 paths already cached1493=== NAME TestClientIntegration1494 client_integration_test.go:360: Retrieved narinfo from S3:1495 StorePath: /build/TestClientIntegration1884379502/002/store/dd93y9d8nxqwnrbyfs92rxnsvl6whqz1-test-file.txt1496 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1497 Compression: zstd1498 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11499 NarSize: 1521500 References: 1501 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11502 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1503 client_integration_test.go:361: Decompressed .ls content (64 bytes):1504 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1505=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1506=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1507=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1508=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1509=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1510=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1511=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1512=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1513=== CONT TestGCBugBareHashReferences1514--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.45s)1515=== CONT TestService_NativeMTLS15162026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=015172026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period15182026/10/02 20:38:03 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=015192026/10/02 20:38:03 INFO Vacuumed table table=pending_closures15202026/10/02 20:38:03 INFO Vacuumed table table=pending_objects15212026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads15222026/10/02 20:38:03 INFO Vacuumed table table=closures15232026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes15242026/10/02 20:38:03 INFO Vacuumed table table=objects15252026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures15262026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15272026/10/02 20:38:03 INFO Uploading qfc94rj7igih8jkzx4xhhxwy5ql2qg3n-test-script (136B)15282026/10/02 20:38:03 WARN Failed to register uploaded object key=log/g378cjcxm4c7y1w9lnl5wb0mnndfnsm2-test-script.drv error="server returned 404: 404 page not found\n"15292026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15302026/10/02 20:38:03 WARN Failed to register uploaded object key=qfc94rj7igih8jkzx4xhhxwy5ql2qg3n.ls error="server returned 404: 404 page not found\n"15312026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15322026/10/02 20:38:03 INFO Signed narinfos id=1 count=115332026/10/02 20:38:03 INFO Uploading 1 narinfos1534=== CONT TestGCMetrics1535--- PASS: TestGCSweepSkipsPendingObjects (0.46s)15362026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete15372026/10/02 20:38:03 WARN Failed to register uploaded object key=qfc94rj7igih8jkzx4xhhxwy5ql2qg3n.narinfo error="server returned 404: 404 page not found\n"15382026/10/02 20:38:03 INFO Received cleanup request method=DELETE path=/api/pending_closures15392026/10/02 20:38:03 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket65/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15402026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=115412026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes15422026/10/02 20:38:03 INFO Upload complete. (95ms)15432026/10/02 20:38:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1544--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.41s)15452026/10/02 20:38:03 INFO Aborted multipart uploads count=1 kept=01546=== CONT TestCacheConfigHandler1547=== RUN TestCacheConfigHandler/full_config,_no_issuer1548=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1549=== RUN TestCacheConfigHandler/no_cache_url_configured1550=== PAUSE TestCacheConfigHandler/no_cache_url_configured1551=== RUN TestCacheConfigHandler/no_signing_keys15522026/10/02 20:38:03 INFO Object in database but missing from S3 key=dd93y9d8nxqwnrbyfs92rxnsvl6whqz1.ls1553=== PAUSE TestCacheConfigHandler/no_signing_keys15542026/10/02 20:38:03 WARN Found objects in DB but missing from S3, will re-upload count=11555=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1556=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1557=== CONT TestPresentReportsOnlyClosureRoots15582026/10/02 20:38:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15592026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=015602026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period1561=== NAME TestOrphanedObjectsGC15622026/10/02 20:38:03 WARN Failed to register uploaded object key=dd93y9d8nxqwnrbyfs92rxnsvl6whqz1.ls error="server returned 404: 404 page not found\n"1563 orphaned_objects_gc_test.go:290: GC Test Summary:15642026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/2/complete1565 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1566 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1567 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1568 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1569 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1570--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.23s)1571=== CONT TestReadProxyNarStreaming15722026/10/02 20:38:03 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=015732026/10/02 20:38:03 INFO Upload complete. (63ms)1574=== NAME TestClientIntegration1575 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1576 client_integration_test.go:389: Decompressed .ls content (49 bytes):1577 {"version":1,"root":{"type":"regular","size":39}}1578--- PASS: TestMultipartCleanup (0.55s)1579=== CONT TestLeadElectsOneAndHandsOver15802026/10/02 20:38:03 INFO Vacuumed table table=pending_closures1581--- PASS: TestOrphanedObjectsGC (0.76s)1582=== CONT TestGCAdvisoryLockBlocksConcurrentRun15832026/10/02 20:38:03 INFO Vacuumed table table=pending_objects15842026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads15852026/10/02 20:38:03 INFO Vacuumed table table=closures15862026/10/02 20:38:03 INFO Vacuumed table table=objects15872026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1588=== NAME TestClientWithDependencies1589 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies509586096/001/store) requires matching store prefix15902026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15912026/10/02 20:38:03 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLmFmZjA3ODZiLTI4ODEtNGRiNS04YzZlLTU0YjdhNWY1NzUyOHgxNzkwOTczNDgyNTQ3Mzk4MjIw error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15922026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjY3NTE0Y2MzLThkNzMtNGU3OC04Y2UxLTM5NjAyNjQ0M2EwY3gxNzkwOTczNDgyNTMzMzc3NTAx parts=1215932026/10/02 20:38:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1594=== CONT TestServerTLSConfig1595--- PASS: TestCacheStatsHandler (0.23s)1596=== RUN TestServerTLSConfig/no_client_CA1597=== PAUSE TestServerTLSConfig/no_client_CA1598=== RUN TestServerTLSConfig/missing_CA_file1599=== PAUSE TestServerTLSConfig/missing_CA_file1600=== RUN TestServerTLSConfig/not_a_PEM_file1601=== PAUSE TestServerTLSConfig/not_a_PEM_file1602=== CONT TestLeadEndsOnShutdown16032026/10/02 20:38:03 INFO Aborted multipart uploads count=1 kept=016042026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjNjY2ViYzhlLTQ4ZGUtNGU5Mi04NDliLTY2MmNkNDU4NDYzYngxNzkwOTczNDgxODczMzQ3ODY0 parts=101605=== CONT TestConnectWaitsForAPeerMigration1606--- PASS: TestClientWithDependencies (0.81s)16072026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16082026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1609--- PASS: TestRedundantMultipartUpload (2.81s)1610=== CONT TestNARDeduplicationMetadataUploadBug16112026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures16122026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1613--- PASS: TestPendingClosureFailureTracksEveryUpload (0.85s)1614=== CONT TestGCTaskStore_GetEmpty1615=== CONT TestGCTaskStore_GetReturnsLatest1616--- PASS: TestGCTaskStore_GetEmpty (0.00s)1617=== CONT TestGCTaskStore_ConflictDifferentParams1618=== CONT TestConnectSerialisesConcurrentMigrations1619--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1620--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)16212026/10/02 20:38:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16222026/10/02 20:38:03 WARN Failed to register uploaded object key=dd93y9d8nxqwnrbyfs92rxnsvl6whqz1.ls error="server returned 404: 404 page not found\n"1623--- PASS: TestService_ReadScope_PublicByDefault (0.28s)1624=== CONT TestGCTaskStore_PhaseUpdates1625--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1626=== CONT TestMetricsInventory16272026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/3/complete16282026/10/02 20:38:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16292026/10/02 20:38:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16302026/10/02 20:38:03 INFO Upload complete. (106ms)1631=== NAME TestClientIntegration1632 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1633 client_integration_test.go:405: Decompressed .ls content (49 bytes):16342026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=01635 {"version":1,"root":{"type":"regular","size":39}}16362026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period1637--- PASS: TestService_NativeMTLS (0.30s)1638=== CONT TestService_RequireScope_OIDC16392026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16402026/10/02 20:38:03 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=016412026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016422026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16432026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16442026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16452026/10/02 20:38:03 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=016462026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016472026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjg3M2VkYWE1LTgwNmQtNDgzOC04YjRkLTUwYzJjYTE0NWFlYngxNzkwOTczNDgxNDg5NzM1Njg1 parts=1016482026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16492026/10/02 20:38:03 INFO Vacuumed table table=closures16502026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16512026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period16522026/10/02 20:38:03 INFO Vacuumed table table=objects16532026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16542026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16552026/10/02 20:38:03 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=016562026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16572026/10/02 20:38:03 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721616582026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16592026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16602026/10/02 20:38:03 INFO Vacuumed table table=closures16612026/10/02 20:38:03 INFO Vacuumed table table=closures16622026/10/02 20:38:03 INFO Vacuumed table table=objects16632026/10/02 20:38:03 INFO Vacuumed table table=objects16642026-10-02 20:38:03.666 UTC [2052] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"16652026-10-02 20:38:03.666 UTC [2052] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.16662026-10-02 20:38:03.666 UTC [2052] STATEMENT: CREATE TABLE goose_db_version (1667 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1668 version_id bigint NOT NULL,1669 is_applied boolean NOT NULL,1670 tstamp timestamp NOT NULL DEFAULT now()1671 )16722026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016732026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period1674--- PASS: TestPushWaitsForSweepHoldingRow (0.97s)1675=== CONT TestCreatePendingClosureRejectsOversizedNAR16762026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1677--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1678=== CONT TestService_ReadAuthMiddleware16792026/10/02 20:38:03 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=016802026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16812026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16822026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16832026/10/02 20:38:03 INFO Vacuumed table table=closures16842026/10/02 20:38:03 INFO lead: acquired remote=192.0.2.1:123416852026/10/02 20:38:03 INFO Vacuumed table table=objects1686=== CONT TestGCTaskStore_StartNew1687--- PASS: TestReadProxyNarinfo (1.57s)1688=== CONT TestGCEndsOnShutdown1689--- PASS: TestGCTaskStore_StartNew (0.00s)1690=== RUN TestGCEndsOnShutdown/before_the_run1691=== PAUSE TestGCEndsOnShutdown/before_the_run1692=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1693=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1694=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1695=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1696=== CONT TestGenerateLandingPage1697=== CONT TestGCTaskStore_DeduplicateSameParams1698--- PASS: TestPush_CompleteCommitsEveryRoot (3.05s)16992026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1700=== CONT TestService_readinessHandler1701--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1702--- PASS: TestGenerateLandingPage (0.01s)1703=== CONT TestGCTaskStore_Fail1704--- PASS: TestGCTaskStore_Fail (0.00s)1705=== CONT TestCommitRacingPendingCleanupKeepsObjects17062026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17072026/10/02 20:38:03 INFO Uploading ygq95j6grv8i14jv1pzywlm3i5jiwhhc-lost-commit.txt (152B)1708--- PASS: TestPushDedupSurvivesConcurrentGC (0.50s)1709=== CONT TestSweepRechecksPendingAfterLocking17102026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"17112026/10/02 20:38:03 WARN Failed to register uploaded object key=ygq95j6grv8i14jv1pzywlm3i5jiwhhc.ls error="server returned 404: 404 page not found\n"17122026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign1713=== CONT TestGCTaskStore_CompletedAllowsNewTask1714--- PASS: TestGCMetrics (0.43s)1715=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1716--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)17172026/10/02 20:38:03 INFO Signed narinfos id=4 count=117182026/10/02 20:38:03 INFO Uploading 1 narinfos17192026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/4/complete17202026/10/02 20:38:03 WARN Failed to register uploaded object key=ygq95j6grv8i14jv1pzywlm3i5jiwhhc.narinfo error="server returned 404: 404 page not found\n"17212026/10/02 20:38:03 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:33769/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33769/api/pushes/4/complete17222026/10/02 20:38:03 INFO lead: acquired remote=192.0.2.1:12341723--- PASS: TestGCBugBareHashReferences (0.56s)1724=== CONT TestProxyWriteTimeout/1_GiB_nar1725=== CONT TestProxyWriteTimeout/unknown_size1726=== CONT TestProxyWriteTimeout/10_GiB_nar1727=== CONT TestProxyWriteTimeout/narinfo1728=== CONT TestPendingClosureWriteTimeout/400_objects1729--- PASS: TestProxyWriteTimeout (0.01s)1730 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1731 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1732 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1733 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1734=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1735--- PASS: TestReadProxyNarStreaming (0.48s)1736=== CONT TestPendingClosureWriteTimeout/670k_objects1737=== CONT TestPendingClosureWriteTimeout/empty1738=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17392026/10/02 20:38:03 INFO Received uploads request method=POST path=/1740=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17412026/10/02 20:38:03 INFO Received uploads request method=POST path=/1742=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17432026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/1744=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17452026/10/02 20:38:03 INFO Received request for more parts method=POST path=/1746=== CONT TestIsValidUploadKey/narinfo1747--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1748 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1749 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1750 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1751 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1752=== CONT TestIsValidUploadKey/unknown_type1753=== CONT TestIsValidUploadKey/absolute1754=== CONT TestIsValidUploadKey/empty_key1755=== CONT TestIsValidUploadKey/traversal_nar1756=== CONT TestIsValidUploadKey/build_log_question_mark1757=== CONT TestIsValidUploadKey/traversal1758=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1759=== CONT TestIsValidUploadKey/realisation_plus_in_output1760=== CONT TestIsValidUploadKey/build_log_plus_in_name1761=== CONT TestIsValidUploadKey/build_log_equals1762=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1763=== CONT TestIsValidUploadKey/nar_xz1764=== CONT TestIsValidUploadKey/nar_zst1765=== CONT TestIsValidUploadKey/index.html1766=== CONT TestIsValidUploadKey/build_log_home-manager_file1767=== CONT TestIsValidUploadKey/nar_plain1768=== CONT TestIsValidUploadKey/listing1769=== CONT TestIsValidUploadKey/nix-cache-info1770=== CONT TestIsValidUploadKey/realisation1771=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1772=== CONT TestIsValidUploadKey/build_log1773=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1774--- PASS: TestIsValidUploadKey (0.01s)1775 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1776 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1777 --- PASS: TestIsValidUploadKey/absolute (0.00s)1778 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1779 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1780 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1781 --- PASS: TestIsValidUploadKey/traversal (0.00s)1782 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1783 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1784 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1785 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1786 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1787 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1788 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1789 --- PASS: TestIsValidUploadKey/index.html (0.00s)1790 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1791 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1792 --- PASS: TestIsValidUploadKey/listing (0.00s)1793 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1794 --- PASS: TestIsValidUploadKey/realisation (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1796 --- PASS: TestIsValidUploadKey/build_log (0.00s)17972026/10/02 20:38:03 INFO Received uploads request method=POST path=/17982026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/deploy17992026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/4/complete18002026-10-02 20:38:03.843 UTC [1532] ERROR: Push does not exist: id=418012026-10-02 20:38:03.843 UTC [1532] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE18022026-10-02 20:38:03.843 UTC [1532] STATEMENT: -- name: CommitPush :exec1803 SELECT commit_push($1::bigint)1804 18052026/10/02 20:38:03 INFO Upload complete. (203ms)1806=== NAME TestClientIntegration1807 client_integration_test.go:435: Retrieved narinfo from S3:1808 StorePath: /build/TestClientIntegration1884379502/002/store/ygq95j6grv8i14jv1pzywlm3i5jiwhhc-lost-commit.txt1809 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1810 Compression: zstd1811 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1812 NarSize: 1521813 References: 1814 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl18152026/10/02 20:38:03 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1816 client_integration_test.go:438: Testing garbage collection...1817--- PASS: TestPresentReportsOnlyClosureRoots (0.54s)1818=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18192026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/18202026/10/02 20:38:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40291/oidc1821=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1822--- PASS: TestCreatePinRejectsBadInput (1.20s)18232026/10/02 20:38:03 INFO Received request for more parts method=POST path=/1824=== NAME TestNARDeduplicationMetadataUploadBug1825 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug62162375/001/store/2hmnjkmbmwlllzwhlk97v57axwq5qi6b-file1.txt18262026/10/02 20:38:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures18272026/10/02 20:38:03 INFO Garbage collection started18282026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=018292026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period1830--- PASS: TestService_ReadAuthMiddleware (0.25s)1831=== CONT TestPush_RejectsBadRequests/no_objects18322026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1833=== CONT TestPush_RejectsBadRequests/no_roots18342026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1835=== CONT TestPush_RejectsBadRequests/root_not_in_objects18362026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1837=== CONT TestPush_RejectsBadRequests/bad_root18382026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1839=== CONT TestResolveDBConnectionString/flag_wins1840=== CONT TestResolveDBConnectionString/nothing_configured1841=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1842=== CONT TestResolveDBConnectionString/file_when_flag_empty1843=== CONT TestResolveDBConnectionString/missing_file_is_an_error1844=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1845--- PASS: TestResolveDBConnectionString (0.00s)1846 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1847 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1848 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1849 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1850 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)18512026/10/02 20:38:03 WARN readiness check failed error="closed pool"18522026/10/02 20:38:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=2 objects-marked-for-deletion=6 objects-deleted-after-grace-period=6 objects-failed-to-delete=018532026/10/02 20:38:03 INFO Vacuumed table table=pending_closures18542026/10/02 20:38:03 INFO Vacuumed table table=pending_objects18552026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads1856--- PASS: TestPush_RejectsBadRequests (1.08s)1857 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1858 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1859 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1860 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)18612026/10/02 20:38:03 INFO Vacuumed table table=closures1862--- PASS: TestService_readinessHandler (0.26s)1863=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18642026/10/02 20:38:03 INFO Vacuumed table table=objects1865=== CONT TestIsValidCachePath/narinfo1866--- PASS: TestMetricsInventory (0.48s)1867=== CONT TestIsValidCachePath/short_hash1868=== CONT TestIsValidCachePath/traversal_parent1869=== CONT TestIsValidCachePath/nix-cache-info1870=== CONT TestIsValidCachePath/log1871=== CONT TestIsValidCachePath/leading_slash1872=== CONT TestIsValidCachePath/nar_zst1873=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1874=== CONT TestIsValidCachePath/empty1875=== CONT TestIsValidCachePath/nar_xz1876=== CONT TestIsValidCachePath/ls1877=== CONT TestIsValidCachePath/wrong_extension1878=== CONT TestIsValidCachePath/nar_bz21879=== CONT TestIsValidCachePath/realisation1880=== CONT TestIsValidCachePath/nar_uncompressed1881=== CONT TestIsValidCachePath/index.html1882=== CONT TestIsValidCachePath/random_path1883=== CONT TestIsValidCachePath/invalid_char_e1884=== CONT TestIsValidCachePath/traversal_in_middle1885=== CONT TestIsValidCachePath/invalid_char_u1886=== CONT TestParseSingleRange/unknown_unit1887--- PASS: TestIsValidCachePath (0.01s)1888 --- PASS: TestIsValidCachePath/narinfo (0.00s)1889 --- PASS: TestIsValidCachePath/short_hash (0.00s)1890 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1891 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1892 --- PASS: TestIsValidCachePath/log (0.00s)1893 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1894 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1895 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1896 --- PASS: TestIsValidCachePath/empty (0.00s)1897 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1898 --- PASS: TestIsValidCachePath/ls (0.00s)1899 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1900 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1901 --- PASS: TestIsValidCachePath/realisation (0.00s)1902 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1903 --- PASS: TestIsValidCachePath/index.html (0.00s)1904 --- PASS: TestIsValidCachePath/random_path (0.00s)1905 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1906 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1907 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1908=== CONT TestParseSingleRange/closed1909=== CONT TestParseSingleRange/start_far_past_EOF1910=== CONT TestParseSingleRange/start_past_EOF1911=== CONT TestParseSingleRange/suffix_exceeds_size1912=== CONT TestParseSingleRange/single_byte1913=== CONT TestParseSingleRange/end_clamped_to_size1914=== CONT TestParseSingleRange/malformed_no_dash1915=== CONT TestParseSingleRange/open-ended1916=== CONT TestParseSingleRange/malformed_end_before_start1917=== CONT TestParseSingleRange/suffix1918=== CONT TestParseSingleRange/none1919=== CONT TestParseSingleRange/multi-range_ignored1920=== CONT TestParseSingleRange/malformed_both_empty1921=== CONT TestClientErrorHandling/InvalidStorePath1922--- PASS: TestParseSingleRange (0.00s)1923 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1924 --- PASS: TestParseSingleRange/closed (0.00s)1925 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1926 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1927 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1928 --- PASS: TestParseSingleRange/single_byte (0.00s)1929 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1930 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1931 --- PASS: TestParseSingleRange/open-ended (0.00s)1932 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1933 --- PASS: TestParseSingleRange/suffix (0.00s)1934 --- PASS: TestParseSingleRange/none (0.00s)1935 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1936 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)19372026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes19382026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19392026/10/02 20:38:03 INFO Uploading 2hmnjkmbmwlllzwhlk97v57axwq5qi6b-file1.txt (160B)19402026/10/02 20:38:04 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19412026/10/02 20:38:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19422026/10/02 20:38:04 WARN Failed to register uploaded object key=2hmnjkmbmwlllzwhlk97v57axwq5qi6b.ls error="server returned 404: 404 page not found\n"19432026/10/02 20:38:04 INFO Signed narinfos id=1 count=119442026/10/02 20:38:04 INFO Uploading 1 narinfos19452026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=019462026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=019472026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period19482026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period19492026/10/02 20:38:04 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=019502026/10/02 20:38:04 INFO Received complete push request method=POST path=/api/pushes/1/complete19512026/10/02 20:38:04 WARN Failed to register uploaded object key=2hmnjkmbmwlllzwhlk97v57axwq5qi6b.narinfo error="server returned 404: 404 page not found\n"19522026/10/02 20:38:04 INFO Vacuumed table table=pending_closures19532026/10/02 20:38:04 INFO Vacuumed table table=pending_objects19542026/10/02 20:38:04 INFO Vacuumed table table=multipart_uploads19552026/10/02 20:38:04 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"19562026/10/02 20:38:04 INFO Vacuumed table table=closures19572026/10/02 20:38:04 INFO Vacuumed table table=objects19582026/10/02 20:38:04 INFO Upload complete. (118ms)19592026/10/02 20:38:04 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=01960=== NAME TestNARDeduplicationMetadataUploadBug1961 metadata_upload_test.go:54: Retrieved narinfo from S3:1962 StorePath: /build/TestNARDeduplicationMetadataUploadBug62162375/001/store/2hmnjkmbmwlllzwhlk97v57axwq5qi6b-file1.txt1963 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1964 Compression: zstd1965 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1966 NarSize: 1601967 References: 1968 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19692026/10/02 20:38:04 INFO Vacuumed table table=pending_closures19702026/10/02 20:38:04 INFO Vacuumed table table=pending_objects19712026/10/02 20:38:04 INFO Vacuumed table table=multipart_uploads1972 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)19732026/10/02 20:38:04 INFO Vacuumed table table=closures1974 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1975 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19762026/10/02 20:38:04 INFO Vacuumed table table=objects19772026/10/02 20:38:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"1978--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)19792026/10/02 20:38:04 WARN mTLS auth: bound subjects configured but subject DN unavailable1980=== CONT TestClientErrorHandling/ServerNotAvailable19812026/10/02 20:38:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1982=== CONT TestClientErrorHandling/InvalidAuthToken1983--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.73s)1984--- PASS: TestSweepRechecksPendingAfterLocking (0.38s)1985=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1986=== NAME TestNARDeduplicationMetadataUploadBug1987 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug62162375/001/store/7q2d9nx28mbfaf3c4qd2dvb67djyz7mp-file2.txt1988--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)1989=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1990=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19912026/10/02 20:38:04 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]1992=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token19932026/10/02 20:38:04 WARN Authentication failed token_preview=eyJhbGciOi...LdOfIC-PLQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1994=== CONT TestCacheConfigHandler/full_config,_no_issuer19952026/10/02 20:38:04 INFO Received uploads request method=POST path=/api/pending_closures1996=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1997=== CONT TestCacheConfigHandler/no_cache_url_configured1998=== CONT TestCacheConfigHandler/no_signing_keys1999=== CONT TestServerTLSConfig/no_client_CA2000--- PASS: TestCacheConfigHandler (0.00s)2001 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2002 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2003 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2004 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2005=== CONT TestServerTLSConfig/not_a_PEM_file2006=== CONT TestServerTLSConfig/missing_CA_file2007=== CONT TestGCEndsOnShutdown/before_the_run2008=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2009--- PASS: TestServerTLSConfig (0.00s)2010 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2011 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2012 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2013--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2014 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2015 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2016 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2017 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2018=== RUN TestService_RequireScope_OIDC/builder_may_write2019=== PAUSE TestService_RequireScope_OIDC/builder_may_write2020=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2021=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2022=== RUN TestService_RequireScope_OIDC/ops_may_admin2023=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2024=== RUN TestService_RequireScope_OIDC/ops_may_not_write2025=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2026=== RUN TestService_RequireScope_OIDC/reader_may_not_write2027=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2028=== RUN TestService_RequireScope_OIDC/static_token_may_admin2029=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2030=== RUN TestService_RequireScope_OIDC/static_token_may_write2031=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2032=== RUN TestService_RequireScope_OIDC/reader_may_read2033=== PAUSE TestService_RequireScope_OIDC/reader_may_read2034=== RUN TestService_RequireScope_OIDC/writer_implies_read2035=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2036=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2037=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2038=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20392026/10/02 20:38:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20402026/10/02 20:38:04 INFO Received push request method=POST path=/api/pushes20412026/10/02 20:38:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20422026/10/02 20:38:04 INFO Received uploads request method=POST path=/api/pending_closures20432026/10/02 20:38:04 WARN Failed to register uploaded object key=7q2d9nx28mbfaf3c4qd2dvb67djyz7mp.ls error="server returned 404: 404 page not found\n"20442026/10/02 20:38:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20452026/10/02 20:38:04 INFO Signed narinfos id=2 count=120462026/10/02 20:38:04 INFO Uploading 1 narinfos20472026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=020482026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period20492026/10/02 20:38:04 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=020502026/10/02 20:38:04 INFO Vacuumed table table=pending_closures20512026/10/02 20:38:04 INFO Vacuumed table table=pending_objects20522026/10/02 20:38:04 INFO Vacuumed table table=multipart_uploads20532026/10/02 20:38:04 INFO Received complete push request method=POST path=/api/pushes/2/complete20542026/10/02 20:38:04 INFO Received uploads request method=POST path=/api/pending_closures20552026/10/02 20:38:04 INFO Vacuumed table table=closures20562026/10/02 20:38:04 WARN Failed to register uploaded object key=7q2d9nx28mbfaf3c4qd2dvb67djyz7mp.narinfo error="server returned 404: 404 page not found\n"20572026/10/02 20:38:04 INFO Vacuumed table table=objects20582026/10/02 20:38:04 INFO Upload complete. (117ms)2059=== NAME TestNARDeduplicationMetadataUploadBug2060 metadata_upload_test.go:76: Retrieved narinfo from S3:2061 StorePath: /build/TestNARDeduplicationMetadataUploadBug62162375/001/store/7q2d9nx28mbfaf3c4qd2dvb67djyz7mp-file2.txt2062 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2063 Compression: zstd2064 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2065 NarSize: 1602066 References: 2067 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf20682026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=020692026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period20702026/10/02 20:38:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.667095ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2071 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2072 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2073 {"version":1,"root":{"type":"regular","size":44}}20742026/10/02 20:38:04 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=020752026/10/02 20:38:04 INFO Vacuumed table table=pending_closures20762026/10/02 20:38:04 INFO Vacuumed table table=pending_objects20772026/10/02 20:38:04 INFO Vacuumed table table=multipart_uploads20782026/10/02 20:38:04 INFO Vacuumed table table=closures20792026/10/02 20:38:04 INFO Vacuumed table table=objects2080=== CONT TestService_RequireScope_OIDC/builder_may_write2081=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2082=== CONT TestService_RequireScope_OIDC/static_token_may_admin2083=== CONT TestService_RequireScope_OIDC/reader_may_read2084=== CONT TestService_RequireScope_OIDC/writer_implies_read2085=== CONT TestService_RequireScope_OIDC/ops_may_admin2086=== CONT TestService_RequireScope_OIDC/static_token_may_write2087=== CONT TestService_RequireScope_OIDC/ops_may_not_write2088=== CONT TestService_RequireScope_OIDC/reader_may_not_write2089--- PASS: TestNARDeduplicationMetadataUploadBug (0.85s)2090=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20912026/10/02 20:38:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2092--- PASS: TestService_RequireScope_OIDC (0.62s)2093 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2094 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2095 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2096 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2097 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2098 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2099 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2103--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2104 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.37s)2105 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.37s)21062026/10/02 20:38:04 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ODAyODc3NDktN2YwNi00ZmM5LTk3MDEtM2QzNDBhM2Y1MjkwLjgwMmYxZGRkLWQxNTYtNDBmYy05NWU2LWFjOGRmYWI1MGI5OXgxNzkwOTczNDgzNDU4NzExNDU3 parts=1021072026/10/02 20:38:04 INFO Received complete push request method=POST path=/api/pushes/2/complete2108--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.72s)21092026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=021102026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period21112026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=021122026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period21132026-10-02 20:38:04.392 UTC [2347] ERROR: canceling statement due to user request21142026-10-02 20:38:04.392 UTC [2347] CONTEXT: SQL statement "UPDATE object_stats2115 SET object_count = object_count + d_count,2116 total_bytes = total_bytes + d_bytes2117 WHERE id"2118 PL/pgSQL function object_stats_apply() line 17 at SQL statement21192026-10-02 20:38:04.392 UTC [2347] STATEMENT: -- name: MarkStaleObjects :execrows2120 WITH RECURSIVE ct AS (2121 SELECT timezone('UTC', now()) AS now2122 ),2123 closure_reach AS (2124 -- Start with all closure keys2125 SELECT o.key, o.refs2126 FROM objects o2127 INNER JOIN closures c ON o.key = c.key2128 UNION2129 -- Recursively add all referenced objects2130 SELECT o.key, o.refs2131 FROM objects o2132 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2133 ),2134 reachable_objects AS (2135 SELECT DISTINCT key FROM closure_reach2136 ),2137 stale_objects AS (2138 SELECT o.key2139 FROM objects AS o, ct2140 WHERE2141 NOT EXISTS (2142 SELECT 12143 FROM reachable_objects ro2144 WHERE ro.key = o.key2145 )2146 AND NOT EXISTS (2147 SELECT 12148 FROM pending_objects AS po2149 WHERE po.key = o.key2150 )2151 AND o.deleted_at IS NULL -- Only mark fresh objects2152 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2153 FOR UPDATE2154 )2155 UPDATE objects2156 SET2157 deleted_at = ct.now,2158 first_deleted_at = COALESCE(first_deleted_at, ct.now)2159 FROM stale_objects, ct2160 WHERE objects.key = stale_objects.key2161 21622026/10/02 20:38:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21632026/10/02 20:38:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38517/bucket97/?delete=\": context canceled"2164--- PASS: TestGCEndsOnShutdown (0.00s)2165 --- PASS: TestGCEndsOnShutdown/before_the_run (0.24s)2166 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)2167 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.28s)21682026/10/02 20:38:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21692026/10/02 20:38:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.916297ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2170=== NAME TestOrphanedObjectsGCStressTest2171 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2172 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2173--- PASS: TestConnectSerialisesConcurrentMigrations (1.21s)21742026/10/02 20:38:04 INFO lead: released remote=192.0.2.1:12342175--- PASS: TestLeadEndsOnShutdown (1.36s)21762026/10/02 20:38:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021772026/10/02 20:38:04 INFO Received create pin request method=POST path=/api/pins/myapp21782026/10/02 20:38:04 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1249170871/001/store/0xm15744wzqrj6hnv0p7hlzsqd9r8wn1-pinned-file.txt narinfo_key=0xm15744wzqrj6hnv0p7hlzsqd9r8wn1.narinfo21792026/10/02 20:38:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures21802026/10/02 20:38:04 INFO Garbage collection started21812026/10/02 20:38:04 INFO Aborted multipart uploads count=0 kept=021822026/10/02 20:38:04 WARN Force mode enabled - objects will be deleted immediately without grace period21832026/10/02 20:38:04 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=021842026/10/02 20:38:04 INFO Vacuumed table table=pending_closures21852026/10/02 20:38:04 INFO Vacuumed table table=pending_objects21862026/10/02 20:38:04 INFO Vacuumed table table=multipart_uploads21872026/10/02 20:38:04 INFO Vacuumed table table=closures21882026/10/02 20:38:04 INFO Vacuumed table table=objects21892026/10/02 20:38:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=768.535792ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2190--- PASS: TestPendingClosureWriteTimeout (0.01s)2191 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2192 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2193 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2194 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.14s)21952026/10/02 20:38:04 INFO lead: released remote=192.0.2.1:12342196=== NAME TestOrphanedObjectsGCStressTest2197 orphaned_objects_gc_test.go:509: Stress test completed successfully:2198 orphaned_objects_gc_test.go:510: - Active objects preserved: 202199 orphaned_objects_gc_test.go:511: - Objects deleted: 2102200 orphaned_objects_gc_test.go:512: - Total GC'd: 21022012026/10/02 20:38:04 INFO lead: acquired remote=192.0.2.1:12342202--- PASS: TestOrphanedObjectsGCStressTest (3.35s)22032026/10/02 20:38:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44638502s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22042026/10/02 20:38:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02205=== NAME TestClientIntegration2206 client_integration_test.go:445: Objects in database after GC:2207 client_integration_test.go:445: Successfully deleted all objects with GC --force2208--- PASS: TestClientIntegration (3.31s)22092026/10/02 20:38:06 INFO lead: released remote=192.0.2.1:12342210--- PASS: TestLeadElectsOneAndHandsOver (2.73s)2211--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.22s)22122026/10/02 20:38:06 WARN Rate limiter enabled after throttle name=s3-test rate=522132026/10/02 20:38:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2214=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2215 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102216 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002217--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.94s)2218=== NAME TestPinProtectsFromGC2219 client_integration_test.go:976: Pin successfully protected closure from garbage collection2220--- PASS: TestPinProtectsFromGC (4.98s)22212026/10/02 20:38:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/10/02 20:38:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.711938ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22232026/10/02 20:38:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.802058ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22242026/10/02 20:38:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.205887ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/10/02 20:38:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746870805s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2226--- PASS: TestConnectWaitsForAPeerMigration (5.21s)22272026/10/02 20:38:09 INFO Aborted multipart uploads count=1 kept=022282026/10/02 20:38:09 INFO Received cleanup request method=DELETE path=/api/pending_closures22292026/10/02 20:38:09 INFO Aborted multipart uploads count=1 kept=02230--- PASS: TestPendingCleanupUsesOneCutoff (6.48s)22312026/10/02 20:38:10 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"22322026/10/02 20:38:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/02 20:38:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.027578ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/10/02 20:38:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.990887ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/10/02 20:38:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=750.788148ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/02 20:38:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.756945325s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2237--- PASS: TestUploadHandlersRejectOversizedBody (0.65s)2238 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.62s)2239 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.66s)2240 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (8.21s)22412026/10/02 20:38:13 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22422026/10/02 20:38:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.479435ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22432026/10/02 20:38:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.63803ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22442026/10/02 20:38:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=758.259995ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22452026/10/02 20:38:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.593514861s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2246--- PASS: TestClientErrorHandling (0.00s)2247 --- PASS: TestClientErrorHandling/InvalidStorePath (0.34s)2248 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2249 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.53s)2250PASS2251{"timestamp":"2026-10-02T20:38:16.605357881Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58430","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(390)"}22522026-10-02 20:38:17.043 UTC [172] LOG: received smart shutdown request22532026-10-02 20:38:17.048 UTC [172] LOG: background worker "logical replication launcher" (PID 182) exited with exit code 122542026-10-02 20:38:17.060 UTC [177] LOG: shutting down22552026-10-02 20:38:17.061 UTC [177] LOG: checkpoint starting: shutdown immediate22562026-10-02 20:38:17.806 UTC [177] LOG: checkpoint complete: wrote 10719 buffers (65.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.286 s, sync=0.414 s, total=0.746 s; sync files=33361, longest=0.069 s, average=0.001 s; distance=467230 kB, estimate=467230 kB; lsn=0/1DFAD848, redo lsn=0/1DFAD84822572026-10-02 20:38:17.889 UTC [172] LOG: database system is shut down2258Running OIDC tests...2259=== RUN TestAudienceForIssuer2260=== PAUSE TestAudienceForIssuer2261=== RUN TestHTTPClientForHasTimeouts2262=== PAUSE TestHTTPClientForHasTimeouts2263=== RUN TestGlobMatch2264=== PAUSE TestGlobMatch2265=== RUN TestValidateToken_ValidToken2266=== PAUSE TestValidateToken_ValidToken2267=== RUN TestValidateToken_WrongAudience2268=== PAUSE TestValidateToken_WrongAudience2269=== RUN TestValidateToken_Expired2270=== PAUSE TestValidateToken_Expired2271=== RUN TestValidateToken_BoundClaimsMismatch2272=== PAUSE TestValidateToken_BoundClaimsMismatch2273=== RUN TestValidateToken_BoundSubjectMismatch2274=== PAUSE TestValidateToken_BoundSubjectMismatch2275=== RUN TestValidateToken_MultipleProviders2276=== PAUSE TestValidateToken_MultipleProviders2277=== RUN TestValidateToken_NoMatchingProvider2278=== PAUSE TestValidateToken_NoMatchingProvider2279=== RUN TestValidateToken_KubernetesServiceAccount2280=== PAUSE TestValidateToken_KubernetesServiceAccount2281=== RUN TestNewValidator_KubernetesRequiresCA2282=== PAUSE TestNewValidator_KubernetesRequiresCA2283=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2284=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2285=== RUN TestPins_ReservedForMatchingRule2286=== PAUSE TestPins_ReservedForMatchingRule2287=== RUN TestPins_TopLevelShorthand2288=== PAUSE TestPins_TopLevelShorthand2289=== RUN TestPins_ConfigValidation2290=== PAUSE TestPins_ConfigValidation2291=== RUN TestScopes_LegacyProviderDefaultsToWrite2292=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2293=== RUN TestScopes_Rules2294=== PAUSE TestScopes_Rules2295=== RUN TestScopes_ConfigValidation2296=== PAUSE TestScopes_ConfigValidation2297=== CONT TestHTTPClientForHasTimeouts2298=== CONT TestPins_ReservedForMatchingRule2299=== CONT TestValidateToken_Expired2300=== CONT TestValidateToken_BoundClaimsMismatch2301=== CONT TestValidateToken_NoMatchingProvider2302=== CONT TestScopes_Rules2303=== CONT TestScopes_ConfigValidation2304=== CONT TestScopes_LegacyProviderDefaultsToWrite2305=== CONT TestPins_ConfigValidation2306=== CONT TestValidateToken_WrongAudience2307=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2308=== CONT TestPins_TopLevelShorthand2309--- PASS: TestScopes_ConfigValidation (0.00s)2310--- PASS: TestPins_ConfigValidation (0.00s)2311=== CONT TestGlobMatch2312=== CONT TestValidateToken_BoundSubjectMismatch2313=== CONT TestNewValidator_KubernetesRequiresCA2314=== CONT TestValidateToken_KubernetesServiceAccount2315=== CONT TestValidateToken_ValidToken2316=== CONT TestAudienceForIssuer2317--- PASS: TestAudienceForIssuer (0.00s)2318=== CONT TestValidateToken_MultipleProviders2319=== RUN TestGlobMatch/foo_foo2320=== PAUSE TestGlobMatch/foo_foo2321=== RUN TestGlobMatch/foo_bar2322=== PAUSE TestGlobMatch/foo_bar2323=== RUN TestGlobMatch/*_2324=== PAUSE TestGlobMatch/*_2325=== RUN TestGlobMatch/*_anything2326=== PAUSE TestGlobMatch/*_anything2327=== RUN TestGlobMatch/foo*_foo2328=== PAUSE TestGlobMatch/foo*_foo2329=== RUN TestGlobMatch/foo*_foobar2330=== PAUSE TestGlobMatch/foo*_foobar2331=== RUN TestGlobMatch/foo*_bar2332=== PAUSE TestGlobMatch/foo*_bar2333=== RUN TestGlobMatch/*bar_bar2334=== PAUSE TestGlobMatch/*bar_bar2335=== RUN TestGlobMatch/*bar_foobar2336=== PAUSE TestGlobMatch/*bar_foobar2337=== RUN TestGlobMatch/*bar_foo2338=== PAUSE TestGlobMatch/*bar_foo2339=== RUN TestGlobMatch/foo*bar_foobar2340=== PAUSE TestGlobMatch/foo*bar_foobar2341=== RUN TestGlobMatch/foo*bar_foo123bar2342=== PAUSE TestGlobMatch/foo*bar_foo123bar2343=== RUN TestGlobMatch/foo*bar_foobarbaz2344=== PAUSE TestGlobMatch/foo*bar_foobarbaz2345=== RUN TestGlobMatch/*/*_foo/bar2346=== PAUSE TestGlobMatch/*/*_foo/bar2347=== RUN TestGlobMatch/*/*_foo2348=== PAUSE TestGlobMatch/*/*_foo2349=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2350=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2351=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02352=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02353=== RUN TestGlobMatch/refs/*/main_refs/heads/main2354=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2355=== RUN TestGlobMatch/fo?_foo2356=== PAUSE TestGlobMatch/fo?_foo2357=== RUN TestGlobMatch/fo?_fo2358=== PAUSE TestGlobMatch/fo?_fo2359=== RUN TestGlobMatch/fo?_fooo2360=== PAUSE TestGlobMatch/fo?_fooo2361=== RUN TestGlobMatch/?oo_foo2362=== PAUSE TestGlobMatch/?oo_foo2363=== RUN TestGlobMatch/?oo_boo2364=== PAUSE TestGlobMatch/?oo_boo2365=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2366=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2367=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2368=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2369=== CONT TestGlobMatch/*_2370=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2371=== CONT TestGlobMatch/?oo_foo2372=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2373=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2374=== CONT TestGlobMatch/foo*bar_foo123bar2375=== CONT TestGlobMatch/?oo_boo2376=== CONT TestGlobMatch/fo?_fooo2377=== CONT TestGlobMatch/foo*_bar2378=== CONT TestGlobMatch/fo?_fo2379=== CONT TestGlobMatch/fo?_foo2380=== CONT TestGlobMatch/*_anything2381=== CONT TestGlobMatch/refs/*/main_refs/heads/main2382=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02383=== CONT TestGlobMatch/*bar_foo2384=== CONT TestGlobMatch/foo*bar_foobarbaz2385=== CONT TestGlobMatch/*bar_bar2386=== CONT TestGlobMatch/foo*_foobar2387=== CONT TestGlobMatch/foo*bar_foobar2388=== CONT TestGlobMatch/*bar_foobar2389=== CONT TestGlobMatch/foo*_foo2390=== CONT TestGlobMatch/foo_foo2391=== CONT TestGlobMatch/*/*_foo/bar2392=== CONT TestGlobMatch/foo_bar2393=== CONT TestGlobMatch/*/*_foo2394--- PASS: TestGlobMatch (0.01s)2395 --- PASS: TestGlobMatch/*_ (0.00s)2396 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2397 --- PASS: TestGlobMatch/?oo_foo (0.00s)2398 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2399 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2400 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2401 --- PASS: TestGlobMatch/?oo_boo (0.00s)2402 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2403 --- PASS: TestGlobMatch/foo*_bar (0.00s)2404 --- PASS: TestGlobMatch/fo?_fo (0.00s)2405 --- PASS: TestGlobMatch/fo?_foo (0.00s)2406 --- PASS: TestGlobMatch/*_anything (0.00s)2407 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2409 --- PASS: TestGlobMatch/*bar_foo (0.00s)2410 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2411 --- PASS: TestGlobMatch/*bar_bar (0.00s)2412 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2414 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/foo*_foo (0.00s)2416 --- PASS: TestGlobMatch/foo_foo (0.00s)2417 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2418 --- PASS: TestGlobMatch/foo_bar (0.00s)2419 --- PASS: TestGlobMatch/*/*_foo (0.00s)24202026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33537/oidc2421--- PASS: TestValidateToken_Expired (0.05s)24222026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34319/oidc2423--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)24242026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33623/oidc2425--- PASS: TestValidateToken_WrongAudience (0.06s)24262026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44995/oidc24272026/10/02 20:38:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324282026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42059/oidc24292026/10/02 20:38:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:350992430--- PASS: TestScopes_Rules (0.09s)2431--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2432--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)2433--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)24342026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44077/oidc2435--- PASS: TestPins_ReservedForMatchingRule (0.11s)24362026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35499/oidc2437--- PASS: TestValidateToken_ValidToken (0.12s)24382026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39359/oidc24392026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38339/oidc2440--- PASS: TestPins_TopLevelShorthand (0.15s)2441--- PASS: TestValidateToken_BoundClaimsMismatch (0.16s)24422026/10/02 20:38:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39253/oidc2443--- PASS: TestValidateToken_NoMatchingProvider (0.18s)24442026/10/02 20:38:21 http: TLS handshake error from 127.0.0.1:40424: remote error: tls: bad certificate2445--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)2446--- PASS: TestHTTPClientForHasTimeouts (0.20s)24472026/10/02 20:38:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41269/oidc24482026/10/02 20:38:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40487/oidc2449--- PASS: TestValidateToken_MultipleProviders (0.40s)2450PASS2451Running signing tests...2452=== RUN TestGenerateFingerprint2453=== PAUSE TestGenerateFingerprint2454=== RUN TestParseSigningKey2455=== PAUSE TestParseSigningKey2456=== RUN TestSignMessage2457=== PAUSE TestSignMessage2458=== RUN TestSignNarinfo2459=== PAUSE TestSignNarinfo2460=== CONT TestGenerateFingerprint2461=== CONT TestSignNarinfo2462=== CONT TestParseSigningKey2463=== CONT TestSignMessage2464=== RUN TestGenerateFingerprint/basic_with_references2465=== RUN TestParseSigningKey/valid_32-byte_key2466=== PAUSE TestParseSigningKey/valid_32-byte_key2467=== PAUSE TestGenerateFingerprint/basic_with_references2468=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2469=== RUN TestGenerateFingerprint/no_references2470=== PAUSE TestGenerateFingerprint/no_references2471=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2472=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2473=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2474=== RUN TestParseSigningKey/no_colon2475=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2476=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2477=== PAUSE TestParseSigningKey/no_colon2478=== RUN TestGenerateFingerprint/invalid_nar_hash_length2479=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2480=== RUN TestParseSigningKey/empty_name2481=== PAUSE TestParseSigningKey/empty_name2482=== RUN TestGenerateFingerprint/invalid_store_path_prefix2483=== RUN TestParseSigningKey/invalid_base642484=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2485=== PAUSE TestParseSigningKey/invalid_base642486=== RUN TestGenerateFingerprint/invalid_reference_prefix2487=== RUN TestParseSigningKey/wrong_length2488=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2489=== PAUSE TestParseSigningKey/wrong_length2490=== CONT TestGenerateFingerprint/invalid_reference_prefix2491=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2492=== CONT TestGenerateFingerprint/invalid_nar_hash_length2493=== CONT TestGenerateFingerprint/basic_with_references2494=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2495=== CONT TestParseSigningKey/empty_name2496=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2497=== CONT TestGenerateFingerprint/no_references2498=== CONT TestParseSigningKey/no_colon2499=== CONT TestParseSigningKey/wrong_length2500=== CONT TestParseSigningKey/invalid_base642501=== CONT TestParseSigningKey/valid_32-byte_key2502=== CONT TestGenerateFingerprint/invalid_store_path_prefix2503--- PASS: TestSignMessage (0.00s)2504--- PASS: TestGenerateFingerprint (0.00s)2505 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2506 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2507 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2508 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2509 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2510 --- PASS: TestGenerateFingerprint/no_references (0.00s)2511 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2512--- PASS: TestParseSigningKey (0.00s)2513 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2514 --- PASS: TestParseSigningKey/empty_name (0.00s)2515 --- PASS: TestParseSigningKey/no_colon (0.00s)2516 --- PASS: TestParseSigningKey/wrong_length (0.00s)2517 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2518 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2519--- PASS: TestSignNarinfo (0.01s)2520PASS2521Running hook tests...2522=== RUN TestSendPathsEmpty2523=== PAUSE TestSendPathsEmpty2524=== RUN TestQueueEnqueueAndFetch2525=== PAUSE TestQueueEnqueueAndFetch2526=== RUN TestQueueDeduplication2527=== PAUSE TestQueueDeduplication2528=== RUN TestQueueRemove2529=== PAUSE TestQueueRemove2530=== RUN TestQueueFetchBatchLimit2531=== PAUSE TestQueueFetchBatchLimit2532=== RUN TestQueueRetryMovesToBack2533=== PAUSE TestQueueRetryMovesToBack2534=== RUN TestQueueFetchRemoveLifecycle2535=== PAUSE TestQueueFetchRemoveLifecycle2536=== RUN TestQueueConcurrentWriters2537=== PAUSE TestQueueConcurrentWriters2538=== RUN TestQueueEnqueueWaitsOutSlowWriter2539=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2540=== RUN TestQueueRemoveLargeClosure2541=== PAUSE TestQueueRemoveLargeClosure2542=== RUN TestServerClientIntegration2543=== PAUSE TestServerClientIntegration2544=== RUN TestServerQueueError2545=== PAUSE TestServerQueueError2546=== RUN TestServerRefusesOversizedAndNonStoreRequests2547=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2548=== RUN TestGetListenerSocketActivation2549 server_test.go:317: === RUN TestGetListenerSocketActivation2550 --- PASS: TestGetListenerSocketActivation (0.00s)2551 PASS2552 2553--- PASS: TestGetListenerSocketActivation (1.02s)2554=== RUN TestServerStalledClientDoesNotBlockShutdown2555=== PAUSE TestServerStalledClientDoesNotBlockShutdown2556=== RUN TestServerBacksOffOnAcceptErrors2557=== PAUSE TestServerBacksOffOnAcceptErrors2558=== RUN TestDrainIsolatesPoisonPath2559=== PAUSE TestDrainIsolatesPoisonPath2560=== RUN TestRunNotBlockedByPoisonHead2561=== PAUSE TestRunNotBlockedByPoisonHead2562=== RUN TestDrainGivesUpWhenServerDown2563=== PAUSE TestDrainGivesUpWhenServerDown2564=== RUN TestFailedPathPrunedByLaterClosure2565=== PAUSE TestFailedPathPrunedByLaterClosure2566=== RUN TestWorkerUploadsAndRemoves2567=== PAUSE TestWorkerUploadsAndRemoves2568=== RUN TestWorkerSkipsGCdPaths2569=== PAUSE TestWorkerSkipsGCdPaths2570=== RUN TestWorkerPrunesClosureDeps2571=== PAUSE TestWorkerPrunesClosureDeps2572=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2573=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2574=== RUN TestDrainTimeout2575=== PAUSE TestDrainTimeout2576=== RUN TestDrainTimeoutDuringIsolation2577=== PAUSE TestDrainTimeoutDuringIsolation2578=== RUN TestShutdownFinishesInFlightPush2579=== PAUSE TestShutdownFinishesInFlightPush2580=== RUN TestWorkerRemoveFailureIsNotProgress2581=== PAUSE TestWorkerRemoveFailureIsNotProgress2582=== RUN TestWorkerKeepsPathItCannotStat2583=== PAUSE TestWorkerKeepsPathItCannotStat2584=== CONT TestSendPathsEmpty2585=== CONT TestServerBacksOffOnAcceptErrors2586=== CONT TestWorkerSkipsGCdPaths2587--- PASS: TestSendPathsEmpty (0.00s)2588=== CONT TestServerRefusesOversizedAndNonStoreRequests25892026/10/02 20:38:24 ERROR Accept failed error="too many open files"2590=== CONT TestServerClientIntegration2591=== CONT TestShutdownFinishesInFlightPush2592=== RUN TestShutdownFinishesInFlightPush/completes2593=== CONT TestQueueRemoveLargeClosure25942026/10/02 20:38:24 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2595=== CONT TestQueueEnqueueWaitsOutSlowWriter2596=== CONT TestDrainTimeoutDuringIsolation2597=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short25982026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store store=/nix/store2599=== CONT TestQueueConcurrentWriters2600=== CONT TestDrainTimeout2601=== CONT TestQueueEnqueueAndFetch2602=== CONT TestQueueRemove2603=== CONT TestWorkerRemoveFailureIsNotProgress26042026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2605=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2606--- PASS: TestServerClientIntegration (0.00s)2607=== CONT TestWorkerKeepsPathItCannotStat2608=== CONT TestServerStalledClientDoesNotBlockShutdown2609=== CONT TestWorkerPrunesClosureDeps2610=== CONT TestFailedPathPrunedByLaterClosure2611=== CONT TestDrainIsolatesPoisonPath2612=== CONT TestQueueFetchRemoveLifecycle2613=== CONT TestWorkerUploadsAndRemoves2614=== CONT TestServerQueueError26152026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2616=== CONT TestQueueRetryMovesToBack2617=== CONT TestDrainGivesUpWhenServerDown2618=== PAUSE TestShutdownFinishesInFlightPush/completes2619=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2620=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2621=== CONT TestQueueFetchBatchLimit2622=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26232026/10/02 20:38:24 ERROR Accept failed error="too many open files"2624=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path26252026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2626=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2627=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2628=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2629=== CONT TestRunNotBlockedByPoisonHead26302026/10/02 20:38:24 ERROR Failed to queue paths error="permission denied" count=126312026/10/02 20:38:24 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2632=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2633=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26342026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2635--- PASS: TestServerQueueError (0.00s)2636=== CONT TestQueueDeduplication2637=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2638=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths26392026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store2640=== CONT TestShutdownFinishesInFlightPush/completes2641=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26422026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26432026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26442026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26452026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26462026/10/02 20:38:24 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26472026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26482026/10/02 20:38:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26492026/10/02 20:38:24 ERROR Failed to decode request error="unexpected EOF"2650--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.02s)2651=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26522026/10/02 20:38:24 ERROR Accept failed error="too many open files"26532026/10/02 20:38:24 ERROR Accept failed error="too many open files"26542026/10/02 20:38:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa: permission denied"26552026/10/02 20:38:24 INFO Upload queue status pending=226562026/10/02 20:38:24 INFO Uploading batch count=226572026/10/02 20:38:24 INFO Uploading batch count=426582026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=42659=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2660--- PASS: TestQueueEnqueueAndFetch (0.07s)26612026/10/02 20:38:24 INFO Uploading batch count=226622026/10/02 20:38:24 INFO Upload queue status pending=226632026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2528995059/002/bbb26642026/10/02 20:38:24 INFO Upload queue status pending=326652026/10/02 20:38:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa: permission denied"26662026/10/02 20:38:24 INFO Upload queue status pending=226672026/10/02 20:38:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2913941567/002/nonexistent26682026/10/02 20:38:24 ERROR Accept failed error="too many open files"26692026/10/02 20:38:24 INFO Upload queue status pending=326702026/10/02 20:38:24 INFO Uploading batch count=226712026/10/02 20:38:24 INFO Uploading batch count=426722026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=42673--- PASS: TestQueueDeduplication (0.07s)2674=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path26752026/10/02 20:38:24 INFO Upload queue status pending=226762026/10/02 20:38:24 INFO Uploading batch count=126772026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=126782026/10/02 20:38:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1382554221/002/locked/aaa: permission denied"26792026/10/02 20:38:24 INFO Uploading batch count=126802026/10/02 20:38:24 INFO Upload queue status pending=226812026/10/02 20:38:24 INFO Uploading batch count=226822026/10/02 20:38:24 INFO Uploading batch count=126832026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=12684=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26852026/10/02 20:38:24 INFO Uploading batch count=22686--- PASS: TestQueueRemove (0.08s)26872026/10/02 20:38:24 INFO Uploading batch count=22688--- PASS: TestQueueRetryMovesToBack (0.08s)26892026/10/02 20:38:24 INFO Uploading batch count=12690=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26912026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=126922026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=126932026/10/02 20:38:24 INFO Uploading batch count=12694--- PASS: TestQueueFetchRemoveLifecycle (0.08s)26952026/10/02 20:38:24 INFO Uploading batch count=226962026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=22697--- PASS: TestQueueFetchBatchLimit (0.08s)26982026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/a26992026/10/02 20:38:24 INFO Uploading batch count=127002026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=127012026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/b27022026/10/02 20:38:24 INFO Uploading batch count=127032026/10/02 20:38:24 INFO Uploading batch count=227042026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=227052026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/c2706--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)2707--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)27082026/10/02 20:38:24 INFO Uploading batch count=127092026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=127102026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/d27112026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=12712--- PASS: TestWorkerPrunesClosureDeps (0.10s)2713--- PASS: TestWorkerSkipsGCdPaths (0.10s)2714--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)27152026/10/02 20:38:24 INFO Uploading batch count=227162026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=22717--- PASS: TestWorkerUploadsAndRemoves (0.10s)27182026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/e27192026/10/02 20:38:24 INFO Uploading batch count=427202026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=42721--- PASS: TestDrainIsolatesPoisonPath (0.10s)27222026/10/02 20:38:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2282021102/002/f27232026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=1027242026/10/02 20:38:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1867606321/001/nonexistent27252026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12726--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27272026/10/02 20:38:24 INFO Uploading batch count=227282026/10/02 20:38:24 INFO Uploading batch count=227292026/10/02 20:38:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1867606321/001/nonexistent27302026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=227312026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227322026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127332026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127342026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127352026/10/02 20:38:24 INFO Uploading batch count=227362026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=227372026/10/02 20:38:24 INFO Uploading batch count=227382026/10/02 20:38:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1867606321/001/nonexistent27392026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127402026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127412026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227422026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127432026/10/02 20:38:24 INFO Uploading batch count=227442026/10/02 20:38:24 ERROR Upload failed error="upload failed" count=227452026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127462026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=127472026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/02 20:38:24 INFO Uploading batch count=227492026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=227502026/10/02 20:38:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227512026/10/02 20:38:24 ERROR Drain finished with paths left in queue remaining=22752--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2753 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)2754 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2755 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)27562026/10/02 20:38:24 ERROR Accept failed error="too many open files"27572026/10/02 20:38:24 ERROR Failed to decode request error="read unix /build/hook2520980973/test.sock->@: i/o timeout"27582026/10/02 20:38:24 ERROR Failed to write response error="write unix /build/hook2520980973/test.sock->@: i/o timeout"2759--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27602026/10/02 20:38:25 ERROR Upload failed error="context canceled" count=227612026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=42762--- PASS: TestDrainTimeout (0.27s)27632026/10/02 20:38:25 ERROR Upload failed error="context canceled" count=227642026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=22765--- PASS: TestShutdownFinishesInFlightPush (0.00s)2766 --- PASS: TestShutdownFinishesInFlightPush/completes (0.18s)2767 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.28s)27682026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=427692026/10/02 20:38:25 ERROR Accept failed error="too many open files"27702026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=32771--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2772 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.24s)2773 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)27742026/10/02 20:38:25 ERROR Accept failed error="too many open files"2775--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2776--- PASS: TestQueueConcurrentWriters (0.72s)27772026/10/02 20:38:25 INFO Uploading batch count=127782026/10/02 20:38:25 INFO Uploading batch count=127792026/10/02 20:38:25 INFO Uploading batch count=127802026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127812026/10/02 20:38:25 INFO Uploading batch count=127822026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127832026/10/02 20:38:25 INFO Uploading batch count=127842026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127852026/10/02 20:38:25 INFO Uploading batch count=127862026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127872026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=12788--- PASS: TestRunNotBlockedByPoisonHead (1.12s)2789--- PASS: TestQueueRemoveLargeClosure (2.17s)2790--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2791PASS2792Running niks3-hook command tests...2793=== RUN TestServeSecondSignalEndsDrain2794=== PAUSE TestServeSecondSignalEndsDrain2795=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2796=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2797=== CONT TestServeSecondSignalEndsDrain2798=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2799--- PASS: TestServeSecondSignalEndsDrain (0.08s)28002026/10/02 20:38:31 INFO Upload queue status pending=128012026/10/02 20:38:31 INFO Uploading batch count=12802--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2803PASS2804Running rate limiter tests...2805=== RUN TestAdaptiveRateLimiter_ThreadSafety2806=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2807=== CONT TestAdaptiveRateLimiter_ThreadSafety28082026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=7028092026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=4928102026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=34.328112026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=24.00999999999999828122026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=16.80728132026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=11.76489999999999928142026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=8.2354328152026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.76480099999999928162026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528172026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528182026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528192026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528202026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528212026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528222026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528232026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528242026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528252026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528262026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528272026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528282026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528292026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528302026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528312026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528322026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528332026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528342026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528352026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=9.07809861035000628362026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=6.35466902724500428372026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528382026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528392026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528402026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528412026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528422026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528432026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528442026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528452026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528462026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528472026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.12435000000000128482026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528492026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528502026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528512026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528522026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528532026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528542026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528552026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528562026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528572026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528582026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528592026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528602026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528612026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528622026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528632026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528642026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528652026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528662026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528672026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528682026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528692026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528702026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528712026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528722026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528732026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528742026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528752026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528762026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528772026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528782026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528792026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528802026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.12435000000000128812026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528822026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528832026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528842026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528852026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528862026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528872026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.12435000000000128882026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528892026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528902026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528912026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528922026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.63678500000000128932026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528942026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528952026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528962026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528972026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528982026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528992026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529002026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529012026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529022026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529032026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529042026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529052026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=8.25281691850000429062026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.77697184295000329072026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=52908--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.09s)2909PASS