niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #348
· 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.13s)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 (1.42s)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 TestRateLimiterFeedback_400DoesNotCountAsSuccess128=== CONT TestRegisterUploadedObjectReusesConnections129=== CONT TestTruncatedNARDumpIsNotCompleted130=== CONT TestDumpPathMatchesNix131=== CONT TestConvertHashToNix32132=== CONT TestGetStorePathHash133=== CONT TestPathInfoHashCompatibility134=== CONT TestEncodeNixBase32WithRealHash135=== CONT TestRateLimiterFeedback136=== CONT TestDumpPathSingleFile137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138=== RUN TestGetStorePathHash/valid_store_path139=== RUN TestRateLimiterFeedback/429_enables_limiter140=== PAUSE TestRateLimiterFeedback/429_enables_limiter141=== RUN TestRateLimiterFeedback/503_enables_limiter142=== PAUSE TestRateLimiterFeedback/503_enables_limiter143--- PASS: TestEncodeNixBase32WithRealHash (0.00s)144=== CONT TestCompletePendingClosure_NotFoundWithoutKey145=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter146=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter147=== PAUSE TestGetStorePathHash/valid_store_path148=== RUN TestGetStorePathHash/basename_without_hyphen_should_error149=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error150=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error151=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error152=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error153=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error154=== CONT TestDumpPathWriterError155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon157=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon158=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI159=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI160=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512161=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512162=== CONT TestPathInfoCACompatibility163=== RUN TestPathInfoCACompatibility/null_ca_field164=== PAUSE TestPathInfoCACompatibility/null_ca_field165=== RUN TestPathInfoCACompatibility/old_string_format_-_text166=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text167=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== RUN TestPathInfoCACompatibility/new_structured_format_-_text170=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text171=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method172=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method173=== CONT TestStreamPushStopsOnCancel174=== RUN TestStreamPushStopsOnCancel/waiting_for_input175=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input176=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot177=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot178=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot179=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot180=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot181=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot182=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot183=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot184=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken185=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken186=== CONT TestEncodeNixBase32187=== RUN TestEncodeNixBase32/test_string_hash188=== PAUSE TestEncodeNixBase32/test_string_hash189=== RUN TestEncodeNixBase32/empty_input190=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter191=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter192=== CONT TestScriptTokenScriptFails193=== PAUSE TestEncodeNixBase32/empty_input194=== CONT TestParsePathInfoJSONMultiplePaths195=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths196=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths198=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== CONT TestScriptTokenBadJSON200=== RUN TestConvertHashToNix32/SRI_format_to_Nix32201=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32202=== RUN TestConvertHashToNix32/already_Nix32_format203=== PAUSE TestConvertHashToNix32/already_Nix32_format204=== RUN TestConvertHashToNix32/invalid_format205=== PAUSE TestConvertHashToNix32/invalid_format206=== CONT TestParsePathInfoJSON207=== RUN TestParsePathInfoJSON/Nix_format208=== PAUSE TestParsePathInfoJSON/Nix_format209=== RUN TestParsePathInfoJSON/Lix_format210=== PAUSE TestParsePathInfoJSON/Lix_format211=== RUN TestParsePathInfoJSON/empty_input212=== PAUSE TestParsePathInfoJSON/empty_input213=== RUN TestParsePathInfoJSON/whitespace_only214=== PAUSE TestParsePathInfoJSON/whitespace_only215=== RUN TestParsePathInfoJSON/invalid_JSON216=== PAUSE TestParsePathInfoJSON/invalid_JSON217=== CONT TestScriptTokenEmptyCommand218--- PASS: TestScriptTokenEmptyCommand (0.00s)219=== CONT TestUploadMultipart_SupersededByPeer220=== RUN TestUploadMultipart_SupersededByPeer/exists221=== PAUSE TestUploadMultipart_SupersededByPeer/exists222=== RUN TestUploadMultipart_SupersededByPeer/missing223=== PAUSE TestUploadMultipart_SupersededByPeer/missing224=== CONT TestScriptTokenNoExpiryRerunsEveryCall225--- PASS: TestScriptTokenScriptFails (0.01s)226=== CONT TestPartSizeForNAR227=== RUN TestPartSizeForNAR/zero_stays_at_minimum228=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum229=== RUN TestPartSizeForNAR/small_stays_at_minimum230=== PAUSE TestPartSizeForNAR/small_stays_at_minimum231=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum232=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum233=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts234=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts235=== RUN TestPartSizeForNAR/1_TiB236=== PAUSE TestPartSizeForNAR/1_TiB237=== RUN TestPartSizeForNAR/5_TiB_S3_max_object238=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object239=== RUN TestPartSizeForNAR/capped_at_5_GiB240=== PAUSE TestPartSizeForNAR/capped_at_5_GiB241=== CONT TestFileTokenMissing242--- PASS: TestFileTokenMissing (0.00s)243=== CONT TestScriptTokenDoesNotWaitForItsChildren244=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs245=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs246=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout247=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout248=== CONT TestFileTokenEmpty249--- PASS: TestFileTokenEmpty (0.00s)250=== CONT TestScriptTokenEmptyToken251--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.02s)252=== CONT TestSetClientTLSErrors253--- PASS: TestScriptTokenBadJSON (0.04s)254=== CONT TestFileTokenReadsAndCaches255=== RUN TestSetClientTLSErrors/missing_cert_file256=== PAUSE TestSetClientTLSErrors/missing_cert_file257=== RUN TestSetClientTLSErrors/missing_key_file258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== RUN TestSetClientTLSErrors/missing_ca_file260--- PASS: TestFileTokenReadsAndCaches (0.00s)261=== CONT TestClientSignaturesByStorePath262--- PASS: TestClientSignaturesByStorePath (0.00s)263=== CONT TestSetClientTLSDoesNotMutateDefaultTransport264=== PAUSE TestSetClientTLSErrors/missing_ca_file265=== RUN TestSetClientTLSErrors/invalid_ca_file266=== PAUSE TestSetClientTLSErrors/invalid_ca_file267=== CONT TestScriptTokenCachesUntilRefresh268--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.03s)269=== CONT TestStreamPushReportsSignatures270--- PASS: TestScriptTokenEmptyToken (0.06s)271=== CONT TestStaticToken272--- PASS: TestStaticToken (0.00s)273=== CONT TestStreamPushRequestLine274--- PASS: TestStreamPushReportsSignatures (0.00s)275=== CONT TestStreamPushGivesUpOnDeadServer276--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)277=== CONT TestStreamPushBatchesUnderLoad278=== RUN TestStreamPushBatchesUnderLoad/together279=== PAUSE TestStreamPushBatchesUnderLoad/together280=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time281=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time282=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent283=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier284=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier285=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up286=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up287=== CONT TestStreamPushReportsEveryPath288--- PASS: TestStreamPushReportsEveryPath (0.00s)289=== CONT TestSetClientTLS290=== RUN TestSetClientTLS/rejects_connection_without_client_cert291=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert292=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA293=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA294=== RUN TestSetClientTLS/preserves_debug_logging_transport295=== PAUSE TestSetClientTLS/preserves_debug_logging_transport296=== CONT TestUploadMultipart_PartsInParallel297--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.13s)298=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure299--- PASS: TestScriptTokenCachesUntilRefresh (0.13s)300=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica301=== CONT TestUploadMultipart_FailedPartBufferNotReused302--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)303--- PASS: TestDumpPathWriterError (0.31s)304=== CONT TestSupersededNARStillUploadsListing305=== RUN TestSupersededNARStillUploadsListing/small_NAR306=== PAUSE TestSupersededNARStillUploadsListing/small_NAR307=== RUN TestSupersededNARStillUploadsListing/dump_cut_short308=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short309=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails310=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails311=== CONT TestUploadMultipart_ProducerErrorIsNotEOF312=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part313=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part314=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary315=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary316=== CONT TestFilterOversizedClosures317=== RUN TestFilterOversizedClosures/no_limit_keeps_everything318=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything319=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321=== RUN TestFilterOversizedClosures/all_closures_skipped322=== PAUSE TestFilterOversizedClosures/all_closures_skipped323=== CONT TestResolveStorePath324--- PASS: TestResolveStorePath (0.00s)325=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer326--- PASS: TestDumpPathSingleFile (0.34s)327=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry328--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.04s)329=== CONT TestStreamPushIsolatesFailures330--- PASS: TestStreamPushIsolatesFailures (0.00s)331=== CONT TestShellSplit332--- PASS: TestShellSplit (0.00s)333=== CONT TestShellSplitErrors334--- PASS: TestShellSplitErrors (0.00s)335=== CONT TestDoWithRetry_FinalResponseBodyReadable336--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)337=== CONT TestDoServerRequestAttachesToken338--- PASS: TestDoServerRequestAttachesToken (0.00s)339=== CONT TestCaseHackSuffix340--- PASS: TestDumpPathMatchesNix (0.44s)341=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun342--- PASS: TestStreamPushRequestLine (0.37s)343=== CONT TestDoWithRetry_BodyReplayedViaGetBody344--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)345=== CONT TestGetStorePathHash/valid_store_path346=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error347=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error348=== CONT TestGetStorePathHash/basename_without_hyphen_should_error349--- PASS: TestGetStorePathHash (0.00s)350 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)351 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)352 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)353 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)354=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon355--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)356=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512357=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)358=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI359=== CONT TestPathInfoCACompatibility/old_string_format_-_text360=== CONT TestPathInfoCACompatibility/new_structured_format_-_text361--- PASS: TestPathInfoHashCompatibility (0.00s)362 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)363 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)364 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)365 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)366=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive367=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method368=== CONT TestPathInfoCACompatibility/null_ca_field369=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot370--- PASS: TestPathInfoCACompatibility (0.00s)371 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)372 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)373 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)374 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)375 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)376=== CONT TestRateLimiterFeedback/429_enables_limiter377=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot378--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.34s)379=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken380--- PASS: TestCaseHackSuffix (0.11s)381=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot382=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot383=== CONT TestStreamPushStopsOnCancel/waiting_for_input384=== CONT TestEncodeNixBase32/empty_input385=== CONT TestEncodeNixBase32/test_string_hash386--- PASS: TestEncodeNixBase32 (0.00s)387 --- PASS: TestEncodeNixBase32/empty_input (0.00s)388 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)389=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths390=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths391--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)392 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)393 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)394=== CONT TestConvertHashToNix32/invalid_format395=== CONT TestConvertHashToNix32/already_Nix32_format396=== CONT TestConvertHashToNix32/SRI_format_to_Nix32397=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter398--- PASS: TestConvertHashToNix32 (0.00s)399 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)400 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)401 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)402=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter403=== CONT TestParsePathInfoJSON/empty_input404=== CONT TestParsePathInfoJSON/invalid_JSON405=== CONT TestParsePathInfoJSON/whitespace_only406=== CONT TestParsePathInfoJSON/Lix_format407=== CONT TestParsePathInfoJSON/Nix_format408=== CONT TestRateLimiterFeedback/503_enables_limiter409=== CONT TestUploadMultipart_SupersededByPeer/missing410--- PASS: TestParsePathInfoJSON (0.00s)411 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)412 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)413 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)414 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)415 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)416=== CONT TestUploadMultipart_SupersededByPeer/exists417--- PASS: TestRateLimiterFeedback (0.00s)418 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)419 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)420 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)421 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)422=== CONT TestPartSizeForNAR/zero_stays_at_minimum423=== CONT TestPartSizeForNAR/capped_at_5_GiB424=== CONT TestPartSizeForNAR/5_TiB_S3_max_object425=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts426=== CONT TestPartSizeForNAR/1_TiB427=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum428=== CONT TestPartSizeForNAR/small_stays_at_minimum429=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs430=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout431--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)432 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)433 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)434=== CONT TestSetClientTLSErrors/missing_key_file435--- PASS: TestPartSizeForNAR (0.00s)436 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)437 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)438 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)439 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)440 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)441 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)442 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)443=== CONT TestSetClientTLSErrors/missing_ca_file444=== CONT TestSetClientTLSErrors/invalid_ca_file445=== CONT TestSetClientTLSErrors/missing_cert_file446=== CONT TestStreamPushBatchesUnderLoad/together447--- PASS: TestSetClientTLSErrors (0.03s)448 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)449 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)450 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)451 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)452=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time453=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up454--- PASS: TestStreamPushBatchesUnderLoad (0.00s)455 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)456 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)457=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier458--- PASS: TestStreamPushStopsOnCancel (0.00s)459 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)460 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.06s)461 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.06s)462 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)463 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)464 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)465=== CONT TestSetClientTLS/preserves_debug_logging_transport466=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA467--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)468 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)469 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)470--- PASS: TestRegisterUploadedObjectReusesConnections (0.60s)471=== CONT TestSetClientTLS/rejects_connection_without_client_cert472=== CONT TestSupersededNARStillUploadsListing/small_NAR473=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part474=== CONT TestSupersededNARStillUploadsListing/dump_cut_short475--- PASS: TestSetClientTLS (0.01s)476 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)477 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)478 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)479=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails480=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary481=== CONT TestFilterOversizedClosures/no_limit_keeps_everything482=== CONT TestFilterOversizedClosures/all_closures_skipped483=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped484--- PASS: TestFilterOversizedClosures (0.00s)485 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)486 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)487 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.09s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.05s)491--- PASS: TestUploadMultipart_PartsInParallel (0.87s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.04s)493--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.84s)494--- PASS: TestSupersededNARStillUploadsListing (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.03s)496 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.05s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.71s)498--- PASS: TestTruncatedNARDumpIsNotCompleted (1.39s)499--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)500--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)501 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.03s)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-3690-3946823596/postgres1051772913/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-3690-3946823596/postgres1051772913/data -l logfile start5315322026-10-02 20:39:55.572 UTC [13852] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5332026-10-02 20:39:55.572 UTC [13852] LOG: listening on Unix socket "/nix/var/nix/builds/nix-3690-3946823596/postgres1051772913/.s.PGSQL.5432"5342026-10-02 20:39:55.576 UTC [13868] LOG: database system was shut down at 2026-10-02 20:39:55 UTC5352026-10-02 20:39:55.577 UTC [13852] LOG: database system is ready to accept connections536/nix/var/nix/builds/nix-3690-3946823596/postgres1051772913:5432 - accepting connections537{"timestamp":"2026-10-02T20:39:57.851545Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a6116cbb-4ef8-4056-b9ab-881e04473c65","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":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}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/10/02 20:39:58 INFO lead: acquired remote=192.0.2.1:12345862026/10/02 20:39:59 INFO lead: released remote=192.0.2.1:12345872026/10/02 20:39:59 INFO lead: acquired remote=192.0.2.1:12345882026/10/02 20:40:00 INFO lead: released remote=192.0.2.1:1234589--- PASS: TestLeadIncumbentWinsAfterRestart (2.61s)590=== RUN TestLeadEndsOnShutdown591=== PAUSE TestLeadEndsOnShutdown592=== RUN TestLeadEndsWhenItsConnectionHangs5932026/10/02 20:40:00 INFO lead: acquired remote=192.0.2.1:12345942026-10-02 20:40:02.202 UTC [15735] FATAL: terminating connection due to administrator command5952026/10/02 20:40:02 INFO lead: acquired remote=192.0.2.1:12345962026/10/02 20:40:03 WARN lead: lock connection lost error="timeout: context deadline exceeded"5972026/10/02 20:40:03 INFO lead: released remote=192.0.2.1:12345982026/10/02 20:40:03 INFO lead: released remote=192.0.2.1:1234599--- PASS: TestLeadEndsWhenItsConnectionHangs (3.05s)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 TestFailedS3DeleteKeepsTombstone621=== PAUSE TestFailedS3DeleteKeepsTombstone622=== RUN TestSweepSkipsRowsLockedByPush623=== PAUSE TestSweepSkipsRowsLockedByPush624=== RUN TestRegisterCompletedObjectNeedsPendingRow625=== PAUSE TestRegisterCompletedObjectNeedsPendingRow626=== RUN TestGetExistingObjectsLocksRows627=== PAUSE TestGetExistingObjectsLocksRows628=== RUN TestSweepRechecksPendingAfterLocking629=== PAUSE TestSweepRechecksPendingAfterLocking630=== RUN TestPushWaitsForSweepHoldingRow631=== PAUSE TestPushWaitsForSweepHoldingRow632=== RUN TestCommitRacingPendingCleanupKeepsObjects633=== PAUSE TestCommitRacingPendingCleanupKeepsObjects634=== RUN TestGCEndsOnShutdown635=== PAUSE TestGCEndsOnShutdown636=== RUN TestGCTaskStore_StartNew637=== PAUSE TestGCTaskStore_StartNew638=== RUN TestGCTaskStore_DeduplicateSameParams639=== PAUSE TestGCTaskStore_DeduplicateSameParams640=== RUN TestGCTaskStore_ConflictDifferentParams641=== PAUSE TestGCTaskStore_ConflictDifferentParams642=== RUN TestGCTaskStore_GetEmpty643=== PAUSE TestGCTaskStore_GetEmpty644=== RUN TestGCTaskStore_GetReturnsLatest645=== PAUSE TestGCTaskStore_GetReturnsLatest646=== RUN TestGCTaskStore_CompletedAllowsNewTask647=== PAUSE TestGCTaskStore_CompletedAllowsNewTask648=== RUN TestGCTaskStore_PhaseUpdates649=== PAUSE TestGCTaskStore_PhaseUpdates650=== RUN TestGCTaskStore_Fail651=== PAUSE TestGCTaskStore_Fail652=== RUN TestGracefulShutdownDrainsInflight653=== PAUSE TestGracefulShutdownDrainsInflight654=== RUN TestService_healthCheckHandler655=== PAUSE TestService_healthCheckHandler656=== RUN TestService_readinessHandler657=== PAUSE TestService_readinessHandler658=== RUN TestGenerateLandingPage659=== PAUSE TestGenerateLandingPage660=== RUN TestCacheConfigHandlerMaxNarSize661=== PAUSE TestCacheConfigHandlerMaxNarSize662=== RUN TestCreatePendingClosureRejectsOversizedNAR663=== PAUSE TestCreatePendingClosureRejectsOversizedNAR664=== RUN TestNARDeduplicationMetadataUploadBug665=== PAUSE TestNARDeduplicationMetadataUploadBug666=== RUN TestMetricsInventory667=== PAUSE TestMetricsInventory668=== RUN TestService_NativeMTLS669=== PAUSE TestService_NativeMTLS670=== RUN TestServerTLSConfig671=== PAUSE TestServerTLSConfig672=== RUN TestMultipartCleanup673=== PAUSE TestMultipartCleanup674=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded675=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== RUN TestPendingCleanupUsesOneCutoff677=== PAUSE TestPendingCleanupUsesOneCutoff678=== RUN TestPendingClosureFailureTracksEveryUpload679=== PAUSE TestPendingClosureFailureTracksEveryUpload680=== RUN TestPendingClosureFailureAbortsItsUploads681=== PAUSE TestPendingClosureFailureAbortsItsUploads682=== RUN TestObjectStatsTrigger683=== PAUSE TestObjectStatsTrigger684=== RUN TestReconnectLeavesObjectsUnlocked685=== PAUSE TestReconnectLeavesObjectsUnlocked686=== RUN TestOrphanedObjectsGC687=== PAUSE TestOrphanedObjectsGC688=== RUN TestOrphanedObjectsGCStressTest689=== PAUSE TestOrphanedObjectsGCStressTest690=== RUN TestCreatePin_ReservedPins691=== PAUSE TestCreatePin_ReservedPins692=== RUN TestConcurrentPinUpdatesAgree693=== PAUSE TestConcurrentPinUpdatesAgree694=== RUN TestCreatePinRejectsBadInput695=== PAUSE TestCreatePinRejectsBadInput696=== RUN TestDeletePinKeepsRowWhenS3Fails697=== PAUSE TestDeletePinKeepsRowWhenS3Fails698=== RUN TestPresentReportsOnlyClosureRoots699=== PAUSE TestPresentReportsOnlyClosureRoots700=== RUN TestPresentNotReportedWhileGCDeletesClosure701=== PAUSE TestPresentNotReportedWhileGCDeletesClosure702=== RUN TestParseSingleRange703=== PAUSE TestParseSingleRange704=== RUN TestProxyHeadersOnlyTrustedOnSocket705=== PAUSE TestProxyHeadersOnlyTrustedOnSocket706=== RUN TestIsValidCachePath707=== PAUSE TestIsValidCachePath708=== RUN TestReadProxyNarinfo709=== PAUSE TestReadProxyNarinfo710=== RUN TestReadProxyNarinfoAlreadyDecompressed711=== PAUSE TestReadProxyNarinfoAlreadyDecompressed712=== RUN TestReadProxyNarStreaming713=== PAUSE TestReadProxyNarStreaming714=== RUN TestReadProxy404715=== PAUSE TestReadProxy404716=== RUN TestReadProxyInvalidPath717=== PAUSE TestReadProxyInvalidPath718=== RUN TestReadProxyHead719=== PAUSE TestReadProxyHead720=== RUN TestReadProxyOutlastsServerWriteTimeout721=== PAUSE TestReadProxyOutlastsServerWriteTimeout722=== RUN TestReadProxyConditionalGet723=== PAUSE TestReadProxyConditionalGet724=== RUN TestReadProxyRootRedirectsToIndexHTML725=== PAUSE TestReadProxyRootRedirectsToIndexHTML726=== RUN TestReadProxyDisabled727=== PAUSE TestReadProxyDisabled728=== RUN TestReadRedirectNar729=== PAUSE TestReadRedirectNar730=== RUN TestReadRedirectKeepsNarinfoProxied731=== PAUSE TestReadRedirectKeepsNarinfoProxied732=== RUN TestReadProxyRangeRequest733=== PAUSE TestReadProxyRangeRequest734=== RUN TestReadRedirectUsesPublicS3URL735=== PAUSE TestReadRedirectUsesPublicS3URL736=== RUN TestPush_OverlappingRootsStoreOneRowPerKey737=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey738=== RUN TestPush_CompleteCommitsEveryRoot739=== PAUSE TestPush_CompleteCommitsEveryRoot740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/02 20:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"775--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)776=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== RUN TestProxyWriteTimeout779=== PAUSE TestProxyWriteTimeout780=== RUN TestPendingClosureWriteTimeout781=== PAUSE TestPendingClosureWriteTimeout782=== RUN TestIsValidUploadKey783=== PAUSE TestIsValidUploadKey784=== RUN TestUploadHandlersRejectInvalidKeys785=== PAUSE TestUploadHandlersRejectInvalidKeys786=== RUN TestUploadHandlersRejectOversizedBody787=== PAUSE TestUploadHandlersRejectOversizedBody788=== RUN TestService_cleanupPendingClosuresHandler789=== PAUSE TestService_cleanupPendingClosuresHandler790=== RUN TestService_createPendingClosureHandler791=== PAUSE TestService_createPendingClosureHandler792=== RUN TestService_verifyS3Integrity793=== PAUSE TestService_verifyS3Integrity794=== RUN TestCompleteMultipartUnregistered795=== PAUSE TestCompleteMultipartUnregistered796=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT797=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestService_ReadAuthMiddleware799=== CONT TestServerTLSConfig800=== RUN TestServerTLSConfig/no_client_CA801=== PAUSE TestServerTLSConfig/no_client_CA802=== CONT TestCompleteMultipartUnregistered803=== CONT TestGCTaskStore_GetEmpty804=== CONT TestReadProxyConditionalGet805=== CONT TestPush_OverlappingRootsStoreOneRowPerKey806=== CONT TestPresignedUploadRegisteredBeforeCommit807=== RUN TestServerTLSConfig/missing_CA_file808=== CONT TestGCBugBareHashReferences809=== CONT TestGCAdvisoryLockBlocksConcurrentRun810=== PAUSE TestServerTLSConfig/missing_CA_file811=== RUN TestServerTLSConfig/not_a_PEM_file812=== PAUSE TestServerTLSConfig/not_a_PEM_file813=== CONT TestPushDedupSurvivesConcurrentGC814--- PASS: TestGCTaskStore_GetEmpty (0.00s)815=== CONT TestLeadElectsOneAndHandsOver816=== CONT TestGCMetrics8172026/10/02 20:40:04 INFO Aborted multipart uploads count=0 kept=08182026/10/02 20:40:04 WARN Force mode enabled - objects will be deleted immediately without grace period8192026/10/02 20:40:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08202026/10/02 20:40:04 INFO Vacuumed table table=pending_closures8212026/10/02 20:40:04 INFO Vacuumed table table=pending_objects8222026/10/02 20:40:04 INFO Vacuumed table table=multipart_uploads8232026/10/02 20:40:04 INFO Vacuumed table table=closures8242026/10/02 20:40:04 INFO Vacuumed table table=objects825--- PASS: TestGCMetrics (0.70s)826=== CONT TestConnectSerialisesConcurrentMigrations8272026/10/02 20:40:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8282026/10/02 20:40:04 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst829--- PASS: TestCompleteMultipartUnregistered (0.87s)830=== CONT TestConnectWaitsForAPeerMigration831--- PASS: TestService_ReadAuthMiddleware (1.08s)832=== CONT TestLeadEndsOnShutdown8332026-10-02 20:40:05.015 UTC [17171] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"8342026-10-02 20:40:05.015 UTC [17171] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.8352026-10-02 20:40:05.015 UTC [17171] STATEMENT: CREATE TABLE goose_db_version (836 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,837 version_id bigint NOT NULL,838 is_applied boolean NOT NULL,839 tstamp timestamp NOT NULL DEFAULT now()840 )8412026/10/02 20:40:05 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/02 20:40:05 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst8432026/10/02 20:40:05 INFO Received uploads request method=POST path=/api/pending_closures844--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.46s)845=== CONT TestResolveDBConnectionString846=== RUN TestResolveDBConnectionString/flag_wins847=== PAUSE TestResolveDBConnectionString/flag_wins848=== RUN TestResolveDBConnectionString/file_when_flag_empty849=== PAUSE TestResolveDBConnectionString/file_when_flag_empty850=== RUN TestResolveDBConnectionString/missing_file_is_an_error851=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error852=== RUN TestResolveDBConnectionString/PGHOST_allows_empty853=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty854=== RUN TestResolveDBConnectionString/nothing_configured855=== PAUSE TestResolveDBConnectionString/nothing_configured856=== CONT TestClientFallsBackToClosures857--- PASS: TestGCBugBareHashReferences (1.52s)858=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8592026/10/02 20:40:05 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/02 20:40:05 INFO Aborted multipart uploads count=0 kept=08612026/10/02 20:40:05 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=08622026/10/02 20:40:05 INFO Vacuumed table table=pending_closures8632026/10/02 20:40:05 INFO Vacuumed table table=pending_objects8642026/10/02 20:40:05 INFO Vacuumed table table=multipart_uploads8652026/10/02 20:40:05 INFO Vacuumed table table=closures8662026/10/02 20:40:05 INFO Vacuumed table table=objects867--- PASS: TestReadProxyConditionalGet (1.85s)868=== CONT TestClientPushesUseOnePush8692026/10/02 20:40:05 INFO Aborted multipart uploads count=0 kept=08702026/10/02 20:40:05 WARN Force mode enabled - objects will be deleted immediately without grace period8712026/10/02 20:40:05 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=08722026/10/02 20:40:05 INFO Vacuumed table table=pending_closures8732026/10/02 20:40:05 INFO Vacuumed table table=pending_objects8742026/10/02 20:40:05 INFO Vacuumed table table=multipart_uploads8752026/10/02 20:40:05 INFO Vacuumed table table=closures8762026/10/02 20:40:05 INFO Vacuumed table table=objects877--- PASS: TestPushDedupSurvivesConcurrentGC (1.90s)878=== CONT TestCacheStatsHandler8792026/10/02 20:40:05 INFO lead: acquired remote=192.0.2.1:1234880--- PASS: TestConnectSerialisesConcurrentMigrations (1.46s)881=== CONT TestClientWithDependencies8822026/10/02 20:40:06 INFO Received push request method=POST path=/api/pushes883--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.54s)884=== CONT TestClientMultipleUploads8852026/10/02 20:40:06 INFO lead: acquired remote=192.0.2.1:12348862026/10/02 20:40:07 INFO lead: released remote=192.0.2.1:12348872026/10/02 20:40:07 INFO lead: acquired remote=192.0.2.1:1234888--- PASS: TestCacheStatsHandler (1.41s)889=== CONT TestClientIntegration8902026/10/02 20:40:07 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/02 20:40:07 INFO Received uploads request method=POST path=/api/pending_closures8922026/10/02 20:40:07 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8932026/10/02 20:40:07 INFO Uploading b7kmjghvmxbb7qv1g705fpgl45klhb4s-a (248B)8942026/10/02 20:40:07 INFO Uploading 0mlhz9fbibw1by7axddn32mabn1fs4jl-shared-dep (136B)8952026/10/02 20:40:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8962026/10/02 20:40:07 WARN Failed to register uploaded object key=b7kmjghvmxbb7qv1g705fpgl45klhb4s.ls error="server returned 404: 404 page not found\n"8972026/10/02 20:40:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8982026/10/02 20:40:07 WARN Failed to register uploaded object key=3d6p1q01j7gghnkdka7ph5zg2javhf07.ls error="server returned 404: 404 page not found\n"8992026/10/02 20:40:07 WARN Failed to register uploaded object key=nar/1fhcrm6axghb027izjj69a5y4j1wbzjapy99k7pkskjbiks5ydhp.nar.zst error="server returned 404: 404 page not found\n"9002026/10/02 20:40:07 WARN Failed to register uploaded object key=0mlhz9fbibw1by7axddn32mabn1fs4jl.ls error="server returned 404: 404 page not found\n"9012026/10/02 20:40:07 INFO Signed narinfos id=1 count=29022026/10/02 20:40:07 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9032026/10/02 20:40:07 INFO Signed narinfos id=2 count=29042026/10/02 20:40:07 INFO Uploading 4 narinfos9052026/10/02 20:40:07 WARN Failed to register uploaded object key=b7kmjghvmxbb7qv1g705fpgl45klhb4s.narinfo error="server returned 404: 404 page not found\n"9062026/10/02 20:40:07 WARN Failed to register uploaded object key=0mlhz9fbibw1by7axddn32mabn1fs4jl.narinfo error="server returned 404: 404 page not found\n"9072026/10/02 20:40:07 WARN Failed to register uploaded object key=3d6p1q01j7gghnkdka7ph5zg2javhf07.narinfo error="server returned 404: 404 page not found\n"9082026/10/02 20:40:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9092026/10/02 20:40:07 WARN Failed to register uploaded object key=0mlhz9fbibw1by7axddn32mabn1fs4jl.narinfo error="server returned 404: 404 page not found\n"9102026/10/02 20:40:07 INFO Completed upload id=29112026/10/02 20:40:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9122026/10/02 20:40:07 INFO Completed upload id=19132026/10/02 20:40:07 INFO Upload complete. (208ms)914=== NAME TestClientFallsBackToClosures915 client_pushes_test.go:112: Retrieved narinfo from S3:916 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientFallsBackToClosures1678401175/001/store/0mlhz9fbibw1by7axddn32mabn1fs4jl-shared-dep917 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst918 Compression: zstd919 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82920 NarSize: 136921 References: 922 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n923 client_pushes_test.go:112: Retrieved narinfo from S3:924 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientFallsBackToClosures1678401175/001/store/b7kmjghvmxbb7qv1g705fpgl45klhb4s-a925 URL: nar/1fhcrm6axghb027izjj69a5y4j1wbzjapy99k7pkskjbiks5ydhp.nar.zst926 Compression: zstd927 NarHash: sha256:1fhcrm6axghb027izjj69a5y4j1wbzjapy99k7pkskjbiks5ydhp928 NarSize: 248929 References: /nix/var/nix/builds/nix-3690-3946823596/TestClientFallsBackToClosures1678401175/001/store/0mlhz9fbibw1by7axddn32mabn1fs4jl-shared-dep930 CA: text:sha256:1zh4lq8aa11gsywfjxq2av3vjkk1ryajjqd2992cjq00m0fh3wpv931 client_pushes_test.go:112: Retrieved narinfo from S3:932 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientFallsBackToClosures1678401175/001/store/3d6p1q01j7gghnkdka7ph5zg2javhf07-b933 URL: nar/1fhcrm6axghb027izjj69a5y4j1wbzjapy99k7pkskjbiks5ydhp.nar.zst934 Compression: zstd935 NarHash: sha256:1fhcrm6axghb027izjj69a5y4j1wbzjapy99k7pkskjbiks5ydhp936 NarSize: 248937 References: /nix/var/nix/builds/nix-3690-3946823596/TestClientFallsBackToClosures1678401175/001/store/0mlhz9fbibw1by7axddn32mabn1fs4jl-shared-dep938 CA: text:sha256:1zh4lq8aa11gsywfjxq2av3vjkk1ryajjqd2992cjq00m0fh3wpv939--- PASS: TestClientFallsBackToClosures (2.08s)940=== CONT TestClientSharedPathCommittedMidPush9412026/10/02 20:40:07 INFO lead: released remote=192.0.2.1:1234942--- PASS: TestLeadEndsOnShutdown (2.62s)943=== CONT TestClientCADerivations9442026/10/02 20:40:07 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"945--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.90s)946=== CONT TestClientErrorHandling947=== RUN TestClientErrorHandling/InvalidStorePath948=== PAUSE TestClientErrorHandling/InvalidStorePath949=== RUN TestClientErrorHandling/InvalidAuthToken950=== PAUSE TestClientErrorHandling/InvalidAuthToken951=== RUN TestClientErrorHandling/ServerNotAvailable952=== PAUSE TestClientErrorHandling/ServerNotAvailable953=== CONT TestPendingClosureWriteTimeout954=== RUN TestPendingClosureWriteTimeout/empty955=== PAUSE TestPendingClosureWriteTimeout/empty956=== RUN TestPendingClosureWriteTimeout/400_objects957=== PAUSE TestPendingClosureWriteTimeout/400_objects958=== RUN TestPendingClosureWriteTimeout/670k_objects959=== PAUSE TestPendingClosureWriteTimeout/670k_objects960=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline961=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline962=== CONT TestService_verifyS3Integrity9632026/10/02 20:40:07 INFO Received push request method=POST path=/api/pushes9642026/10/02 20:40:07 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9652026/10/02 20:40:07 INFO Uploading hwf7mim4v36ljxkmwvbn3msb6alwjfrb-a (248B)9662026/10/02 20:40:07 INFO Uploading n9hism3389z6xm7iyc82hgfcjr92b4xc-shared-dep (136B)9672026/10/02 20:40:07 WARN Failed to register uploaded object key=n9hism3389z6xm7iyc82hgfcjr92b4xc.ls error="server returned 404: 404 page not found\n"9682026/10/02 20:40:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9692026/10/02 20:40:07 WARN Failed to register uploaded object key=nar/07911ik4cflv96jshwx8pyvigvh6nwwrn6pv2rpc67bj9n97whx4.nar.zst error="server returned 404: 404 page not found\n"9702026/10/02 20:40:07 WARN Failed to register uploaded object key=kz7817a6p7hly6j7jcangvfws7h4rsvi.ls error="server returned 404: 404 page not found\n"9712026/10/02 20:40:07 WARN Failed to register uploaded object key=hwf7mim4v36ljxkmwvbn3msb6alwjfrb.ls error="server returned 404: 404 page not found\n"9722026/10/02 20:40:07 INFO Signed narinfos id=1 count=39732026/10/02 20:40:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9742026/10/02 20:40:07 INFO Uploading 3 narinfos9752026/10/02 20:40:08 WARN Failed to register uploaded object key=n9hism3389z6xm7iyc82hgfcjr92b4xc.narinfo error="server returned 404: 404 page not found\n"9762026/10/02 20:40:08 WARN Failed to register uploaded object key=kz7817a6p7hly6j7jcangvfws7h4rsvi.narinfo error="server returned 404: 404 page not found\n"9772026/10/02 20:40:08 INFO Received complete push request method=POST path=/api/pushes/1/complete9782026/10/02 20:40:08 WARN Failed to register uploaded object key=hwf7mim4v36ljxkmwvbn3msb6alwjfrb.narinfo error="server returned 404: 404 page not found\n"9792026/10/02 20:40:08 INFO Upload complete. (227ms)980=== NAME TestClientPushesUseOnePush981 client_pushes_test.go:97: Retrieved narinfo from S3:982 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientPushesUseOnePush4174884033/001/store/n9hism3389z6xm7iyc82hgfcjr92b4xc-shared-dep983 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst984 Compression: zstd985 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82986 NarSize: 136987 References: 988 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n989 client_pushes_test.go:97: Retrieved narinfo from S3:990 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientPushesUseOnePush4174884033/001/store/hwf7mim4v36ljxkmwvbn3msb6alwjfrb-a991 URL: nar/07911ik4cflv96jshwx8pyvigvh6nwwrn6pv2rpc67bj9n97whx4.nar.zst992 Compression: zstd993 NarHash: sha256:07911ik4cflv96jshwx8pyvigvh6nwwrn6pv2rpc67bj9n97whx4994 NarSize: 248995 References: /nix/var/nix/builds/nix-3690-3946823596/TestClientPushesUseOnePush4174884033/001/store/n9hism3389z6xm7iyc82hgfcjr92b4xc-shared-dep996 CA: text:sha256:05944289mx1j4k7cb97mk52xgprazaccaqx0myp18xnpa6255n5c997 client_pushes_test.go:97: Retrieved narinfo from S3:998 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientPushesUseOnePush4174884033/001/store/kz7817a6p7hly6j7jcangvfws7h4rsvi-b999 URL: nar/07911ik4cflv96jshwx8pyvigvh6nwwrn6pv2rpc67bj9n97whx4.nar.zst1000 Compression: zstd1001 NarHash: sha256:07911ik4cflv96jshwx8pyvigvh6nwwrn6pv2rpc67bj9n97whx41002 NarSize: 2481003 References: /nix/var/nix/builds/nix-3690-3946823596/TestClientPushesUseOnePush4174884033/001/store/n9hism3389z6xm7iyc82hgfcjr92b4xc-shared-dep1004 CA: text:sha256:05944289mx1j4k7cb97mk52xgprazaccaqx0myp18xnpa6255n5c1005--- PASS: TestClientPushesUseOnePush (2.38s)1006=== CONT TestService_createPendingClosureHandler1007=== NAME TestClientWithDependencies1008 client_integration_test.go:735: Built derivation: /nix/var/nix/builds/nix-3690-3946823596/TestClientWithDependencies521650521/001/store/b4npv6dp41pvq4zydfqp70zk2bbsscwc-test-script10092026/10/02 20:40:08 INFO lead: released remote=192.0.2.1:12341010 client_integration_test.go:737: Found 1 dependencies (including self)1011=== NAME TestClientMultipleUploads1012 client_integration_test.go:480: Created store path 0: /nix/var/nix/builds/nix-3690-3946823596/TestClientMultipleUploads731827334/001/store/5sprcp5lcv9r3pxm2i4in825c0cdm8d2-test-file-0.txt1013--- PASS: TestLeadElectsOneAndHandsOver (4.39s)1014=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1015=== NAME TestClientMultipleUploads1016 client_integration_test.go:480: Created store path 1: /nix/var/nix/builds/nix-3690-3946823596/TestClientMultipleUploads731827334/001/store/60pcz529mza28a0k7m3fh8r593fr27mr-test-file-1.txt1017=== NAME TestClientIntegration1018 client_integration_test.go:334: Created store path: /nix/var/nix/builds/nix-3690-3946823596/TestClientIntegration4039494934/002/store/zcf7cpx3niac1cxsp5mlyj4adhqqln3x-test-file.txt1019=== NAME TestClientMultipleUploads1020 client_integration_test.go:480: Created store path 2: /nix/var/nix/builds/nix-3690-3946823596/TestClientMultipleUploads731827334/001/store/mab6wnj5w5k76ib3n2nk9vd4vqj1n5xw-test-file-2.txt10212026/10/02 20:40:08 INFO Received push request method=POST path=/api/pushes10222026/10/02 20:40:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10232026/10/02 20:40:08 INFO Uploading b4npv6dp41pvq4zydfqp70zk2bbsscwc-test-script (136B)10242026/10/02 20:40:08 WARN Failed to register uploaded object key=b4npv6dp41pvq4zydfqp70zk2bbsscwc.ls error="server returned 404: 404 page not found\n"10252026/10/02 20:40:08 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10262026/10/02 20:40:08 WARN Failed to register uploaded object key=log/y4j0swdhyi08is33wx3xsjvl8qj6cqb0-test-script.drv error="server returned 404: 404 page not found\n"10272026/10/02 20:40:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10282026/10/02 20:40:08 INFO Signed narinfos id=1 count=110292026/10/02 20:40:08 INFO Uploading 1 narinfos10302026/10/02 20:40:08 INFO Received push request method=POST path=/api/pushes10312026/10/02 20:40:08 INFO Received complete push request method=POST path=/api/pushes/1/complete10322026/10/02 20:40:08 WARN Failed to register uploaded object key=b4npv6dp41pvq4zydfqp70zk2bbsscwc.narinfo error="server returned 404: 404 page not found\n"10332026/10/02 20:40:08 INFO Upload complete. (368ms)10342026/10/02 20:40:08 INFO Received push request method=POST path=/api/pushes10352026/10/02 20:40:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10362026/10/02 20:40:08 INFO Uploading zcf7cpx3niac1cxsp5mlyj4adhqqln3x-test-file.txt (152B)10372026/10/02 20:40:08 INFO Aborted multipart uploads count=0 kept=010382026/10/02 20:40:08 WARN Force mode enabled - objects will be deleted immediately without grace period10392026/10/02 20:40:08 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10402026/10/02 20:40:08 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=010412026/10/02 20:40:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10422026/10/02 20:40:08 WARN Failed to register uploaded object key=zcf7cpx3niac1cxsp5mlyj4adhqqln3x.ls error="server returned 404: 404 page not found\n"10432026/10/02 20:40:08 INFO Signed narinfos id=1 count=110442026/10/02 20:40:08 INFO Uploading 1 narinfos10452026/10/02 20:40:08 INFO Vacuumed table table=pending_closures10462026/10/02 20:40:08 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10472026/10/02 20:40:08 INFO Uploading mab6wnj5w5k76ib3n2nk9vd4vqj1n5xw-test-file-2.txt (160B)10482026/10/02 20:40:08 INFO Uploading 60pcz529mza28a0k7m3fh8r593fr27mr-test-file-1.txt (160B)10492026/10/02 20:40:08 INFO Uploading 5sprcp5lcv9r3pxm2i4in825c0cdm8d2-test-file-0.txt (160B)1050--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.41s)1051=== CONT TestUploadHandlersRejectOversizedBody10522026/10/02 20:40:08 INFO Vacuumed table table=pending_objects10532026/10/02 20:40:08 INFO Received complete push request method=POST path=/api/pushes/1/complete10542026/10/02 20:40:08 WARN Failed to register uploaded object key=zcf7cpx3niac1cxsp5mlyj4adhqqln3x.narinfo error="server returned 404: 404 page not found\n"10552026/10/02 20:40:08 INFO Vacuumed table table=multipart_uploads10562026/10/02 20:40:08 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10572026/10/02 20:40:08 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10582026/10/02 20:40:08 WARN Failed to register uploaded object key=5sprcp5lcv9r3pxm2i4in825c0cdm8d2.ls error="server returned 404: 404 page not found\n"10592026/10/02 20:40:08 WARN Failed to register uploaded object key=60pcz529mza28a0k7m3fh8r593fr27mr.ls error="server returned 404: 404 page not found\n"10602026/10/02 20:40:08 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10612026/10/02 20:40:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10622026/10/02 20:40:08 WARN Failed to register uploaded object key=mab6wnj5w5k76ib3n2nk9vd4vqj1n5xw.ls error="server returned 404: 404 page not found\n"10632026/10/02 20:40:08 INFO Signed narinfos id=1 count=310642026/10/02 20:40:08 INFO Uploading 3 narinfos10652026/10/02 20:40:08 INFO Upload complete. (241ms)10662026/10/02 20:40:08 INFO Vacuumed table table=closures10672026/10/02 20:40:08 WARN Failed to register uploaded object key=mab6wnj5w5k76ib3n2nk9vd4vqj1n5xw.narinfo error="server returned 404: 404 page not found\n"10682026/10/02 20:40:08 WARN Failed to register uploaded object key=60pcz529mza28a0k7m3fh8r593fr27mr.narinfo error="server returned 404: 404 page not found\n"10692026/10/02 20:40:08 INFO Received complete push request method=POST path=/api/pushes/1/complete10702026/10/02 20:40:08 WARN Failed to register uploaded object key=5sprcp5lcv9r3pxm2i4in825c0cdm8d2.narinfo error="server returned 404: 404 page not found\n"10712026/10/02 20:40:08 INFO Vacuumed table table=objects1072=== NAME TestClientWithDependencies1073 client_integration_test.go:753: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-3690-3946823596/TestClientWithDependencies521650521/001/store) requires matching store prefix10742026/10/02 20:40:08 INFO Upload complete. (232ms)1075=== NAME TestClientMultipleUploads1076 client_integration_test.go:491: Uploaded 3 paths in 373.292667ms10772026/10/02 20:40:08 INFO All 1 paths already cached1078=== NAME TestClientIntegration1079 client_integration_test.go:360: Retrieved narinfo from S3:1080 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientIntegration4039494934/002/store/zcf7cpx3niac1cxsp5mlyj4adhqqln3x-test-file.txt1081 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1082 Compression: zstd1083 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11084 NarSize: 1521085 References: 1086 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11087--- PASS: TestClientWithDependencies (2.87s)1088=== CONT TestService_cleanupPendingClosuresHandler1089=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1090=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1091=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1092=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1093=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1094=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1095=== CONT TestIsValidUploadKey1096=== RUN TestIsValidUploadKey/narinfo1097=== PAUSE TestIsValidUploadKey/narinfo1098=== RUN TestIsValidUploadKey/nar_zst1099=== PAUSE TestIsValidUploadKey/nar_zst1100=== RUN TestIsValidUploadKey/nar_xz1101=== PAUSE TestIsValidUploadKey/nar_xz1102=== RUN TestIsValidUploadKey/nar_plain1103=== PAUSE TestIsValidUploadKey/nar_plain1104=== RUN TestIsValidUploadKey/listing1105=== PAUSE TestIsValidUploadKey/listing1106=== RUN TestIsValidUploadKey/build_log1107=== PAUSE TestIsValidUploadKey/build_log1108=== RUN TestIsValidUploadKey/build_log_home-manager_file1109=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1110=== RUN TestIsValidUploadKey/build_log_plus_in_name1111=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1112=== RUN TestIsValidUploadKey/build_log_question_mark1113=== PAUSE TestIsValidUploadKey/build_log_question_mark1114=== RUN TestIsValidUploadKey/build_log_equals1115=== PAUSE TestIsValidUploadKey/build_log_equals1116=== NAME TestClientIntegration1117 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1118=== RUN TestIsValidUploadKey/realisation1119=== NAME TestClientIntegration1120 client_integration_test.go:361: Decompressed .ls content (64 bytes):1121 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1122=== PAUSE TestIsValidUploadKey/realisation1123=== RUN TestIsValidUploadKey/realisation_plus_in_output1124=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1125=== RUN TestIsValidUploadKey/nix-cache-info1126=== PAUSE TestIsValidUploadKey/nix-cache-info1127=== RUN TestIsValidUploadKey/index.html1128=== PAUSE TestIsValidUploadKey/index.html1129=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1130=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1131=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1132=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1133=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1134=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1135=== RUN TestIsValidUploadKey/traversal1136=== PAUSE TestIsValidUploadKey/traversal1137=== RUN TestIsValidUploadKey/traversal_nar1138=== PAUSE TestIsValidUploadKey/traversal_nar1139=== RUN TestIsValidUploadKey/absolute1140=== PAUSE TestIsValidUploadKey/absolute1141=== RUN TestIsValidUploadKey/empty_key1142=== PAUSE TestIsValidUploadKey/empty_key1143=== RUN TestIsValidUploadKey/unknown_type1144=== PAUSE TestIsValidUploadKey/unknown_type1145=== CONT TestCompletedNarNotReofferedAcrossClosures1146--- PASS: TestClientMultipleUploads (2.60s)1147=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11482026/10/02 20:40:09 INFO Received push request method=POST path=/api/pushes11492026/10/02 20:40:09 INFO Received uploads request method=POST path=/api/pending_closures11502026/10/02 20:40:09 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11512026/10/02 20:40:09 INFO Uploading xlcgw73kfxr6in2w2v3zqb3gq53alb6v-top (256B)11522026/10/02 20:40:09 INFO Uploading bysmni6kcdyjsfzkv60gbv4cyj91ayhz-shared-dep (136B)11532026/10/02 20:40:09 INFO Received push request method=POST path=/api/pushes11542026/10/02 20:40:09 WARN Failed to register uploaded object key=xlcgw73kfxr6in2w2v3zqb3gq53alb6v.ls error="server returned 404: 404 page not found\n"11552026/10/02 20:40:09 WARN Failed to register uploaded object key=nar/1n86g731kd9ydf5h40hmjb3x13hh4v4bvp4j18k2lwjsd1z88d95.nar.zst error="server returned 404: 404 page not found\n"11562026/10/02 20:40:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11572026/10/02 20:40:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11582026/10/02 20:40:09 INFO Object in database but missing from S3 key=zcf7cpx3niac1cxsp5mlyj4adhqqln3x.ls11592026/10/02 20:40:09 WARN Found objects in DB but missing from S3, will re-upload count=111602026/10/02 20:40:09 WARN Failed to register uploaded object key=bysmni6kcdyjsfzkv60gbv4cyj91ayhz.ls error="server returned 404: 404 page not found\n"11612026/10/02 20:40:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11622026/10/02 20:40:09 INFO Signed narinfos id=1 count=211632026/10/02 20:40:09 INFO Uploading 2 narinfos11642026/10/02 20:40:09 INFO Received complete push request method=POST path=/api/pushes/2/complete11652026/10/02 20:40:09 WARN Failed to register uploaded object key=zcf7cpx3niac1cxsp5mlyj4adhqqln3x.ls error="server returned 404: 404 page not found\n"11662026/10/02 20:40:09 WARN Failed to register uploaded object key=xlcgw73kfxr6in2w2v3zqb3gq53alb6v.narinfo error="server returned 404: 404 page not found\n"11672026/10/02 20:40:09 INFO Received complete push request method=POST path=/api/pushes/1/complete11682026/10/02 20:40:09 WARN Failed to register uploaded object key=bysmni6kcdyjsfzkv60gbv4cyj91ayhz.narinfo error="server returned 404: 404 page not found\n"11692026/10/02 20:40:09 INFO Upload complete. (143ms)1170=== NAME TestClientIntegration1171 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1172 client_integration_test.go:389: Decompressed .ls content (49 bytes):1173 {"version":1,"root":{"type":"regular","size":39}}11742026/10/02 20:40:09 INFO Upload complete. (206ms)1175=== NAME TestClientSharedPathCommittedMidPush1176 client_integration_test.go:816: Retrieved narinfo from S3:1177 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientSharedPathCommittedMidPush1695155173/001/store/bysmni6kcdyjsfzkv60gbv4cyj91ayhz-shared-dep1178 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1179 Compression: zstd1180 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821181 NarSize: 1361182 References: 1183 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1184 client_integration_test.go:816: Retrieved narinfo from S3:1185 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientSharedPathCommittedMidPush1695155173/001/store/xlcgw73kfxr6in2w2v3zqb3gq53alb6v-top1186 URL: nar/1n86g731kd9ydf5h40hmjb3x13hh4v4bvp4j18k2lwjsd1z88d95.nar.zst1187 Compression: zstd1188 NarHash: sha256:1n86g731kd9ydf5h40hmjb3x13hh4v4bvp4j18k2lwjsd1z88d951189 NarSize: 2561190 References: /nix/var/nix/builds/nix-3690-3946823596/TestClientSharedPathCommittedMidPush1695155173/001/store/bysmni6kcdyjsfzkv60gbv4cyj91ayhz-shared-dep1191 CA: text:sha256:1nawp7q3r6q81vmxzhapjhh5j5k0y1kay9p7q7m9py7vdi52242g1192--- PASS: TestClientSharedPathCommittedMidPush (1.88s)1193=== CONT TestRedundantMultipartUpload11942026/10/02 20:40:09 INFO Received uploads request method=POST path=/api/pending_closures11952026/10/02 20:40:09 INFO Received uploads request method=POST path=/api/pending_closures11962026/10/02 20:40:09 INFO Received uploads request method=POST path=/api/pending_closures11972026/10/02 20:40:09 INFO Received push request method=POST path=/api/pushes11982026/10/02 20:40:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11992026/10/02 20:40:09 INFO Received complete push request method=POST path=/api/pushes/3/complete12002026/10/02 20:40:09 WARN Failed to register uploaded object key=zcf7cpx3niac1cxsp5mlyj4adhqqln3x.ls error="server returned 404: 404 page not found\n"12012026/10/02 20:40:09 INFO Upload complete. (147ms)1202=== NAME TestClientIntegration1203 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1204 client_integration_test.go:405: Decompressed .ls content (49 bytes):1205 {"version":1,"root":{"type":"regular","size":39}}1206=== NAME TestClientCADerivations1207 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-3690-3946823596/TestClientCADerivations2112690128/001/store/5vwzkpiq1r0pg8ghwfagi1yv2z0gwvyf-ca-test1208 client_ca_test.go:139: Found 1 dependencies (including self)12092026/10/02 20:40:09 INFO Received uploads request method=POST path=/api/pending_closures12102026/10/02 20:40:09 INFO Received push request method=POST path=/api/pushes12112026/10/02 20:40:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12122026/10/02 20:40:09 INFO Uploading bkjwsawbvgzaiclssvxiqldvrrj1bzl8-lost-commit.txt (152B)12132026/10/02 20:40:09 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"12142026/10/02 20:40:09 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign12152026/10/02 20:40:09 WARN Failed to register uploaded object key=bkjwsawbvgzaiclssvxiqldvrrj1bzl8.ls error="server returned 404: 404 page not found\n"12162026/10/02 20:40:09 INFO Signed narinfos id=4 count=112172026/10/02 20:40:09 INFO Uploading 1 narinfos1218--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.69s)1219=== CONT TestPresentNotReportedWhileGCDeletesClosure12202026/10/02 20:40:09 INFO Received complete push request method=POST path=/api/pushes/4/complete12212026/10/02 20:40:09 WARN Failed to register uploaded object key=bkjwsawbvgzaiclssvxiqldvrrj1bzl8.narinfo error="server returned 404: 404 page not found\n"12222026/10/02 20:40:09 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:60359/api/pushes/4/complete\": EOF" url=http://127.0.0.1:60359/api/pushes/4/complete12232026/10/02 20:40:10 INFO Received push request method=POST path=/api/pushes12242026/10/02 20:40:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12252026/10/02 20:40:10 INFO Uploading 5vwzkpiq1r0pg8ghwfagi1yv2z0gwvyf-ca-test (144B)12262026/10/02 20:40:10 INFO Received complete push request method=POST path=/api/pushes/4/complete12272026-10-02 20:40:10.071 UTC [18022] ERROR: Push does not exist: id=412282026-10-02 20:40:10.071 UTC [18022] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE12292026-10-02 20:40:10.071 UTC [18022] STATEMENT: -- name: CommitPush :exec1230 SELECT commit_push($1::bigint)1231 12322026/10/02 20:40:10 INFO Upload complete. (301ms)1233=== NAME TestClientIntegration1234 client_integration_test.go:435: Retrieved narinfo from S3:1235 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientIntegration4039494934/002/store/bkjwsawbvgzaiclssvxiqldvrrj1bzl8-lost-commit.txt1236 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1237 Compression: zstd1238 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1239 NarSize: 1521240 References: 1241 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1242 client_integration_test.go:438: Testing garbage collection...12432026/10/02 20:40:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12442026/10/02 20:40:10 WARN Failed to register uploaded object key=5vwzkpiq1r0pg8ghwfagi1yv2z0gwvyf.ls error="server returned 404: 404 page not found\n"12452026/10/02 20:40:10 WARN Failed to register uploaded object key=log/fbd983pxjwfb0y50bjvanxkwmyndrydq-ca-test.drv error="server returned 404: 404 page not found\n"12462026/10/02 20:40:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12472026/10/02 20:40:10 INFO Signed narinfos id=1 count=112482026/10/02 20:40:10 INFO Uploading 1 narinfos12492026/10/02 20:40:10 INFO Received complete push request method=POST path=/api/pushes/1/complete12502026/10/02 20:40:10 WARN Failed to register uploaded object key=5vwzkpiq1r0pg8ghwfagi1yv2z0gwvyf.narinfo error="server returned 404: 404 page not found\n"12512026/10/02 20:40:10 INFO Upload complete. (348ms)1252=== NAME TestClientCADerivations1253 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestClientCADerivations2112690128/001/store/5vwzkpiq1r0pg8ghwfagi1yv2z0gwvyf-ca-test1254 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1255 Compression: zstd1256 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1257 NarSize: 1441258 References: 1259 Deriver: /nix/var/nix/builds/nix-3690-3946823596/TestClientCADerivations2112690128/001/store/fbd983pxjwfb0y50bjvanxkwmyndrydq-ca-test.drv1260 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1261 client_ca_test.go:185: Checking for realisation files in S3...1262 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1263 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache12642026/10/02 20:40:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures12652026/10/02 20:40:10 INFO Garbage collection started12662026/10/02 20:40:10 INFO Aborted multipart uploads count=0 kept=012672026/10/02 20:40:10 WARN Force mode enabled - objects will be deleted immediately without grace period1268 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket23?endpoint=http://localhost:60185®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-3690-3946823596/TestClientCADerivations2112690128/001/store'1269 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 112702026/10/02 20:40:10 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=012712026/10/02 20:40:10 INFO Vacuumed table table=pending_closures12722026/10/02 20:40:10 INFO Vacuumed table table=pending_objects12732026/10/02 20:40:10 INFO Vacuumed table table=multipart_uploads12742026/10/02 20:40:10 INFO Vacuumed table table=closures1275--- PASS: TestClientCADerivations (2.93s)1276=== CONT TestReadProxyOutlastsServerWriteTimeout12772026/10/02 20:40:10 INFO Vacuumed table table=objects1278--- PASS: TestConnectWaitsForAPeerMigration (5.78s)1279=== CONT TestReadProxyRootRedirectsToIndexHTML12802026/10/02 20:40:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12812026/10/02 20:40:10 INFO Aborted multipart uploads count=0 kept=012822026/10/02 20:40:10 INFO Received uploads request method=POST path=/api/pending_closures12832026/10/02 20:40:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/10/02 20:40:10 INFO Received cleanup request method=DELETE path=/api/pending_closures12852026/10/02 20:40:10 INFO Aborted multipart uploads count=1 kept=012862026/10/02 20:40:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12872026/10/02 20:40:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjUyYzhhYjYyLWUyMmEtNGE3YS1hZmRmLTA3NTc2YWYxMjYyYXgxNzkwOTczNjA5MTg2OTcyMDAw parts=1012882026-10-02 20:40:10.823 UTC [18606] ERROR: Closure does not exist: id=112892026-10-02 20:40:10.823 UTC [18606] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12902026-10-02 20:40:10.823 UTC [18606] STATEMENT: -- name: CommitPendingClosure :exec1291 SELECT commit_pending_closure($1::bigint)1292 12932026/10/02 20:40:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1294--- PASS: TestService_cleanupPendingClosuresHandler (1.94s)1295=== CONT TestReadProxyHead12962026/10/02 20:40:10 INFO Completed upload id=112972026/10/02 20:40:10 INFO Received uploads request method=POST path=/api/pending_closures12982026/10/02 20:40:10 INFO Received uploads request method=POST path=/api/pending_closures12992026/10/02 20:40:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13002026/10/02 20:40:10 WARN Found objects in DB but missing from S3, will re-upload count=113012026/10/02 20:40:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13022026/10/02 20:40:10 INFO Completed upload id=31303--- PASS: TestService_verifyS3Integrity (3.18s)1304=== CONT TestReadProxy40413052026/10/02 20:40:11 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/02 20:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13072026/10/02 20:40:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjllMjU1NTJhLTM0YzQtNDcxNC1iYzhiLTdhODVmNzliMGI4YngxNzkwOTczNjA5NTAxNDk1MDAw parts=1013082026/10/02 20:40:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13092026/10/02 20:40:11 INFO Completed upload id=113102026/10/02 20:40:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013112026/10/02 20:40:11 INFO Received uploads request method=POST path=/api/pending_closures13122026/10/02 20:40:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures13132026/10/02 20:40:11 INFO Aborted multipart uploads count=0 kept=013142026/10/02 20:40:11 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=013152026/10/02 20:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13162026/10/02 20:40:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjlkMmVlMWVhLTBlMjAtNDVmMS05YWI5LWE4OWQwMDBkOTA3MXgxNzkwOTczNjExMDg0MDU2MDAw13172026/10/02 20:40:11 INFO Vacuumed table table=pending_closures13182026/10/02 20:40:11 INFO Received uploads request method=POST path=/api/pending_closures13192026/10/02 20:40:11 INFO Vacuumed table table=pending_objects13202026/10/02 20:40:11 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjlkMmVlMWVhLTBlMjAtNDVmMS05YWI5LWE4OWQwMDBkOTA3MXgxNzkwOTczNjExMDg0MDU2MDAw error="Delete \"http://localhost:60185/bucket28/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjlkMmVlMWVhLTBlMjAtNDVmMS05YWI5LWE4OWQwMDBkOTA3MXgxNzkwOTczNjExMDg0MDU2MDAw\": injected: abort refused"13212026/10/02 20:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13222026/10/02 20:40:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjlkMmVlMWVhLTBlMjAtNDVmMS05YWI5LWE4OWQwMDBkOTA3MXgxNzkwOTczNjExMDg0MDU2MDAw13232026/10/02 20:40:11 INFO Vacuumed table table=multipart_uploads13242026/10/02 20:40:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjlkMmVlMWVhLTBlMjAtNDVmMS05YWI5LWE4OWQwMDBkOTA3MXgxNzkwOTczNjExMDg0MDU2MDAw parts=113252026/10/02 20:40:11 INFO Vacuumed table table=closures1326--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.48s)1327=== CONT TestReadProxyInvalidPath13282026/10/02 20:40:11 INFO Vacuumed table table=objects13292026/10/02 20:40:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001330--- PASS: TestService_createPendingClosureHandler (3.43s)1331=== CONT TestReadProxyNarinfoAlreadyDecompressed13322026/10/02 20:40:11 INFO Received uploads request method=POST path=/api/pending_closures13332026/10/02 20:40:11 INFO Received uploads request method=POST path=/api/pending_closures13342026/10/02 20:40:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01335=== NAME TestClientIntegration1336 client_integration_test.go:445: Objects in database after GC:1337 client_integration_test.go:445: Successfully deleted all objects with GC --force1338--- PASS: TestClientIntegration (5.13s)1339=== CONT TestReadProxyNarinfo1340--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.95s)1341=== CONT TestReadProxyNarStreaming13422026/10/02 20:40:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13432026/10/02 20:40:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjhkMzEzOTM3LTk1OTYtNDFhYy1hNDBkLTFjNGU0MGE5Mzk2ZHgxNzkwOTczNjExMzg5MDc3MDAw parts=1213442026/10/02 20:40:13 INFO Received uploads request method=POST path=/api/pending_closures1345--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.56s)1346=== CONT TestProxyHeadersOnlyTrustedOnSocket1347--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.06s)1348=== CONT TestParseSingleRange1349=== RUN TestParseSingleRange/none1350=== PAUSE TestParseSingleRange/none1351=== RUN TestParseSingleRange/unknown_unit1352=== PAUSE TestParseSingleRange/unknown_unit1353=== RUN TestParseSingleRange/multi-range_ignored1354=== PAUSE TestParseSingleRange/multi-range_ignored1355=== RUN TestParseSingleRange/malformed_no_dash1356=== PAUSE TestParseSingleRange/malformed_no_dash1357=== RUN TestParseSingleRange/malformed_both_empty1358=== PAUSE TestParseSingleRange/malformed_both_empty1359=== RUN TestParseSingleRange/malformed_end_before_start1360=== PAUSE TestParseSingleRange/malformed_end_before_start1361=== RUN TestParseSingleRange/closed1362=== PAUSE TestParseSingleRange/closed1363=== RUN TestParseSingleRange/open-ended1364=== PAUSE TestParseSingleRange/open-ended1365=== RUN TestParseSingleRange/end_clamped_to_size1366=== PAUSE TestParseSingleRange/end_clamped_to_size1367=== RUN TestParseSingleRange/suffix1368=== PAUSE TestParseSingleRange/suffix1369=== RUN TestParseSingleRange/suffix_exceeds_size1370=== PAUSE TestParseSingleRange/suffix_exceeds_size1371=== RUN TestParseSingleRange/single_byte1372=== PAUSE TestParseSingleRange/single_byte1373=== RUN TestParseSingleRange/start_past_EOF1374=== PAUSE TestParseSingleRange/start_past_EOF1375=== RUN TestParseSingleRange/start_far_past_EOF1376=== PAUSE TestParseSingleRange/start_far_past_EOF1377=== CONT TestIsValidCachePath1378=== RUN TestIsValidCachePath/narinfo1379=== PAUSE TestIsValidCachePath/narinfo1380=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1381=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1382=== RUN TestIsValidCachePath/nar_zst1383=== PAUSE TestIsValidCachePath/nar_zst1384=== RUN TestIsValidCachePath/nar_xz1385=== PAUSE TestIsValidCachePath/nar_xz1386=== RUN TestIsValidCachePath/nar_bz21387=== PAUSE TestIsValidCachePath/nar_bz21388=== RUN TestIsValidCachePath/nar_uncompressed1389=== PAUSE TestIsValidCachePath/nar_uncompressed1390=== RUN TestIsValidCachePath/ls1391=== PAUSE TestIsValidCachePath/ls1392=== RUN TestIsValidCachePath/log1393=== PAUSE TestIsValidCachePath/log1394=== RUN TestIsValidCachePath/realisation1395=== PAUSE TestIsValidCachePath/realisation1396=== RUN TestIsValidCachePath/nix-cache-info1397=== PAUSE TestIsValidCachePath/nix-cache-info1398=== RUN TestIsValidCachePath/index.html1399=== PAUSE TestIsValidCachePath/index.html1400=== RUN TestIsValidCachePath/traversal_parent1401=== PAUSE TestIsValidCachePath/traversal_parent1402=== RUN TestIsValidCachePath/traversal_in_middle1403=== PAUSE TestIsValidCachePath/traversal_in_middle1404=== RUN TestIsValidCachePath/invalid_char_e1405=== PAUSE TestIsValidCachePath/invalid_char_e1406=== RUN TestIsValidCachePath/invalid_char_u1407=== PAUSE TestIsValidCachePath/invalid_char_u1408=== RUN TestIsValidCachePath/random_path1409=== PAUSE TestIsValidCachePath/random_path1410=== RUN TestIsValidCachePath/empty1411=== PAUSE TestIsValidCachePath/empty1412=== RUN TestIsValidCachePath/leading_slash1413=== PAUSE TestIsValidCachePath/leading_slash1414=== RUN TestIsValidCachePath/wrong_extension1415=== PAUSE TestIsValidCachePath/wrong_extension1416=== RUN TestIsValidCachePath/short_hash1417=== PAUSE TestIsValidCachePath/short_hash1418=== CONT TestPresentReportsOnlyClosureRoots14192026/10/02 20:40:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14202026/10/02 20:40:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjZhZWIzM2Y2LTU4MDEtNDExNy05OTI0LWQ1OTQxMmM0ZTc2M3gxNzkwOTczNjExNzIxNzIwMDAw parts=1214212026/10/02 20:40:13 INFO Received uploads request method=POST path=/api/pending_closures1422--- PASS: TestReadProxyHead (3.05s)1423=== CONT TestDeletePinKeepsRowWhenS3Fails14242026/10/02 20:40:13 INFO Received uploads request method=POST path=/api/pending_closures1425--- PASS: TestReadProxyInvalidPath (2.94s)1426=== CONT TestPush_SignsNarinfosOfItsPendingObjects14272026/10/02 20:40:14 WARN Rate limiter enabled after throttle name=s3-test rate=514282026/10/02 20:40:14 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14292026/10/02 20:40:14 WARN Rate limiter backed off name=s3-test rate=514302026/10/02 20:40:14 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1431--- PASS: TestReadProxy404 (3.77s)1432=== CONT TestPush_RejectsBadRequests1433--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.25s)1434=== CONT TestPush_CompleteCommitsEveryRoot14352026/10/02 20:40:15 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1436--- PASS: TestReadProxyNarStreaming (2.48s)1437=== CONT TestReadRedirectNar14382026/10/02 20:40:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14392026/10/02 20:40:15 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721614402026/10/02 20:40:15 INFO Starting HTTP server address=127.0.0.1:6057314412026/10/02 20:40:15 INFO Starting HTTP server address=/nix/var/nix/builds/nix-3690-3946823596/TestProxyHeadersOnlyTrustedOnSocket494985983/001/proxy.sock14422026/10/02 20:40:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14432026/10/02 20:40:15 INFO Shutdown signal received, draining in-flight requests timeout=10s1444--- PASS: TestReadProxyNarinfo (3.35s)1445=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1446--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.19s)1447=== CONT TestReadRedirectUsesPublicS3URL14482026/10/02 20:40:15 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLmUyMDE2YjQ1LTY4N2UtNDYwZS05YzkzLTMxN2IwOGQxNzU0ZXgxNzkwOTczNjEzOTAwMzUxMDAw error="Get \"http://127.0.0.1:1/bucket30/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14492026/10/02 20:40:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjgzZWYyZGRiLWEyNmUtNDUxZC04NTVjLTVkZDY4NGJkMzUwOXgxNzkwOTczNjEzODQ5NjcyMDAw parts=1214502026/10/02 20:40:15 INFO Received cleanup request method=DELETE path=/api/pending_closures14512026/10/02 20:40:15 INFO Aborted multipart uploads count=1 kept=01452--- PASS: TestRedundantMultipartUpload (6.46s)1453=== CONT TestReadRedirectKeepsNarinfoProxied1454--- PASS: TestPresentReportsOnlyClosureRoots (2.40s)1455=== CONT TestConcurrentPinUpdatesAgree14562026/10/02 20:40:16 INFO Received create pin request method=POST path=/api/pins/app14572026/10/02 20:40:16 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo14582026/10/02 20:40:16 INFO Received delete pin request method=DELETE path=/api/pins/app14592026/10/02 20:40:16 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket42/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14602026/10/02 20:40:16 INFO Received delete pin request method=DELETE path=/api/pins/app14612026/10/02 20:40:16 INFO Deleted pin name=app1462--- PASS: TestDeletePinKeepsRowWhenS3Fails (2.38s)1463=== CONT TestCreatePinRejectsBadInput14642026/10/02 20:40:16 INFO Received push request method=POST path=/api/pushes14652026/10/02 20:40:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14662026/10/02 20:40:16 INFO Signed narinfos id=1 count=11467--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.14s)1468=== CONT TestCreatePin_ReservedPins14692026/10/02 20:40:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60596/oidc1470=== RUN TestPush_RejectsBadRequests/bad_root1471=== PAUSE TestPush_RejectsBadRequests/bad_root1472=== RUN TestPush_RejectsBadRequests/root_not_in_objects1473=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1474=== RUN TestPush_RejectsBadRequests/no_roots1475=== PAUSE TestPush_RejectsBadRequests/no_roots1476=== RUN TestPush_RejectsBadRequests/no_objects1477=== PAUSE TestPush_RejectsBadRequests/no_objects1478=== CONT TestOrphanedObjectsGCStressTest14792026/10/02 20:40:16 INFO Received push request method=POST path=/api/pushes1480--- PASS: TestReadRedirectNar (1.84s)1481=== CONT TestOrphanedObjectsGC1482--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.96s)1483=== CONT TestReconnectLeavesObjectsUnlocked14842026/10/02 20:40:17 INFO Received push request method=POST path=/api/pushes1485--- PASS: TestReadRedirectKeepsNarinfoProxied (2.05s)1486=== CONT TestObjectStatsTrigger14872026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/app14882026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/app14892026/10/02 20:40:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1490--- PASS: TestReadRedirectUsesPublicS3URL (2.81s)1491=== CONT TestReadProxyDisabled14922026/10/02 20:40:18 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLmZiYjJiYjFiLTYzMWMtNDc5NC05YmU1LTMyYjYxOGI1ZDFjZngxNzkwOTczNjE2OTU0Mjk0MDAw parts=1014932026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14942026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14952026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14962026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14972026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14982026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy14992026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy15002026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy15012026/10/02 20:40:18 INFO Received create pin request method=POST path=/api/pins/deploy15022026/10/02 20:40:18 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo15032026/10/02 20:40:18 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1504--- PASS: TestConcurrentPinUpdatesAgree (2.93s)1505=== CONT TestReadProxyRangeRequest15062026/10/02 20:40:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15072026/10/02 20:40:19 WARN Refused reserved pin name=worker-x86_64-linux15082026/10/02 20:40:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15092026/10/02 20:40:19 INFO Received create pin request method=POST path=/api/pins/my-app15102026/10/02 20:40:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1511--- PASS: TestCreatePin_ReservedPins (2.63s)1512=== CONT TestPendingCleanupUsesOneCutoff15132026/10/02 20:40:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15142026/10/02 20:40:19 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjhlYThhYjg1LTc0ODctNDFkYi04ZGNmLTk0YWVjNTMzNWU3M3gxNzkwOTczNjE3NTA0ODk2MDAw parts=1015152026/10/02 20:40:19 INFO Received create pin request method=POST path=/api/pins/deploy15162026/10/02 20:40:19 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1517--- PASS: TestCreatePinRejectsBadInput (3.28s)1518=== CONT TestPendingClosureFailureAbortsItsUploads1519--- PASS: TestReconnectLeavesObjectsUnlocked (2.30s)1520=== CONT TestPendingClosureFailureTracksEveryUpload1521--- PASS: TestObjectStatsTrigger (2.35s)1522=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1523=== NAME TestOrphanedObjectsGC1524 orphaned_objects_gc_test.go:290: GC Test Summary:1525 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1526 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1527 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1528 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1529 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects15302026/10/02 20:40:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1531--- PASS: TestOrphanedObjectsGC (3.14s)1532=== CONT TestService_NativeMTLS15332026/10/02 20:40:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLmRjZmJkMzY3LWZiYzItNDc5OC1hNWM3LTY3MDFiZTQ3MzQ4NXgxNzkwOTczNjE2OTU1MDc0MDAw parts=101534--- PASS: TestReadProxyDisabled (1.98s)1535=== CONT TestMultipartCleanup15362026/10/02 20:40:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15372026/10/02 20:40:21 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLmFiZTFlNGEyLTg0MzAtNDJjMi05MDRkLWQzNWY3MzJkMGRjZngxNzkwOTczNjE3NTA0MjMxMDAw parts=1015382026/10/02 20:40:21 INFO Received complete push request method=POST path=/api/pushes/1/complete15392026/10/02 20:40:21 INFO Received push request method=POST path=/api/pushes15402026/10/02 20:40:21 INFO Aborted multipart uploads count=0 kept=015412026/10/02 20:40:21 WARN Force mode enabled - objects will be deleted immediately without grace period15422026/10/02 20:40:21 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=015432026/10/02 20:40:21 INFO Vacuumed table table=pending_closures15442026/10/02 20:40:21 INFO Vacuumed table table=pending_objects15452026/10/02 20:40:21 INFO Vacuumed table table=multipart_uploads15462026/10/02 20:40:21 INFO Vacuumed table table=closures15472026/10/02 20:40:21 INFO Vacuumed table table=objects1548--- PASS: TestReadProxyRangeRequest (2.79s)1549=== CONT TestService_AuthMiddleware_OIDC15502026/10/02 20:40:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15512026/10/02 20:40:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60696/oidc15522026/10/02 20:40:21 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLmEzYjc5Yzg2LWJhNzAtNDNiNi05YTUzLWMwN2I2NTViNDVkMHgxNzkwOTczNjE2OTU1MTQzMDAw parts=1015532026/10/02 20:40:21 INFO Received complete push request method=POST path=/api/pushes/1/complete1554--- PASS: TestPush_CompleteCommitsEveryRoot (7.13s)1555=== CONT TestService_ReadScope_PublicByDefault15562026/10/02 20:40:22 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/02 20:40:22 INFO Received uploads request method=POST path=/api/pending_closures15582026/10/02 20:40:22 INFO Received cleanup request method=DELETE path=/api/pending_closures15592026/10/02 20:40:22 INFO Received uploads request method=POST path=/api/pending_closures1560--- PASS: TestPendingClosureFailureAbortsItsUploads (3.21s)1561=== CONT TestCacheConfigHandler1562=== RUN TestCacheConfigHandler/full_config,_no_issuer1563=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1564=== RUN TestCacheConfigHandler/no_cache_url_configured1565=== PAUSE TestCacheConfigHandler/no_cache_url_configured1566=== RUN TestCacheConfigHandler/no_signing_keys1567=== PAUSE TestCacheConfigHandler/no_signing_keys1568=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1569=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1570=== CONT TestService_RequireScope_OIDC15712026/10/02 20:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60714/oidc15722026/10/02 20:40:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15732026/10/02 20:40:22 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MWE3ZDJhOGMtNzkxNi00YzNiLTg2YjYtYTU0MTJhMmFlNGNjLjJhZDlmZmFhLTE0ZTMtNDU2My04NjdkLTJhODQ3NDM3MDgyMngxNzkwOTczNjIxMTExMzU4MDAw parts=1015742026/10/02 20:40:22 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/02 20:40:22 INFO Received complete push request method=POST path=/api/pushes/2/complete1576--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.35s)1577=== CONT TestService_AuthMiddleware_MTLSProxyHeader15782026/10/02 20:40:23 INFO Received uploads request method=POST path=/api/pending_closures1579--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (3.18s)1580=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15812026/10/02 20:40:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15822026/10/02 20:40:23 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1583--- PASS: TestService_NativeMTLS (3.17s)1584=== CONT TestParseSize1585--- PASS: TestParseSize (0.00s)1586=== CONT TestProxyWriteTimeout1587=== RUN TestProxyWriteTimeout/narinfo1588=== PAUSE TestProxyWriteTimeout/narinfo1589=== RUN TestProxyWriteTimeout/1_GiB_nar1590=== PAUSE TestProxyWriteTimeout/1_GiB_nar1591=== RUN TestProxyWriteTimeout/10_GiB_nar1592=== PAUSE TestProxyWriteTimeout/10_GiB_nar1593=== RUN TestProxyWriteTimeout/unknown_size1594=== PAUSE TestProxyWriteTimeout/unknown_size1595=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1596--- PASS: TestPendingClosureFailureTracksEveryUpload (3.87s)1597=== CONT TestUploadHandlersRejectInvalidKeys1598=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1599=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1600=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1601=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1602=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1603=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1604=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1605=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1606=== CONT TestService_AuthMiddleware16072026/10/02 20:40:23 INFO Received uploads request method=POST path=/api/pending_closures16082026/10/02 20:40:23 INFO Received cleanup request method=DELETE path=/api/pending_closures16092026/10/02 20:40:23 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket64/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16102026/10/02 20:40:23 INFO Aborted multipart uploads count=0 kept=116112026/10/02 20:40:23 INFO Received cleanup request method=DELETE path=/api/pending_closures16122026/10/02 20:40:23 INFO Aborted multipart uploads count=1 kept=01613--- PASS: TestMultipartCleanup (3.47s)1614=== CONT TestService_Rustfstest1615=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1616=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1617=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1618=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1619=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1620=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1621=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1622=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1623=== CONT TestSkippedUploadsHandler16242026/10/02 20:40:24 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001625--- PASS: TestSkippedUploadsHandler (0.00s)1626=== CONT TestDeduplicatedObjectsRecordedAsPending1627--- PASS: TestService_ReadScope_PublicByDefault (2.42s)1628=== CONT TestGCTaskStore_StartNew1629--- PASS: TestGCTaskStore_StartNew (0.00s)1630=== CONT TestGCTaskStore_DeduplicateSameParams1631--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1632=== CONT TestMetricsInventory1633=== RUN TestService_RequireScope_OIDC/builder_may_write1634=== PAUSE TestService_RequireScope_OIDC/builder_may_write1635=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1636=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1637=== RUN TestService_RequireScope_OIDC/ops_may_admin1638=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1639=== RUN TestService_RequireScope_OIDC/ops_may_not_write1640=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1641=== RUN TestService_RequireScope_OIDC/reader_may_not_write1642=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1643=== RUN TestService_RequireScope_OIDC/static_token_may_admin1644=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1645=== RUN TestService_RequireScope_OIDC/static_token_may_write1646=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1647=== RUN TestService_RequireScope_OIDC/reader_may_read1648=== PAUSE TestService_RequireScope_OIDC/reader_may_read1649=== RUN TestService_RequireScope_OIDC/writer_implies_read1650=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1651=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1652=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1653=== CONT TestCommitRacingPendingCleanupKeepsObjects1654=== NAME TestOrphanedObjectsGCStressTest1655 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1656--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.09s)1657=== CONT TestServerTLSConfig/not_a_PEM_file1658=== CONT TestCreatePendingClosureRejectsOversizedNAR16592026/10/02 20:40:25 INFO Received uploads request method=POST path=/api/pending_closures1660--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1661=== CONT TestPushWaitsForSweepHoldingRow1662=== NAME TestOrphanedObjectsGCStressTest1663 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion16642026/10/02 20:40:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16652026/10/02 20:40:25 WARN mTLS auth: bound subjects configured but subject DN unavailable16662026/10/02 20:40:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1667--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.01s)1668=== CONT TestNARDeduplicationMetadataUploadBug16692026/10/02 20:40:25 INFO Received uploads request method=POST path=/api/pending_closures16702026/10/02 20:40:25 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1671--- PASS: TestService_AuthMiddleware (2.19s)1672=== CONT TestGCEndsOnShutdown1673=== RUN TestGCEndsOnShutdown/before_the_run1674=== PAUSE TestGCEndsOnShutdown/before_the_run1675=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1676=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1677=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1678=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1679=== CONT TestCacheConfigHandlerMaxNarSize1680--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1681=== CONT TestGetExistingObjectsLocksRows16822026/10/02 20:40:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1683--- PASS: TestService_Rustfstest (2.06s)1684=== CONT TestService_readinessHandler16852026/10/02 20:40:26 INFO Received uploads request method=POST path=/api/pending_closures1686--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.25s)1687=== CONT TestRegisterCompletedObjectNeedsPendingRow1688--- PASS: TestMetricsInventory (2.20s)1689=== CONT TestGenerateLandingPage1690--- PASS: TestGenerateLandingPage (0.00s)1691=== CONT TestSweepSkipsRowsLockedByPush16922026/10/02 20:40:26 INFO Aborted multipart uploads count=0 kept=016932026/10/02 20:40:26 WARN Force mode enabled - objects will be deleted immediately without grace period16942026/10/02 20:40:26 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=016952026/10/02 20:40:26 INFO Vacuumed table table=pending_closures16962026/10/02 20:40:26 INFO Vacuumed table table=pending_objects16972026/10/02 20:40:26 INFO Vacuumed table table=multipart_uploads16982026/10/02 20:40:26 INFO Vacuumed table table=closures16992026/10/02 20:40:26 INFO Vacuumed table table=objects1700--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.06s)1701=== CONT TestGracefulShutdownDrainsInflight17022026/10/02 20:40:26 INFO Starting HTTP server address=127.0.0.1:6078617032026/10/02 20:40:26 INFO Shutdown signal received, draining in-flight requests timeout=10s1704--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1705=== CONT TestSweepRechecksPendingAfterLocking17062026/10/02 20:40:26 INFO Received uploads request method=POST path=/api/pending_closures1707=== NAME TestNARDeduplicationMetadataUploadBug1708 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-3690-3946823596/TestNARDeduplicationMetadataUploadBug1067373100/001/store/sc8d3f8p3irqx7bljln79xdm6aqgbq55-file1.txt1709--- PASS: TestPushWaitsForSweepHoldingRow (2.40s)1710=== CONT TestGCTaskStore_Fail1711--- PASS: TestGCTaskStore_Fail (0.00s)1712=== CONT TestGCTaskStore_PhaseUpdates1713--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1714=== CONT TestForceGCDuringPushOffersSweptObject1715=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1716=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1717=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1718=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1719=== CONT TestService_healthCheckHandler17202026/10/02 20:40:27 INFO Received push request method=POST path=/api/pushes1721--- PASS: TestGetExistingObjectsLocksRows (1.79s)1722=== CONT TestFailedS3DeleteKeepsTombstone1723=== NAME TestOrphanedObjectsGCStressTest1724 orphaned_objects_gc_test.go:509: Stress test completed successfully:1725 orphaned_objects_gc_test.go:510: - Active objects preserved: 201726 orphaned_objects_gc_test.go:511: - Objects deleted: 2101727 orphaned_objects_gc_test.go:512: - Total GC'd: 21017282026/10/02 20:40:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17292026/10/02 20:40:27 INFO Uploading sc8d3f8p3irqx7bljln79xdm6aqgbq55-file1.txt (160B)17302026/10/02 20:40:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17312026/10/02 20:40:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17322026/10/02 20:40:27 WARN Failed to register uploaded object key=sc8d3f8p3irqx7bljln79xdm6aqgbq55.ls error="server returned 404: 404 page not found\n"17332026/10/02 20:40:27 INFO Signed narinfos id=1 count=117342026/10/02 20:40:27 INFO Uploading 1 narinfos1735--- PASS: TestOrphanedObjectsGCStressTest (10.98s)1736=== CONT TestGCTaskStore_CompletedAllowsNewTask1737--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1738=== CONT TestGCTaskStore_GetReturnsLatest1739--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1740=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection17412026/10/02 20:40:27 INFO Received complete push request method=POST path=/api/pushes/1/complete17422026/10/02 20:40:27 WARN Failed to register uploaded object key=sc8d3f8p3irqx7bljln79xdm6aqgbq55.narinfo error="server returned 404: 404 page not found\n"17432026/10/02 20:40:27 INFO Upload complete. (220ms)1744=== NAME TestNARDeduplicationMetadataUploadBug1745 metadata_upload_test.go:54: Retrieved narinfo from S3:1746 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestNARDeduplicationMetadataUploadBug1067373100/001/store/sc8d3f8p3irqx7bljln79xdm6aqgbq55-file1.txt1747 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1748 Compression: zstd1749 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1750 NarSize: 1601751 References: 1752 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1753 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1754 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1755 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1756 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-3690-3946823596/TestNARDeduplicationMetadataUploadBug1067373100/001/store/rhs7jcfavvmn3avvyn8qn2rrh0zajh5z-file2.txt17572026/10/02 20:40:27 WARN readiness check failed error="closed pool"1758--- PASS: TestService_readinessHandler (1.88s)1759=== CONT TestGCTaskStore_ConflictDifferentParams1760--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1761=== CONT TestGCSweepDeliversEachKeyOnce17622026/10/02 20:40:27 INFO Received push request method=POST path=/api/pushes17632026/10/02 20:40:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17642026/10/02 20:40:27 WARN Failed to register uploaded object key=rhs7jcfavvmn3avvyn8qn2rrh0zajh5z.ls error="server returned 404: 404 page not found\n"17652026/10/02 20:40:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17662026/10/02 20:40:27 INFO Signed narinfos id=2 count=117672026/10/02 20:40:27 INFO Uploading 1 narinfos17682026/10/02 20:40:27 INFO Received complete push request method=POST path=/api/pushes/2/complete17692026/10/02 20:40:27 WARN Failed to register uploaded object key=rhs7jcfavvmn3avvyn8qn2rrh0zajh5z.narinfo error="server returned 404: 404 page not found\n"17702026/10/02 20:40:27 INFO Upload complete. (112ms)1771=== NAME TestNARDeduplicationMetadataUploadBug1772 metadata_upload_test.go:76: Retrieved narinfo from S3:1773 StorePath: /nix/var/nix/builds/nix-3690-3946823596/TestNARDeduplicationMetadataUploadBug1067373100/001/store/rhs7jcfavvmn3avvyn8qn2rrh0zajh5z-file2.txt1774 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1775 Compression: zstd1776 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1777 NarSize: 1601778 References: 1779 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1780 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1781 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1782 {"version":1,"root":{"type":"regular","size":44}}1783--- PASS: TestNARDeduplicationMetadataUploadBug (2.77s)1784=== CONT TestGCSweepSkipsPendingObjects1785--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.95s)1786=== CONT TestPinProtectsFromGC17872026/10/02 20:40:28 INFO Aborted multipart uploads count=1 kept=017882026/10/02 20:40:28 INFO Received cleanup request method=DELETE path=/api/pending_closures17892026/10/02 20:40:28 INFO Aborted multipart uploads count=1 kept=01790--- PASS: TestPendingCleanupUsesOneCutoff (9.37s)1791=== CONT TestTombstonedObjectOfferedWithoutWaiting17922026/10/02 20:40:28 INFO Aborted multipart uploads count=0 kept=017932026/10/02 20:40:28 WARN Force mode enabled - objects will be deleted immediately without grace period17942026/10/02 20:40:28 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=017952026/10/02 20:40:28 INFO Vacuumed table table=pending_closures17962026/10/02 20:40:28 INFO Vacuumed table table=pending_objects17972026/10/02 20:40:28 INFO Vacuumed table table=multipart_uploads17982026/10/02 20:40:28 INFO Vacuumed table table=closures17992026/10/02 20:40:28 INFO Vacuumed table table=objects18002026/10/02 20:40:28 INFO Aborted multipart uploads count=0 kept=018012026/10/02 20:40:28 WARN Force mode enabled - objects will be deleted immediately without grace period18022026/10/02 20:40:28 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=018032026/10/02 20:40:28 INFO Vacuumed table table=pending_closures18042026/10/02 20:40:28 INFO Vacuumed table table=pending_objects18052026/10/02 20:40:28 INFO Vacuumed table table=multipart_uploads18062026/10/02 20:40:28 INFO Vacuumed table table=closures18072026/10/02 20:40:28 INFO Vacuumed table table=objects1808--- PASS: TestSweepSkipsRowsLockedByPush (2.16s)1809=== CONT TestServerTLSConfig/no_client_CA1810=== CONT TestServerTLSConfig/missing_CA_file1811=== CONT TestResolveDBConnectionString/nothing_configured1812--- PASS: TestServerTLSConfig (0.01s)1813 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1814 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1815 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1816=== CONT TestResolveDBConnectionString/missing_file_is_an_error1817=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1818=== CONT TestResolveDBConnectionString/file_when_flag_empty1819=== CONT TestResolveDBConnectionString/flag_wins1820=== CONT TestClientErrorHandling/ServerNotAvailable1821--- PASS: TestResolveDBConnectionString (0.02s)1822 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1823 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1824 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1825 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1826 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)18272026/10/02 20:40:28 INFO Aborted multipart uploads count=0 kept=018282026/10/02 20:40:28 WARN Force mode enabled - objects will be deleted immediately without grace period18292026/10/02 20:40:28 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=018302026/10/02 20:40:28 INFO Vacuumed table table=pending_closures18312026/10/02 20:40:28 INFO Vacuumed table table=pending_objects18322026/10/02 20:40:28 INFO Vacuumed table table=multipart_uploads18332026/10/02 20:40:28 INFO Vacuumed table table=closures18342026/10/02 20:40:28 INFO Vacuumed table table=objects1835--- PASS: TestSweepRechecksPendingAfterLocking (2.01s)1836=== CONT TestClientErrorHandling/InvalidAuthToken18372026/10/02 20:40:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18382026/10/02 20:40:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.062718ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18392026/10/02 20:40:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.220129ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18402026/10/02 20:40:29 INFO Received uploads request method=POST path=/api/pending_closures18412026/10/02 20:40:29 INFO Aborted multipart uploads count=0 kept=018422026/10/02 20:40:29 WARN Force mode enabled - objects will be deleted immediately without grace period18432026/10/02 20:40:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."18442026/10/02 20:40:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1845--- PASS: TestFailedS3DeleteKeepsTombstone (1.92s)1846=== CONT TestClientErrorHandling/InvalidStorePath1847--- PASS: TestService_healthCheckHandler (2.11s)1848=== CONT TestPendingClosureWriteTimeout/400_objects1849=== CONT TestPendingClosureWriteTimeout/670k_objects1850=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18512026/10/02 20:40:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.102188ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18522026/10/02 20:40:29 INFO Received uploads request method=POST path=/api/pending_closures1853--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.40s)1854=== CONT TestPendingClosureWriteTimeout/empty1855=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18562026/10/02 20:40:30 INFO Received uploads request method=POST path=/18572026/10/02 20:40:30 INFO Aborted multipart uploads count=0 kept=018582026/10/02 20:40:30 WARN Force mode enabled - objects will be deleted immediately without grace period18592026/10/02 20:40:30 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=018602026/10/02 20:40:30 INFO Vacuumed table table=pending_closures18612026/10/02 20:40:30 INFO Vacuumed table table=pending_objects18622026/10/02 20:40:30 INFO Vacuumed table table=multipart_uploads18632026/10/02 20:40:30 INFO Vacuumed table table=closures18642026/10/02 20:40:30 INFO Vacuumed table table=objects1865--- PASS: TestGCSweepDeliversEachKeyOnce (2.40s)1866=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18672026/10/02 20:40:30 INFO Received complete multipart upload request method=POST path=/18682026/10/02 20:40:30 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/02 20:40:30 INFO Aborted multipart uploads count=0 kept=018702026/10/02 20:40:30 WARN Force mode enabled - objects will be deleted immediately without grace period18712026/10/02 20:40:30 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=018722026/10/02 20:40:30 INFO Vacuumed table table=pending_closures18732026/10/02 20:40:30 INFO Vacuumed table table=pending_objects18742026/10/02 20:40:30 INFO Vacuumed table table=multipart_uploads18752026/10/02 20:40:30 INFO Vacuumed table table=closures18762026/10/02 20:40:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.700946763s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18772026/10/02 20:40:30 INFO Vacuumed table table=objects1878--- PASS: TestGCSweepSkipsPendingObjects (2.42s)1879=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18802026/10/02 20:40:30 INFO Received request for more parts method=POST path=/1881=== CONT TestIsValidUploadKey/narinfo1882=== CONT TestIsValidUploadKey/realisation1883=== CONT TestIsValidUploadKey/empty_key1884=== CONT TestIsValidUploadKey/unknown_type1885=== CONT TestIsValidUploadKey/traversal_nar1886=== CONT TestIsValidUploadKey/traversal1887=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1888=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1889=== CONT TestIsValidUploadKey/absolute1890=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1891=== CONT TestIsValidUploadKey/nix-cache-info1892=== CONT TestIsValidUploadKey/index.html1893=== CONT TestIsValidUploadKey/build_log_home-manager_file1894=== CONT TestIsValidUploadKey/realisation_plus_in_output1895=== CONT TestIsValidUploadKey/build_log_question_mark1896=== CONT TestIsValidUploadKey/build_log_plus_in_name1897=== CONT TestIsValidUploadKey/nar_xz1898=== CONT TestIsValidUploadKey/listing1899=== CONT TestIsValidUploadKey/nar_plain1900=== CONT TestIsValidUploadKey/build_log1901=== CONT TestIsValidUploadKey/nar_zst1902=== CONT TestIsValidUploadKey/build_log_equals1903=== CONT TestParseSingleRange/unknown_unit1904--- PASS: TestIsValidUploadKey (0.01s)1905 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1906 --- PASS: TestIsValidUploadKey/realisation (0.00s)1907 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1908 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1909 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1910 --- PASS: TestIsValidUploadKey/traversal (0.00s)1911 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1912 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1913 --- PASS: TestIsValidUploadKey/absolute (0.00s)1914 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1915 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1916 --- PASS: TestIsValidUploadKey/index.html (0.00s)1917 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1918 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1919 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1920 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1921 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1922 --- PASS: TestIsValidUploadKey/listing (0.00s)1923 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1924 --- PASS: TestIsValidUploadKey/build_log (0.00s)1925 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1926 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1927=== CONT TestParseSingleRange/start_far_past_EOF1928=== CONT TestParseSingleRange/start_past_EOF1929=== CONT TestParseSingleRange/single_byte1930=== CONT TestParseSingleRange/suffix_exceeds_size1931=== CONT TestParseSingleRange/suffix1932=== CONT TestParseSingleRange/end_clamped_to_size1933=== CONT TestParseSingleRange/open-ended1934=== CONT TestParseSingleRange/closed1935=== CONT TestParseSingleRange/malformed_both_empty1936=== CONT TestParseSingleRange/malformed_no_dash1937=== CONT TestParseSingleRange/multi-range_ignored1938=== CONT TestParseSingleRange/none1939=== CONT TestParseSingleRange/malformed_end_before_start1940=== CONT TestIsValidCachePath/nar_xz1941--- PASS: TestParseSingleRange (0.00s)1942 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1943 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1944 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1945 --- PASS: TestParseSingleRange/single_byte (0.00s)1946 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1947 --- PASS: TestParseSingleRange/suffix (0.00s)1948 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1949 --- PASS: TestParseSingleRange/open-ended (0.00s)1950 --- PASS: TestParseSingleRange/closed (0.00s)1951 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1952 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1953 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1954 --- PASS: TestParseSingleRange/none (0.00s)1955 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1956=== CONT TestIsValidCachePath/nix-cache-info1957=== CONT TestIsValidCachePath/wrong_extension1958=== CONT TestIsValidCachePath/leading_slash1959=== CONT TestIsValidCachePath/short_hash1960=== CONT TestIsValidCachePath/random_path1961=== CONT TestIsValidCachePath/invalid_char_e1962=== CONT TestIsValidCachePath/traversal_parent1963=== CONT TestIsValidCachePath/traversal_in_middle1964=== CONT TestIsValidCachePath/realisation1965=== CONT TestIsValidCachePath/invalid_char_u1966=== CONT TestIsValidCachePath/log1967=== CONT TestIsValidCachePath/empty1968=== CONT TestIsValidCachePath/ls1969=== CONT TestIsValidCachePath/nar_bz21970=== CONT TestIsValidCachePath/nar_uncompressed1971=== CONT TestIsValidCachePath/nar_zst1972=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1973=== CONT TestIsValidCachePath/index.html1974=== CONT TestIsValidCachePath/narinfo1975--- PASS: TestIsValidCachePath (0.00s)1976 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1977 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1978 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1979 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1980 --- PASS: TestIsValidCachePath/short_hash (0.00s)1981 --- PASS: TestIsValidCachePath/random_path (0.00s)1982 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1983 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1984 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1985 --- PASS: TestIsValidCachePath/realisation (0.00s)1986 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1987 --- PASS: TestIsValidCachePath/log (0.00s)1988 --- PASS: TestIsValidCachePath/empty (0.00s)1989 --- PASS: TestIsValidCachePath/ls (0.00s)1990 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1991 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1992 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1993 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1994 --- PASS: TestIsValidCachePath/index.html (0.00s)1995 --- PASS: TestIsValidCachePath/narinfo (0.00s)1996=== CONT TestPush_RejectsBadRequests/no_roots19972026/10/02 20:40:30 INFO Received push request method=POST path=/api/pushes1998=== CONT TestPush_RejectsBadRequests/no_objects19992026/10/02 20:40:30 INFO Received push request method=POST path=/api/pushes2000=== CONT TestPush_RejectsBadRequests/root_not_in_objects20012026/10/02 20:40:30 INFO Received push request method=POST path=/api/pushes2002=== CONT TestPush_RejectsBadRequests/bad_root20032026/10/02 20:40:30 INFO Received push request method=POST path=/api/pushes2004=== CONT TestCacheConfigHandler/no_cache_url_configured2005=== CONT TestCacheConfigHandler/no_signing_keys2006=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2007=== CONT TestCacheConfigHandler/full_config,_no_issuer2008=== CONT TestProxyWriteTimeout/narinfo2009--- PASS: TestCacheConfigHandler (0.00s)2010 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2011 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2012 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2013 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2014=== CONT TestProxyWriteTimeout/unknown_size2015=== CONT TestProxyWriteTimeout/10_GiB_nar2016=== CONT TestProxyWriteTimeout/1_GiB_nar2017=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2018--- PASS: TestProxyWriteTimeout (0.00s)2019 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2020 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2021 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2022 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)20232026/10/02 20:40:30 INFO Received uploads request method=POST path=/2024=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20252026/10/02 20:40:30 INFO Received request for more parts method=POST path=/2026=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20272026/10/02 20:40:30 INFO Received complete multipart upload request method=POST path=/2028=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20292026/10/02 20:40:30 INFO Received uploads request method=POST path=/2030=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2031--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2032 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2033 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2034 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2035 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2036=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20372026/10/02 20:40:30 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]2038=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20392026/10/02 20:40:30 WARN Authentication failed token_preview=eyJhbGciOi...wLUUqBdVlg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2040=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2041=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2042=== CONT TestService_RequireScope_OIDC/reader_may_not_write2043=== CONT TestService_RequireScope_OIDC/writer_implies_read2044=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2045=== CONT TestService_RequireScope_OIDC/static_token_may_write2046=== CONT TestService_RequireScope_OIDC/static_token_may_admin2047=== CONT TestService_RequireScope_OIDC/ops_may_admin2048=== CONT TestService_RequireScope_OIDC/reader_may_read2049=== CONT TestService_RequireScope_OIDC/ops_may_not_write2050=== CONT TestService_RequireScope_OIDC/builder_may_write2051=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2052--- PASS: TestService_AuthMiddleware_OIDC (2.38s)2053 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2054 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2055 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2056 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2057--- PASS: TestService_RequireScope_OIDC (2.11s)2058 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2061 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2062 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2063 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2064 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2065 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2066 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2067 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2068--- PASS: TestPush_RejectsBadRequests (2.10s)2069 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2070 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2071 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2072 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)20732026/10/02 20:40:30 WARN Rate limiter enabled after throttle name=s3-test rate=520742026/10/02 20:40:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2075=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2076 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102077 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002078--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.17s)2079=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2080=== CONT TestGCEndsOnShutdown/before_the_run20812026/10/02 20:40:30 INFO Received uploads request method=POST path=/api/pending_closures2082--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.43s)2083=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2084=== NAME TestPinProtectsFromGC2085 client_integration_test.go:867: Pinned store path: /nix/var/nix/builds/nix-3690-3946823596/TestPinProtectsFromGC2240095908/001/store/gdp8mvwx77sfn96kbqz8w7pxfgk4jihc-pinned-file.txt2086 client_integration_test.go:868: Unpinned store path: /nix/var/nix/builds/nix-3690-3946823596/TestPinProtectsFromGC2240095908/001/store/0y1nah6hbfqsbj9lf8qc4kzf77j302c2-unpinned-file.txt20872026/10/02 20:40:31 INFO Received push request method=POST path=/api/pushes20882026/10/02 20:40:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20892026/10/02 20:40:31 INFO Uploading gdp8mvwx77sfn96kbqz8w7pxfgk4jihc-pinned-file.txt (128B)20902026/10/02 20:40:31 WARN Failed to register uploaded object key=gdp8mvwx77sfn96kbqz8w7pxfgk4jihc.ls error="server returned 404: 404 page not found\n"20912026/10/02 20:40:31 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20922026/10/02 20:40:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20932026/10/02 20:40:31 INFO Signed narinfos id=1 count=120942026/10/02 20:40:31 INFO Uploading 1 narinfos20952026/10/02 20:40:31 INFO Received complete push request method=POST path=/api/pushes/1/complete20962026/10/02 20:40:31 WARN Failed to register uploaded object key=gdp8mvwx77sfn96kbqz8w7pxfgk4jihc.narinfo error="server returned 404: 404 page not found\n"20972026/10/02 20:40:31 INFO Upload complete. (129ms)20982026/10/02 20:40:31 INFO Received push request method=POST path=/api/pushes20992026/10/02 20:40:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21002026/10/02 20:40:31 INFO Uploading 0y1nah6hbfqsbj9lf8qc4kzf77j302c2-unpinned-file.txt (128B)21012026/10/02 20:40:31 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"21022026/10/02 20:40:31 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21032026/10/02 20:40:31 WARN Failed to register uploaded object key=0y1nah6hbfqsbj9lf8qc4kzf77j302c2.ls error="server returned 404: 404 page not found\n"21042026/10/02 20:40:31 INFO Signed narinfos id=2 count=121052026/10/02 20:40:31 INFO Uploading 1 narinfos21062026/10/02 20:40:31 INFO Received complete push request method=POST path=/api/pushes/2/complete21072026/10/02 20:40:31 WARN Failed to register uploaded object key=0y1nah6hbfqsbj9lf8qc4kzf77j302c2.narinfo error="server returned 404: 404 page not found\n"21082026/10/02 20:40:31 INFO Upload complete. (94ms)21092026/10/02 20:40:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21102026/10/02 20:40:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures21112026/10/02 20:40:31 INFO Garbage collection started21122026/10/02 20:40:31 INFO Aborted multipart uploads count=0 kept=021132026/10/02 20:40:31 WARN Force mode enabled - objects will be deleted immediately without grace period21142026/10/02 20:40:31 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=021152026/10/02 20:40:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21162026/10/02 20:40:31 INFO Vacuumed table table=pending_closures21172026/10/02 20:40:31 INFO Vacuumed table table=pending_objects21182026/10/02 20:40:31 INFO Vacuumed table table=multipart_uploads2119=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21202026/10/02 20:40:31 INFO Vacuumed table table=closures21212026/10/02 20:40:31 INFO Vacuumed table table=objects21222026/10/02 20:40:31 INFO Received uploads request method=POST path=/api/pending_closures21232026/10/02 20:40:32 INFO Aborted multipart uploads count=0 kept=021242026/10/02 20:40:32 WARN Force mode enabled - objects will be deleted immediately without grace period21252026/10/02 20:40:32 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:60185/bucket93/?delete=\": context canceled"21262026/10/02 20:40:32 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21272026/10/02 20:40:32 INFO Aborted multipart uploads count=0 kept=021282026/10/02 20:40:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.781427ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21292026/10/02 20:40:32 WARN Force mode enabled - objects will be deleted immediately without grace period21302026-10-02 20:40:32.346 UTC [24670] ERROR: canceling statement due to user request21312026-10-02 20:40:32.346 UTC [24670] STATEMENT: -- name: MarkStaleObjects :execrows2132 WITH RECURSIVE ct AS (2133 SELECT timezone('UTC', now()) AS now2134 ),2135 closure_reach AS (2136 -- Start with all closure keys2137 SELECT o.key, o.refs2138 FROM objects o2139 INNER JOIN closures c ON o.key = c.key2140 UNION2141 -- Recursively add all referenced objects2142 SELECT o.key, o.refs2143 FROM objects o2144 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2145 ),2146 reachable_objects AS (2147 SELECT DISTINCT key FROM closure_reach2148 ),2149 stale_objects AS (2150 SELECT o.key2151 FROM objects AS o, ct2152 WHERE2153 NOT EXISTS (2154 SELECT 12155 FROM reachable_objects ro2156 WHERE ro.key = o.key2157 )2158 AND NOT EXISTS (2159 SELECT 12160 FROM pending_objects AS po2161 WHERE po.key = o.key2162 )2163 AND o.deleted_at IS NULL -- Only mark fresh objects2164 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2165 FOR UPDATE2166 )2167 UPDATE objects2168 SET2169 deleted_at = ct.now,2170 first_deleted_at = COALESCE(first_deleted_at, ct.now)2171 FROM stale_objects, ct2172 WHERE objects.key = stale_objects.key2173 2174--- PASS: TestPendingClosureWriteTimeout (0.00s)2175 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2176 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2177 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2178 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.89s)21792026/10/02 20:40:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.90309ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2180--- PASS: TestGCEndsOnShutdown (0.00s)2181 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.55s)2182 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (1.68s)2183 --- PASS: TestGCEndsOnShutdown/before_the_run (1.73s)21842026/10/02 20:40:32 INFO Received uploads request method=POST path=/api/pending_closures21852026/10/02 20:40:32 INFO Aborted multipart uploads count=0 kept=021862026/10/02 20:40:32 WARN Force mode enabled - objects will be deleted immediately without grace period21872026/10/02 20:40:32 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=021882026/10/02 20:40:32 INFO Vacuumed table table=pending_closures21892026/10/02 20:40:32 INFO Vacuumed table table=pending_objects21902026/10/02 20:40:32 INFO Vacuumed table table=multipart_uploads21912026/10/02 20:40:32 INFO Vacuumed table table=closures21922026/10/02 20:40:32 INFO Vacuumed table table=objects21932026/10/02 20:40:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.977532ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21942026/10/02 20:40:33 INFO Received uploads request method=POST path=/api/pending_closures21952026/10/02 20:40:33 INFO Aborted multipart uploads count=0 kept=021962026/10/02 20:40:33 WARN Force mode enabled - objects will be deleted immediately without grace period21972026/10/02 20:40:33 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=021982026/10/02 20:40:33 INFO Vacuumed table table=pending_closures21992026/10/02 20:40:33 INFO Vacuumed table table=pending_objects22002026/10/02 20:40:33 INFO Vacuumed table table=multipart_uploads22012026/10/02 20:40:33 INFO Vacuumed table table=closures22022026/10/02 20:40:33 INFO Vacuumed table table=objects2203--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2204 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.86s)2205 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.62s)22062026/10/02 20:40:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022072026/10/02 20:40:33 INFO Received create pin request method=POST path=/api/pins/myapp22082026/10/02 20:40:33 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-3690-3946823596/TestPinProtectsFromGC2240095908/001/store/gdp8mvwx77sfn96kbqz8w7pxfgk4jihc-pinned-file.txt narinfo_key=gdp8mvwx77sfn96kbqz8w7pxfgk4jihc.narinfo22092026/10/02 20:40:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures22102026/10/02 20:40:33 INFO Garbage collection started22112026/10/02 20:40:33 INFO Aborted multipart uploads count=0 kept=022122026/10/02 20:40:33 WARN Force mode enabled - objects will be deleted immediately without grace period22132026/10/02 20:40:33 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=022142026/10/02 20:40:33 INFO Vacuumed table table=pending_closures22152026/10/02 20:40:33 INFO Vacuumed table table=pending_objects22162026/10/02 20:40:33 INFO Vacuumed table table=multipart_uploads22172026/10/02 20:40:33 INFO Vacuumed table table=closures22182026/10/02 20:40:33 INFO Vacuumed table table=objects22192026/10/02 20:40:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.478230208s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2220--- PASS: TestUploadHandlersRejectOversizedBody (0.13s)2221 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.29s)2222 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.31s)2223 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.59s)22242026/10/02 20:40:35 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22252026/10/02 20:40:35 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22262026/10/02 20:40:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.063315ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2227=== NAME TestPinProtectsFromGC2228 client_integration_test.go:976: Pin successfully protected closure from garbage collection2229--- PASS: TestPinProtectsFromGC (7.18s)22302026/10/02 20:40:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=388.595804ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/10/02 20:40:35 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=792.627081ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/10/02 20:40:36 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.459983216s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/02 20:40:38 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22342026/10/02 20:40:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.176464ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/10/02 20:40:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.259016ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22362026/10/02 20:40:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=746.167899ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22372026/10/02 20:40:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.545366803s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2238--- PASS: TestClientErrorHandling (0.00s)2239 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.55s)2240 --- PASS: TestClientErrorHandling/InvalidStorePath (2.01s)2241 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.39s)2242PASS22432026-10-02 20:40:41.193 UTC [13852] LOG: received smart shutdown request22442026-10-02 20:40:41.194 UTC [13852] LOG: background worker "logical replication launcher" (PID 13872) exited with exit code 122452026-10-02 20:40:41.203 UTC [13866] LOG: shutting down22462026-10-02 20:40:41.203 UTC [13866] LOG: checkpoint starting: shutdown immediate22472026-10-02 20:40:42.518 UTC [13866] LOG: checkpoint complete: wrote 12782 buffers (78.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.672 s, sync=0.595 s, total=1.316 s; sync files=33361, longest=0.001 s, average=0.001 s; distance=475052 kB, estimate=475052 kB; lsn=0/1E778150, redo lsn=0/1E77815022482026-10-02 20:40:42.525 UTC [13852] LOG: database system is shut down2249Running OIDC tests...2250=== RUN TestAudienceForIssuer2251=== PAUSE TestAudienceForIssuer2252=== RUN TestHTTPClientForHasTimeouts2253=== PAUSE TestHTTPClientForHasTimeouts2254=== RUN TestGlobMatch2255=== PAUSE TestGlobMatch2256=== RUN TestValidateToken_ValidToken2257=== PAUSE TestValidateToken_ValidToken2258=== RUN TestValidateToken_WrongAudience2259=== PAUSE TestValidateToken_WrongAudience2260=== RUN TestValidateToken_Expired2261=== PAUSE TestValidateToken_Expired2262=== RUN TestValidateToken_BoundClaimsMismatch2263=== PAUSE TestValidateToken_BoundClaimsMismatch2264=== RUN TestValidateToken_BoundSubjectMismatch2265=== PAUSE TestValidateToken_BoundSubjectMismatch2266=== RUN TestValidateToken_MultipleProviders2267=== PAUSE TestValidateToken_MultipleProviders2268=== RUN TestValidateToken_NoMatchingProvider2269=== PAUSE TestValidateToken_NoMatchingProvider2270=== RUN TestValidateToken_KubernetesServiceAccount2271=== PAUSE TestValidateToken_KubernetesServiceAccount2272=== RUN TestNewValidator_KubernetesRequiresCA2273=== PAUSE TestNewValidator_KubernetesRequiresCA2274=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2275=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2276=== RUN TestPins_ReservedForMatchingRule2277=== PAUSE TestPins_ReservedForMatchingRule2278=== RUN TestPins_TopLevelShorthand2279=== PAUSE TestPins_TopLevelShorthand2280=== RUN TestPins_ConfigValidation2281=== PAUSE TestPins_ConfigValidation2282=== RUN TestScopes_LegacyProviderDefaultsToWrite2283=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2284=== RUN TestScopes_Rules2285=== PAUSE TestScopes_Rules2286=== RUN TestScopes_ConfigValidation2287=== PAUSE TestScopes_ConfigValidation2288=== CONT TestAudienceForIssuer2289=== CONT TestScopes_Rules2290--- PASS: TestAudienceForIssuer (0.00s)2291=== CONT TestPins_ConfigValidation2292=== CONT TestScopes_LegacyProviderDefaultsToWrite2293=== CONT TestPins_TopLevelShorthand2294=== CONT TestPins_ReservedForMatchingRule2295=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2296=== CONT TestNewValidator_KubernetesRequiresCA2297=== CONT TestValidateToken_NoMatchingProvider2298=== CONT TestValidateToken_MultipleProviders2299=== CONT TestValidateToken_BoundSubjectMismatch2300--- PASS: TestPins_ConfigValidation (0.00s)2301=== CONT TestValidateToken_BoundClaimsMismatch23022026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60974/oidc23032026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60976/oidc2304--- PASS: TestPins_TopLevelShorthand (0.05s)2305=== CONT TestValidateToken_Expired2306--- PASS: TestPins_ReservedForMatchingRule (0.05s)2307=== CONT TestValidateToken_WrongAudience23082026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60978/oidc23092026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60980/oidc2310--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2311=== CONT TestValidateToken_KubernetesServiceAccount2312--- PASS: TestScopes_Rules (0.07s)2313=== CONT TestValidateToken_ValidToken23142026/10/02 20:40:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232315--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)2316=== CONT TestGlobMatch2317=== RUN TestGlobMatch/foo_foo2318=== PAUSE TestGlobMatch/foo_foo2319=== RUN TestGlobMatch/foo_bar2320=== PAUSE TestGlobMatch/foo_bar2321=== RUN TestGlobMatch/*_2322=== PAUSE TestGlobMatch/*_2323=== RUN TestGlobMatch/*_anything2324=== PAUSE TestGlobMatch/*_anything2325=== RUN TestGlobMatch/foo*_foo2326=== PAUSE TestGlobMatch/foo*_foo2327=== RUN TestGlobMatch/foo*_foobar2328=== PAUSE TestGlobMatch/foo*_foobar2329=== RUN TestGlobMatch/foo*_bar2330=== PAUSE TestGlobMatch/foo*_bar2331=== RUN TestGlobMatch/*bar_bar2332=== PAUSE TestGlobMatch/*bar_bar2333=== RUN TestGlobMatch/*bar_foobar2334=== PAUSE TestGlobMatch/*bar_foobar2335=== RUN TestGlobMatch/*bar_foo2336=== PAUSE TestGlobMatch/*bar_foo2337=== RUN TestGlobMatch/foo*bar_foobar2338=== PAUSE TestGlobMatch/foo*bar_foobar2339=== RUN TestGlobMatch/foo*bar_foo123bar2340=== PAUSE TestGlobMatch/foo*bar_foo123bar2341=== RUN TestGlobMatch/foo*bar_foobarbaz2342=== PAUSE TestGlobMatch/foo*bar_foobarbaz2343=== RUN TestGlobMatch/*/*_foo/bar2344=== PAUSE TestGlobMatch/*/*_foo/bar2345=== RUN TestGlobMatch/*/*_foo2346=== PAUSE TestGlobMatch/*/*_foo2347=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2348=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2349=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02350=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02351=== RUN TestGlobMatch/refs/*/main_refs/heads/main2352=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2353=== RUN TestGlobMatch/fo?_foo2354=== PAUSE TestGlobMatch/fo?_foo2355=== RUN TestGlobMatch/fo?_fo2356=== PAUSE TestGlobMatch/fo?_fo2357=== RUN TestGlobMatch/fo?_fooo2358=== PAUSE TestGlobMatch/fo?_fooo2359=== RUN TestGlobMatch/?oo_foo2360=== PAUSE TestGlobMatch/?oo_foo2361=== RUN TestGlobMatch/?oo_boo2362=== PAUSE TestGlobMatch/?oo_boo2363=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2364=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2365=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2366=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2367=== CONT TestHTTPClientForHasTimeouts23682026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60987/oidc23692026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60989/oidc2370--- PASS: TestValidateToken_WrongAudience (0.03s)2371=== CONT TestScopes_ConfigValidation2372=== CONT TestGlobMatch/foo_foo2373=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2374=== CONT TestGlobMatch/*/*_foo/bar2375--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/?oo_boo2378=== CONT TestGlobMatch/?oo_foo2379=== CONT TestGlobMatch/fo?_fooo2380=== CONT TestGlobMatch/fo?_fo2381=== CONT TestGlobMatch/fo?_foo2382=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02383=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2384=== CONT TestGlobMatch/*/*_foo2385=== CONT TestGlobMatch/refs/*/main_refs/heads/main2386=== CONT TestGlobMatch/foo*bar_foobarbaz2387=== CONT TestGlobMatch/foo*_foobar2388=== CONT TestGlobMatch/foo*bar_foo123bar2389=== CONT TestGlobMatch/*bar_foo2390=== CONT TestGlobMatch/*bar_foobar2391=== CONT TestGlobMatch/*bar_bar2392=== CONT TestGlobMatch/foo*_bar2393=== CONT TestGlobMatch/*_2394=== CONT TestGlobMatch/foo*bar_foobar2395=== CONT TestGlobMatch/*_anything2396=== CONT TestGlobMatch/foo*_foo2397=== CONT TestGlobMatch/foo_bar2398--- PASS: TestGlobMatch (0.00s)2399 --- PASS: TestGlobMatch/foo_foo (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/?oo_boo (0.00s)2404 --- PASS: TestGlobMatch/?oo_foo (0.00s)2405 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2406 --- PASS: TestGlobMatch/fo?_fo (0.00s)2407 --- PASS: TestGlobMatch/fo?_foo (0.00s)2408 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2409 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo (0.00s)2411 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2413 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foo (0.00s)2416 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2417 --- PASS: TestGlobMatch/*bar_bar (0.00s)2418 --- PASS: TestGlobMatch/foo*_bar (0.00s)2419 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/*_ (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/foo*_foo (0.00s)2423 --- PASS: TestGlobMatch/foo_bar (0.00s)2424--- PASS: TestScopes_ConfigValidation (0.00s)24252026/10/02 20:40:45 http: TLS handshake error from 127.0.0.1:60986: remote error: tls: bad certificate2426--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)24272026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60993/oidc2428--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)24292026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60995/oidc24302026/10/02 20:40:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60997/oidc2431--- PASS: TestValidateToken_Expired (0.07s)2432--- PASS: TestValidateToken_ValidToken (0.05s)24332026/10/02 20:40:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60982/oidc2434--- PASS: TestValidateToken_NoMatchingProvider (0.17s)24352026/10/02 20:40:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:610022436--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)24372026/10/02 20:40:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61001/oidc24382026/10/02 20:40:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:61004/oidc2439--- PASS: TestValidateToken_MultipleProviders (0.28s)2440--- PASS: TestHTTPClientForHasTimeouts (0.20s)2441PASS2442Running signing tests...2443=== RUN TestGenerateFingerprint2444=== PAUSE TestGenerateFingerprint2445=== RUN TestParseSigningKey2446=== PAUSE TestParseSigningKey2447=== RUN TestSignMessage2448=== PAUSE TestSignMessage2449=== RUN TestSignNarinfo2450=== PAUSE TestSignNarinfo2451=== CONT TestSignNarinfo2452=== CONT TestParseSigningKey2453=== RUN TestParseSigningKey/valid_32-byte_key2454=== CONT TestGenerateFingerprint2455=== RUN TestGenerateFingerprint/basic_with_references2456=== CONT TestSignMessage2457=== PAUSE TestGenerateFingerprint/basic_with_references2458=== PAUSE TestParseSigningKey/valid_32-byte_key2459=== RUN TestGenerateFingerprint/no_references2460=== PAUSE TestGenerateFingerprint/no_references2461=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2462=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2463=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2464=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2465=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2466=== RUN TestParseSigningKey/no_colon2467=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2468=== PAUSE TestParseSigningKey/no_colon2469=== RUN TestGenerateFingerprint/invalid_nar_hash_length2470=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2471=== RUN TestGenerateFingerprint/invalid_store_path_prefix2472=== RUN TestParseSigningKey/empty_name2473=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2474=== PAUSE TestParseSigningKey/empty_name2475=== RUN TestGenerateFingerprint/invalid_reference_prefix2476=== RUN TestParseSigningKey/invalid_base642477=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2478=== PAUSE TestParseSigningKey/invalid_base642479=== RUN TestParseSigningKey/wrong_length2480=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2481=== PAUSE TestParseSigningKey/wrong_length2482=== CONT TestGenerateFingerprint/no_references2483=== CONT TestGenerateFingerprint/basic_with_references2484=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2485=== CONT TestParseSigningKey/no_colon2486=== CONT TestParseSigningKey/valid_32-byte_key2487=== CONT TestGenerateFingerprint/invalid_nar_hash_length2488=== CONT TestGenerateFingerprint/invalid_reference_prefix2489=== CONT TestGenerateFingerprint/invalid_store_path_prefix2490=== CONT TestParseSigningKey/wrong_length2491=== CONT TestParseSigningKey/empty_name2492=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2493=== CONT TestParseSigningKey/invalid_base642494--- PASS: TestGenerateFingerprint (0.00s)2495 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2496 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2497 --- PASS: TestGenerateFingerprint/no_references (0.00s)2498 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2499 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2500 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2501 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2502--- PASS: TestParseSigningKey (0.00s)2503 --- PASS: TestParseSigningKey/no_colon (0.00s)2504 --- PASS: TestParseSigningKey/wrong_length (0.00s)2505 --- PASS: TestParseSigningKey/empty_name (0.00s)2506 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2507 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2508 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2509--- PASS: TestSignMessage (0.00s)2510--- PASS: TestSignNarinfo (0.01s)2511PASS2512Running hook tests...2513=== RUN TestSendPathsEmpty2514=== PAUSE TestSendPathsEmpty2515=== RUN TestQueueEnqueueAndFetch2516=== PAUSE TestQueueEnqueueAndFetch2517=== RUN TestQueueDeduplication2518=== PAUSE TestQueueDeduplication2519=== RUN TestQueueRemove2520=== PAUSE TestQueueRemove2521=== RUN TestQueueFetchBatchLimit2522=== PAUSE TestQueueFetchBatchLimit2523=== RUN TestQueueRetryMovesToBack2524=== PAUSE TestQueueRetryMovesToBack2525=== RUN TestQueueFetchRemoveLifecycle2526=== PAUSE TestQueueFetchRemoveLifecycle2527=== RUN TestQueueConcurrentWriters2528=== PAUSE TestQueueConcurrentWriters2529=== RUN TestQueueEnqueueWaitsOutSlowWriter2530=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2531=== RUN TestQueueRemoveLargeClosure2532=== PAUSE TestQueueRemoveLargeClosure2533=== RUN TestServerClientIntegration2534=== PAUSE TestServerClientIntegration2535=== RUN TestServerQueueError2536=== PAUSE TestServerQueueError2537=== RUN TestServerRefusesOversizedAndNonStoreRequests2538=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2539=== RUN TestGetListenerSocketActivation2540 server_test.go:317: === RUN TestGetListenerSocketActivation2541 --- PASS: TestGetListenerSocketActivation (0.00s)2542 PASS2543 2544--- PASS: TestGetListenerSocketActivation (1.03s)2545=== RUN TestServerStalledClientDoesNotBlockShutdown2546=== PAUSE TestServerStalledClientDoesNotBlockShutdown2547=== RUN TestServerBacksOffOnAcceptErrors2548=== PAUSE TestServerBacksOffOnAcceptErrors2549=== RUN TestDrainIsolatesPoisonPath2550=== PAUSE TestDrainIsolatesPoisonPath2551=== RUN TestRunNotBlockedByPoisonHead2552=== PAUSE TestRunNotBlockedByPoisonHead2553=== RUN TestDrainGivesUpWhenServerDown2554=== PAUSE TestDrainGivesUpWhenServerDown2555=== RUN TestFailedPathPrunedByLaterClosure2556=== PAUSE TestFailedPathPrunedByLaterClosure2557=== RUN TestWorkerUploadsAndRemoves2558=== PAUSE TestWorkerUploadsAndRemoves2559=== RUN TestWorkerSkipsGCdPaths2560=== PAUSE TestWorkerSkipsGCdPaths2561=== RUN TestWorkerPrunesClosureDeps2562=== PAUSE TestWorkerPrunesClosureDeps2563=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2564=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2565=== RUN TestDrainTimeout2566=== PAUSE TestDrainTimeout2567=== RUN TestDrainTimeoutDuringIsolation2568=== PAUSE TestDrainTimeoutDuringIsolation2569=== RUN TestShutdownFinishesInFlightPush2570=== PAUSE TestShutdownFinishesInFlightPush2571=== RUN TestWorkerRemoveFailureIsNotProgress2572=== PAUSE TestWorkerRemoveFailureIsNotProgress2573=== RUN TestWorkerKeepsPathItCannotStat2574=== PAUSE TestWorkerKeepsPathItCannotStat2575=== CONT TestQueueDeduplication2576=== CONT TestServerStalledClientDoesNotBlockShutdown2577=== CONT TestWorkerKeepsPathItCannotStat2578=== CONT TestWorkerRemoveFailureIsNotProgress2579=== CONT TestShutdownFinishesInFlightPush2580=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2581=== CONT TestDrainTimeout2582=== RUN TestShutdownFinishesInFlightPush/completes2583=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2584=== CONT TestWorkerPrunesClosureDeps2585=== CONT TestWorkerSkipsGCdPaths2586=== CONT TestWorkerUploadsAndRemoves2587=== PAUSE TestShutdownFinishesInFlightPush/completes2588=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2589=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2590=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2591=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2592=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2593=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2594=== CONT TestDrainTimeoutDuringIsolation2595=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2596=== CONT TestFailedPathPrunedByLaterClosure2597=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2598=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2599=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2600=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2601=== CONT TestDrainGivesUpWhenServerDown26022026/10/02 20:40:48 INFO Upload queue status pending=226032026/10/02 20:40:48 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa error="lstat /nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa: permission denied"26042026/10/02 20:40:48 INFO Uploading batch count=126052026/10/02 20:40:48 INFO Upload queue status pending=326062026/10/02 20:40:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerSkipsGCdPaths2232161630/002/nonexistent26072026/10/02 20:40:48 INFO Upload queue status pending=226082026/10/02 20:40:48 INFO Uploading batch count=226092026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=226102026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/a26112026/10/02 20:40:48 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa error="lstat /nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa: permission denied"26122026/10/02 20:40:48 INFO Upload queue status pending=226132026/10/02 20:40:48 INFO Uploading batch count=226142026/10/02 20:40:48 INFO Uploading batch count=226152026/10/02 20:40:48 INFO Uploading batch count=126162026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=126172026/10/02 20:40:48 INFO Uploading batch count=226182026/10/02 20:40:48 INFO Uploading batch count=22619--- PASS: TestQueueDeduplication (0.01s)2620=== CONT TestRunNotBlockedByPoisonHead26212026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/b26222026/10/02 20:40:48 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa error="lstat /nix/var/nix/builds/nix-3690-3946823596/TestWorkerKeepsPathItCannotStat3319090455/002/locked/aaa: permission denied"26232026/10/02 20:40:48 INFO Uploading batch count=126242026/10/02 20:40:48 INFO Uploading batch count=226252026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=226262026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/c26272026/10/02 20:40:48 ERROR Drain finished with paths left in queue remaining=126282026/10/02 20:40:48 INFO Uploading batch count=126292026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/d2630--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2631=== CONT TestServerBacksOffOnAcceptErrors26322026/10/02 20:40:48 ERROR Accept failed error="too many open files"26332026/10/02 20:40:48 INFO Uploading batch count=226342026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=226352026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/e26362026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainGivesUpWhenServerDown4088295359/002/f2637--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2638=== CONT TestDrainIsolatesPoisonPath26392026/10/02 20:40:48 ERROR Drain finished with paths left in queue remaining=1026402026/10/02 20:40:48 INFO Upload queue status pending=326412026/10/02 20:40:48 INFO Uploading batch count=126422026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=12643--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2644=== CONT TestServerRefusesOversizedAndNonStoreRequests26452026/10/02 20:40:48 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26462026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store store=/nix/store26472026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26482026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26492026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26502026/10/02 20:40:48 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26512026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26522026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26532026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26542026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26552026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26562026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26572026/10/02 20:40:48 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26582026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26592026/10/02 20:40:48 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26602026/10/02 20:40:48 ERROR Accept failed error="too many open files"26612026/10/02 20:40:48 ERROR Failed to decode request error="unexpected EOF"26622026/10/02 20:40:48 INFO Uploading batch count=426632026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=42664--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.00s)2665=== CONT TestQueueRemoveLargeClosure26662026/10/02 20:40:48 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-3690-3946823596/TestDrainIsolatesPoisonPath4233964192/002/bbb26672026/10/02 20:40:48 INFO Uploading batch count=126682026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=126692026/10/02 20:40:48 INFO Uploading batch count=126702026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=126712026/10/02 20:40:48 INFO Uploading batch count=126722026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=126732026/10/02 20:40:48 ERROR Drain finished with paths left in queue remaining=12674--- PASS: TestDrainIsolatesPoisonPath (0.01s)2675=== CONT TestServerQueueError26762026/10/02 20:40:48 ERROR Failed to queue paths error="permission denied" count=12677--- PASS: TestServerQueueError (0.00s)2678=== CONT TestServerClientIntegration2679--- PASS: TestServerClientIntegration (0.00s)2680=== CONT TestQueueRemove26812026/10/02 20:40:48 ERROR Accept failed error="too many open files"2682--- PASS: TestQueueRemove (0.00s)2683=== CONT TestQueueEnqueueWaitsOutSlowWriter2684--- PASS: TestWorkerSkipsGCdPaths (0.03s)2685=== CONT TestQueueRetryMovesToBack2686--- PASS: TestWorkerUploadsAndRemoves (0.03s)2687=== CONT TestQueueConcurrentWriters2688--- PASS: TestWorkerPrunesClosureDeps (0.03s)2689=== CONT TestQueueFetchRemoveLifecycle2690--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.03s)2691=== CONT TestQueueEnqueueAndFetch2692--- PASS: TestQueueRetryMovesToBack (0.01s)2693=== CONT TestQueueFetchBatchLimit2694--- PASS: TestQueueEnqueueAndFetch (0.01s)2695=== CONT TestSendPathsEmpty2696--- PASS: TestSendPathsEmpty (0.00s)2697=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2698--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2699=== CONT TestShutdownFinishesInFlightPush/completes2700--- PASS: TestQueueFetchBatchLimit (0.01s)2701=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27022026/10/02 20:40:48 INFO Upload queue status pending=227032026/10/02 20:40:48 INFO Upload queue status pending=227042026/10/02 20:40:48 INFO Uploading batch count=227052026/10/02 20:40:48 INFO Uploading batch count=227062026/10/02 20:40:48 ERROR Accept failed error="too many open files"27072026/10/02 20:40:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerRemoveFailureIsNotProgresscollected_path3010322811/001/nonexistent27082026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127092026/10/02 20:40:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerRemoveFailureIsNotProgresscollected_path3010322811/001/nonexistent27102026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127112026/10/02 20:40:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-3690-3946823596/TestWorkerRemoveFailureIsNotProgresscollected_path3010322811/001/nonexistent27122026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127132026/10/02 20:40:48 ERROR Drain finished with paths left in queue remaining=12714=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27152026/10/02 20:40:48 INFO Uploading batch count=227162026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=227172026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127182026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127192026/10/02 20:40:48 INFO Uploading batch count=227202026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=227212026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127222026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127232026/10/02 20:40:48 INFO Uploading batch count=227242026/10/02 20:40:48 ERROR Upload failed error="upload failed" count=227252026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127262026/10/02 20:40:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127272026/10/02 20:40:48 ERROR Drain finished with paths left in queue remaining=22728=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27292026/10/02 20:40:49 INFO Uploading batch count=227302026/10/02 20:40:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227312026/10/02 20:40:49 INFO Uploading batch count=227322026/10/02 20:40:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227332026/10/02 20:40:49 INFO Uploading batch count=227342026/10/02 20:40:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227352026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=22736=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2737--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2738 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.01s)2739 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.01s)2740 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.01s)27412026/10/02 20:40:49 INFO Uploading batch count=427422026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=427432026/10/02 20:40:49 ERROR Accept failed error="too many open files"2744=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27452026/10/02 20:40:49 INFO Uploading batch count=427462026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=42747--- PASS: TestQueueConcurrentWriters (0.13s)27482026/10/02 20:40:49 ERROR Accept failed error="too many open files"27492026/10/02 20:40:49 ERROR Failed to decode request error="read unix /nix/var/nix/builds/nix-3690-3946823596/hook756199440/test.sock->: i/o timeout"27502026/10/02 20:40:49 ERROR Failed to write response error="write unix /nix/var/nix/builds/nix-3690-3946823596/hook756199440/test.sock->: i/o timeout"2751--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27522026/10/02 20:40:49 ERROR Upload failed error="context canceled" count=227532026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=42754--- PASS: TestDrainTimeout (0.22s)27552026/10/02 20:40:49 ERROR Upload failed error="context canceled" count=227562026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=22757--- PASS: TestShutdownFinishesInFlightPush (0.00s)2758 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2759 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.21s)27602026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=427612026/10/02 20:40:49 ERROR Accept failed error="too many open files"27622026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=32763--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2764 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.21s)2765 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.31s)27662026/10/02 20:40:49 ERROR Accept failed error="too many open files"2767--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27682026/10/02 20:40:49 INFO Uploading batch count=127692026/10/02 20:40:49 INFO Uploading batch count=127702026/10/02 20:40:49 INFO Uploading batch count=127712026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=127722026/10/02 20:40:49 INFO Uploading batch count=127732026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=127742026/10/02 20:40:49 INFO Uploading batch count=127752026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=127762026/10/02 20:40:49 INFO Uploading batch count=127772026/10/02 20:40:49 ERROR Upload failed error="upload failed" count=127782026/10/02 20:40:49 ERROR Drain finished with paths left in queue remaining=12779--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2780--- PASS: TestQueueRemoveLargeClosure (1.22s)2781--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.01s)2782PASS2783Running niks3-hook command tests...2784=== RUN TestServeSecondSignalEndsDrain2785=== PAUSE TestServeSecondSignalEndsDrain2786=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2787=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2788=== CONT TestServeSecondSignalEndsDrain2789=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2790--- PASS: TestServeSecondSignalEndsDrain (0.08s)27912026/10/02 20:40:56 INFO Upload queue status pending=127922026/10/02 20:40:56 INFO Uploading batch count=12793--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2794PASS2795Running rate limiter tests...2796=== RUN TestAdaptiveRateLimiter_ThreadSafety2797=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2798=== CONT TestAdaptiveRateLimiter_ThreadSafety27992026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=7028002026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=4928012026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=34.328022026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=24.00999999999999828032026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=16.80728042026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=11.76489999999999928052026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=8.2354328062026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=5.76480099999999928072026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528082026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528092026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528102026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528112026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528122026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528132026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528142026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528152026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528162026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528172026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528182026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528192026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=19.45971059722283828202026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=13.62179741805598528212026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=9.53525819263918928222026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=6.67468073484743228232026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528242026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528252026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528262026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528272026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528282026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528292026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528302026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528312026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528322026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528332026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528342026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528352026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528362026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528372026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528382026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528392026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=5.63678500000000128402026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528412026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528422026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528432026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528442026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528452026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528462026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528472026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528482026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528492026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528502026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528512026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528522026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528532026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528542026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528552026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528562026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528572026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528582026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528592026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=5.63678500000000128602026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528612026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528622026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528632026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528642026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528652026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528662026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528672026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528682026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528692026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=9.98590847138500628702026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=6.99013592996950428712026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528722026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528732026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528742026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528752026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528762026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528772026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528782026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528792026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528802026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528812026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528822026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528832026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528842026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528852026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528862026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528872026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528882026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528892026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528902026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528912026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528922026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528932026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528942026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528952026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528962026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528972026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=528982026/10/02 20:40:57 WARN Rate limiter backed off name=test rate=52899--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.10s)2900PASS