niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #272
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry5=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry6=== RUN TestRegisterUploadedObjectReusesConnections7=== PAUSE TestRegisterUploadedObjectReusesConnections8=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica9=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica10=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun11=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun12=== RUN TestCaseHackSuffix13=== PAUSE TestCaseHackSuffix14=== RUN TestFilterOversizedClosures15=== PAUSE TestFilterOversizedClosures16=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure17=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== RUN TestUploadMultipart_PartsInParallel19=== PAUSE TestUploadMultipart_PartsInParallel20=== RUN TestUploadMultipart_ProducerErrorIsNotEOF21=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF22=== RUN TestUploadMultipart_FailedPartBufferNotReused23=== PAUSE TestUploadMultipart_FailedPartBufferNotReused24=== RUN TestPartSizeForNAR25=== PAUSE TestPartSizeForNAR26=== RUN TestUploadMultipart_SupersededByPeer27=== PAUSE TestUploadMultipart_SupersededByPeer28=== RUN TestDumpPathCaseHackMatchesNix29--- PASS: TestDumpPathCaseHackMatchesNix (0.22s)30=== RUN TestDumpPathCaseHackCollision31--- PASS: TestDumpPathCaseHackCollision (0.00s)32=== RUN TestSupersededNARStillUploadsListing33=== PAUSE TestSupersededNARStillUploadsListing34=== RUN TestTruncatedNARDumpIsNotCompleted35=== PAUSE TestTruncatedNARDumpIsNotCompleted36=== RUN TestDumpPathMatchesNix37=== PAUSE TestDumpPathMatchesNix38=== RUN TestDumpPathSingleFile39=== PAUSE TestDumpPathSingleFile40=== RUN TestDumpPathWriterError41=== PAUSE TestDumpPathWriterError42=== RUN TestDumpPathWriterErrorStopsReading43 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory44--- SKIP: TestDumpPathWriterErrorStopsReading (0.38s)45=== RUN TestEncodeNixBase3246=== PAUSE TestEncodeNixBase3247=== RUN TestEncodeNixBase32WithRealHash48=== PAUSE TestEncodeNixBase32WithRealHash49=== RUN TestConvertHashToNix3250=== PAUSE TestConvertHashToNix3251=== RUN TestGetStorePathHash52=== PAUSE TestGetStorePathHash53=== RUN TestPathInfoHashCompatibility54=== PAUSE TestPathInfoHashCompatibility55=== RUN TestParsePathInfoJSON56=== PAUSE TestParsePathInfoJSON57=== RUN TestParsePathInfoJSONMultiplePaths58=== PAUSE TestParsePathInfoJSONMultiplePaths59=== RUN TestPathInfoCACompatibility60=== PAUSE TestPathInfoCACompatibility61=== RUN TestUploadPendingObjectsStopsStartingAfterFailure62--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.01s)63=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent64=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== RUN TestCompletePendingClosure_NotFoundWithoutKey66=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey67=== RUN TestRateLimiterFeedback68=== PAUSE TestRateLimiterFeedback69=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess70=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer72=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer73=== RUN TestResolveStorePath74=== PAUSE TestResolveStorePath75=== RUN TestDoWithRetry_BodyReplayedViaGetBody76=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody77=== RUN TestDoWithRetry_FinalResponseBodyReadable78=== PAUSE TestDoWithRetry_FinalResponseBodyReadable79=== RUN TestShellSplit80=== PAUSE TestShellSplit81=== RUN TestShellSplitErrors82=== PAUSE TestShellSplitErrors83=== RUN TestStreamPushReportsEveryPath84=== PAUSE TestStreamPushReportsEveryPath85=== RUN TestStreamPushBatchesUnderLoad86=== PAUSE TestStreamPushBatchesUnderLoad87=== RUN TestStreamPushIsolatesFailures88=== PAUSE TestStreamPushIsolatesFailures89=== RUN TestStreamPushGivesUpOnDeadServer90=== PAUSE TestStreamPushGivesUpOnDeadServer91=== RUN TestStreamPushRequestLine92=== PAUSE TestStreamPushRequestLine93=== RUN TestStreamPushReportsSignatures94=== PAUSE TestStreamPushReportsSignatures95=== RUN TestClientSignaturesByStorePath96=== PAUSE TestClientSignaturesByStorePath97=== RUN TestStreamPushStopsOnCancel98=== PAUSE TestStreamPushStopsOnCancel99=== RUN TestSetClientTLS100=== PAUSE TestSetClientTLS101=== RUN TestSetClientTLSDoesNotMutateDefaultTransport102=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport103=== RUN TestSetClientTLSErrors104=== PAUSE TestSetClientTLSErrors105=== RUN TestStaticToken106=== PAUSE TestStaticToken107=== RUN TestFileTokenReadsAndCaches108=== PAUSE TestFileTokenReadsAndCaches109=== RUN TestFileTokenMissing110=== PAUSE TestFileTokenMissing111=== RUN TestFileTokenEmpty112=== PAUSE TestFileTokenEmpty113=== RUN TestScriptTokenNoExpiryRerunsEveryCall114=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall115=== RUN TestScriptTokenCachesUntilRefresh116=== PAUSE TestScriptTokenCachesUntilRefresh117=== RUN TestScriptTokenEmptyToken118=== PAUSE TestScriptTokenEmptyToken119=== RUN TestScriptTokenBadJSON120=== PAUSE TestScriptTokenBadJSON121=== RUN TestScriptTokenScriptFails122=== PAUSE TestScriptTokenScriptFails123=== RUN TestScriptTokenEmptyCommand124=== PAUSE TestScriptTokenEmptyCommand125=== RUN TestScriptTokenDoesNotWaitForItsChildren126=== PAUSE TestScriptTokenDoesNotWaitForItsChildren127=== CONT TestCompletePendingClosure_NotFoundWithoutKey128=== CONT TestRegisterUploadedObjectReusesConnections129=== CONT TestRateLimiterFeedback130=== RUN TestRateLimiterFeedback/429_enables_limiter131=== PAUSE TestRateLimiterFeedback/429_enables_limiter132=== RUN TestRateLimiterFeedback/503_enables_limiter133=== CONT TestSupersededNARStillUploadsListing134=== RUN TestSupersededNARStillUploadsListing/small_NAR135=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess136=== PAUSE TestRateLimiterFeedback/503_enables_limiter137=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter138=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter139=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter140=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter141=== CONT TestGetStorePathHash142=== RUN TestGetStorePathHash/valid_store_path143=== CONT TestPathInfoCACompatibility144=== RUN TestPathInfoCACompatibility/null_ca_field145=== PAUSE TestPathInfoCACompatibility/null_ca_field146=== CONT TestParsePathInfoJSONMultiplePaths147=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths149=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths150=== CONT TestParsePathInfoJSON151=== RUN TestPathInfoCACompatibility/old_string_format_-_text152=== RUN TestParsePathInfoJSON/Nix_format153=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text154=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent155=== CONT TestPathInfoHashCompatibility156=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive157=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== PAUSE TestGetStorePathHash/valid_store_path160=== PAUSE TestParsePathInfoJSON/Nix_format161=== PAUSE TestSupersededNARStillUploadsListing/small_NAR162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== RUN TestSupersededNARStillUploadsListing/dump_cut_short164=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short166=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error167=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier170=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier171=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up172=== RUN TestParsePathInfoJSON/Lix_format173=== CONT TestEncodeNixBase32WithRealHash174--- PASS: TestEncodeNixBase32WithRealHash (0.00s)175--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)176=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up177=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error178=== CONT TestEncodeNixBase32179=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails180=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error181=== CONT TestDumpPathWriterError182=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error183=== RUN TestEncodeNixBase32/test_string_hash184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon186=== CONT TestDumpPathSingleFile187=== CONT TestDumpPathMatchesNix188=== PAUSE TestEncodeNixBase32/test_string_hash189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== RUN TestEncodeNixBase32/empty_input191=== PAUSE TestEncodeNixBase32/empty_input192=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== CONT TestConvertHashToNix32194=== CONT TestFileTokenEmpty195=== RUN TestConvertHashToNix32/SRI_format_to_Nix32196=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32197=== RUN TestConvertHashToNix32/already_Nix32_format198=== PAUSE TestConvertHashToNix32/already_Nix32_format199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI200=== RUN TestPathInfoCACompatibility/new_structured_format_-_text201=== PAUSE TestParsePathInfoJSON/Lix_format202=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text203=== RUN TestParsePathInfoJSON/empty_input204=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method205=== PAUSE TestParsePathInfoJSON/empty_input206=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512207=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512208=== RUN TestParsePathInfoJSON/whitespace_only209=== CONT TestScriptTokenEmptyCommand210=== PAUSE TestParsePathInfoJSON/whitespace_only211=== RUN TestParsePathInfoJSON/invalid_JSON212=== PAUSE TestParsePathInfoJSON/invalid_JSON213--- PASS: TestFileTokenEmpty (0.00s)214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== CONT TestScriptTokenDoesNotWaitForItsChildren216=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs217=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs218=== CONT TestScriptTokenBadJSON219--- PASS: TestScriptTokenEmptyCommand (0.00s)220=== RUN TestConvertHashToNix32/invalid_format221=== PAUSE TestConvertHashToNix32/invalid_format222=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout223=== CONT TestScriptTokenCachesUntilRefresh224=== CONT TestScriptTokenScriptFails225=== CONT TestScriptTokenNoExpiryRerunsEveryCall226=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout227=== CONT TestStreamPushStopsOnCancel228=== RUN TestStreamPushStopsOnCancel/waiting_for_input229=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input230=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot231=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot232=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot233=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot234=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot235=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot236=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot237=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot238=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken239=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken240=== CONT TestFileTokenMissing241--- PASS: TestFileTokenMissing (0.00s)242=== CONT TestScriptTokenEmptyToken243--- PASS: TestScriptTokenScriptFails (0.01s)244=== CONT TestStaticToken245--- PASS: TestStaticToken (0.00s)246=== CONT TestSetClientTLSDoesNotMutateDefaultTransport247--- PASS: TestScriptTokenBadJSON (0.01s)248=== CONT TestSetClientTLSErrors249=== RUN TestSetClientTLSErrors/missing_cert_file250=== PAUSE TestSetClientTLSErrors/missing_cert_file251=== RUN TestSetClientTLSErrors/missing_key_file252=== PAUSE TestSetClientTLSErrors/missing_key_file253--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)254=== RUN TestSetClientTLSErrors/missing_ca_file255=== PAUSE TestSetClientTLSErrors/missing_ca_file256=== RUN TestSetClientTLSErrors/invalid_ca_file257=== PAUSE TestSetClientTLSErrors/invalid_ca_file258=== CONT TestFileTokenReadsAndCaches259--- PASS: TestScriptTokenEmptyToken (0.02s)260=== CONT TestTruncatedNARDumpIsNotCompleted261--- PASS: TestFileTokenReadsAndCaches (0.00s)262=== CONT TestFilterOversizedClosures263=== CONT TestPartSizeForNAR264=== RUN TestFilterOversizedClosures/no_limit_keeps_everything265=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything266=== RUN TestPartSizeForNAR/zero_stays_at_minimum267=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum268=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped269=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped270=== RUN TestPartSizeForNAR/small_stays_at_minimum271=== PAUSE TestPartSizeForNAR/small_stays_at_minimum272=== RUN TestFilterOversizedClosures/all_closures_skipped273=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum274=== PAUSE TestFilterOversizedClosures/all_closures_skipped275=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum276=== CONT TestUploadMultipart_SupersededByPeer277=== RUN TestUploadMultipart_SupersededByPeer/exists278=== PAUSE TestUploadMultipart_SupersededByPeer/exists279=== RUN TestUploadMultipart_SupersededByPeer/missing280=== PAUSE TestUploadMultipart_SupersededByPeer/missing281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== CONT TestStreamPushBatchesUnderLoad285=== RUN TestStreamPushBatchesUnderLoad/together286=== PAUSE TestStreamPushBatchesUnderLoad/together287=== PAUSE TestPartSizeForNAR/1_TiB288=== RUN TestPartSizeForNAR/5_TiB_S3_max_object289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time291=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time292=== RUN TestPartSizeForNAR/capped_at_5_GiB293=== PAUSE TestPartSizeForNAR/capped_at_5_GiB294=== CONT TestUploadMultipart_FailedPartBufferNotReused295=== CONT TestSetClientTLS296=== RUN TestSetClientTLS/rejects_connection_without_client_cert297=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert298=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA299=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA300=== RUN TestSetClientTLS/preserves_debug_logging_transport301=== PAUSE TestSetClientTLS/preserves_debug_logging_transport302=== CONT TestClientSignaturesByStorePath303--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)304=== CONT TestStreamPushRequestLine305--- PASS: TestClientSignaturesByStorePath (0.00s)306=== CONT TestStreamPushReportsSignatures307--- PASS: TestStreamPushReportsSignatures (0.00s)308=== CONT TestUploadMultipart_PartsInParallel309--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)310=== CONT TestStreamPushIsolatesFailures311--- PASS: TestStreamPushIsolatesFailures (0.00s)312=== CONT TestStreamPushGivesUpOnDeadServer313--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)314=== CONT TestShellSplit315=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure316--- PASS: TestShellSplit (0.00s)317--- PASS: TestDumpPathSingleFile (0.07s)318=== CONT TestStreamPushReportsEveryPath319--- PASS: TestStreamPushReportsEveryPath (0.00s)320=== CONT TestShellSplitErrors321--- PASS: TestShellSplitErrors (0.00s)322=== CONT TestDoServerRequestAttachesToken323--- PASS: TestDumpPathWriterError (0.07s)324=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica325--- PASS: TestDoServerRequestAttachesToken (0.00s)326=== CONT TestDoWithRetry_BodyReplayedViaGetBody327--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)328=== CONT TestResolveStorePath329--- PASS: TestResolveStorePath (0.00s)330=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry331--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)332=== CONT TestCaseHackSuffix333=== CONT TestDoWithRetry_FinalResponseBodyReadable334--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)335--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)336=== CONT TestUploadMultipart_ProducerErrorIsNotEOF337=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part338=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part339=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary340=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary341=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun342--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)343=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer344--- PASS: TestDumpPathMatchesNix (0.12s)345=== CONT TestRateLimiterFeedback/429_enables_limiter346=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter347=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter348=== CONT TestRateLimiterFeedback/503_enables_limiter349=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths350=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths351--- PASS: TestRateLimiterFeedback (0.00s)352 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)353 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier357--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)358 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)359 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)360=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up361=== CONT TestSupersededNARStillUploadsListing/small_NAR362--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)363 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)364 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)365=== CONT TestGetStorePathHash/valid_store_path366=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error367=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error368=== CONT TestGetStorePathHash/basename_without_hyphen_should_error369--- PASS: TestGetStorePathHash (0.00s)370 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)371 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)372 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)373 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)374=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails375--- PASS: TestStreamPushRequestLine (0.10s)376=== CONT TestSupersededNARStillUploadsListing/dump_cut_short377=== CONT TestEncodeNixBase32/empty_input378=== CONT TestEncodeNixBase32/test_string_hash379=== CONT TestParsePathInfoJSON/Nix_format380--- PASS: TestEncodeNixBase32 (0.01s)381 --- PASS: TestEncodeNixBase32/empty_input (0.00s)382 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)383=== CONT TestParsePathInfoJSON/Lix_format384--- PASS: TestCaseHackSuffix (0.08s)385=== CONT TestParsePathInfoJSON/empty_input386=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)387=== CONT TestPathInfoCACompatibility/null_ca_field388=== CONT TestConvertHashToNix32/already_Nix32_format389=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512390=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI391=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive392=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon393=== CONT TestPathInfoCACompatibility/new_structured_format_-_text394=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method395--- PASS: TestPathInfoHashCompatibility (0.01s)396 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)397 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)398 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)399 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)400=== CONT TestPathInfoCACompatibility/old_string_format_-_text401=== CONT TestParsePathInfoJSON/whitespace_only402=== CONT TestConvertHashToNix32/invalid_format403=== CONT TestConvertHashToNix32/SRI_format_to_Nix32404=== CONT TestParsePathInfoJSON/invalid_JSON405--- PASS: TestParsePathInfoJSON (0.01s)406 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)407 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)408 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)409 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)410 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)411--- PASS: TestConvertHashToNix32 (0.00s)412 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)413 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)414 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)415=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout416=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs417--- PASS: TestPathInfoCACompatibility (0.01s)418 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)419 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)420 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)421 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)422 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)423--- PASS: TestRegisterUploadedObjectReusesConnections (0.23s)424=== CONT TestStreamPushStopsOnCancel/waiting_for_input425--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.17s)426=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot427=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot428=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken429--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.20s)430=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot431=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot432=== CONT TestSetClientTLSErrors/invalid_ca_file433=== CONT TestSetClientTLSErrors/missing_key_file434=== CONT TestSetClientTLSErrors/missing_ca_file435=== CONT TestSetClientTLSErrors/missing_cert_file436=== CONT TestFilterOversizedClosures/no_limit_keeps_everything437=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped438=== CONT TestFilterOversizedClosures/all_closures_skipped439--- PASS: TestFilterOversizedClosures (0.00s)440 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)441 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)442 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)443=== CONT TestUploadMultipart_SupersededByPeer/exists444--- PASS: TestSetClientTLSErrors (0.01s)445 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)446 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)447 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)448 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)449=== CONT TestUploadMultipart_SupersededByPeer/missing450=== CONT TestStreamPushBatchesUnderLoad/together451--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)452 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)453 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)454=== CONT TestPartSizeForNAR/small_stays_at_minimum455=== CONT TestPartSizeForNAR/5_TiB_S3_max_object456=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time457=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum458=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts459--- PASS: TestStreamPushStopsOnCancel (0.00s)460 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)461 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)462 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)463 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)464 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)465 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)466=== CONT TestPartSizeForNAR/1_TiB467=== CONT TestPartSizeForNAR/zero_stays_at_minimum468=== CONT TestPartSizeForNAR/capped_at_5_GiB469=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA470--- PASS: TestPartSizeForNAR (0.00s)471 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)472 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)473 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)474 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)475 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)476 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)477 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)478=== CONT TestSetClientTLS/preserves_debug_logging_transport479=== CONT TestSetClientTLS/rejects_connection_without_client_cert480=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part481--- PASS: TestSetClientTLS (0.00s)482 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)483 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)484 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)485--- PASS: TestTruncatedNARDumpIsNotCompleted (0.38s)486=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary487--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)488 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.02s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.03s)490--- PASS: TestStreamPushBatchesUnderLoad (0.00s)491 --- PASS: TestStreamPushBatchesUnderLoad/together (0.10s)492 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.17s)493--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.66s)494--- PASS: TestUploadMultipart_PartsInParallel (0.69s)495--- PASS: TestSupersededNARStillUploadsListing (0.00s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)497 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)498 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.60s)499--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)500--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)501 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.21s)503PASS504Running server tests...505The files belonging to this database system will be owned by user "_nixbld1".506This user must also own the server process.507508The database cluster will be initialized with locale "C".509The default database encoding has accordingly been set to "SQL_ASCII".510The default text search configuration will be set to "english".511512Data page checksums are enabled.513514creating directory /nix/var/nix/builds/nix-11432-1070387528/postgres4272606229/data ... ok515creating subdirectories ... ok516selecting dynamic shared memory implementation ... posix517selecting default "max_connections" ... 100518selecting default "shared_buffers" ... 128MB519selecting default time zone ... UTC520creating configuration files ... ok521running bootstrap script ... ok522performing post-bootstrap initialization ... ok523syncing data to disk ... ok524525initdb: warning: enabling "trust" authentication for local connections526initdb: 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.527528Success. You can now start the database server using:529530 pg_ctl -D /nix/var/nix/builds/nix-11432-1070387528/postgres4272606229/data -l logfile start5315322026-09-24 17:46:21.041 UTC [11486] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5332026-09-24 17:46:21.041 UTC [11486] LOG: listening on Unix socket "/nix/var/nix/builds/nix-11432-1070387528/postgres4272606229/.s.PGSQL.5432"5342026-09-24 17:46:21.043 UTC [11493] LOG: database system was shut down at 2026-09-24 17:46:21 UTC5352026-09-24 17:46:21.044 UTC [11486] LOG: database system is ready to accept connections536/nix/var/nix/builds/nix-11432-1070387528/postgres4272606229:5432 - accepting connections537{"timestamp":"2026-09-24T17:46:23.152324Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"0fb15776-2713-4f52-b872-352b59e4dffe","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":463,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}538=== RUN TestService_AuthMiddleware539=== PAUSE TestService_AuthMiddleware540=== RUN TestService_AuthMiddleware_MTLSProxyHeader541=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader542=== RUN TestService_AuthMiddleware_MTLSBoundSubjects543=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects544=== RUN TestService_ReadAuthMiddleware545=== PAUSE TestService_ReadAuthMiddleware546=== RUN TestService_AuthMiddleware_OIDC547=== PAUSE TestService_AuthMiddleware_OIDC548=== RUN TestService_RequireScope_OIDC549=== PAUSE TestService_RequireScope_OIDC550=== RUN TestService_ReadScope_PublicByDefault551=== PAUSE TestService_ReadScope_PublicByDefault552=== RUN TestCacheConfigHandler553=== PAUSE TestCacheConfigHandler554=== RUN TestCacheStatsHandler555=== PAUSE TestCacheStatsHandler556=== RUN TestClientCADerivations557=== PAUSE TestClientCADerivations558=== RUN TestClientErrorHandling559=== PAUSE TestClientErrorHandling560=== RUN TestClientIntegration561=== PAUSE TestClientIntegration562=== RUN TestClientMultipleUploads563=== PAUSE TestClientMultipleUploads564=== RUN TestClientWithDependencies565=== PAUSE TestClientWithDependencies566=== RUN TestClientSharedPathCommittedMidPush567=== PAUSE TestClientSharedPathCommittedMidPush568=== RUN TestPinProtectsFromGC569=== PAUSE TestPinProtectsFromGC570=== RUN TestClientPushesUseOnePush571=== PAUSE TestClientPushesUseOnePush572=== RUN TestClientFallsBackToClosures573=== PAUSE TestClientFallsBackToClosures574=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock575=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== RUN TestResolveDBConnectionString577=== PAUSE TestResolveDBConnectionString578=== RUN TestConnectWaitsForAPeerMigration579=== PAUSE TestConnectWaitsForAPeerMigration580=== RUN TestConnectSerialisesConcurrentMigrations581=== PAUSE TestConnectSerialisesConcurrentMigrations582=== RUN TestLeadElectsOneAndHandsOver583=== PAUSE TestLeadElectsOneAndHandsOver584=== RUN TestLeadIncumbentWinsAfterRestart5852026/09/24 17:46:23 INFO lead: acquired remote=192.0.2.1:12345862026/09/24 17:46:24 INFO lead: released remote=192.0.2.1:12345872026/09/24 17:46:24 INFO lead: acquired remote=192.0.2.1:12345882026/09/24 17:46:25 INFO lead: released remote=192.0.2.1:1234589--- PASS: TestLeadIncumbentWinsAfterRestart (2.58s)590=== RUN TestLeadEndsOnShutdown591=== PAUSE TestLeadEndsOnShutdown592=== RUN TestLeadEndsWhenItsConnectionHangs5932026/09/24 17:46:26 INFO lead: acquired remote=192.0.2.1:12345942026-09-24 17:46:27.225 UTC [11528] FATAL: terminating connection due to administrator command5952026/09/24 17:46:27 INFO lead: acquired remote=192.0.2.1:12345962026/09/24 17:46:28 WARN lead: lock connection lost error="timeout: context deadline exceeded"5972026/09/24 17:46:28 INFO lead: released remote=192.0.2.1:12345982026/09/24 17:46:28 INFO lead: released remote=192.0.2.1:1234599--- PASS: TestLeadEndsWhenItsConnectionHangs (2.80s)600=== RUN TestGCAdvisoryLockBlocksConcurrentRun601=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun602=== RUN TestGCBugBareHashReferences603=== PAUSE TestGCBugBareHashReferences604=== RUN TestGCMetrics605=== PAUSE TestGCMetrics606=== RUN TestPushDedupSurvivesConcurrentGC607=== PAUSE TestPushDedupSurvivesConcurrentGC608=== RUN TestDeduplicatedObjectsRecordedAsPending609=== PAUSE TestDeduplicatedObjectsRecordedAsPending610=== RUN TestGCSweepSkipsPendingObjects611=== PAUSE TestGCSweepSkipsPendingObjects612=== RUN TestTombstonedObjectOfferedWithoutWaiting613=== PAUSE TestTombstonedObjectOfferedWithoutWaiting614=== RUN TestGCSweepDeliversEachKeyOnce615=== PAUSE TestGCSweepDeliversEachKeyOnce616=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection617=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection618=== RUN TestForceGCDuringPushOffersSweptObject619=== PAUSE TestForceGCDuringPushOffersSweptObject620=== RUN TestSweepRowDeleteSparesResurrectedObject621=== PAUSE TestSweepRowDeleteSparesResurrectedObject622=== RUN TestSweepSparesObjectReuploadedMidSweep623=== PAUSE TestSweepSparesObjectReuploadedMidSweep624=== RUN TestCommitRacingPendingCleanupKeepsObjects625=== PAUSE TestCommitRacingPendingCleanupKeepsObjects626=== RUN TestGCEndsOnShutdown627=== PAUSE TestGCEndsOnShutdown628=== RUN TestGCTaskStore_StartNew629=== PAUSE TestGCTaskStore_StartNew630=== RUN TestGCTaskStore_DeduplicateSameParams631=== PAUSE TestGCTaskStore_DeduplicateSameParams632=== RUN TestGCTaskStore_ConflictDifferentParams633=== PAUSE TestGCTaskStore_ConflictDifferentParams634=== RUN TestGCTaskStore_GetEmpty635=== PAUSE TestGCTaskStore_GetEmpty636=== RUN TestGCTaskStore_GetReturnsLatest637=== PAUSE TestGCTaskStore_GetReturnsLatest638=== RUN TestGCTaskStore_CompletedAllowsNewTask639=== PAUSE TestGCTaskStore_CompletedAllowsNewTask640=== RUN TestGCTaskStore_PhaseUpdates641=== PAUSE TestGCTaskStore_PhaseUpdates642=== RUN TestGCTaskStore_Fail643=== PAUSE TestGCTaskStore_Fail644=== RUN TestGracefulShutdownDrainsInflight645=== PAUSE TestGracefulShutdownDrainsInflight646=== RUN TestService_healthCheckHandler647=== PAUSE TestService_healthCheckHandler648=== RUN TestService_readinessHandler649=== PAUSE TestService_readinessHandler650=== RUN TestGenerateLandingPage651=== PAUSE TestGenerateLandingPage652=== RUN TestCacheConfigHandlerMaxNarSize653=== PAUSE TestCacheConfigHandlerMaxNarSize654=== RUN TestCreatePendingClosureRejectsOversizedNAR655=== PAUSE TestCreatePendingClosureRejectsOversizedNAR656=== RUN TestNARDeduplicationMetadataUploadBug657=== PAUSE TestNARDeduplicationMetadataUploadBug658=== RUN TestMetricsInventory659=== PAUSE TestMetricsInventory660=== RUN TestService_NativeMTLS661=== PAUSE TestService_NativeMTLS662=== RUN TestServerTLSConfig663=== PAUSE TestServerTLSConfig664=== RUN TestMultipartCleanup665=== PAUSE TestMultipartCleanup666=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded667=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded668=== RUN TestPendingCleanupUsesOneCutoff669=== PAUSE TestPendingCleanupUsesOneCutoff670=== RUN TestPendingClosureFailureTracksEveryUpload671=== PAUSE TestPendingClosureFailureTracksEveryUpload672=== RUN TestPendingClosureFailureAbortsItsUploads673=== PAUSE TestPendingClosureFailureAbortsItsUploads674=== RUN TestObjectStatsTrigger675=== PAUSE TestObjectStatsTrigger676=== RUN TestReconnectLeavesObjectsUnlocked677=== PAUSE TestReconnectLeavesObjectsUnlocked678=== RUN TestValidateS3Concurrency679=== PAUSE TestValidateS3Concurrency680=== RUN TestOrphanedObjectsGC681=== PAUSE TestOrphanedObjectsGC682=== RUN TestOrphanedObjectsGCStressTest683=== PAUSE TestOrphanedObjectsGCStressTest684=== RUN TestResurrectedObjectNotDeleted685=== PAUSE TestResurrectedObjectNotDeleted686=== RUN TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown687=== PAUSE TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown688=== RUN TestCreatePin_ReservedPins689=== PAUSE TestCreatePin_ReservedPins690=== RUN TestConcurrentPinUpdatesAgree691=== PAUSE TestConcurrentPinUpdatesAgree692=== RUN TestCreatePinRejectsBadInput693=== PAUSE TestCreatePinRejectsBadInput694=== RUN TestDeletePinKeepsRowWhenS3Fails695=== PAUSE TestDeletePinKeepsRowWhenS3Fails696=== RUN TestPresentReportsOnlyClosureRoots697=== PAUSE TestPresentReportsOnlyClosureRoots698=== RUN TestPresentNotReportedWhileGCDeletesClosure699=== PAUSE TestPresentNotReportedWhileGCDeletesClosure700=== RUN TestParseSingleRange701=== PAUSE TestParseSingleRange702=== RUN TestProxyHeadersOnlyTrustedOnSocket703=== PAUSE TestProxyHeadersOnlyTrustedOnSocket704=== RUN TestIsValidCachePath705=== PAUSE TestIsValidCachePath706=== RUN TestReadProxyNarinfo707=== PAUSE TestReadProxyNarinfo708=== RUN TestReadProxyNarinfoAlreadyDecompressed709=== PAUSE TestReadProxyNarinfoAlreadyDecompressed710=== RUN TestReadProxyNarStreaming711=== PAUSE TestReadProxyNarStreaming712=== RUN TestReadProxy404713=== PAUSE TestReadProxy404714=== RUN TestReadProxyInvalidPath715=== PAUSE TestReadProxyInvalidPath716=== RUN TestReadProxyHead717=== PAUSE TestReadProxyHead718=== RUN TestReadProxyOutlastsServerWriteTimeout719=== PAUSE TestReadProxyOutlastsServerWriteTimeout720=== RUN TestReadProxyConditionalGet721=== PAUSE TestReadProxyConditionalGet722=== RUN TestReadProxyRootRedirectsToIndexHTML723=== PAUSE TestReadProxyRootRedirectsToIndexHTML724=== RUN TestReadProxyDisabled725=== PAUSE TestReadProxyDisabled726=== RUN TestReadRedirectNar727=== PAUSE TestReadRedirectNar728=== RUN TestReadRedirectKeepsNarinfoProxied729=== PAUSE TestReadRedirectKeepsNarinfoProxied730=== RUN TestReadProxyRangeRequest731=== PAUSE TestReadProxyRangeRequest732=== RUN TestReadRedirectUsesPublicS3URL733=== PAUSE TestReadRedirectUsesPublicS3URL734=== RUN TestPush_OverlappingRootsStoreOneRowPerKey735=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey736=== RUN TestPush_CompleteCommitsEveryRoot737=== PAUSE TestPush_CompleteCommitsEveryRoot738=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit739=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit740=== RUN TestPush_RejectsBadRequests741=== PAUSE TestPush_RejectsBadRequests742=== RUN TestPush_SignsNarinfosOfItsPendingObjects743=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects744=== RUN TestRedundantMultipartUpload745=== PAUSE TestRedundantMultipartUpload746=== RUN TestCompleteMultipartUpload_ErrorButObjectExists747=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists748=== RUN TestCompletedNarNotReofferedAcrossClosures749=== PAUSE TestCompletedNarNotReofferedAcrossClosures750=== RUN TestPresignedUploadRegisteredBeforeCommit751=== PAUSE TestPresignedUploadRegisteredBeforeCommit752=== RUN TestService_Rustfstest753=== PAUSE TestService_Rustfstest754=== RUN TestParseSize755=== PAUSE TestParseSize756=== RUN TestSkippedUploadsHandler757=== PAUSE TestSkippedUploadsHandler758=== RUN TestSystemdListenerNotActivated759--- PASS: TestSystemdListenerNotActivated (0.00s)760=== RUN TestWatchdogBeatsWhenHealthy761--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)762=== RUN TestWatchdogSkipsWhenUnhealthy7632026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/09/24 17:46:28 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"773--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)774=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle775=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle776=== RUN TestProxyWriteTimeout777=== PAUSE TestProxyWriteTimeout778=== RUN TestPendingClosureWriteTimeout779=== PAUSE TestPendingClosureWriteTimeout780=== RUN TestIsValidUploadKey781=== PAUSE TestIsValidUploadKey782=== RUN TestUploadHandlersRejectInvalidKeys783=== PAUSE TestUploadHandlersRejectInvalidKeys784=== RUN TestUploadHandlersRejectOversizedBody785=== PAUSE TestUploadHandlersRejectOversizedBody786=== RUN TestService_cleanupPendingClosuresHandler787=== PAUSE TestService_cleanupPendingClosuresHandler788=== RUN TestService_createPendingClosureHandler789=== PAUSE TestService_createPendingClosureHandler790=== RUN TestService_verifyS3Integrity791=== PAUSE TestService_verifyS3Integrity792=== RUN TestCompleteMultipartUnregistered793=== PAUSE TestCompleteMultipartUnregistered794=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT795=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT796=== CONT TestService_Rustfstest797=== CONT TestCacheConfigHandlerMaxNarSize798=== CONT TestGCTaskStore_Fail799--- PASS: TestGCTaskStore_Fail (0.00s)800=== CONT TestService_AuthMiddleware_MTLSProxyHeader801=== CONT TestCompleteMultipartUnregistered802=== CONT TestPendingClosureWriteTimeout803=== RUN TestPendingClosureWriteTimeout/empty804=== CONT TestUploadHandlersRejectOversizedBody805=== CONT TestGracefulShutdownDrainsInflight806--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)807=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT808=== PAUSE TestPendingClosureWriteTimeout/empty809=== RUN TestPendingClosureWriteTimeout/negative810=== CONT TestService_verifyS3Integrity811=== PAUSE TestPendingClosureWriteTimeout/negative812=== CONT TestService_cleanupPendingClosuresHandler813=== CONT TestService_readinessHandler814=== RUN TestPendingClosureWriteTimeout/400_objects815=== PAUSE TestPendingClosureWriteTimeout/400_objects8162026/09/24 17:46:28 INFO Starting HTTP server address=127.0.0.1:51767817=== RUN TestPendingClosureWriteTimeout/670k_objects818=== PAUSE TestPendingClosureWriteTimeout/670k_objects819=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline820=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline821=== CONT TestService_createPendingClosureHandler8222026/09/24 17:46:28 INFO Shutdown signal received, draining in-flight requests timeout=10s823=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts824=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts825=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure826=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure827=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart828=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart829=== CONT TestUploadHandlersRejectInvalidKeys830=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info831=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info832=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal833=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal834=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key835=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key836=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key837=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key838=== CONT TestReadProxyNarinfoAlreadyDecompressed839--- PASS: TestGracefulShutdownDrainsInflight (0.10s)840=== CONT TestPush_SignsNarinfosOfItsPendingObjects8412026/09/24 17:46:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8422026/09/24 17:46:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst843--- PASS: TestCompleteMultipartUnregistered (0.45s)844=== CONT TestPush_RejectsBadRequests845--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.58s)846=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit8472026/09/24 17:46:29 INFO Received uploads request method=POST path=/api/pending_closures8482026/09/24 17:46:29 INFO Received uploads request method=POST path=/api/pending_closures8492026/09/24 17:46:29 INFO Received uploads request method=POST path=/api/pending_closures8502026/09/24 17:46:29 INFO Received cleanup request method=DELETE path=/api/pending_closures8512026/09/24 17:46:29 INFO Aborted multipart uploads count=0 kept=08522026/09/24 17:46:29 INFO Received uploads request method=POST path=/api/pending_closures8532026/09/24 17:46:29 INFO Received cleanup request method=DELETE path=/api/pending_closures8542026/09/24 17:46:29 INFO Aborted multipart uploads count=1 kept=08552026/09/24 17:46:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8562026-09-24 17:46:29.847 UTC [11555] ERROR: Closure does not exist: id=18572026-09-24 17:46:29.847 UTC [11555] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 19 at RAISE8582026-09-24 17:46:29.847 UTC [11555] STATEMENT: -- name: CommitPendingClosure :exec859 SELECT commit_pending_closure($1::bigint)860 861--- PASS: TestService_cleanupPendingClosuresHandler (0.98s)862=== CONT TestPush_CompleteCommitsEveryRoot863--- PASS: TestService_Rustfstest (1.11s)864=== CONT TestRedundantMultipartUpload8652026/09/24 17:46:30 INFO Received uploads request method=POST path=/api/pending_closures8662026/09/24 17:46:30 INFO Received uploads request method=POST path=/api/pending_closures867--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.61s)868=== CONT TestReadRedirectUsesPublicS3URL869--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.70s)870=== CONT TestPush_OverlappingRootsStoreOneRowPerKey8712026/09/24 17:46:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8722026/09/24 17:46:30 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjAwMDdhYjM3LWU1YmItNDJmMi05NDQyLTMyNTQ3ZTQ4ZjkyN3gxNzkwMjcxOTg5NjYxOTcwMDAw parts=108732026/09/24 17:46:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8742026/09/24 17:46:30 INFO Completed upload id=18752026/09/24 17:46:30 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008762026/09/24 17:46:30 INFO Received uploads request method=POST path=/api/pending_closures8772026/09/24 17:46:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures8782026/09/24 17:46:30 INFO Aborted multipart uploads count=0 kept=08792026/09/24 17:46:30 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=08802026/09/24 17:46:30 INFO Vacuumed table table=pending_closures8812026/09/24 17:46:30 INFO Vacuumed table table=pending_objects8822026/09/24 17:46:30 WARN readiness check failed error="closed pool"883--- PASS: TestService_readinessHandler (2.05s)884=== CONT TestReadProxyRangeRequest8852026/09/24 17:46:30 INFO Vacuumed table table=multipart_uploads8862026/09/24 17:46:30 INFO Vacuumed table table=closures8872026/09/24 17:46:30 INFO Vacuumed table table=objects8882026/09/24 17:46:31 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000889--- PASS: TestService_createPendingClosureHandler (2.15s)890=== CONT TestReadRedirectKeepsNarinfoProxied8912026/09/24 17:46:31 INFO Received push request method=POST path=/api/pushes8922026/09/24 17:46:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8932026/09/24 17:46:31 INFO Signed narinfos id=1 count=1894--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.25s)895=== CONT TestReadRedirectNar896=== RUN TestPush_RejectsBadRequests/no_roots897=== PAUSE TestPush_RejectsBadRequests/no_roots898=== RUN TestPush_RejectsBadRequests/no_objects899=== PAUSE TestPush_RejectsBadRequests/no_objects900=== RUN TestPush_RejectsBadRequests/bad_root901=== PAUSE TestPush_RejectsBadRequests/bad_root902=== RUN TestPush_RejectsBadRequests/root_not_in_objects903=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects904=== CONT TestReadProxyDisabled9052026/09/24 17:46:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9062026/09/24 17:46:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjY5NzU5MzU0LTFiZTktNGMwYi1hNWNjLTFhZDhlMDEwMWFlNHgxNzkwMjcxOTkwMjAyNTc3MDAw parts=109072026/09/24 17:46:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9082026/09/24 17:46:31 INFO Completed upload id=19092026/09/24 17:46:31 INFO Received uploads request method=POST path=/api/pending_closures9102026/09/24 17:46:31 INFO Received uploads request method=POST path=/api/pending_closures9112026/09/24 17:46:31 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9122026/09/24 17:46:31 WARN Found objects in DB but missing from S3, will re-upload count=19132026/09/24 17:46:31 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete9142026/09/24 17:46:31 INFO Completed upload id=3915--- PASS: TestService_verifyS3Integrity (2.66s)916=== CONT TestReadProxyConditionalGet9172026/09/24 17:46:31 INFO Received push request method=POST path=/api/pushes9182026/09/24 17:46:31 INFO Received push request method=POST path=/api/pushes9192026/09/24 17:46:32 INFO Received uploads request method=POST path=/api/pending_closures9202026/09/24 17:46:32 INFO Received uploads request method=POST path=/api/pending_closures9212026/09/24 17:46:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9222026/09/24 17:46:32 INFO Received push request method=POST path=/api/pushes9232026/09/24 17:46:33 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM1NzgxZWQ5LWY5N2ItNGViZS05NDg3LTE3ZWI4NDJhMGQzOXgxNzkwMjcxOTkxNTg5NjI2MDAw parts=10924--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.42s)925=== CONT TestReadProxyRootRedirectsToIndexHTML9262026/09/24 17:46:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9272026/09/24 17:46:33 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjIyMTEyYzM4LTBhYzgtNGJlYi1hOTE3LTY1YzI3M2Y2MTZmN3gxNzkwMjcxOTkxODI3OTEyMDAw parts=10928--- PASS: TestReadRedirectUsesPublicS3URL (2.90s)929=== CONT TestReadProxyHead930--- PASS: TestReadProxyRangeRequest (2.76s)931=== CONT TestParseSize932--- PASS: TestParseSize (0.00s)933=== CONT TestReadProxyInvalidPath9342026/09/24 17:46:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9352026/09/24 17:46:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LmY5NTFkYWNkLWY0MzMtNDc1Yy05ZjI5LTg5ZTA2N2M5MWUxYngxNzkwMjcxOTkyMDMzMTMzMDAw parts=129362026/09/24 17:46:33 INFO Received uploads request method=POST path=/api/pending_closures9372026/09/24 17:46:33 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestReadRedirectKeepsNarinfoProxied (2.96s)939=== CONT TestReadProxy404940--- PASS: TestReadRedirectNar (3.09s)941=== CONT TestProxyWriteTimeout942=== RUN TestProxyWriteTimeout/narinfo943=== PAUSE TestProxyWriteTimeout/narinfo944=== RUN TestProxyWriteTimeout/1_GiB_nar945=== PAUSE TestProxyWriteTimeout/1_GiB_nar946=== RUN TestProxyWriteTimeout/10_GiB_nar947=== PAUSE TestProxyWriteTimeout/10_GiB_nar948=== RUN TestProxyWriteTimeout/unknown_size949=== PAUSE TestProxyWriteTimeout/unknown_size950=== CONT TestReadProxyNarStreaming9512026/09/24 17:46:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete952--- PASS: TestReadProxyDisabled (3.25s)953=== CONT TestGCTaskStore_CompletedAllowsNewTask954--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)955=== CONT TestIsValidCachePath956=== RUN TestIsValidCachePath/narinfo957=== PAUSE TestIsValidCachePath/narinfo958=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars959=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars960=== RUN TestIsValidCachePath/nar_zst961=== PAUSE TestIsValidCachePath/nar_zst962=== RUN TestIsValidCachePath/nar_xz963=== PAUSE TestIsValidCachePath/nar_xz964=== RUN TestIsValidCachePath/nar_bz2965=== PAUSE TestIsValidCachePath/nar_bz2966=== RUN TestIsValidCachePath/nar_uncompressed967=== PAUSE TestIsValidCachePath/nar_uncompressed968=== RUN TestIsValidCachePath/ls969=== PAUSE TestIsValidCachePath/ls970=== RUN TestIsValidCachePath/log971=== PAUSE TestIsValidCachePath/log972=== RUN TestIsValidCachePath/realisation973=== PAUSE TestIsValidCachePath/realisation974=== RUN TestIsValidCachePath/nix-cache-info975=== PAUSE TestIsValidCachePath/nix-cache-info976=== RUN TestIsValidCachePath/index.html977=== PAUSE TestIsValidCachePath/index.html978=== RUN TestIsValidCachePath/traversal_parent979=== PAUSE TestIsValidCachePath/traversal_parent980=== RUN TestIsValidCachePath/traversal_in_middle981=== PAUSE TestIsValidCachePath/traversal_in_middle982=== RUN TestIsValidCachePath/invalid_char_e983=== PAUSE TestIsValidCachePath/invalid_char_e984=== RUN TestIsValidCachePath/invalid_char_u985=== PAUSE TestIsValidCachePath/invalid_char_u986=== RUN TestIsValidCachePath/random_path987=== PAUSE TestIsValidCachePath/random_path988=== RUN TestIsValidCachePath/empty989=== PAUSE TestIsValidCachePath/empty990=== RUN TestIsValidCachePath/leading_slash991=== PAUSE TestIsValidCachePath/leading_slash992=== RUN TestIsValidCachePath/wrong_extension993=== PAUSE TestIsValidCachePath/wrong_extension994=== RUN TestIsValidCachePath/short_hash995=== PAUSE TestIsValidCachePath/short_hash996=== CONT TestGCTaskStore_GetReturnsLatest997--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)998=== CONT TestParseSingleRange999=== RUN TestParseSingleRange/none1000=== PAUSE TestParseSingleRange/none1001=== RUN TestParseSingleRange/unknown_unit1002=== PAUSE TestParseSingleRange/unknown_unit1003=== RUN TestParseSingleRange/multi-range_ignored1004=== PAUSE TestParseSingleRange/multi-range_ignored1005=== RUN TestParseSingleRange/malformed_no_dash1006=== PAUSE TestParseSingleRange/malformed_no_dash1007=== RUN TestParseSingleRange/malformed_both_empty1008=== PAUSE TestParseSingleRange/malformed_both_empty1009=== RUN TestParseSingleRange/malformed_end_before_start1010=== PAUSE TestParseSingleRange/malformed_end_before_start1011=== RUN TestParseSingleRange/closed1012=== PAUSE TestParseSingleRange/closed1013=== RUN TestParseSingleRange/open-ended1014=== PAUSE TestParseSingleRange/open-ended1015=== RUN TestParseSingleRange/end_clamped_to_size1016=== PAUSE TestParseSingleRange/end_clamped_to_size1017=== RUN TestParseSingleRange/suffix1018=== PAUSE TestParseSingleRange/suffix1019=== RUN TestParseSingleRange/suffix_exceeds_size1020=== PAUSE TestParseSingleRange/suffix_exceeds_size1021=== RUN TestParseSingleRange/single_byte1022=== PAUSE TestParseSingleRange/single_byte1023=== RUN TestParseSingleRange/start_past_EOF1024=== PAUSE TestParseSingleRange/start_past_EOF1025=== RUN TestParseSingleRange/start_far_past_EOF1026=== PAUSE TestParseSingleRange/start_far_past_EOF1027=== CONT TestGCTaskStore_GetEmpty1028--- PASS: TestGCTaskStore_GetEmpty (0.00s)1029=== CONT TestPresentNotReportedWhileGCDeletesClosure10302026/09/24 17:46:34 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LmMwNGUxZWEzLWE3MWEtNDg3OS04ZjZmLTc1MWVmYWQ4NzYzNngxNzkwMjcxOTkxNTg5OTcyMDAw parts=1010312026/09/24 17:46:34 INFO Received complete push request method=POST path=/api/pushes/1/complete10322026/09/24 17:46:34 INFO Received push request method=POST path=/api/pushes10332026/09/24 17:46:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10342026/09/24 17:46:34 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjhjM2I1MzBmLTAyZDYtNGE3Yy1hYjVhLWM1Zjc0MDViZWM1YXgxNzkwMjcxOTkxODI3NjA0MDAw parts=1010352026/09/24 17:46:34 INFO Aborted multipart uploads count=0 kept=010362026/09/24 17:46:34 WARN Force mode enabled - objects will be deleted immediately without grace period10372026/09/24 17:46:34 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=010382026/09/24 17:46:34 INFO Vacuumed table table=pending_closures10392026/09/24 17:46:34 INFO Vacuumed table table=pending_objects10402026/09/24 17:46:34 INFO Vacuumed table table=multipart_uploads1041--- PASS: TestReadProxyConditionalGet (3.40s)1042=== CONT TestGCTaskStore_PhaseUpdates1043--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1044=== CONT TestProxyHeadersOnlyTrustedOnSocket10452026/09/24 17:46:34 INFO Vacuumed table table=closures10462026/09/24 17:46:34 INFO Vacuumed table table=objects10472026/09/24 17:46:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10482026/09/24 17:46:35 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LmQ2OWFlNzdjLTlhN2UtNDcxYi1iZTBhLTBlYWI1YTEzOWZlNXgxNzkwMjcxOTkzODY1MTgwMDAw error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10492026/09/24 17:46:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LmNmNTNiM2NlLTEzMzUtNGU0YS1iMWU3LTIzNGUxM2JmZTI4YXgxNzkwMjcxOTkzODI0ODY2MDAw parts=1210502026/09/24 17:46:35 INFO Received cleanup request method=DELETE path=/api/pending_closures10512026/09/24 17:46:35 INFO Aborted multipart uploads count=1 kept=01052--- PASS: TestRedundantMultipartUpload (5.71s)1053=== CONT TestGCTaskStore_DeduplicateSameParams1054=== CONT TestReadProxyOutlastsServerWriteTimeout1055--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1056--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.95s)1057=== CONT TestGCTaskStore_ConflictDifferentParams1058--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1059=== CONT TestSkippedUploadsHandler10602026/09/24 17:46:36 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001061--- PASS: TestSkippedUploadsHandler (0.00s)1062=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10632026/09/24 17:46:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/09/24 17:46:36 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjdiOTIwZWVmLWY5MzItNGE3YS1hMDZhLWRiMzJkMGZiNjQ5OXgxNzkwMjcxOTkxODI3OTQxMDAw parts=1010652026/09/24 17:46:36 INFO Received complete push request method=POST path=/api/pushes/1/complete1066--- PASS: TestPush_CompleteCommitsEveryRoot (6.35s)1067=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10682026/09/24 17:46:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10692026/09/24 17:46:36 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LmEyZDhiZjdkLWEwZmQtNDRkMC1hZGMwLTU0ZDRhOGMxY2I3YngxNzkwMjcxOTk0NjY2NzMxMDAw parts=1010702026/09/24 17:46:36 INFO Received complete push request method=POST path=/api/pushes/2/complete1071--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (6.95s)1072=== CONT TestGCEndsOnShutdown1073=== RUN TestGCEndsOnShutdown/before_the_run1074=== PAUSE TestGCEndsOnShutdown/before_the_run1075=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1076=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1077=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1078=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1079=== CONT TestTombstonedObjectOfferedWithoutWaiting1080--- PASS: TestReadProxyHead (3.18s)1081=== CONT TestPushDedupSurvivesConcurrentGC1082--- PASS: TestReadProxyInvalidPath (3.19s)1083=== CONT TestDeduplicatedObjectsRecordedAsPending10842026/09/24 17:46:37 WARN Rate limiter enabled after throttle name=s3-test rate=510852026/09/24 17:46:37 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1086--- PASS: TestReadProxyNarStreaming (3.14s)1087=== CONT TestGCBugBareHashReferences10882026/09/24 17:46:37 WARN Rate limiter backed off name=s3-test rate=510892026/09/24 17:46:37 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1090--- PASS: TestReadProxy404 (3.48s)1091=== CONT TestGCMetrics10922026/09/24 17:46:37 INFO Starting HTTP server address=127.0.0.1:5187310932026/09/24 17:46:37 INFO Starting HTTP server address=/nix/var/nix/builds/nix-11432-1070387528/TestProxyHeadersOnlyTrustedOnSocket3859951596/001/proxy.sock10942026/09/24 17:46:37 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10952026/09/24 17:46:37 INFO Shutdown signal received, draining in-flight requests timeout=10s1096--- PASS: TestProxyHeadersOnlyTrustedOnSocket (3.06s)1097=== CONT TestGCAdvisoryLockBlocksConcurrentRun1098--- PASS: TestPresentNotReportedWhileGCDeletesClosure (3.68s)1099=== CONT TestLeadEndsOnShutdown11002026/09/24 17:46:38 INFO Received uploads request method=POST path=/api/pending_closures1101--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.60s)1102=== CONT TestConnectSerialisesConcurrentMigrations11032026/09/24 17:46:39 INFO Received uploads request method=POST path=/api/pending_closures11042026/09/24 17:46:39 INFO Aborted multipart uploads count=0 kept=011052026/09/24 17:46:39 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=011062026/09/24 17:46:39 INFO Vacuumed table table=pending_closures11072026/09/24 17:46:39 INFO Vacuumed table table=pending_objects11082026/09/24 17:46:39 INFO Vacuumed table table=multipart_uploads11092026/09/24 17:46:39 INFO Vacuumed table table=closures11102026/09/24 17:46:39 INFO Vacuumed table table=objects11112026/09/24 17:46:39 INFO Received uploads request method=POST path=/api/pending_closures11122026/09/24 17:46:39 INFO Aborted multipart uploads count=0 kept=011132026/09/24 17:46:39 WARN Force mode enabled - objects will be deleted immediately without grace period11142026/09/24 17:46:39 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=011152026/09/24 17:46:39 INFO Vacuumed table table=pending_closures11162026/09/24 17:46:39 INFO Vacuumed table table=pending_objects11172026/09/24 17:46:39 INFO Vacuumed table table=multipart_uploads11182026/09/24 17:46:39 INFO Vacuumed table table=closures11192026/09/24 17:46:39 INFO Vacuumed table table=objects1120--- PASS: TestPushDedupSurvivesConcurrentGC (2.90s)1121=== CONT TestLeadElectsOneAndHandsOver11222026/09/24 17:46:39 INFO Received uploads request method=POST path=/api/pending_closures1123--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.78s)1124=== CONT TestResolveDBConnectionString1125=== RUN TestResolveDBConnectionString/flag_wins1126=== PAUSE TestResolveDBConnectionString/flag_wins1127=== RUN TestResolveDBConnectionString/file_when_flag_empty1128=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1129=== RUN TestResolveDBConnectionString/missing_file_is_an_error1130=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1131=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1132=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1133=== RUN TestResolveDBConnectionString/nothing_configured1134=== PAUSE TestResolveDBConnectionString/nothing_configured1135=== CONT TestGCTaskStore_StartNew1136--- PASS: TestGCTaskStore_StartNew (0.00s)1137=== CONT TestConnectWaitsForAPeerMigration11382026/09/24 17:46:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11392026/09/24 17:46:39 INFO Aborted multipart uploads count=0 kept=011402026/09/24 17:46:39 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/09/24 17:46:39 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=011422026/09/24 17:46:39 INFO Vacuumed table table=pending_closures11432026/09/24 17:46:39 INFO Vacuumed table table=pending_objects11442026/09/24 17:46:39 INFO Vacuumed table table=multipart_uploads11452026/09/24 17:46:39 INFO Vacuumed table table=closures11462026/09/24 17:46:39 INFO Vacuumed table table=objects1147--- PASS: TestGCMetrics (2.31s)1148=== CONT TestCommitRacingPendingCleanupKeepsObjects11492026-09-24 17:46:40.159 UTC [11697] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"11502026-09-24 17:46:40.159 UTC [11697] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.11512026-09-24 17:46:40.159 UTC [11697] STATEMENT: CREATE TABLE goose_db_version (1152 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1153 version_id bigint NOT NULL,1154 is_applied boolean NOT NULL,1155 tstamp timestamp NOT NULL DEFAULT now()1156 )1157--- PASS: TestGCBugBareHashReferences (2.74s)1158=== CONT TestSweepSparesObjectReuploadedMidSweep11592026/09/24 17:46:40 INFO lead: acquired remote=192.0.2.1:123411602026/09/24 17:46:40 INFO lead: acquired remote=192.0.2.1:12341161--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (4.77s)1162=== CONT TestPresignedUploadRegisteredBeforeCommit11632026/09/24 17:46:40 INFO Aborted multipart uploads count=0 kept=011642026/09/24 17:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period11652026/09/24 17:46:40 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=011662026/09/24 17:46:40 INFO Vacuumed table table=pending_closures11672026/09/24 17:46:40 INFO Vacuumed table table=pending_objects11682026/09/24 17:46:40 INFO Vacuumed table table=multipart_uploads11692026/09/24 17:46:40 INFO Vacuumed table table=closures11702026/09/24 17:46:40 INFO Vacuumed table table=objects1171--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.06s)1172=== CONT TestSweepRowDeleteSparesResurrectedObject11732026/09/24 17:46:40 INFO Aborted multipart uploads count=0 kept=011742026/09/24 17:46:41 INFO Received uploads request method=POST path=/api/pending_closures11752026/09/24 17:46:41 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1176--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.14s)1177=== CONT TestIsValidUploadKey1178=== RUN TestIsValidUploadKey/narinfo1179=== PAUSE TestIsValidUploadKey/narinfo1180=== RUN TestIsValidUploadKey/nar_zst1181=== PAUSE TestIsValidUploadKey/nar_zst1182=== RUN TestIsValidUploadKey/nar_xz1183=== PAUSE TestIsValidUploadKey/nar_xz1184=== RUN TestIsValidUploadKey/nar_plain1185=== PAUSE TestIsValidUploadKey/nar_plain1186=== RUN TestIsValidUploadKey/listing1187=== PAUSE TestIsValidUploadKey/listing1188=== RUN TestIsValidUploadKey/build_log1189=== PAUSE TestIsValidUploadKey/build_log1190=== RUN TestIsValidUploadKey/build_log_home-manager_file1191=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1192=== RUN TestIsValidUploadKey/build_log_plus_in_name1193=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1194=== RUN TestIsValidUploadKey/build_log_question_mark1195=== PAUSE TestIsValidUploadKey/build_log_question_mark1196=== RUN TestIsValidUploadKey/build_log_equals1197=== PAUSE TestIsValidUploadKey/build_log_equals1198=== RUN TestIsValidUploadKey/realisation1199=== PAUSE TestIsValidUploadKey/realisation1200=== RUN TestIsValidUploadKey/realisation_plus_in_output1201=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1202=== RUN TestIsValidUploadKey/nix-cache-info1203=== PAUSE TestIsValidUploadKey/nix-cache-info1204=== RUN TestIsValidUploadKey/index.html1205=== PAUSE TestIsValidUploadKey/index.html1206=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1207=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1208=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1209=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1210=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1211=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1212=== RUN TestIsValidUploadKey/traversal1213=== PAUSE TestIsValidUploadKey/traversal1214=== RUN TestIsValidUploadKey/traversal_nar1215=== PAUSE TestIsValidUploadKey/traversal_nar1216=== RUN TestIsValidUploadKey/absolute1217=== PAUSE TestIsValidUploadKey/absolute1218=== RUN TestIsValidUploadKey/empty_key1219=== PAUSE TestIsValidUploadKey/empty_key1220=== RUN TestIsValidUploadKey/unknown_type1221=== PAUSE TestIsValidUploadKey/unknown_type1222=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1223--- PASS: TestConnectSerialisesConcurrentMigrations (2.16s)1224=== CONT TestClientFallsBackToClosures12252026/09/24 17:46:41 INFO lead: released remote=192.0.2.1:12341226--- PASS: TestLeadEndsOnShutdown (3.06s)1227=== CONT TestServerTLSConfig1228=== RUN TestServerTLSConfig/no_client_CA1229=== PAUSE TestServerTLSConfig/no_client_CA1230=== RUN TestServerTLSConfig/missing_CA_file1231=== PAUSE TestServerTLSConfig/missing_CA_file1232=== RUN TestServerTLSConfig/not_a_PEM_file1233=== PAUSE TestServerTLSConfig/not_a_PEM_file1234=== CONT TestForceGCDuringPushOffersSweptObject1235=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1236=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1237=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1238=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1239=== CONT TestPendingClosureFailureTracksEveryUpload12402026/09/24 17:46:41 INFO Received uploads request method=POST path=/api/pending_closures12412026/09/24 17:46:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12422026/09/24 17:46:41 INFO Received uploads request method=POST path=/api/pending_closures1243--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.57s)1244=== CONT TestGCSweepDeliversEachKeyOnce1245--- PASS: TestSweepRowDeleteSparesResurrectedObject (0.72s)1246=== CONT TestPendingClosureFailureAbortsItsUploads12472026/09/24 17:46:41 INFO lead: released remote=192.0.2.1:123412482026/09/24 17:46:41 INFO lead: acquired remote=192.0.2.1:123412492026/09/24 17:46:41 INFO Received uploads request method=POST path=/api/pending_closures12502026/09/24 17:46:42 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=01251--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.88s)1252=== CONT TestClientPushesUseOnePush12532026/09/24 17:46:42 INFO Vacuumed table table=pending_closures12542026/09/24 17:46:42 INFO Vacuumed table table=pending_objects12552026/09/24 17:46:42 INFO Vacuumed table table=multipart_uploads12562026/09/24 17:46:42 INFO Vacuumed table table=closures12572026/09/24 17:46:42 INFO Vacuumed table table=objects1258--- PASS: TestSweepSparesObjectReuploadedMidSweep (1.87s)1259=== CONT TestGCSweepSkipsPendingObjects12602026/09/24 17:46:42 INFO Received uploads request method=POST path=/api/pending_closures12612026/09/24 17:46:42 INFO Received uploads request method=POST path=/api/pending_closures12622026/09/24 17:46:42 INFO Received uploads request method=POST path=/api/pending_closures12632026/09/24 17:46:42 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12642026/09/24 17:46:42 INFO Uploading 4grylcvdj6z3xwm78ywrv6pqxj2w5bnr-shared-dep (136B)12652026/09/24 17:46:42 INFO Uploading l021q00g9xwjf0577b9fr3rfpjys293b-a (248B)12662026/09/24 17:46:42 WARN Failed to register uploaded object key=nar/0jvdyx4hkrllhsf8cz7hmwrsci4z83njlr9cj8zkvgi8qqdslr6f.nar.zst error="server returned 404: 404 page not found\n"12672026/09/24 17:46:42 WARN Failed to register uploaded object key=h26sr9l9w0b4qjm1nbwgnw891ig30yr1.ls error="server returned 404: 404 page not found\n"12682026/09/24 17:46:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12692026/09/24 17:46:42 WARN Failed to register uploaded object key=l021q00g9xwjf0577b9fr3rfpjys293b.ls error="server returned 404: 404 page not found\n"12702026/09/24 17:46:42 WARN Failed to register uploaded object key=4grylcvdj6z3xwm78ywrv6pqxj2w5bnr.ls error="server returned 404: 404 page not found\n"12712026/09/24 17:46:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12722026/09/24 17:46:42 INFO Signed narinfos id=1 count=212732026/09/24 17:46:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12742026/09/24 17:46:42 INFO Signed narinfos id=2 count=212752026/09/24 17:46:42 INFO Uploading 4 narinfos12762026/09/24 17:46:42 WARN Failed to register uploaded object key=h26sr9l9w0b4qjm1nbwgnw891ig30yr1.narinfo error="server returned 404: 404 page not found\n"12772026/09/24 17:46:42 WARN Failed to register uploaded object key=l021q00g9xwjf0577b9fr3rfpjys293b.narinfo error="server returned 404: 404 page not found\n"12782026/09/24 17:46:42 WARN Failed to register uploaded object key=4grylcvdj6z3xwm78ywrv6pqxj2w5bnr.narinfo error="server returned 404: 404 page not found\n"12792026/09/24 17:46:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12802026/09/24 17:46:42 WARN Failed to register uploaded object key=4grylcvdj6z3xwm78ywrv6pqxj2w5bnr.narinfo error="server returned 404: 404 page not found\n"12812026/09/24 17:46:42 INFO Completed upload id=112822026/09/24 17:46:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12832026/09/24 17:46:42 INFO Completed upload id=212842026/09/24 17:46:42 INFO Upload complete. (171ms)1285=== NAME TestClientFallsBackToClosures1286 client_pushes_test.go:112: Retrieved narinfo from S3:1287 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientFallsBackToClosures168298907/001/store/4grylcvdj6z3xwm78ywrv6pqxj2w5bnr-shared-dep1288 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1289 Compression: zstd1290 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821291 NarSize: 1361292 References: 1293 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1294 client_pushes_test.go:112: Retrieved narinfo from S3:1295 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientFallsBackToClosures168298907/001/store/l021q00g9xwjf0577b9fr3rfpjys293b-a1296 URL: nar/0jvdyx4hkrllhsf8cz7hmwrsci4z83njlr9cj8zkvgi8qqdslr6f.nar.zst1297 Compression: zstd1298 NarHash: sha256:0jvdyx4hkrllhsf8cz7hmwrsci4z83njlr9cj8zkvgi8qqdslr6f1299 NarSize: 2481300 References: /nix/var/nix/builds/nix-11432-1070387528/TestClientFallsBackToClosures168298907/001/store/4grylcvdj6z3xwm78ywrv6pqxj2w5bnr-shared-dep1301 CA: text:sha256:0a6ksq8653yf0g0y6yf9434vy1smq7clqnb6sifks9f1jp5kgbni1302 client_pushes_test.go:112: Retrieved narinfo from S3:1303 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientFallsBackToClosures168298907/001/store/h26sr9l9w0b4qjm1nbwgnw891ig30yr1-b1304 URL: nar/0jvdyx4hkrllhsf8cz7hmwrsci4z83njlr9cj8zkvgi8qqdslr6f.nar.zst1305 Compression: zstd1306 NarHash: sha256:0jvdyx4hkrllhsf8cz7hmwrsci4z83njlr9cj8zkvgi8qqdslr6f1307 NarSize: 2481308 References: /nix/var/nix/builds/nix-11432-1070387528/TestClientFallsBackToClosures168298907/001/store/4grylcvdj6z3xwm78ywrv6pqxj2w5bnr-shared-dep1309 CA: text:sha256:0a6ksq8653yf0g0y6yf9434vy1smq7clqnb6sifks9f1jp5kgbni1310--- PASS: TestClientFallsBackToClosures (1.29s)1311=== CONT TestPendingCleanupUsesOneCutoff13122026/09/24 17:46:42 INFO Aborted multipart uploads count=0 kept=013132026/09/24 17:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period13142026/09/24 17:46:42 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=013152026/09/24 17:46:42 INFO Vacuumed table table=pending_closures13162026/09/24 17:46:42 INFO Vacuumed table table=pending_objects13172026/09/24 17:46:42 INFO Vacuumed table table=multipart_uploads13182026/09/24 17:46:42 INFO Vacuumed table table=closures13192026/09/24 17:46:42 INFO Vacuumed table table=objects1320--- PASS: TestGCSweepDeliversEachKeyOnce (1.22s)1321=== CONT TestNARDeduplicationMetadataUploadBug1322--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.95s)1323=== CONT TestService_NativeMTLS13242026/09/24 17:46:42 INFO Received uploads request method=POST path=/api/pending_closures1325--- PASS: TestPendingClosureFailureAbortsItsUploads (1.14s)1326=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13272026/09/24 17:46:42 WARN Rate limiter enabled after throttle name=s3-test rate=513282026/09/24 17:46:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1329=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1330 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101331 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001332--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.57s)1333=== CONT TestGenerateLandingPage1334--- PASS: TestGenerateLandingPage (0.00s)1335=== CONT TestCreatePendingClosureRejectsOversizedNAR13362026/09/24 17:46:42 INFO Received uploads request method=POST path=/api/pending_closures1337--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1338=== CONT TestMultipartCleanup13392026/09/24 17:46:42 INFO lead: released remote=192.0.2.1:12341340--- PASS: TestPendingClosureFailureTracksEveryUpload (1.48s)1341=== CONT TestResurrectedObjectNotDeleted1342--- PASS: TestLeadElectsOneAndHandsOver (3.36s)1343=== CONT TestValidateS3Concurrency1344=== CONT TestCreatePinRejectsBadInput1345--- PASS: TestValidateS3Concurrency (0.00s)13462026/09/24 17:46:43 INFO Received uploads request method=POST path=/api/pending_closures13472026/09/24 17:46:43 INFO Aborted multipart uploads count=0 kept=013482026/09/24 17:46:43 WARN Force mode enabled - objects will be deleted immediately without grace period13492026/09/24 17:46:43 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=013502026/09/24 17:46:43 INFO Vacuumed table table=pending_closures13512026/09/24 17:46:43 INFO Vacuumed table table=pending_objects13522026/09/24 17:46:43 INFO Vacuumed table table=multipart_uploads13532026/09/24 17:46:43 INFO Vacuumed table table=closures13542026/09/24 17:46:43 INFO Vacuumed table table=objects13552026/09/24 17:46:43 INFO Received push request method=POST path=/api/pushes1356--- PASS: TestGCSweepSkipsPendingObjects (1.16s)1357=== CONT TestOrphanedObjectsGCStressTest13582026/09/24 17:46:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13592026/09/24 17:46:43 INFO Uploading zirgl2byyzn7lmy4r4cydrb0qiavqdi8-b (248B)13602026/09/24 17:46:43 INFO Uploading k788sw5br1qmhdzh9pv9k1h4iws57952-shared-dep (136B)13612026/09/24 17:46:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13622026/09/24 17:46:43 WARN Failed to register uploaded object key=nar/0y91k0rm60jsx6l5p7sncpik91qndk772k71873qgmmlkyc47pvl.nar.zst error="server returned 404: 404 page not found\n"13632026/09/24 17:46:43 WARN Failed to register uploaded object key=bva2cyd026y2snf576ihigjfm3fv2z2h.ls error="server returned 404: 404 page not found\n"13642026/09/24 17:46:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13652026/09/24 17:46:43 WARN Failed to register uploaded object key=zirgl2byyzn7lmy4r4cydrb0qiavqdi8.ls error="server returned 404: 404 page not found\n"13662026/09/24 17:46:43 WARN Failed to register uploaded object key=k788sw5br1qmhdzh9pv9k1h4iws57952.ls error="server returned 404: 404 page not found\n"13672026/09/24 17:46:43 INFO Signed narinfos id=1 count=313682026/09/24 17:46:43 INFO Uploading 3 narinfos13692026/09/24 17:46:43 INFO Received complete push request method=POST path=/api/pushes/1/complete13702026/09/24 17:46:43 WARN Failed to register uploaded object key=bva2cyd026y2snf576ihigjfm3fv2z2h.narinfo error="server returned 404: 404 page not found\n"13712026/09/24 17:46:43 WARN Failed to register uploaded object key=zirgl2byyzn7lmy4r4cydrb0qiavqdi8.narinfo error="server returned 404: 404 page not found\n"13722026/09/24 17:46:43 WARN Failed to register uploaded object key=k788sw5br1qmhdzh9pv9k1h4iws57952.narinfo error="server returned 404: 404 page not found\n"13732026/09/24 17:46:43 INFO Upload complete. (96ms)1374=== NAME TestClientPushesUseOnePush1375 client_pushes_test.go:97: Retrieved narinfo from S3:1376 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientPushesUseOnePush2915576936/001/store/k788sw5br1qmhdzh9pv9k1h4iws57952-shared-dep1377 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1378 Compression: zstd1379 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821380 NarSize: 1361381 References: 1382 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1383 client_pushes_test.go:97: Retrieved narinfo from S3:1384 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientPushesUseOnePush2915576936/001/store/bva2cyd026y2snf576ihigjfm3fv2z2h-a1385 URL: nar/0y91k0rm60jsx6l5p7sncpik91qndk772k71873qgmmlkyc47pvl.nar.zst1386 Compression: zstd1387 NarHash: sha256:0y91k0rm60jsx6l5p7sncpik91qndk772k71873qgmmlkyc47pvl1388 NarSize: 2481389 References: /nix/var/nix/builds/nix-11432-1070387528/TestClientPushesUseOnePush2915576936/001/store/k788sw5br1qmhdzh9pv9k1h4iws57952-shared-dep1390 CA: text:sha256:1igwwsqmwd0n2i0m2l0j3gz4xzb7waqb7639dfcqgx09hl009b8d1391 client_pushes_test.go:97: Retrieved narinfo from S3:1392 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientPushesUseOnePush2915576936/001/store/zirgl2byyzn7lmy4r4cydrb0qiavqdi8-b1393 URL: nar/0y91k0rm60jsx6l5p7sncpik91qndk772k71873qgmmlkyc47pvl.nar.zst1394 Compression: zstd1395 NarHash: sha256:0y91k0rm60jsx6l5p7sncpik91qndk772k71873qgmmlkyc47pvl1396 NarSize: 2481397 References: /nix/var/nix/builds/nix-11432-1070387528/TestClientPushesUseOnePush2915576936/001/store/k788sw5br1qmhdzh9pv9k1h4iws57952-shared-dep1398 CA: text:sha256:1igwwsqmwd0n2i0m2l0j3gz4xzb7waqb7639dfcqgx09hl009b8d1399--- PASS: TestClientPushesUseOnePush (1.28s)1400=== CONT TestCompletedNarNotReofferedAcrossClosures14012026/09/24 17:46:43 INFO Received uploads request method=POST path=/api/pending_closures14022026/09/24 17:46:43 INFO Received uploads request method=POST path=/api/pending_closures14032026/09/24 17:46:43 INFO Received cleanup request method=DELETE path=/api/pending_closures14042026/09/24 17:46:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"14052026/09/24 17:46:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1406--- PASS: TestService_NativeMTLS (1.06s)1407=== CONT TestOrphanedObjectsGC1408=== NAME TestNARDeduplicationMetadataUploadBug1409 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-11432-1070387528/TestNARDeduplicationMetadataUploadBug3431501268/001/store/g0i1mx6ng1fd2vknywdvk00lpsv2wapb-file1.txt14102026/09/24 17:46:44 INFO Received uploads request method=POST path=/api/pending_closures1411--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.42s)1412=== CONT TestReconnectLeavesObjectsUnlocked14132026/09/24 17:46:44 INFO Received push request method=POST path=/api/pushes14142026/09/24 17:46:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14152026/09/24 17:46:44 INFO Uploading g0i1mx6ng1fd2vknywdvk00lpsv2wapb-file1.txt (160B)14162026/09/24 17:46:44 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14172026/09/24 17:46:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14182026/09/24 17:46:44 WARN Failed to register uploaded object key=g0i1mx6ng1fd2vknywdvk00lpsv2wapb.ls error="server returned 404: 404 page not found\n"14192026/09/24 17:46:44 INFO Signed narinfos id=1 count=114202026/09/24 17:46:44 INFO Uploading 1 narinfos14212026/09/24 17:46:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14222026/09/24 17:46:44 WARN Failed to register uploaded object key=g0i1mx6ng1fd2vknywdvk00lpsv2wapb.narinfo error="server returned 404: 404 page not found\n"14232026/09/24 17:46:44 INFO Upload complete. (141ms)1424=== NAME TestNARDeduplicationMetadataUploadBug1425 metadata_upload_test.go:54: Retrieved narinfo from S3:1426 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestNARDeduplicationMetadataUploadBug3431501268/001/store/g0i1mx6ng1fd2vknywdvk00lpsv2wapb-file1.txt1427 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1428 Compression: zstd1429 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1430 NarSize: 1601431 References: 1432 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1433 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1434 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1435 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14362026/09/24 17:46:44 INFO Received uploads request method=POST path=/api/pending_closures1437 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-11432-1070387528/TestNARDeduplicationMetadataUploadBug3431501268/001/store/h8qc8wv8rgad6z08vrcjfp7qhpm1czdi-file2.txt14382026/09/24 17:46:44 INFO Received push request method=POST path=/api/pushes14392026/09/24 17:46:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14402026/09/24 17:46:44 WARN Failed to register uploaded object key=h8qc8wv8rgad6z08vrcjfp7qhpm1czdi.ls error="server returned 404: 404 page not found\n"14412026/09/24 17:46:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14422026/09/24 17:46:44 INFO Signed narinfos id=2 count=114432026/09/24 17:46:44 INFO Uploading 1 narinfos14442026/09/24 17:46:44 INFO Received complete push request method=POST path=/api/pushes/2/complete14452026/09/24 17:46:44 WARN Failed to register uploaded object key=h8qc8wv8rgad6z08vrcjfp7qhpm1czdi.narinfo error="server returned 404: 404 page not found\n"14462026/09/24 17:46:44 INFO Upload complete. (89ms)1447 metadata_upload_test.go:76: Retrieved narinfo from S3:1448 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestNARDeduplicationMetadataUploadBug3431501268/001/store/h8qc8wv8rgad6z08vrcjfp7qhpm1czdi-file2.txt1449 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1450 Compression: zstd1451 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1452 NarSize: 1601453 References: 1454 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1455 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1456 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1457 {"version":1,"root":{"type":"regular","size":44}}1458--- PASS: TestNARDeduplicationMetadataUploadBug (1.86s)1459=== CONT TestObjectStatsTrigger14602026/09/24 17:46:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14612026/09/24 17:46:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket58/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14622026/09/24 17:46:44 INFO Aborted multipart uploads count=0 kept=114632026/09/24 17:46:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14642026/09/24 17:46:44 INFO Aborted multipart uploads count=1 kept=01465--- PASS: TestMultipartCleanup (1.72s)1466=== CONT TestService_ReadScope_PublicByDefault14672026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14682026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14692026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14702026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14712026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14722026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14732026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14742026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14752026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy1476--- PASS: TestResurrectedObjectNotDeleted (1.96s)1477=== CONT TestPinProtectsFromGC14782026/09/24 17:46:44 INFO Received create pin request method=POST path=/api/pins/deploy14792026/09/24 17:46:44 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1480--- PASS: TestCreatePinRejectsBadInput (2.00s)1481=== CONT TestClientWithDependencies14822026/09/24 17:46:45 INFO Received uploads request method=POST path=/api/pending_closures1483--- PASS: TestConnectWaitsForAPeerMigration (6.12s)1484=== CONT TestClientSharedPathCommittedMidPush1485--- PASS: TestReconnectLeavesObjectsUnlocked (1.76s)1486=== CONT TestClientMultipleUploads1487=== NAME TestOrphanedObjectsGC1488 orphaned_objects_gc_test.go:296: GC Test Summary:1489 orphaned_objects_gc_test.go:297: - Kept: 2 objects from closure A1490 orphaned_objects_gc_test.go:298: - Deleted: 2 objects from closure B1491 orphaned_objects_gc_test.go:299: - Deleted: 6 orphaned chain objects (X1->X2->X3)1492 orphaned_objects_gc_test.go:300: - Deleted: 2 orphaned single objects (Y)1493 orphaned_objects_gc_test.go:301: - Total deleted: 10 objects1494--- PASS: TestOrphanedObjectsGC (2.23s)1495=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1496--- PASS: TestService_ReadScope_PublicByDefault (1.89s)1497=== CONT TestClientIntegration14982026/09/24 17:46:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1499--- PASS: TestObjectStatsTrigger (2.31s)1500=== CONT TestClientErrorHandling1501=== RUN TestClientErrorHandling/InvalidStorePath1502=== PAUSE TestClientErrorHandling/InvalidStorePath1503=== RUN TestClientErrorHandling/InvalidAuthToken1504=== PAUSE TestClientErrorHandling/InvalidAuthToken1505=== RUN TestClientErrorHandling/ServerNotAvailable1506=== PAUSE TestClientErrorHandling/ServerNotAvailable1507=== CONT TestClientCADerivations15082026/09/24 17:46:46 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4Ljc0ODRjMDI4LTNmNWQtNDQ4OS05NzFhLTQyNGJmYWI2NmRjMHgxNzkwMjcyMDA1MTEzMjIzMDAw parts=1215092026/09/24 17:46:46 INFO Received uploads request method=POST path=/api/pending_closures1510--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.53s)1511=== CONT TestCacheConfigHandler1512=== RUN TestCacheConfigHandler/full_config,_no_issuer1513=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1514=== RUN TestCacheConfigHandler/no_cache_url_configured1515=== PAUSE TestCacheConfigHandler/no_cache_url_configured1516=== RUN TestCacheConfigHandler/no_signing_keys1517=== PAUSE TestCacheConfigHandler/no_signing_keys1518=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1519=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1520=== CONT TestService_ReadAuthMiddleware1521=== NAME TestPinProtectsFromGC1522 client_integration_test.go:867: Pinned store path: /nix/var/nix/builds/nix-11432-1070387528/TestPinProtectsFromGC3425638681/001/store/q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5-pinned-file.txt1523 client_integration_test.go:868: Unpinned store path: /nix/var/nix/builds/nix-11432-1070387528/TestPinProtectsFromGC3425638681/001/store/812l5zky9kg1zpc5j3xb0j86zvk08y80-unpinned-file.txt15242026/09/24 17:46:47 INFO Received push request method=POST path=/api/pushes15252026/09/24 17:46:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15262026/09/24 17:46:47 INFO Uploading q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5-pinned-file.txt (128B)15272026/09/24 17:46:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15282026/09/24 17:46:47 WARN Failed to register uploaded object key=q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5.ls error="server returned 404: 404 page not found\n"15292026/09/24 17:46:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15302026/09/24 17:46:47 INFO Signed narinfos id=1 count=115312026/09/24 17:46:47 INFO Uploading 1 narinfos15322026/09/24 17:46:47 INFO Received complete push request method=POST path=/api/pushes/1/complete15332026/09/24 17:46:47 WARN Failed to register uploaded object key=q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5.narinfo error="server returned 404: 404 page not found\n"15342026/09/24 17:46:47 INFO Upload complete. (103ms)15352026/09/24 17:46:47 INFO Received push request method=POST path=/api/pushes15362026/09/24 17:46:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15372026/09/24 17:46:47 INFO Uploading 812l5zky9kg1zpc5j3xb0j86zvk08y80-unpinned-file.txt (128B)15382026/09/24 17:46:47 WARN Failed to register uploaded object key=812l5zky9kg1zpc5j3xb0j86zvk08y80.ls error="server returned 404: 404 page not found\n"15392026/09/24 17:46:47 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15402026/09/24 17:46:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15412026/09/24 17:46:47 INFO Signed narinfos id=2 count=115422026/09/24 17:46:47 INFO Uploading 1 narinfos15432026/09/24 17:46:47 INFO Received complete push request method=POST path=/api/pushes/2/complete15442026/09/24 17:46:47 WARN Failed to register uploaded object key=812l5zky9kg1zpc5j3xb0j86zvk08y80.narinfo error="server returned 404: 404 page not found\n"15452026/09/24 17:46:47 INFO Upload complete. (95ms)1546=== NAME TestClientWithDependencies1547 client_integration_test.go:735: Built derivation: /nix/var/nix/builds/nix-11432-1070387528/TestClientWithDependencies1194123645/001/store/8xhqainn8zxsi80r691qg9g6kc9gwpp9-test-script15482026/09/24 17:46:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures15492026/09/24 17:46:47 INFO Garbage collection started1550 client_integration_test.go:737: Found 1 dependencies (including self)15512026/09/24 17:46:47 INFO Aborted multipart uploads count=0 kept=015522026/09/24 17:46:47 WARN Force mode enabled - objects will be deleted immediately without grace period15532026/09/24 17:46:47 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=015542026/09/24 17:46:47 INFO Vacuumed table table=pending_closures15552026/09/24 17:46:47 INFO Received push request method=POST path=/api/pushes15562026/09/24 17:46:47 INFO Vacuumed table table=pending_objects15572026/09/24 17:46:47 INFO Vacuumed table table=multipart_uploads15582026/09/24 17:46:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/09/24 17:46:47 INFO Uploading 8xhqainn8zxsi80r691qg9g6kc9gwpp9-test-script (136B)15602026/09/24 17:46:47 INFO Vacuumed table table=closures15612026/09/24 17:46:47 WARN Failed to register uploaded object key=8xhqainn8zxsi80r691qg9g6kc9gwpp9.ls error="server returned 404: 404 page not found\n"15622026/09/24 17:46:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15632026/09/24 17:46:47 INFO Vacuumed table table=objects15642026/09/24 17:46:47 WARN Failed to register uploaded object key=log/6g7w6kw6hfvzj9sy3a1si837bydq7vpn-test-script.drv error="server returned 404: 404 page not found\n"15652026/09/24 17:46:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15662026/09/24 17:46:47 INFO Signed narinfos id=1 count=115672026/09/24 17:46:47 INFO Uploading 1 narinfos15682026/09/24 17:46:47 INFO Received complete push request method=POST path=/api/pushes/1/complete15692026/09/24 17:46:47 WARN Failed to register uploaded object key=8xhqainn8zxsi80r691qg9g6kc9gwpp9.narinfo error="server returned 404: 404 page not found\n"15702026/09/24 17:46:47 INFO Upload complete. (166ms)15712026/09/24 17:46:47 INFO Aborted multipart uploads count=0 kept=015722026/09/24 17:46:47 WARN Force mode enabled - objects will be deleted immediately without grace period15732026/09/24 17:46:47 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=015742026/09/24 17:46:47 INFO Vacuumed table table=pending_closures15752026/09/24 17:46:47 INFO Vacuumed table table=pending_objects15762026/09/24 17:46:47 INFO Vacuumed table table=multipart_uploads15772026/09/24 17:46:47 INFO Vacuumed table table=closures15782026/09/24 17:46:47 INFO Vacuumed table table=objects1579 client_integration_test.go:753: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-11432-1070387528/TestClientWithDependencies1194123645/001/store) requires matching store prefix15802026/09/24 17:46:48 INFO Received uploads request method=POST path=/api/pending_closures1581--- PASS: TestClientWithDependencies (3.24s)1582=== CONT TestCacheStatsHandler15832026/09/24 17:46:48 INFO Received push request method=POST path=/api/pushes15842026/09/24 17:46:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15852026/09/24 17:46:48 INFO Uploading lz3k5d8k519y8prqd4xklisniqv4q9s2-top (256B)15862026/09/24 17:46:48 INFO Uploading b60b8nxhh4kqapn0jj9fnmjwfgj2440q-shared-dep (136B)15872026/09/24 17:46:48 WARN Failed to register uploaded object key=lz3k5d8k519y8prqd4xklisniqv4q9s2.ls error="server returned 404: 404 page not found\n"15882026/09/24 17:46:48 WARN Failed to register uploaded object key=b60b8nxhh4kqapn0jj9fnmjwfgj2440q.ls error="server returned 404: 404 page not found\n"15892026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/0b4l31frxx4h0c2dxn61yy25p47c3417211v4q83bw4bx9nr880b.nar.zst error="server returned 404: 404 page not found\n"15902026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15912026/09/24 17:46:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15922026/09/24 17:46:48 INFO Signed narinfos id=1 count=215932026/09/24 17:46:48 INFO Uploading 2 narinfos15942026/09/24 17:46:48 WARN Failed to register uploaded object key=lz3k5d8k519y8prqd4xklisniqv4q9s2.narinfo error="server returned 404: 404 page not found\n"15952026/09/24 17:46:48 INFO Received complete push request method=POST path=/api/pushes/1/complete15962026/09/24 17:46:48 WARN Failed to register uploaded object key=b60b8nxhh4kqapn0jj9fnmjwfgj2440q.narinfo error="server returned 404: 404 page not found\n"15972026/09/24 17:46:48 INFO Upload complete. (152ms)1598=== NAME TestClientSharedPathCommittedMidPush1599 client_integration_test.go:816: Retrieved narinfo from S3:1600 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientSharedPathCommittedMidPush3388901786/001/store/b60b8nxhh4kqapn0jj9fnmjwfgj2440q-shared-dep1601 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1602 Compression: zstd1603 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821604 NarSize: 1361605 References: 1606 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1607 client_integration_test.go:816: Retrieved narinfo from S3:1608 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientSharedPathCommittedMidPush3388901786/001/store/lz3k5d8k519y8prqd4xklisniqv4q9s2-top1609 URL: nar/0b4l31frxx4h0c2dxn61yy25p47c3417211v4q83bw4bx9nr880b.nar.zst1610 Compression: zstd1611 NarHash: sha256:0b4l31frxx4h0c2dxn61yy25p47c3417211v4q83bw4bx9nr880b1612 NarSize: 2561613 References: /nix/var/nix/builds/nix-11432-1070387528/TestClientSharedPathCommittedMidPush3388901786/001/store/b60b8nxhh4kqapn0jj9fnmjwfgj2440q-shared-dep1614 CA: text:sha256:0pz6cynf79na5zqxsz2f3ngqg2mm4h789k2s840cim9ypbc9bbks16152026/09/24 17:46:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16162026/09/24 17:46:48 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM3MjRjZTIzLWRiODMtNDY0Ny1hYjBkLTFjZTY3MDUzY2RjZXgxNzkwMjcyMDA4MDcxODYyMDAw1617--- PASS: TestClientSharedPathCommittedMidPush (2.58s)1618=== CONT TestConcurrentPinUpdatesAgree16192026/09/24 17:46:48 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM3MjRjZTIzLWRiODMtNDY0Ny1hYjBkLTFjZTY3MDUzY2RjZXgxNzkwMjcyMDA4MDcxODYyMDAw error="Delete \"http://localhost:51717/bucket70/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM3MjRjZTIzLWRiODMtNDY0Ny1hYjBkLTFjZTY3MDUzY2RjZXgxNzkwMjcyMDA4MDcxODYyMDAw\": injected: abort refused"1620=== NAME TestClientMultipleUploads1621 client_integration_test.go:480: Created store path 0: /nix/var/nix/builds/nix-11432-1070387528/TestClientMultipleUploads2795038155/001/store/q48slvv6jd4z7likskw4n2npywdbczyd-test-file-0.txt16222026/09/24 17:46:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16232026/09/24 17:46:48 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM3MjRjZTIzLWRiODMtNDY0Ny1hYjBkLTFjZTY3MDUzY2RjZXgxNzkwMjcyMDA4MDcxODYyMDAw16242026/09/24 17:46:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTUwNTU5M2MtOWQxOC00MzE0LTkxMWQtODI0NDlmMjI2YzI4LjM3MjRjZTIzLWRiODMtNDY0Ny1hYjBkLTFjZTY3MDUzY2RjZXgxNzkwMjcyMDA4MDcxODYyMDAw parts=11625--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.60s)1626=== CONT TestPresentReportsOnlyClosureRoots1627=== NAME TestClientMultipleUploads1628 client_integration_test.go:480: Created store path 1: /nix/var/nix/builds/nix-11432-1070387528/TestClientMultipleUploads2795038155/001/store/vmbgqy4al6z161vb438jr08f5vakwlkm-test-file-1.txt1629 client_integration_test.go:480: Created store path 2: /nix/var/nix/builds/nix-11432-1070387528/TestClientMultipleUploads2795038155/001/store/57mw1p9qk2chdig0s776q9kxp4kh9hl5-test-file-2.txt1630=== NAME TestClientIntegration1631 client_integration_test.go:334: Created store path: /nix/var/nix/builds/nix-11432-1070387528/TestClientIntegration2772890539/002/store/xm158jv2dg5vmlkn75y1w6zqrgw4xmdc-test-file.txt16322026/09/24 17:46:48 INFO Received push request method=POST path=/api/pushes16332026/09/24 17:46:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16342026/09/24 17:46:48 INFO Uploading q48slvv6jd4z7likskw4n2npywdbczyd-test-file-0.txt (160B)16352026/09/24 17:46:48 INFO Uploading 57mw1p9qk2chdig0s776q9kxp4kh9hl5-test-file-2.txt (160B)16362026/09/24 17:46:48 INFO Uploading vmbgqy4al6z161vb438jr08f5vakwlkm-test-file-1.txt (160B)16372026/09/24 17:46:48 WARN Failed to register uploaded object key=vmbgqy4al6z161vb438jr08f5vakwlkm.ls error="server returned 404: 404 page not found\n"16382026/09/24 17:46:48 WARN Failed to register uploaded object key=57mw1p9qk2chdig0s776q9kxp4kh9hl5.ls error="server returned 404: 404 page not found\n"16392026/09/24 17:46:48 WARN Failed to register uploaded object key=q48slvv6jd4z7likskw4n2npywdbczyd.ls error="server returned 404: 404 page not found\n"16402026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16412026/09/24 17:46:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16422026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16432026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16442026/09/24 17:46:48 INFO Signed narinfos id=1 count=316452026/09/24 17:46:48 INFO Uploading 3 narinfos16462026/09/24 17:46:48 WARN Failed to register uploaded object key=57mw1p9qk2chdig0s776q9kxp4kh9hl5.narinfo error="server returned 404: 404 page not found\n"16472026/09/24 17:46:48 INFO Received complete push request method=POST path=/api/pushes/1/complete16482026/09/24 17:46:48 WARN Failed to register uploaded object key=q48slvv6jd4z7likskw4n2npywdbczyd.narinfo error="server returned 404: 404 page not found\n"16492026/09/24 17:46:48 WARN Failed to register uploaded object key=vmbgqy4al6z161vb438jr08f5vakwlkm.narinfo error="server returned 404: 404 page not found\n"16502026/09/24 17:46:48 INFO Received push request method=POST path=/api/pushes16512026/09/24 17:46:48 INFO Upload complete. (159ms)1652=== NAME TestClientMultipleUploads1653 client_integration_test.go:491: Uploaded 3 paths in 192.636583ms16542026/09/24 17:46:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16552026/09/24 17:46:48 INFO Uploading xm158jv2dg5vmlkn75y1w6zqrgw4xmdc-test-file.txt (152B)16562026/09/24 17:46:48 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16572026/09/24 17:46:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16582026/09/24 17:46:48 WARN Failed to register uploaded object key=xm158jv2dg5vmlkn75y1w6zqrgw4xmdc.ls error="server returned 404: 404 page not found\n"16592026/09/24 17:46:48 INFO Signed narinfos id=1 count=116602026/09/24 17:46:48 INFO Uploading 1 narinfos16612026/09/24 17:46:48 INFO Received complete push request method=POST path=/api/pushes/1/complete16622026/09/24 17:46:48 WARN Failed to register uploaded object key=xm158jv2dg5vmlkn75y1w6zqrgw4xmdc.narinfo error="server returned 404: 404 page not found\n"16632026/09/24 17:46:48 INFO Upload complete. (142ms)1664--- PASS: TestClientMultipleUploads (3.07s)1665=== CONT TestCreatePin_ReservedPins16662026/09/24 17:46:48 INFO All 1 paths already cached1667=== NAME TestClientIntegration1668 client_integration_test.go:360: Retrieved narinfo from S3:1669 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientIntegration2772890539/002/store/xm158jv2dg5vmlkn75y1w6zqrgw4xmdc-test-file.txt1670 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1671 Compression: zstd1672 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11673 NarSize: 1521674 References: 1675 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11676 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1677 client_integration_test.go:361: Decompressed .ls content (64 bytes):1678 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1679--- PASS: TestService_ReadAuthMiddleware (2.17s)1680=== CONT TestDeletePinKeepsRowWhenS3Fails16812026/09/24 17:46:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52055/oidc16822026/09/24 17:46:49 INFO Received push request method=POST path=/api/pushes16832026/09/24 17:46:49 INFO Object in database but missing from S3 key=xm158jv2dg5vmlkn75y1w6zqrgw4xmdc.ls16842026/09/24 17:46:49 WARN Found objects in DB but missing from S3, will re-upload count=116852026/09/24 17:46:49 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16862026/09/24 17:46:49 INFO Received complete push request method=POST path=/api/pushes/2/complete16872026/09/24 17:46:49 WARN Failed to register uploaded object key=xm158jv2dg5vmlkn75y1w6zqrgw4xmdc.ls error="server returned 404: 404 page not found\n"16882026/09/24 17:46:49 INFO Upload complete. (70ms)1689=== NAME TestClientIntegration1690 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1691 client_integration_test.go:389: Decompressed .ls content (49 bytes):1692 {"version":1,"root":{"type":"regular","size":39}}1693=== NAME TestClientCADerivations1694 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-11432-1070387528/TestClientCADerivations2359426831/001/store/zfmpk0kcmcvm25x15hcxnzk692f134aj-ca-test16952026/09/24 17:46:49 INFO Received push request method=POST path=/api/pushes16962026/09/24 17:46:49 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1697 client_ca_test.go:139: Found 1 dependencies (including self)16982026/09/24 17:46:49 INFO Received complete push request method=POST path=/api/pushes/3/complete16992026/09/24 17:46:49 WARN Failed to register uploaded object key=xm158jv2dg5vmlkn75y1w6zqrgw4xmdc.ls error="server returned 404: 404 page not found\n"17002026/09/24 17:46:49 INFO Upload complete. (75ms)1701=== NAME TestClientIntegration1702 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1703 client_integration_test.go:405: Decompressed .ls content (49 bytes):1704 {"version":1,"root":{"type":"regular","size":39}}1705=== NAME TestOrphanedObjectsGCStressTest1706 orphaned_objects_gc_test.go:431: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17072026/09/24 17:46:49 INFO Received push request method=POST path=/api/pushes17082026/09/24 17:46:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17092026/09/24 17:46:49 INFO Uploading zfmpk0kcmcvm25x15hcxnzk692f134aj-ca-test (144B)1710 orphaned_objects_gc_test.go:452: Marked 210 objects for deletion17112026/09/24 17:46:49 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17122026/09/24 17:46:49 WARN Failed to register uploaded object key=zfmpk0kcmcvm25x15hcxnzk692f134aj.ls error="server returned 404: 404 page not found\n"17132026/09/24 17:46:49 WARN Failed to register uploaded object key=log/0a2lbfspfrxm3qyxlk622npwx8hyya8z-ca-test.drv error="server returned 404: 404 page not found\n"17142026/09/24 17:46:49 INFO Received push request method=POST path=/api/pushes17152026/09/24 17:46:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17162026/09/24 17:46:49 INFO Uploading dqa2rl4rlp5rfq8pwd7dw4kmz933yyai-lost-commit.txt (152B)17172026/09/24 17:46:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17182026/09/24 17:46:49 INFO Signed narinfos id=1 count=117192026/09/24 17:46:49 INFO Uploading 1 narinfos17202026/09/24 17:46:49 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"17212026/09/24 17:46:49 WARN Failed to register uploaded object key=zfmpk0kcmcvm25x15hcxnzk692f134aj.narinfo error="server returned 404: 404 page not found\n"17222026/09/24 17:46:49 WARN Failed to register uploaded object key=dqa2rl4rlp5rfq8pwd7dw4kmz933yyai.ls error="server returned 404: 404 page not found\n"17232026/09/24 17:46:49 INFO Received complete push request method=POST path=/api/pushes/1/complete17242026/09/24 17:46:49 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign17252026/09/24 17:46:49 INFO Signed narinfos id=4 count=117262026/09/24 17:46:49 INFO Uploading 1 narinfos17272026/09/24 17:46:49 INFO Upload complete. (181ms)17282026/09/24 17:46:49 INFO Received complete push request method=POST path=/api/pushes/4/complete17292026/09/24 17:46:49 WARN Failed to register uploaded object key=dqa2rl4rlp5rfq8pwd7dw4kmz933yyai.narinfo error="server returned 404: 404 page not found\n"17302026/09/24 17:46:49 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:52033/api/pushes/4/complete\": EOF" url=http://127.0.0.1:52033/api/pushes/4/complete1731=== NAME TestClientCADerivations1732 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientCADerivations2359426831/001/store/zfmpk0kcmcvm25x15hcxnzk692f134aj-ca-test1733 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1734 Compression: zstd1735 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1736 NarSize: 1441737 References: 1738 Deriver: /nix/var/nix/builds/nix-11432-1070387528/TestClientCADerivations2359426831/001/store/0a2lbfspfrxm3qyxlk622npwx8hyya8z-ca-test.drv1739 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1740 client_ca_test.go:185: Checking for realisation files in S3...1741 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1742 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1743 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket73?endpoint=http://localhost:51717®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-11432-1070387528/TestClientCADerivations2359426831/001/store'1744 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117452026/09/24 17:46:49 INFO Received complete push request method=POST path=/api/pushes/4/complete17462026-09-24 17:46:49.551 UTC [11890] ERROR: Push does not exist: id=417472026-09-24 17:46:49.551 UTC [11890] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE17482026-09-24 17:46:49.551 UTC [11890] STATEMENT: -- name: CommitPush :exec1749 SELECT commit_push($1::bigint)1750 17512026/09/24 17:46:49 INFO Upload complete. (180ms)1752=== NAME TestClientIntegration1753 client_integration_test.go:435: Retrieved narinfo from S3:1754 StorePath: /nix/var/nix/builds/nix-11432-1070387528/TestClientIntegration2772890539/002/store/dqa2rl4rlp5rfq8pwd7dw4kmz933yyai-lost-commit.txt1755 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1756 Compression: zstd1757 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1758 NarSize: 1521759 References: 1760 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1761 client_integration_test.go:438: Testing garbage collection...1762--- PASS: TestClientCADerivations (2.79s)1763=== CONT TestService_healthCheckHandler17642026/09/24 17:46:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures17652026/09/24 17:46:49 INFO Garbage collection started17662026/09/24 17:46:49 INFO Aborted multipart uploads count=0 kept=017672026/09/24 17:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period17682026/09/24 17:46:49 INFO Aborted multipart uploads count=1 kept=017692026/09/24 17:46:49 INFO Received cleanup request method=DELETE path=/api/pending_closures17702026/09/24 17:46:49 INFO Aborted multipart uploads count=1 kept=01771--- PASS: TestPendingCleanupUsesOneCutoff (7.24s)1772=== CONT TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown17732026/09/24 17:46:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=017742026/09/24 17:46:49 INFO Received create pin request method=POST path=/api/pins/myapp17752026/09/24 17:46:49 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=017762026/09/24 17:46:49 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-11432-1070387528/TestPinProtectsFromGC3425638681/001/store/q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5-pinned-file.txt narinfo_key=q4ipwxh7rg7ha5fqwgpkrzcnjjr89hy5.narinfo17772026/09/24 17:46:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures17782026/09/24 17:46:49 INFO Garbage collection started17792026/09/24 17:46:49 INFO Aborted multipart uploads count=0 kept=017802026/09/24 17:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period17812026/09/24 17:46:49 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=017822026/09/24 17:46:49 INFO Vacuumed table table=pending_closures17832026/09/24 17:46:49 INFO Vacuumed table table=pending_objects17842026/09/24 17:46:49 INFO Vacuumed table table=multipart_uploads17852026/09/24 17:46:49 INFO Vacuumed table table=closures17862026/09/24 17:46:49 INFO Vacuumed table table=objects17872026/09/24 17:46:49 INFO Vacuumed table table=pending_closures17882026/09/24 17:46:49 INFO Vacuumed table table=pending_objects17892026/09/24 17:46:49 INFO Vacuumed table table=multipart_uploads17902026/09/24 17:46:49 INFO Vacuumed table table=closures17912026/09/24 17:46:49 INFO Vacuumed table table=objects1792--- PASS: TestCacheStatsHandler (1.78s)1793=== CONT TestService_AuthMiddleware_OIDC17942026/09/24 17:46:49 INFO Received create pin request method=POST path=/api/pins/app17952026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/app17962026/09/24 17:46:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52086/oidc1797--- PASS: TestPresentReportsOnlyClosureRoots (1.71s)1798=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17992026/09/24 17:46:50 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo18002026/09/24 17:46:50 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo18012026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/app1802--- PASS: TestConcurrentPinUpdatesAgree (2.21s)1803=== CONT TestService_RequireScope_OIDC18042026/09/24 17:46:50 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo18052026/09/24 17:46:50 INFO Received delete pin request method=DELETE path=/api/pins/app18062026/09/24 17:46:50 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket78/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18072026/09/24 17:46:50 INFO Received delete pin request method=DELETE path=/api/pins/app18082026/09/24 17:46:50 INFO Deleted pin name=app1809--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.61s)1810=== CONT TestReadProxyNarinfo18112026/09/24 17:46:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52094/oidc18122026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18132026/09/24 17:46:50 WARN Refused reserved pin name=worker-x86_64-linux18142026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18152026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/my-app18162026/09/24 17:46:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1817--- PASS: TestCreatePin_ReservedPins (1.89s)1818=== CONT TestMetricsInventory1819=== NAME TestOrphanedObjectsGCStressTest1820 orphaned_objects_gc_test.go:515: Stress test completed successfully:1821 orphaned_objects_gc_test.go:516: - Active objects preserved: 201822 orphaned_objects_gc_test.go:517: - Objects deleted: 2101823 orphaned_objects_gc_test.go:518: - Total GC'd: 2101824--- PASS: TestOrphanedObjectsGCStressTest (7.78s)1825=== CONT TestService_AuthMiddleware1826--- PASS: TestService_healthCheckHandler (1.77s)1827=== CONT TestPendingClosureWriteTimeout/400_objects1828=== CONT TestPendingClosureWriteTimeout/670k_objects1829=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18302026/09/24 17:46:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01831=== NAME TestClientIntegration1832 client_integration_test.go:445: Objects in database after GC:1833 client_integration_test.go:445: Successfully deleted all objects with GC --force18342026/09/24 17:46:51 INFO Aborted multipart uploads count=0 kept=018352026/09/24 17:46:51 WARN Force mode enabled - objects will be deleted immediately without grace period1836--- PASS: TestClientIntegration (5.34s)1837=== CONT TestPendingClosureWriteTimeout/negative1838=== CONT TestPendingClosureWriteTimeout/empty1839=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18402026/09/24 17:46:51 INFO Received request for more parts method=POST path=/1841=== NAME TestPinProtectsFromGC1842 client_integration_test.go:981: Pin successfully protected closure from garbage collection1843--- PASS: TestPinProtectsFromGC (7.08s)1844=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18452026/09/24 17:46:51 INFO Received complete multipart upload request method=POST path=/18462026/09/24 17:46:51 ERROR failed to remove object object=nar/nnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnn.nar.zst error="We encountered an internal error."18472026/09/24 17:46:51 INFO Received uploads request method=POST path=/api/pending_closures18482026/09/24 17:46:51 INFO Aborted multipart uploads count=0 kept=018492026/09/24 17:46:51 WARN Force mode enabled - objects will be deleted immediately without grace period18502026/09/24 17:46:51 INFO Garbage collection completed failed-uploads-deleted=1 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=2 objects-failed-to-delete=018512026/09/24 17:46:51 INFO Vacuumed table table=pending_closures1852=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1853=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1854=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1855=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1856=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1857=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1858=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1859=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1860=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18612026/09/24 17:46:51 INFO Received uploads request method=POST path=/18622026/09/24 17:46:51 INFO Vacuumed table table=pending_objects18632026/09/24 17:46:51 INFO Vacuumed table table=multipart_uploads18642026/09/24 17:46:51 INFO Vacuumed table table=closures18652026/09/24 17:46:51 INFO Vacuumed table table=objects1866--- PASS: TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown (2.24s)1867=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18682026/09/24 17:46:51 INFO Received request for more parts method=POST path=/1869=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18702026/09/24 17:46:51 INFO Received uploads request method=POST path=/1871=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18722026/09/24 17:46:51 INFO Received complete multipart upload request method=POST path=/1873=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18742026/09/24 17:46:51 INFO Received uploads request method=POST path=/1875--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1876 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1877 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1878 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1879 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1880=== CONT TestPush_RejectsBadRequests/no_objects18812026/09/24 17:46:51 INFO Received push request method=POST path=/api/pushes1882=== CONT TestPush_RejectsBadRequests/bad_root18832026/09/24 17:46:51 INFO Received push request method=POST path=/api/pushes1884=== CONT TestPush_RejectsBadRequests/root_not_in_objects18852026/09/24 17:46:51 INFO Received push request method=POST path=/api/pushes1886=== CONT TestPush_RejectsBadRequests/no_roots18872026/09/24 17:46:51 INFO Received push request method=POST path=/api/pushes1888=== CONT TestProxyWriteTimeout/narinfo1889=== CONT TestProxyWriteTimeout/unknown_size1890=== CONT TestProxyWriteTimeout/10_GiB_nar1891=== CONT TestProxyWriteTimeout/1_GiB_nar1892=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1893--- PASS: TestProxyWriteTimeout (0.00s)1894 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1895 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1896 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1897 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1898=== CONT TestIsValidCachePath/random_path1899=== CONT TestIsValidCachePath/wrong_extension1900=== CONT TestIsValidCachePath/short_hash1901=== CONT TestIsValidCachePath/empty1902=== CONT TestIsValidCachePath/leading_slash1903=== CONT TestIsValidCachePath/invalid_char_u1904=== CONT TestIsValidCachePath/invalid_char_e1905=== CONT TestIsValidCachePath/traversal_in_middle1906=== CONT TestIsValidCachePath/traversal_parent1907=== CONT TestIsValidCachePath/index.html1908=== CONT TestIsValidCachePath/nar_xz1909=== CONT TestIsValidCachePath/nar_bz21910=== CONT TestIsValidCachePath/nar_zst1911=== CONT TestIsValidCachePath/ls1912=== CONT TestIsValidCachePath/nix-cache-info1913=== CONT TestIsValidCachePath/realisation1914=== CONT TestIsValidCachePath/nar_uncompressed1915=== CONT TestIsValidCachePath/log1916=== CONT TestIsValidCachePath/narinfo1917--- PASS: TestIsValidCachePath (0.00s)1918 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1919 --- PASS: TestIsValidCachePath/random_path (0.00s)1920 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1921 --- PASS: TestIsValidCachePath/short_hash (0.00s)1922 --- PASS: TestIsValidCachePath/empty (0.00s)1923 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1924 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1925 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1926 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1927 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1928 --- PASS: TestIsValidCachePath/index.html (0.00s)1929 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1930 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1931 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1932 --- PASS: TestIsValidCachePath/ls (0.00s)1933 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1934 --- PASS: TestIsValidCachePath/realisation (0.00s)1935 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1936 --- PASS: TestIsValidCachePath/log (0.00s)1937 --- PASS: TestIsValidCachePath/narinfo (0.00s)1938=== CONT TestParseSingleRange/unknown_unit1939=== CONT TestParseSingleRange/start_far_past_EOF1940=== CONT TestParseSingleRange/closed1941=== CONT TestParseSingleRange/start_past_EOF1942=== CONT TestParseSingleRange/single_byte1943=== CONT TestParseSingleRange/suffix_exceeds_size1944=== CONT TestParseSingleRange/suffix1945=== CONT TestParseSingleRange/end_clamped_to_size1946=== CONT TestParseSingleRange/open-ended1947=== CONT TestParseSingleRange/multi-range_ignored1948=== CONT TestParseSingleRange/malformed_end_before_start1949=== CONT TestParseSingleRange/malformed_no_dash1950=== CONT TestParseSingleRange/none1951=== CONT TestParseSingleRange/malformed_both_empty1952--- PASS: TestParseSingleRange (0.00s)1953 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1954 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1955 --- PASS: TestParseSingleRange/closed (0.00s)1956 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1957 --- PASS: TestParseSingleRange/single_byte (0.00s)1958 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1959 --- PASS: TestParseSingleRange/suffix (0.00s)1960 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1961 --- PASS: TestParseSingleRange/open-ended (0.00s)1962 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1963 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1964 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1965 --- PASS: TestParseSingleRange/none (0.00s)1966 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1967=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1968--- PASS: TestPush_RejectsBadRequests (2.06s)1969 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1970 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1971 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1972 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1973=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1974=== CONT TestGCEndsOnShutdown/before_the_run19752026/09/24 17:46:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19762026/09/24 17:46:52 WARN mTLS auth: bound subjects configured but subject DN unavailable19772026/09/24 17:46:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1978--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.18s)1979=== CONT TestResolveDBConnectionString/flag_wins1980=== CONT TestResolveDBConnectionString/nothing_configured1981=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1982=== CONT TestResolveDBConnectionString/missing_file_is_an_error1983=== CONT TestResolveDBConnectionString/file_when_flag_empty1984=== CONT TestIsValidUploadKey/nar_zst1985=== CONT TestIsValidUploadKey/empty_key1986=== CONT TestIsValidUploadKey/unknown_type1987=== CONT TestIsValidUploadKey/traversal_nar1988=== CONT TestIsValidUploadKey/absolute1989=== CONT TestIsValidUploadKey/traversal1990=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1991=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1992=== CONT TestIsValidUploadKey/index.html1993=== CONT TestIsValidUploadKey/nix-cache-info1994=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1995=== CONT TestIsValidUploadKey/realisation_plus_in_output1996=== CONT TestIsValidUploadKey/build_log_equals1997=== CONT TestIsValidUploadKey/realisation1998=== CONT TestIsValidUploadKey/build_log_question_mark1999=== CONT TestIsValidUploadKey/build_log_home-manager_file2000=== CONT TestIsValidUploadKey/build_log2001=== CONT TestIsValidUploadKey/listing2002=== CONT TestIsValidUploadKey/nar_plain2003=== CONT TestIsValidUploadKey/build_log_plus_in_name2004=== CONT TestIsValidUploadKey/nar_xz2005=== CONT TestIsValidUploadKey/narinfo2006=== CONT TestServerTLSConfig/no_client_CA2007--- PASS: TestIsValidUploadKey (0.00s)2008 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2009 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2010 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2011 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2012 --- PASS: TestIsValidUploadKey/absolute (0.00s)2013 --- PASS: TestIsValidUploadKey/traversal (0.00s)2014 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2015 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2016 --- PASS: TestIsValidUploadKey/index.html (0.00s)2017 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2018 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2019 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2020 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2021 --- PASS: TestIsValidUploadKey/realisation (0.00s)2022 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2023 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2024 --- PASS: TestIsValidUploadKey/build_log (0.00s)2025 --- PASS: TestIsValidUploadKey/listing (0.00s)2026 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2027 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2028 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2029 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2030=== CONT TestServerTLSConfig/not_a_PEM_file2031--- PASS: TestResolveDBConnectionString (0.02s)2032 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2033 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2034 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2035 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2036 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2037=== CONT TestServerTLSConfig/missing_CA_file2038=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2039--- PASS: TestServerTLSConfig (0.00s)2040 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2041 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2042 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)20432026/09/24 17:46:52 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"2044=== RUN TestService_RequireScope_OIDC/builder_may_write2045=== PAUSE TestService_RequireScope_OIDC/builder_may_write2046=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2047=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2048=== RUN TestService_RequireScope_OIDC/ops_may_admin2049=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2050=== RUN TestService_RequireScope_OIDC/ops_may_not_write2051=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2052=== RUN TestService_RequireScope_OIDC/reader_may_not_write2053=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2054=== RUN TestService_RequireScope_OIDC/static_token_may_admin2055=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2056=== RUN TestService_RequireScope_OIDC/static_token_may_write2057=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2058=== RUN TestService_RequireScope_OIDC/reader_may_read2059=== PAUSE TestService_RequireScope_OIDC/reader_may_read2060=== RUN TestService_RequireScope_OIDC/writer_implies_read2061=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2062=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2063=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2064=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20652026/09/24 17:46:53 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772162066--- PASS: TestReadProxyNarinfo (2.49s)2067=== CONT TestClientErrorHandling/ServerNotAvailable2068--- PASS: TestMetricsInventory (2.44s)2069=== CONT TestClientErrorHandling/InvalidAuthToken20702026/09/24 17:46:53 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20712026/09/24 17:46:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.545653ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20722026/09/24 17:46:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2073--- PASS: TestService_AuthMiddleware (2.48s)2074=== CONT TestClientErrorHandling/InvalidStorePath20752026/09/24 17:46:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.546005ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20762026/09/24 17:46:53 INFO Received uploads request method=POST path=/api/pending_closures20772026/09/24 17:46:54 INFO Aborted multipart uploads count=0 kept=020782026/09/24 17:46:54 WARN Force mode enabled - objects will be deleted immediately without grace period20792026/09/24 17:46:54 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.965206ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20802026/09/24 17:46:54 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:51717/bucket89/?delete=\": context canceled"2081=== CONT TestCacheConfigHandler/no_signing_keys2082=== CONT TestCacheConfigHandler/no_cache_url_configured2083=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2084=== CONT TestCacheConfigHandler/full_config,_no_issuer2085=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2086--- PASS: TestCacheConfigHandler (0.00s)2087 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2088 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2089 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2090 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)20912026/09/24 17:46:54 WARN Authentication failed token_preview=eyJhbGciOi...t4EY1Oy_ug token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2092=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2093=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2094=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20952026/09/24 17:46:54 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2096=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2097=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2098=== CONT TestService_RequireScope_OIDC/writer_implies_read2099=== CONT TestService_RequireScope_OIDC/static_token_may_admin2100=== CONT TestService_RequireScope_OIDC/ops_may_admin2101=== CONT TestService_RequireScope_OIDC/ops_may_not_write2102=== CONT TestService_RequireScope_OIDC/reader_may_not_write2103=== CONT TestService_RequireScope_OIDC/static_token_may_write2104=== CONT TestService_RequireScope_OIDC/builder_may_write2105=== CONT TestService_RequireScope_OIDC/reader_may_read2106--- PASS: TestService_AuthMiddleware_OIDC (2.08s)2107 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2108 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2109 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2110 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2111--- PASS: TestService_RequireScope_OIDC (2.41s)2112 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2113 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2114 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2115 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2116 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2117 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2118 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2119 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2120 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2121 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)21222026/09/24 17:46:54 INFO Aborted multipart uploads count=0 kept=021232026/09/24 17:46:54 WARN Force mode enabled - objects will be deleted immediately without grace period21242026-09-24 17:46:54.271 UTC [12059] ERROR: canceling statement due to user request21252026-09-24 17:46:54.271 UTC [12059] STATEMENT: -- name: MarkStaleObjects :execrows2126 WITH RECURSIVE ct AS (2127 SELECT timezone('UTC', now()) AS now2128 ),2129 closure_reach AS (2130 -- Start with all closure keys2131 SELECT o.key, o.refs2132 FROM objects o2133 INNER JOIN closures c ON o.key = c.key2134 UNION2135 -- Recursively add all referenced objects2136 SELECT o.key, o.refs2137 FROM objects o2138 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2139 ),2140 reachable_objects AS (2141 SELECT DISTINCT key FROM closure_reach2142 ),2143 stale_objects AS (2144 SELECT o.key2145 FROM objects AS o, ct2146 WHERE2147 NOT EXISTS (2148 SELECT 12149 FROM reachable_objects ro2150 WHERE ro.key = o.key2151 )2152 AND NOT EXISTS (2153 SELECT 12154 FROM pending_objects AS po2155 WHERE po.key = o.key2156 )2157 AND o.deleted_at IS NULL -- Only mark fresh objects2158 ORDER BY o.key -- lock in key order, like commit_pending_closure2159 FOR UPDATE2160 )2161 UPDATE objects2162 SET2163 deleted_at = ct.now,2164 first_deleted_at = COALESCE(first_deleted_at, ct.now)2165 FROM stale_objects, ct2166 WHERE objects.key = stale_objects.key2167 2168--- PASS: TestGCEndsOnShutdown (0.00s)2169 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.12s)2170 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.22s)2171 --- PASS: TestGCEndsOnShutdown/before_the_run (2.32s)2172--- PASS: TestPendingClosureWriteTimeout (0.02s)2173 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2174 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2175 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2176 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2177 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.18s)21782026/09/24 17:46:54 INFO Received uploads request method=POST path=/api/pending_closures21792026/09/24 17:46:54 INFO Aborted multipart uploads count=0 kept=021802026/09/24 17:46:54 WARN Force mode enabled - objects will be deleted immediately without grace period21812026/09/24 17:46:54 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=021822026/09/24 17:46:54 INFO Vacuumed table table=pending_closures21832026/09/24 17:46:54 INFO Vacuumed table table=pending_objects21842026/09/24 17:46:54 INFO Vacuumed table table=multipart_uploads21852026/09/24 17:46:54 INFO Vacuumed table table=closures21862026/09/24 17:46:54 INFO Vacuumed table table=objects21872026/09/24 17:46:54 INFO Received uploads request method=POST path=/api/pending_closures21882026/09/24 17:46:54 INFO Aborted multipart uploads count=0 kept=021892026/09/24 17:46:54 WARN Force mode enabled - objects will be deleted immediately without grace period21902026/09/24 17:46:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.472202129s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21912026/09/24 17:46:54 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=021922026/09/24 17:46:54 INFO Vacuumed table table=pending_closures21932026/09/24 17:46:54 INFO Vacuumed table table=pending_objects21942026/09/24 17:46:54 INFO Vacuumed table table=multipart_uploads21952026/09/24 17:46:54 INFO Vacuumed table table=closures21962026/09/24 17:46:54 INFO Vacuumed table table=objects2197--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2198 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.31s)2199 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.03s)22002026/09/24 17:46:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22012026/09/24 17:46:55 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2202--- PASS: TestUploadHandlersRejectOversizedBody (0.10s)2203 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.32s)2204 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.30s)2205 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.43s)22062026/09/24 17:46:56 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/09/24 17:46:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.432826ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/09/24 17:46:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=360.136603ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/09/24 17:46:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.113511ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22102026/09/24 17:46:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.61255367s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22112026/09/24 17:46:59 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 127.0.0.1:19999: connect: connection refused"22122026/09/24 17:46:59 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22132026/09/24 17:46:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.261692ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22142026/09/24 17:46:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.074351ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22152026/09/24 17:47:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=871.876833ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22162026/09/24 17:47:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.745303902s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22172026/09/24 17:47:02 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22182026/09/24 17:47:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.594583ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22192026/09/24 17:47:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=393.422248ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22202026/09/24 17:47:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=847.982662ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22212026/09/24 17:47:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.598988907s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2222--- PASS: TestClientErrorHandling (0.00s)2223 --- PASS: TestClientErrorHandling/InvalidStorePath (1.76s)2224 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.98s)2225 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.80s)2226PASS2227{"timestamp":"2026-09-24T17:47:05.912601Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52059","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}22282026-09-24 17:47:06.048 UTC [11486] LOG: received smart shutdown request22292026-09-24 17:47:06.049 UTC [11486] LOG: background worker "logical replication launcher" (PID 11496) exited with exit code 122302026-09-24 17:47:06.057 UTC [11491] LOG: shutting down22312026-09-24 17:47:06.058 UTC [11491] LOG: checkpoint starting: shutdown immediate22322026-09-24 17:47:07.375 UTC [11491] LOG: checkpoint complete: wrote 12696 buffers (77.5%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.720 s, sync=0.558 s, total=1.318 s; sync files=32692, longest=0.001 s, average=0.001 s; distance=471163 kB, estimate=471163 kB; lsn=0/1E3ABD98, redo lsn=0/1E3ABD9822332026-09-24 17:47:07.381 UTC [11486] LOG: database system is shut down2234Running OIDC tests...2235=== RUN TestAudienceForIssuer2236=== PAUSE TestAudienceForIssuer2237=== RUN TestHTTPClientForHasTimeouts2238=== PAUSE TestHTTPClientForHasTimeouts2239=== RUN TestGlobMatch2240=== PAUSE TestGlobMatch2241=== RUN TestValidateToken_ValidToken2242=== PAUSE TestValidateToken_ValidToken2243=== RUN TestValidateToken_WrongAudience2244=== PAUSE TestValidateToken_WrongAudience2245=== RUN TestValidateToken_Expired2246=== PAUSE TestValidateToken_Expired2247=== RUN TestValidateToken_BoundClaimsMismatch2248=== PAUSE TestValidateToken_BoundClaimsMismatch2249=== RUN TestValidateToken_BoundSubjectMismatch2250=== PAUSE TestValidateToken_BoundSubjectMismatch2251=== RUN TestValidateToken_MultipleProviders2252=== PAUSE TestValidateToken_MultipleProviders2253=== RUN TestValidateToken_NoMatchingProvider2254=== PAUSE TestValidateToken_NoMatchingProvider2255=== RUN TestValidateToken_KubernetesServiceAccount2256=== PAUSE TestValidateToken_KubernetesServiceAccount2257=== RUN TestNewValidator_KubernetesRequiresCA2258=== PAUSE TestNewValidator_KubernetesRequiresCA2259=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2260=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2261=== RUN TestPins_ReservedForMatchingRule2262=== PAUSE TestPins_ReservedForMatchingRule2263=== RUN TestPins_TopLevelShorthand2264=== PAUSE TestPins_TopLevelShorthand2265=== RUN TestPins_ConfigValidation2266=== PAUSE TestPins_ConfigValidation2267=== RUN TestScopes_LegacyProviderDefaultsToWrite2268=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2269=== RUN TestScopes_Rules2270=== PAUSE TestScopes_Rules2271=== RUN TestScopes_ConfigValidation2272=== PAUSE TestScopes_ConfigValidation2273=== CONT TestAudienceForIssuer2274=== CONT TestValidateToken_KubernetesServiceAccount2275=== CONT TestNewValidator_KubernetesRequiresCA2276=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2277=== CONT TestPins_TopLevelShorthand2278=== CONT TestPins_ReservedForMatchingRule2279=== CONT TestScopes_ConfigValidation2280=== CONT TestPins_ConfigValidation2281=== CONT TestScopes_LegacyProviderDefaultsToWrite2282=== CONT TestValidateToken_BoundSubjectMismatch2283=== CONT TestValidateToken_NoMatchingProvider2284--- PASS: TestAudienceForIssuer (0.00s)2285--- PASS: TestScopes_ConfigValidation (0.00s)2286=== CONT TestValidateToken_MultipleProviders2287--- PASS: TestPins_ConfigValidation (0.00s)2288=== CONT TestValidateToken_BoundClaimsMismatch22892026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52193/oidc2290--- PASS: TestPins_TopLevelShorthand (0.09s)2291=== CONT TestValidateToken_Expired22922026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52196/oidc2293--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2294=== CONT TestValidateToken_WrongAudience22952026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52200/oidc2296--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)2297=== CONT TestGlobMatch2298=== RUN TestGlobMatch/foo_foo2299=== PAUSE TestGlobMatch/foo_foo2300=== RUN TestGlobMatch/foo_bar2301=== PAUSE TestGlobMatch/foo_bar2302=== RUN TestGlobMatch/*_2303=== PAUSE TestGlobMatch/*_2304=== RUN TestGlobMatch/*_anything2305=== PAUSE TestGlobMatch/*_anything2306=== RUN TestGlobMatch/foo*_foo2307=== PAUSE TestGlobMatch/foo*_foo2308=== RUN TestGlobMatch/foo*_foobar2309=== PAUSE TestGlobMatch/foo*_foobar2310=== RUN TestGlobMatch/foo*_bar2311=== PAUSE TestGlobMatch/foo*_bar2312=== RUN TestGlobMatch/*bar_bar2313=== PAUSE TestGlobMatch/*bar_bar2314=== RUN TestGlobMatch/*bar_foobar2315=== PAUSE TestGlobMatch/*bar_foobar2316=== RUN TestGlobMatch/*bar_foo2317=== PAUSE TestGlobMatch/*bar_foo2318=== RUN TestGlobMatch/foo*bar_foobar2319=== PAUSE TestGlobMatch/foo*bar_foobar2320=== RUN TestGlobMatch/foo*bar_foo123bar2321=== PAUSE TestGlobMatch/foo*bar_foo123bar2322=== RUN TestGlobMatch/foo*bar_foobarbaz2323=== PAUSE TestGlobMatch/foo*bar_foobarbaz2324=== RUN TestGlobMatch/*/*_foo/bar2325=== PAUSE TestGlobMatch/*/*_foo/bar2326=== RUN TestGlobMatch/*/*_foo2327=== PAUSE TestGlobMatch/*/*_foo2328=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2329=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2330=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02331=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02332=== RUN TestGlobMatch/refs/*/main_refs/heads/main2333=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2334=== RUN TestGlobMatch/fo?_foo2335=== PAUSE TestGlobMatch/fo?_foo2336=== RUN TestGlobMatch/fo?_fo2337=== PAUSE TestGlobMatch/fo?_fo2338=== RUN TestGlobMatch/fo?_fooo2339=== PAUSE TestGlobMatch/fo?_fooo2340=== RUN TestGlobMatch/?oo_foo2341=== PAUSE TestGlobMatch/?oo_foo2342=== RUN TestGlobMatch/?oo_boo2343=== PAUSE TestGlobMatch/?oo_boo2344=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2345=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2346=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2347=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2348=== CONT TestHTTPClientForHasTimeouts23492026/09/24 17:47:10 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:521982350--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)2351=== CONT TestValidateToken_ValidToken23522026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52204/oidc2353=== CONT TestScopes_Rules2354--- PASS: TestPins_ReservedForMatchingRule (0.13s)23552026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52207/oidc23562026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52206/oidc2357--- PASS: TestValidateToken_WrongAudience (0.05s)2358=== CONT TestGlobMatch/*_anything2359=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2360=== CONT TestGlobMatch/?oo_boo2361--- PASS: TestValidateToken_Expired (0.05s)2362=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2363=== CONT TestGlobMatch/fo?_fooo2364=== CONT TestGlobMatch/?oo_foo2365=== CONT TestGlobMatch/fo?_foo2366=== CONT TestGlobMatch/refs/*/main_refs/heads/main2367=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2368=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02369=== CONT TestGlobMatch/fo?_fo2370=== CONT TestGlobMatch/*/*_foo/bar2371=== CONT TestGlobMatch/foo*bar_foobarbaz2372=== CONT TestGlobMatch/*/*_foo2373=== CONT TestGlobMatch/*bar_foo2374=== CONT TestGlobMatch/*bar_foobar2375=== CONT TestGlobMatch/*bar_bar2376=== CONT TestGlobMatch/foo*bar_foobar2377=== CONT TestGlobMatch/foo*bar_foo123bar2378=== CONT TestGlobMatch/foo*_foobar2379=== CONT TestGlobMatch/foo*_foo2380=== CONT TestGlobMatch/foo*_bar2381=== CONT TestGlobMatch/*_2382=== CONT TestGlobMatch/foo_foo2383=== CONT TestGlobMatch/foo_bar2384--- PASS: TestGlobMatch (0.00s)2385 --- PASS: TestGlobMatch/*_anything (0.00s)2386 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2387 --- PASS: TestGlobMatch/?oo_boo (0.00s)2388 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2389 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2390 --- PASS: TestGlobMatch/?oo_foo (0.00s)2391 --- PASS: TestGlobMatch/fo?_foo (0.00s)2392 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2393 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2394 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2395 --- PASS: TestGlobMatch/fo?_fo (0.00s)2396 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2397 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2398 --- PASS: TestGlobMatch/*/*_foo (0.00s)2399 --- PASS: TestGlobMatch/*bar_foo (0.00s)2400 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2401 --- PASS: TestGlobMatch/*bar_bar (0.00s)2402 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2403 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2404 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2405 --- PASS: TestGlobMatch/foo*_foo (0.00s)2406 --- PASS: TestGlobMatch/foo*_bar (0.00s)2407 --- PASS: TestGlobMatch/*_ (0.00s)2408 --- PASS: TestGlobMatch/foo_foo (0.00s)2409 --- PASS: TestGlobMatch/foo_bar (0.00s)24102026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52211/oidc2411--- PASS: TestValidateToken_BoundClaimsMismatch (0.16s)24122026/09/24 17:47:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324132026/09/24 17:47:10 http: TLS handshake error from 127.0.0.1:52214: remote error: tls: bad certificate2414--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)2415--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.19s)24162026/09/24 17:47:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52210/oidc24172026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52219/oidc2418--- PASS: TestValidateToken_NoMatchingProvider (0.19s)24192026/09/24 17:47:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:52195/oidc24202026/09/24 17:47:10 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:52221/oidc2421--- PASS: TestValidateToken_MultipleProviders (0.19s)2422--- PASS: TestScopes_Rules (0.07s)24232026/09/24 17:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52224/oidc2424--- PASS: TestValidateToken_ValidToken (0.10s)2425--- PASS: TestHTTPClientForHasTimeouts (0.20s)2426PASS2427Running signing tests...2428=== RUN TestGenerateFingerprint2429=== PAUSE TestGenerateFingerprint2430=== RUN TestParseSigningKey2431=== PAUSE TestParseSigningKey2432=== RUN TestSignMessage2433=== PAUSE TestSignMessage2434=== RUN TestSignNarinfo2435=== PAUSE TestSignNarinfo2436=== CONT TestGenerateFingerprint2437=== CONT TestSignNarinfo2438=== CONT TestSignMessage2439=== RUN TestGenerateFingerprint/basic_with_references2440=== CONT TestParseSigningKey2441=== RUN TestParseSigningKey/valid_32-byte_key2442=== PAUSE TestGenerateFingerprint/basic_with_references2443=== RUN TestGenerateFingerprint/no_references2444=== PAUSE TestParseSigningKey/valid_32-byte_key2445=== PAUSE TestGenerateFingerprint/no_references2446=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2447=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2448=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2449=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2450=== RUN TestParseSigningKey/no_colon2451=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2452=== PAUSE TestParseSigningKey/no_colon2453=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2454=== RUN TestParseSigningKey/empty_name2455=== RUN TestGenerateFingerprint/invalid_nar_hash_length2456=== PAUSE TestParseSigningKey/empty_name2457=== RUN TestParseSigningKey/invalid_base642458=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2459=== RUN TestGenerateFingerprint/invalid_store_path_prefix2460=== PAUSE TestParseSigningKey/invalid_base642461=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2462=== RUN TestParseSigningKey/wrong_length2463=== RUN TestGenerateFingerprint/invalid_reference_prefix2464=== PAUSE TestParseSigningKey/wrong_length2465=== CONT TestParseSigningKey/valid_32-byte_key2466=== CONT TestParseSigningKey/empty_name2467=== CONT TestParseSigningKey/no_colon2468=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2469=== CONT TestParseSigningKey/wrong_length2470=== CONT TestParseSigningKey/invalid_base642471=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2472=== CONT TestGenerateFingerprint/invalid_store_path_prefix2473=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2474=== CONT TestGenerateFingerprint/basic_with_references2475=== CONT TestGenerateFingerprint/invalid_nar_hash_length2476=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2477=== CONT TestGenerateFingerprint/no_references2478=== CONT TestGenerateFingerprint/invalid_reference_prefix2479--- PASS: TestGenerateFingerprint (0.00s)2480 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2481 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2482 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2483 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2484 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2485 --- PASS: TestGenerateFingerprint/no_references (0.00s)2486 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2487--- PASS: TestParseSigningKey (0.00s)2488 --- PASS: TestParseSigningKey/empty_name (0.00s)2489 --- PASS: TestParseSigningKey/no_colon (0.00s)2490 --- PASS: TestParseSigningKey/wrong_length (0.00s)2491 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2492 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2493 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2494--- PASS: TestSignMessage (0.01s)2495--- PASS: TestSignNarinfo (0.01s)2496PASS2497Running hook tests...2498=== RUN TestSendPathsEmpty2499=== PAUSE TestSendPathsEmpty2500=== RUN TestQueueEnqueueAndFetch2501=== PAUSE TestQueueEnqueueAndFetch2502=== RUN TestQueueDeduplication2503=== PAUSE TestQueueDeduplication2504=== RUN TestQueueRemove2505=== PAUSE TestQueueRemove2506=== RUN TestQueueFetchBatchLimit2507=== PAUSE TestQueueFetchBatchLimit2508=== RUN TestQueueRetryMovesToBack2509=== PAUSE TestQueueRetryMovesToBack2510=== RUN TestQueueFetchRemoveLifecycle2511=== PAUSE TestQueueFetchRemoveLifecycle2512=== RUN TestQueueConcurrentWriters2513=== PAUSE TestQueueConcurrentWriters2514=== RUN TestQueueEnqueueWaitsOutSlowWriter2515=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2516=== RUN TestQueueRemoveLargeClosure2517=== PAUSE TestQueueRemoveLargeClosure2518=== RUN TestServerClientIntegration2519=== PAUSE TestServerClientIntegration2520=== RUN TestServerQueueError2521=== PAUSE TestServerQueueError2522=== RUN TestServerRefusesOversizedAndNonStoreRequests2523=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2524=== RUN TestGetListenerSocketActivation2525 server_test.go:304: === RUN TestGetListenerSocketActivation2526 --- PASS: TestGetListenerSocketActivation (0.00s)2527 PASS2528 2529--- PASS: TestGetListenerSocketActivation (1.18s)2530=== RUN TestServerStalledClientDoesNotBlockShutdown2531=== PAUSE TestServerStalledClientDoesNotBlockShutdown2532=== RUN TestServerBacksOffOnAcceptErrors2533=== PAUSE TestServerBacksOffOnAcceptErrors2534=== RUN TestDrainIsolatesPoisonPath2535=== PAUSE TestDrainIsolatesPoisonPath2536=== RUN TestRunNotBlockedByPoisonHead2537=== PAUSE TestRunNotBlockedByPoisonHead2538=== RUN TestDrainGivesUpWhenServerDown2539=== PAUSE TestDrainGivesUpWhenServerDown2540=== RUN TestFailedPathPrunedByLaterClosure2541=== PAUSE TestFailedPathPrunedByLaterClosure2542=== RUN TestWorkerUploadsAndRemoves2543=== PAUSE TestWorkerUploadsAndRemoves2544=== RUN TestWorkerSkipsGCdPaths2545=== PAUSE TestWorkerSkipsGCdPaths2546=== RUN TestWorkerPrunesClosureDeps2547=== PAUSE TestWorkerPrunesClosureDeps2548=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2549=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2550=== RUN TestDrainTimeout2551=== PAUSE TestDrainTimeout2552=== RUN TestDrainTimeoutDuringIsolation2553=== PAUSE TestDrainTimeoutDuringIsolation2554=== RUN TestShutdownFinishesInFlightPush2555=== PAUSE TestShutdownFinishesInFlightPush2556=== RUN TestWorkerRemoveFailureIsNotProgress2557=== PAUSE TestWorkerRemoveFailureIsNotProgress2558=== RUN TestWorkerKeepsPathItCannotStat2559=== PAUSE TestWorkerKeepsPathItCannotStat2560=== CONT TestSendPathsEmpty2561=== CONT TestServerBacksOffOnAcceptErrors2562=== CONT TestDrainTimeoutDuringIsolation2563=== CONT TestWorkerSkipsGCdPaths2564=== CONT TestWorkerRemoveFailureIsNotProgress2565=== CONT TestShutdownFinishesInFlightPush2566=== CONT TestWorkerKeepsPathItCannotStat2567=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2568=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2569=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2570=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch25712026/09/24 17:47:14 ERROR Accept failed error="too many open files"2572=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2573=== RUN TestShutdownFinishesInFlightPush/completes2574=== CONT TestWorkerUploadsAndRemoves2575=== PAUSE TestShutdownFinishesInFlightPush/completes2576=== CONT TestWorkerPrunesClosureDeps2577--- PASS: TestSendPathsEmpty (0.00s)2578=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2579=== CONT TestDrainTimeout2580=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2581=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2582=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2583=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2584=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2585=== CONT TestFailedPathPrunedByLaterClosure2586=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2587=== CONT TestRunNotBlockedByPoisonHead2588=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2589=== CONT TestDrainIsolatesPoisonPath25902026/09/24 17:47:14 ERROR Accept failed error="too many open files"25912026/09/24 17:47:14 ERROR Accept failed error="too many open files"25922026/09/24 17:47:14 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa error="lstat /nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa: permission denied"25932026/09/24 17:47:14 INFO Upload queue status pending=225942026/09/24 17:47:14 INFO Upload queue status pending=325952026/09/24 17:47:14 INFO Upload queue status pending=225962026/09/24 17:47:14 INFO Upload queue status pending=325972026/09/24 17:47:14 INFO Upload queue status pending=225982026/09/24 17:47:14 INFO Uploading batch count=225992026/09/24 17:47:14 INFO Uploading batch count=126002026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=126012026/09/24 17:47:14 INFO Uploading batch count=426022026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=426032026/09/24 17:47:14 INFO Uploading batch count=126042026/09/24 17:47:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerSkipsGCdPaths3241354262/002/nonexistent26052026/09/24 17:47:14 INFO Uploading batch count=126062026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=126072026/09/24 17:47:14 INFO Uploading batch count=226082026/09/24 17:47:14 INFO Uploading batch count=226092026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainIsolatesPoisonPath3854039442/002/bbb26102026/09/24 17:47:14 INFO Uploading batch count=226112026/09/24 17:47:14 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa error="lstat /nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa: permission denied"26122026/09/24 17:47:14 INFO Uploading batch count=126132026/09/24 17:47:14 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa error="lstat /nix/var/nix/builds/nix-11432-1070387528/TestWorkerKeepsPathItCannotStat4027777612/002/locked/aaa: permission denied"26142026/09/24 17:47:14 INFO Uploading batch count=126152026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=126162026/09/24 17:47:14 INFO Uploading batch count=126172026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=126182026/09/24 17:47:14 INFO Uploading batch count=126192026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=12620--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)2621=== CONT TestQueueFetchRemoveLifecycle26222026/09/24 17:47:14 INFO Uploading batch count=126232026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=12624--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)2625=== CONT TestServerStalledClientDoesNotBlockShutdown2626 server_test.go:318: listen: listen unix /nix/var/nix/builds/nix-11432-1070387528/TestServerStalledClientDoesNotBlockShutdown2299815929/001/test.sock: bind: invalid argument2627--- FAIL: TestServerStalledClientDoesNotBlockShutdown (0.00s)2628=== CONT TestServerRefusesOversizedAndNonStoreRequests26292026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=12630 server_test.go:153: listen: listen unix /nix/var/nix/builds/nix-11432-1070387528/TestServerRefusesOversizedAndNonStoreRequests1028590067/001/test.sock: bind: invalid argument2631--- FAIL: TestServerRefusesOversizedAndNonStoreRequests (0.00s)2632=== CONT TestQueueRetryMovesToBack26332026/09/24 17:47:14 ERROR Accept failed error="too many open files"2634--- PASS: TestDrainIsolatesPoisonPath (0.03s)2635=== CONT TestQueueEnqueueWaitsOutSlowWriter2636--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2637=== CONT TestQueueRemoveLargeClosure2638--- PASS: TestQueueRetryMovesToBack (0.01s)2639=== CONT TestQueueConcurrentWriters2640--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2641=== CONT TestServerClientIntegration2642--- PASS: TestWorkerPrunesClosureDeps (0.05s)2643=== CONT TestServerQueueError26442026/09/24 17:47:14 ERROR Failed to queue paths error="permission denied" count=12645=== CONT TestQueueEnqueueAndFetch2646--- PASS: TestWorkerUploadsAndRemoves (0.05s)2647--- PASS: TestServerClientIntegration (0.00s)2648=== CONT TestQueueFetchBatchLimit2649--- PASS: TestServerQueueError (0.00s)2650=== CONT TestQueueDeduplication2651=== CONT TestQueueRemove2652--- PASS: TestWorkerSkipsGCdPaths (0.05s)2653=== CONT TestDrainGivesUpWhenServerDown2654--- PASS: TestQueueFetchBatchLimit (0.01s)2655--- PASS: TestQueueEnqueueAndFetch (0.01s)2656=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2657--- PASS: TestQueueDeduplication (0.01s)2658=== CONT TestShutdownFinishesInFlightPush/completes2659--- PASS: TestQueueRemove (0.01s)2660=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26612026/09/24 17:47:14 INFO Upload queue status pending=226622026/09/24 17:47:14 INFO Uploading batch count=226632026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226642026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/a26652026/09/24 17:47:14 INFO Uploading batch count=226662026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/b26672026/09/24 17:47:14 INFO Upload queue status pending=226682026/09/24 17:47:14 INFO Uploading batch count=226692026/09/24 17:47:14 INFO Uploading batch count=226702026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226712026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/c26722026/09/24 17:47:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerRemoveFailureIsNotProgresscollected_path3545965727/001/nonexistent26732026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/d26742026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126752026/09/24 17:47:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerRemoveFailureIsNotProgresscollected_path3545965727/001/nonexistent26762026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126772026/09/24 17:47:14 INFO Uploading batch count=226782026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226792026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/e26802026/09/24 17:47:14 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-11432-1070387528/TestWorkerRemoveFailureIsNotProgresscollected_path3545965727/001/nonexistent26812026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126822026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=126832026/09/24 17:47:14 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-11432-1070387528/TestDrainGivesUpWhenServerDown3352855483/002/f26842026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=102685=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2686--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2687=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26882026/09/24 17:47:14 INFO Uploading batch count=226892026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226902026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126912026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126922026/09/24 17:47:14 INFO Uploading batch count=226932026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226942026/09/24 17:47:14 ERROR Accept failed error="too many open files"26952026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126962026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126972026/09/24 17:47:14 INFO Uploading batch count=226982026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=226992026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127002026/09/24 17:47:14 INFO Uploading batch count=227012026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127022026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=227032026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227042026/09/24 17:47:14 INFO Uploading batch count=227052026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=22706=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27072026/09/24 17:47:14 INFO Uploading batch count=227082026/09/24 17:47:14 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227092026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=22710=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2711--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2712 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.01s)2713 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.01s)2714 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.01s)27152026/09/24 17:47:14 INFO Uploading batch count=427162026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=427172026/09/24 17:47:14 INFO Uploading batch count=427182026/09/24 17:47:14 ERROR Upload failed error="upload failed" count=427192026/09/24 17:47:14 ERROR Accept failed error="too many open files"2720--- PASS: TestQueueConcurrentWriters (0.14s)27212026/09/24 17:47:14 ERROR Upload failed error="context canceled" count=227222026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=42723--- PASS: TestDrainTimeout (0.23s)27242026/09/24 17:47:14 ERROR Upload failed error="context canceled" count=227252026/09/24 17:47:14 ERROR Drain finished with paths left in queue remaining=22726--- PASS: TestShutdownFinishesInFlightPush (0.00s)2727 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2728 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.21s)27292026/09/24 17:47:15 ERROR Drain finished with paths left in queue remaining=427302026/09/24 17:47:15 ERROR Accept failed error="too many open files"27312026/09/24 17:47:15 ERROR Drain finished with paths left in queue remaining=32732--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2733 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.21s)2734 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.31s)27352026/09/24 17:47:15 ERROR Accept failed error="too many open files"2736--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27372026/09/24 17:47:15 INFO Uploading batch count=127382026/09/24 17:47:15 INFO Uploading batch count=127392026/09/24 17:47:15 INFO Uploading batch count=127402026/09/24 17:47:15 ERROR Upload failed error="upload failed" count=127412026/09/24 17:47:15 INFO Uploading batch count=127422026/09/24 17:47:15 ERROR Upload failed error="upload failed" count=127432026/09/24 17:47:15 INFO Uploading batch count=127442026/09/24 17:47:15 ERROR Upload failed error="upload failed" count=127452026/09/24 17:47:15 INFO Uploading batch count=127462026/09/24 17:47:15 ERROR Upload failed error="upload failed" count=127472026/09/24 17:47:15 ERROR Drain finished with paths left in queue remaining=12748--- PASS: TestRunNotBlockedByPoisonHead (1.05s)2749--- PASS: TestQueueRemoveLargeClosure (1.16s)2750--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.01s)2751FAIL