niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #327
· 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.05s)30=== RUN TestDumpPathCaseHackCollision31--- PASS: TestDumpPathCaseHackCollision (0.00s)32=== RUN TestSupersededNARStillUploadsListing33=== PAUSE TestSupersededNARStillUploadsListing34=== RUN TestTruncatedNARDumpIsNotCompleted35=== PAUSE TestTruncatedNARDumpIsNotCompleted36=== RUN TestDumpPathMatchesNix37=== PAUSE TestDumpPathMatchesNix38=== RUN TestDumpPathSingleFile39=== PAUSE TestDumpPathSingleFile40=== RUN TestDumpPathWriterError41=== PAUSE TestDumpPathWriterError42=== RUN TestDumpPathWriterErrorStopsReading43 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory44--- SKIP: TestDumpPathWriterErrorStopsReading (0.34s)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 TestRateLimiterFeedback128=== CONT TestPartSizeForNAR129=== RUN TestRateLimiterFeedback/429_enables_limiter130=== RUN TestPartSizeForNAR/zero_stays_at_minimum131=== PAUSE TestRateLimiterFeedback/429_enables_limiter132=== CONT TestDoServerRequestAttachesToken133=== RUN TestRateLimiterFeedback/503_enables_limiter134=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum135=== RUN TestPartSizeForNAR/small_stays_at_minimum136=== PAUSE TestPartSizeForNAR/small_stays_at_minimum137=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum138=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum139=== PAUSE TestRateLimiterFeedback/503_enables_limiter140=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter141=== CONT TestSupersededNARStillUploadsListing142=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts143=== RUN TestSupersededNARStillUploadsListing/small_NAR144=== PAUSE TestSupersededNARStillUploadsListing/small_NAR145=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter146=== CONT TestCompletePendingClosure_NotFoundWithoutKey147=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter148=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter149=== CONT TestParsePathInfoJSONMultiplePaths150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent153=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier154=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier155=== CONT TestParsePathInfoJSON156=== CONT TestTruncatedNARDumpIsNotCompleted157=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess158=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts159=== CONT TestConvertHashToNix32160=== RUN TestConvertHashToNix32/SRI_format_to_Nix32161=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32162=== RUN TestConvertHashToNix32/already_Nix32_format163=== RUN TestPartSizeForNAR/1_TiB164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up166=== RUN TestParsePathInfoJSON/Nix_format167=== PAUSE TestConvertHashToNix32/already_Nix32_format168=== PAUSE TestPartSizeForNAR/1_TiB169=== PAUSE TestParsePathInfoJSON/Nix_format170=== RUN TestPartSizeForNAR/5_TiB_S3_max_object171=== RUN TestConvertHashToNix32/invalid_format172=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up173=== RUN TestSupersededNARStillUploadsListing/dump_cut_short174=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object175=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== PAUSE TestConvertHashToNix32/invalid_format177=== RUN TestPartSizeForNAR/capped_at_5_GiB178=== RUN TestParsePathInfoJSON/Lix_format179--- PASS: TestDoServerRequestAttachesToken (0.00s)180=== CONT TestGetStorePathHash181=== CONT TestEncodeNixBase32182=== RUN TestGetStorePathHash/valid_store_path183=== PAUSE TestPartSizeForNAR/capped_at_5_GiB184=== PAUSE TestParsePathInfoJSON/Lix_format185=== RUN TestParsePathInfoJSON/empty_input186=== CONT TestScriptTokenDoesNotWaitForItsChildren187=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs188=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs189--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)190=== CONT TestDumpPathSingleFile191=== CONT TestSetClientTLSDoesNotMutateDefaultTransport192=== CONT TestPathInfoHashCompatibility193=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short194=== PAUSE TestGetStorePathHash/valid_store_path195=== RUN TestEncodeNixBase32/test_string_hash196=== PAUSE TestParsePathInfoJSON/empty_input197=== RUN TestGetStorePathHash/basename_without_hyphen_should_error198=== PAUSE TestEncodeNixBase32/test_string_hash199=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error200=== RUN TestParsePathInfoJSON/whitespace_only201=== RUN TestEncodeNixBase32/empty_input202=== PAUSE TestParsePathInfoJSON/whitespace_only203=== PAUSE TestEncodeNixBase32/empty_input204=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails205=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout206=== RUN TestParsePathInfoJSON/invalid_JSON207=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout208=== CONT TestDumpPathMatchesNix209=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)210=== CONT TestScriptTokenScriptFails211=== PAUSE TestParsePathInfoJSON/invalid_JSON212=== CONT TestScriptTokenEmptyToken213=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)214=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error215=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails216=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon217=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error218=== CONT TestStreamPushReportsEveryPath219=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error220=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error221=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon222=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI223=== CONT TestScriptTokenNoExpiryRerunsEveryCall224=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI225=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512226=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512227=== CONT TestScriptTokenBadJSON228--- PASS: TestStreamPushReportsEveryPath (0.00s)229=== CONT TestFileTokenMissing230--- PASS: TestScriptTokenScriptFails (0.01s)231=== CONT TestClientSignaturesByStorePath232--- PASS: TestClientSignaturesByStorePath (0.00s)233=== CONT TestFileTokenReadsAndCaches234--- PASS: TestFileTokenMissing (0.00s)235=== CONT TestStreamPushStopsOnCancel236=== RUN TestStreamPushStopsOnCancel/waiting_for_input237=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input238=== CONT TestStaticToken239--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)240=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot241--- PASS: TestStaticToken (0.00s)242=== CONT TestStreamPushBatchesUnderLoad243=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot244=== CONT TestFileTokenEmpty245=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot246--- PASS: TestFileTokenReadsAndCaches (0.00s)247=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot248=== RUN TestStreamPushBatchesUnderLoad/together249=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot250=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot251=== PAUSE TestStreamPushBatchesUnderLoad/together252=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot253=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time254=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time255=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot256=== CONT TestScriptTokenEmptyCommand257=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken258--- PASS: TestFileTokenEmpty (0.00s)259=== CONT TestScriptTokenCachesUntilRefresh260=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken261=== CONT TestSetClientTLSErrors262--- PASS: TestScriptTokenEmptyCommand (0.00s)263=== CONT TestUploadMultipart_PartsInParallel264=== RUN TestSetClientTLSErrors/missing_cert_file265=== PAUSE TestSetClientTLSErrors/missing_cert_file266=== RUN TestSetClientTLSErrors/missing_key_file267=== PAUSE TestSetClientTLSErrors/missing_key_file268=== RUN TestSetClientTLSErrors/missing_ca_file269=== PAUSE TestSetClientTLSErrors/missing_ca_file270=== RUN TestSetClientTLSErrors/invalid_ca_file271=== PAUSE TestSetClientTLSErrors/invalid_ca_file272=== CONT TestStreamPushRequestLine273--- PASS: TestScriptTokenBadJSON (0.01s)274=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica275--- PASS: TestScriptTokenEmptyToken (0.01s)276=== CONT TestSetClientTLS277--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)278=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure279=== RUN TestSetClientTLS/rejects_connection_without_client_cert280=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert281=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA282=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA283=== RUN TestSetClientTLS/preserves_debug_logging_transport284=== PAUSE TestSetClientTLS/preserves_debug_logging_transport285=== CONT TestDumpPathWriterError286--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)287=== CONT TestUploadMultipart_SupersededByPeer288=== RUN TestUploadMultipart_SupersededByPeer/exists289=== PAUSE TestUploadMultipart_SupersededByPeer/exists290=== RUN TestUploadMultipart_SupersededByPeer/missing291=== PAUSE TestUploadMultipart_SupersededByPeer/missing292=== CONT TestPathInfoCACompatibility293=== RUN TestPathInfoCACompatibility/null_ca_field294=== PAUSE TestPathInfoCACompatibility/null_ca_field295=== RUN TestPathInfoCACompatibility/old_string_format_-_text296=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text297=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive299=== RUN TestPathInfoCACompatibility/new_structured_format_-_text300=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text301=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method302=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== CONT TestRegisterUploadedObjectReusesConnections304--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)305=== CONT TestCaseHackSuffix306--- PASS: TestDumpPathSingleFile (0.05s)307=== CONT TestEncodeNixBase32WithRealHash308--- PASS: TestEncodeNixBase32WithRealHash (0.00s)309=== CONT TestFilterOversizedClosures310=== RUN TestFilterOversizedClosures/no_limit_keeps_everything311=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything312=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped313=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped314=== RUN TestFilterOversizedClosures/all_closures_skipped315=== PAUSE TestFilterOversizedClosures/all_closures_skipped316=== CONT TestUploadMultipart_FailedPartBufferNotReused317--- PASS: TestStreamPushRequestLine (0.10s)318=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun319--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)320=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry321--- PASS: TestRegisterUploadedObjectReusesConnections (0.12s)322=== CONT TestShellSplit323--- PASS: TestShellSplit (0.00s)324=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer325--- PASS: TestCaseHackSuffix (0.27s)326=== CONT TestShellSplitErrors327--- PASS: TestShellSplitErrors (0.00s)328=== CONT TestResolveStorePath329--- PASS: TestResolveStorePath (0.01s)330=== CONT TestStreamPushGivesUpOnDeadServer331--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)332=== CONT TestStreamPushIsolatesFailures333--- PASS: TestStreamPushIsolatesFailures (0.00s)334=== CONT TestUploadMultipart_ProducerErrorIsNotEOF335=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part336=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part337=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary338=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary339=== CONT TestDoWithRetry_FinalResponseBodyReadable340--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)341=== CONT TestStreamPushReportsSignatures342--- PASS: TestStreamPushReportsSignatures (0.00s)343=== CONT TestDoWithRetry_BodyReplayedViaGetBody344--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)345=== CONT TestRateLimiterFeedback/503_enables_limiter346=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter347=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter348--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.22s)349=== CONT TestRateLimiterFeedback/429_enables_limiter350=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up351=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier352--- PASS: TestRateLimiterFeedback (0.00s)353 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)354 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)356 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)357=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths358--- PASS: TestDumpPathWriterError (0.31s)359=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths360=== CONT TestConvertHashToNix32/SRI_format_to_Nix32361=== CONT TestConvertHashToNix32/already_Nix32_format362--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)363 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)365=== CONT TestConvertHashToNix32/invalid_format366=== CONT TestPartSizeForNAR/small_stays_at_minimum367=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts368=== CONT TestPartSizeForNAR/capped_at_5_GiB369--- PASS: TestConvertHashToNix32 (0.00s)370 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)371 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)372 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)373=== CONT TestPartSizeForNAR/5_TiB_S3_max_object374=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum375=== CONT TestPartSizeForNAR/1_TiB376=== CONT TestPartSizeForNAR/zero_stays_at_minimum377=== CONT TestParsePathInfoJSON/invalid_JSON378=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs379=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout380--- PASS: TestPartSizeForNAR (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)384 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)385 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)386 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)387 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)388=== CONT TestParsePathInfoJSON/empty_input389--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)390 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)391 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)392=== CONT TestParsePathInfoJSON/whitespace_only393=== CONT TestEncodeNixBase32/test_string_hash394=== CONT TestParsePathInfoJSON/Lix_format395=== CONT TestParsePathInfoJSON/Nix_format396=== CONT TestEncodeNixBase32/empty_input397--- PASS: TestEncodeNixBase32 (0.00s)398 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)399 --- PASS: TestEncodeNixBase32/empty_input (0.00s)400--- PASS: TestParsePathInfoJSON (0.00s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)403 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)404 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)405 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)406=== CONT TestSupersededNARStillUploadsListing/small_NAR407=== CONT TestSupersededNARStillUploadsListing/dump_cut_short408--- PASS: TestDumpPathMatchesNix (0.36s)409=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails410=== CONT TestGetStorePathHash/basename_without_hyphen_should_error411=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error412=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error413=== CONT TestGetStorePathHash/valid_store_path414=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon415--- PASS: TestGetStorePathHash (0.00s)416 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)417 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)418 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)419 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)420=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512421=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI422=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)423=== CONT TestStreamPushBatchesUnderLoad/together424--- PASS: TestPathInfoHashCompatibility (0.00s)425 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)426 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)427 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)428 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)429=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time430=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot431--- PASS: TestStreamPushBatchesUnderLoad (0.00s)432 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)433 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)434--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.37s)435=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken436=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot437=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot438=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot439=== CONT TestStreamPushStopsOnCancel/waiting_for_input440=== CONT TestSetClientTLSErrors/missing_cert_file441=== CONT TestSetClientTLSErrors/invalid_ca_file442=== CONT TestSetClientTLSErrors/missing_key_file443=== CONT TestSetClientTLSErrors/missing_ca_file444=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA445--- PASS: TestSetClientTLSErrors (0.00s)446 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)447 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)448 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)449 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)450=== CONT TestSetClientTLS/preserves_debug_logging_transport451=== CONT TestSetClientTLS/rejects_connection_without_client_cert452=== CONT TestUploadMultipart_SupersededByPeer/missing453--- PASS: TestSetClientTLS (0.00s)454 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)455 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)456 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)457=== CONT TestUploadMultipart_SupersededByPeer/exists458=== CONT TestPathInfoCACompatibility/new_structured_format_-_text459--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)460 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)461 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)462=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive463=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method464=== CONT TestPathInfoCACompatibility/old_string_format_-_text465=== CONT TestPathInfoCACompatibility/null_ca_field466=== CONT TestFilterOversizedClosures/no_limit_keeps_everything467=== CONT TestFilterOversizedClosures/all_closures_skipped468--- PASS: TestPathInfoCACompatibility (0.00s)469 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)470 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)471 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)472 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)473 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)474=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped475=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary476--- PASS: TestFilterOversizedClosures (0.00s)477 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)478 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)479 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)480--- PASS: TestStreamPushStopsOnCancel (0.00s)481 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)482 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)483 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)484 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)485 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)486 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)487=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.02s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.03s)491--- PASS: TestTruncatedNARDumpIsNotCompleted (0.60s)492--- PASS: TestUploadMultipart_PartsInParallel (0.65s)493--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.62s)494--- PASS: TestSupersededNARStillUploadsListing (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)496 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.00s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.58s)498--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)499--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)500--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)501 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)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-97131-1810668750/postgres731085966/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-97131-1810668750/postgres731085966/data -l logfile start531532/nix/var/nix/builds/nix-97131-1810668750/postgres731085966:5432 - no response5332026-10-01 09:57:32.722 UTC [97177] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5342026-10-01 09:57:32.722 UTC [97177] LOG: listening on Unix socket "/nix/var/nix/builds/nix-97131-1810668750/postgres731085966/.s.PGSQL.5432"5352026-10-01 09:57:32.724 UTC [97184] LOG: database system was shut down at 2026-10-01 09:57:32 UTC5362026-10-01 09:57:32.725 UTC [97177] LOG: database system is ready to accept connections537/nix/var/nix/builds/nix-97131-1810668750/postgres731085966:5432 - accepting connections538=== 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/01 09:57:33 INFO lead: acquired remote=192.0.2.1:12345862026/10/01 09:57:34 INFO lead: released remote=192.0.2.1:12345872026/10/01 09:57:34 INFO lead: acquired remote=192.0.2.1:12345882026/10/01 09:57:35 INFO lead: released remote=192.0.2.1:1234589--- PASS: TestLeadIncumbentWinsAfterRestart (2.40s)590=== RUN TestLeadEndsOnShutdown591=== PAUSE TestLeadEndsOnShutdown592=== RUN TestLeadEndsWhenItsConnectionHangs5932026/10/01 09:57:35 INFO lead: acquired remote=192.0.2.1:12345942026-10-01 09:57:36.712 UTC [97220] FATAL: terminating connection due to administrator command5952026/10/01 09:57:36 INFO lead: acquired remote=192.0.2.1:12345962026/10/01 09:57:37 WARN lead: lock connection lost error="timeout: context deadline exceeded"5972026/10/01 09:57:37 INFO lead: released remote=192.0.2.1:12345982026/10/01 09:57:38 INFO lead: released remote=192.0.2.1:1234599--- PASS: TestLeadEndsWhenItsConnectionHangs (2.79s)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 TestValidateS3Concurrency687=== PAUSE TestValidateS3Concurrency688=== RUN TestOrphanedObjectsGC689=== PAUSE TestOrphanedObjectsGC690=== RUN TestOrphanedObjectsGCStressTest691=== PAUSE TestOrphanedObjectsGCStressTest692=== RUN TestCreatePin_ReservedPins693=== PAUSE TestCreatePin_ReservedPins694=== RUN TestConcurrentPinUpdatesAgree695=== PAUSE TestConcurrentPinUpdatesAgree696=== RUN TestCreatePinRejectsBadInput697=== PAUSE TestCreatePinRejectsBadInput698=== RUN TestDeletePinKeepsRowWhenS3Fails699=== PAUSE TestDeletePinKeepsRowWhenS3Fails700=== RUN TestPresentReportsOnlyClosureRoots701=== PAUSE TestPresentReportsOnlyClosureRoots702=== RUN TestPresentNotReportedWhileGCDeletesClosure703=== PAUSE TestPresentNotReportedWhileGCDeletesClosure704=== RUN TestParseSingleRange705=== PAUSE TestParseSingleRange706=== RUN TestProxyHeadersOnlyTrustedOnSocket707=== PAUSE TestProxyHeadersOnlyTrustedOnSocket708=== RUN TestIsValidCachePath709=== PAUSE TestIsValidCachePath710=== RUN TestReadProxyNarinfo711=== PAUSE TestReadProxyNarinfo712=== RUN TestReadProxyNarinfoAlreadyDecompressed713=== PAUSE TestReadProxyNarinfoAlreadyDecompressed714=== RUN TestReadProxyNarStreaming715=== PAUSE TestReadProxyNarStreaming716=== RUN TestReadProxy404717=== PAUSE TestReadProxy404718=== RUN TestReadProxyInvalidPath719=== PAUSE TestReadProxyInvalidPath720=== RUN TestReadProxyHead721=== PAUSE TestReadProxyHead722=== RUN TestReadProxyOutlastsServerWriteTimeout723=== PAUSE TestReadProxyOutlastsServerWriteTimeout724=== RUN TestReadProxyConditionalGet725=== PAUSE TestReadProxyConditionalGet726=== RUN TestReadProxyRootRedirectsToIndexHTML727=== PAUSE TestReadProxyRootRedirectsToIndexHTML728=== RUN TestReadProxyDisabled729=== PAUSE TestReadProxyDisabled730=== RUN TestReadRedirectNar731=== PAUSE TestReadRedirectNar732=== RUN TestReadRedirectKeepsNarinfoProxied733=== PAUSE TestReadRedirectKeepsNarinfoProxied734=== RUN TestReadProxyRangeRequest735=== PAUSE TestReadProxyRangeRequest736=== RUN TestReadRedirectUsesPublicS3URL737=== PAUSE TestReadRedirectUsesPublicS3URL738=== RUN TestPush_OverlappingRootsStoreOneRowPerKey739=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey740=== RUN TestPush_CompleteCommitsEveryRoot741=== PAUSE TestPush_CompleteCommitsEveryRoot742=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit743=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit744=== RUN TestPush_RejectsBadRequests745=== PAUSE TestPush_RejectsBadRequests746=== RUN TestPush_SignsNarinfosOfItsPendingObjects747=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects748=== RUN TestRedundantMultipartUpload749=== PAUSE TestRedundantMultipartUpload750=== RUN TestCompleteMultipartUpload_ErrorButObjectExists751=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists752=== RUN TestCompletedNarNotReofferedAcrossClosures753=== PAUSE TestCompletedNarNotReofferedAcrossClosures754=== RUN TestPresignedUploadRegisteredBeforeCommit755=== PAUSE TestPresignedUploadRegisteredBeforeCommit756=== RUN TestService_Rustfstest757=== PAUSE TestService_Rustfstest758=== RUN TestParseSize759=== PAUSE TestParseSize760=== RUN TestSkippedUploadsHandler761=== PAUSE TestSkippedUploadsHandler762=== RUN TestSystemdListenerNotActivated763--- PASS: TestSystemdListenerNotActivated (0.00s)764=== RUN TestWatchdogBeatsWhenHealthy765--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)766=== RUN TestWatchdogSkipsWhenUnhealthy7672026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/01 09:57:38 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"777--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)778=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== RUN TestProxyWriteTimeout781=== PAUSE TestProxyWriteTimeout782=== RUN TestPendingClosureWriteTimeout783=== PAUSE TestPendingClosureWriteTimeout784=== RUN TestIsValidUploadKey785=== PAUSE TestIsValidUploadKey786=== RUN TestUploadHandlersRejectInvalidKeys787=== PAUSE TestUploadHandlersRejectInvalidKeys788=== RUN TestUploadHandlersRejectOversizedBody789=== PAUSE TestUploadHandlersRejectOversizedBody790=== RUN TestService_cleanupPendingClosuresHandler791=== PAUSE TestService_cleanupPendingClosuresHandler792=== RUN TestService_createPendingClosureHandler793=== PAUSE TestService_createPendingClosureHandler794=== RUN TestService_verifyS3Integrity795=== PAUSE TestService_verifyS3Integrity796=== RUN TestCompleteMultipartUnregistered797=== PAUSE TestCompleteMultipartUnregistered798=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT799=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestReadRedirectNar801=== CONT TestReadProxyDisabled802=== CONT TestResolveDBConnectionString803=== CONT TestCommitRacingPendingCleanupKeepsObjects804=== CONT TestService_AuthMiddleware_MTLSProxyHeader805=== CONT TestConnectSerialisesConcurrentMigrations806=== CONT TestGCTaskStore_StartNew807=== CONT TestReconnectLeavesObjectsUnlocked808=== RUN TestResolveDBConnectionString/flag_wins809=== CONT TestReadProxyConditionalGet810=== CONT TestGCEndsOnShutdown811=== CONT TestReadProxyOutlastsServerWriteTimeout812--- PASS: TestGCTaskStore_StartNew (0.00s)813=== PAUSE TestResolveDBConnectionString/flag_wins814=== RUN TestGCEndsOnShutdown/before_the_run815=== PAUSE TestGCEndsOnShutdown/before_the_run816=== RUN TestResolveDBConnectionString/file_when_flag_empty817=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete818=== PAUSE TestResolveDBConnectionString/file_when_flag_empty819=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete820=== RUN TestResolveDBConnectionString/missing_file_is_an_error821=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error822=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark823=== RUN TestResolveDBConnectionString/PGHOST_allows_empty824=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty825=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark826=== CONT TestReadProxyHead827=== RUN TestResolveDBConnectionString/nothing_configured828=== PAUSE TestResolveDBConnectionString/nothing_configured829=== CONT TestReadProxyInvalidPath8302026-10-01 09:57:38.735 UTC [97244] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"8312026-10-01 09:57:38.735 UTC [97244] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.8322026-10-01 09:57:38.735 UTC [97244] STATEMENT: CREATE TABLE goose_db_version (833 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,834 version_id bigint NOT NULL,835 is_applied boolean NOT NULL,836 tstamp timestamp NOT NULL DEFAULT now()837 )838=== CONT TestReadProxyRootRedirectsToIndexHTML839--- PASS: TestReadRedirectNar (0.50s)8402026/10/01 09:57:39 INFO Aborted multipart uploads count=0 kept=08412026/10/01 09:57:39 WARN Force mode enabled - objects will be deleted immediately without grace period8422026/10/01 09:57:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08432026/10/01 09:57:39 INFO Vacuumed table table=pending_closures8442026/10/01 09:57:39 INFO Vacuumed table table=pending_objects8452026/10/01 09:57:39 INFO Vacuumed table table=multipart_uploads8462026/10/01 09:57:39 INFO Vacuumed table table=closures8472026/10/01 09:57:39 INFO Vacuumed table table=objects848--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.77s)849=== CONT TestReadProxy404850--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.80s)851=== CONT TestReadProxyNarStreaming852--- PASS: TestReadProxyConditionalGet (1.19s)853=== CONT TestReadProxyNarinfoAlreadyDecompressed854--- PASS: TestReadProxyDisabled (1.32s)855=== CONT TestIsValidCachePath856=== RUN TestIsValidCachePath/narinfo857=== PAUSE TestIsValidCachePath/narinfo858=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars859=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars860=== RUN TestIsValidCachePath/nar_zst861=== PAUSE TestIsValidCachePath/nar_zst862=== RUN TestIsValidCachePath/nar_xz863=== PAUSE TestIsValidCachePath/nar_xz864=== RUN TestIsValidCachePath/nar_bz2865=== PAUSE TestIsValidCachePath/nar_bz2866=== RUN TestIsValidCachePath/nar_uncompressed867=== PAUSE TestIsValidCachePath/nar_uncompressed868=== RUN TestIsValidCachePath/ls869=== PAUSE TestIsValidCachePath/ls870=== RUN TestIsValidCachePath/log871=== PAUSE TestIsValidCachePath/log872=== RUN TestIsValidCachePath/realisation873=== PAUSE TestIsValidCachePath/realisation874=== RUN TestIsValidCachePath/nix-cache-info875=== PAUSE TestIsValidCachePath/nix-cache-info876=== RUN TestIsValidCachePath/index.html877=== PAUSE TestIsValidCachePath/index.html878=== RUN TestIsValidCachePath/traversal_parent879=== PAUSE TestIsValidCachePath/traversal_parent880=== RUN TestIsValidCachePath/traversal_in_middle881=== PAUSE TestIsValidCachePath/traversal_in_middle882=== RUN TestIsValidCachePath/invalid_char_e883=== PAUSE TestIsValidCachePath/invalid_char_e884=== RUN TestIsValidCachePath/invalid_char_u885=== PAUSE TestIsValidCachePath/invalid_char_u886=== RUN TestIsValidCachePath/random_path887=== PAUSE TestIsValidCachePath/random_path888=== RUN TestIsValidCachePath/empty889=== PAUSE TestIsValidCachePath/empty890=== RUN TestIsValidCachePath/leading_slash891=== PAUSE TestIsValidCachePath/leading_slash892=== RUN TestIsValidCachePath/wrong_extension893=== PAUSE TestIsValidCachePath/wrong_extension894=== RUN TestIsValidCachePath/short_hash895=== PAUSE TestIsValidCachePath/short_hash896=== CONT TestReadProxyNarinfo897=== CONT TestParseSingleRange898--- PASS: TestConnectSerialisesConcurrentMigrations (1.38s)899=== RUN TestParseSingleRange/none900=== PAUSE TestParseSingleRange/none901=== RUN TestParseSingleRange/unknown_unit902=== PAUSE TestParseSingleRange/unknown_unit903=== RUN TestParseSingleRange/multi-range_ignored904=== PAUSE TestParseSingleRange/multi-range_ignored905=== RUN TestParseSingleRange/malformed_no_dash906=== PAUSE TestParseSingleRange/malformed_no_dash907=== RUN TestParseSingleRange/malformed_both_empty908=== PAUSE TestParseSingleRange/malformed_both_empty909=== RUN TestParseSingleRange/malformed_end_before_start910=== PAUSE TestParseSingleRange/malformed_end_before_start911=== RUN TestParseSingleRange/closed912=== PAUSE TestParseSingleRange/closed913=== RUN TestParseSingleRange/open-ended914=== PAUSE TestParseSingleRange/open-ended915=== RUN TestParseSingleRange/end_clamped_to_size916=== PAUSE TestParseSingleRange/end_clamped_to_size917=== RUN TestParseSingleRange/suffix918=== PAUSE TestParseSingleRange/suffix919=== RUN TestParseSingleRange/suffix_exceeds_size920=== PAUSE TestParseSingleRange/suffix_exceeds_size921=== RUN TestParseSingleRange/single_byte922=== PAUSE TestParseSingleRange/single_byte923=== RUN TestParseSingleRange/start_past_EOF924=== PAUSE TestParseSingleRange/start_past_EOF925=== RUN TestParseSingleRange/start_far_past_EOF926=== PAUSE TestParseSingleRange/start_far_past_EOF927=== CONT TestPresentNotReportedWhileGCDeletesClosure928--- PASS: TestReadProxyInvalidPath (1.45s)929=== CONT TestProxyHeadersOnlyTrustedOnSocket930--- PASS: TestReadProxyHead (1.63s)931=== CONT TestPresentReportsOnlyClosureRoots932--- PASS: TestReconnectLeavesObjectsUnlocked (1.78s)933=== CONT TestCreatePinRejectsBadInput934--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.44s)935=== CONT TestConcurrentPinUpdatesAgree9362026/10/01 09:57:40 WARN Rate limiter enabled after throttle name=s3-test rate=59372026/10/01 09:57:40 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."938--- PASS: TestReadProxyNarStreaming (1.52s)939=== CONT TestCreatePin_ReservedPins9402026/10/01 09:57:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56905/oidc9412026/10/01 09:57:40 WARN Rate limiter backed off name=s3-test rate=59422026/10/01 09:57:40 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."943--- PASS: TestReadProxy404 (1.67s)944=== CONT TestDeletePinKeepsRowWhenS3Fails945--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.29s)946=== CONT TestOrphanedObjectsGC9472026/10/01 09:57:41 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"9482026/10/01 09:57:41 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216949--- PASS: TestReadProxyNarinfo (1.73s)950=== CONT TestValidateS3Concurrency951=== CONT TestGCTaskStore_GetEmpty952--- PASS: TestValidateS3Concurrency (0.00s)953=== CONT TestService_NativeMTLS954--- PASS: TestGCTaskStore_GetEmpty (0.00s)9552026/10/01 09:57:41 INFO Starting HTTP server address=127.0.0.1:569289562026/10/01 09:57:41 INFO Starting HTTP server address=/nix/var/nix/builds/nix-97131-1810668750/TestProxyHeadersOnlyTrustedOnSocket419912612/001/proxy.sock9572026/10/01 09:57:41 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9582026/10/01 09:57:41 INFO Shutdown signal received, draining in-flight requests timeout=10s959--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.64s)960=== CONT TestReadRedirectKeepsNarinfoProxied961--- PASS: TestPresentReportsOnlyClosureRoots (1.62s)962=== CONT TestNARDeduplicationMetadataUploadBug9632026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9642026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9652026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9662026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9672026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9682026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9692026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9702026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy9712026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/deploy972--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.09s)973=== CONT TestClientCADerivations9742026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/app9752026/10/01 09:57:41 INFO Received create pin request method=POST path=/api/pins/app9762026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/deploy9772026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9782026/10/01 09:57:42 WARN Refused reserved pin name=worker-x86_64-linux9792026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9802026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/my-app9812026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux982--- PASS: TestCreatePin_ReservedPins (1.42s)983=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9842026/10/01 09:57:42 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo985--- PASS: TestCreatePinRejectsBadInput (1.99s)986=== CONT TestClientFallsBackToClosures9872026/10/01 09:57:42 INFO Received create pin request method=POST path=/api/pins/app9882026/10/01 09:57:42 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9892026/10/01 09:57:42 INFO Received delete pin request method=DELETE path=/api/pins/app9902026/10/01 09:57:42 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9912026/10/01 09:57:42 INFO Received delete pin request method=DELETE path=/api/pins/app9922026/10/01 09:57:42 INFO Deleted pin name=app993--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.54s)994=== CONT TestConnectWaitsForAPeerMigration9952026/10/01 09:57:42 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo9962026/10/01 09:57:42 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo997--- PASS: TestConcurrentPinUpdatesAgree (2.22s)998=== CONT TestPinProtectsFromGC9992026/10/01 09:57:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10002026/10/01 09:57:42 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1001--- PASS: TestService_NativeMTLS (1.39s)1002=== CONT TestClientSharedPathCommittedMidPush1003=== NAME TestOrphanedObjectsGC1004 orphaned_objects_gc_test.go:290: GC Test Summary:1005 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1006 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1007 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1008 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1009 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1010--- PASS: TestOrphanedObjectsGC (2.20s)1011=== CONT TestClientWithDependencies1012--- PASS: TestReadRedirectKeepsNarinfoProxied (1.59s)1013=== CONT TestClientMultipleUploads1014=== NAME TestNARDeduplicationMetadataUploadBug1015 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-97131-1810668750/TestNARDeduplicationMetadataUploadBug481543697/001/store/md9sf4vls5bdwv6495pf54caxbf6vbxk-file1.txt10162026/10/01 09:57:43 INFO Received push request method=POST path=/api/pushes10172026/10/01 09:57:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10182026/10/01 09:57:43 INFO Uploading md9sf4vls5bdwv6495pf54caxbf6vbxk-file1.txt (160B)10192026/10/01 09:57:43 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10202026/10/01 09:57:43 WARN Failed to register uploaded object key=md9sf4vls5bdwv6495pf54caxbf6vbxk.ls error="server returned 404: 404 page not found\n"10212026/10/01 09:57:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/01 09:57:43 INFO Signed narinfos id=1 count=110232026/10/01 09:57:43 INFO Uploading 1 narinfos10242026/10/01 09:57:43 INFO Received complete push request method=POST path=/api/pushes/1/complete10252026/10/01 09:57:43 WARN Failed to register uploaded object key=md9sf4vls5bdwv6495pf54caxbf6vbxk.narinfo error="server returned 404: 404 page not found\n"10262026/10/01 09:57:43 INFO Upload complete. (136ms)1027 metadata_upload_test.go:54: Retrieved narinfo from S3:1028 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestNARDeduplicationMetadataUploadBug481543697/001/store/md9sf4vls5bdwv6495pf54caxbf6vbxk-file1.txt1029 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1030 Compression: zstd1031 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1032 NarSize: 1601033 References: 1034 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1035 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1036 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1037 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1038--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.23s)1039=== CONT TestClientIntegration1040=== NAME TestNARDeduplicationMetadataUploadBug1041 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-97131-1810668750/TestNARDeduplicationMetadataUploadBug481543697/001/store/qyknx2nhrif90l0v92mk2i0hpkzvzm1y-file2.txt1042=== NAME TestClientCADerivations1043 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-97131-1810668750/TestClientCADerivations1789541046/001/store/rnlm84y89r641wxw0f8fglsf6xrhm310-ca-test10442026/10/01 09:57:43 INFO Received push request method=POST path=/api/pushes10452026/10/01 09:57:43 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10462026/10/01 09:57:43 WARN Failed to register uploaded object key=qyknx2nhrif90l0v92mk2i0hpkzvzm1y.ls error="server returned 404: 404 page not found\n"10472026/10/01 09:57:43 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10482026/10/01 09:57:43 INFO Signed narinfos id=2 count=110492026/10/01 09:57:43 INFO Uploading 1 narinfos1050 client_ca_test.go:139: Found 1 dependencies (including self)10512026/10/01 09:57:43 INFO Received complete push request method=POST path=/api/pushes/2/complete10522026/10/01 09:57:43 WARN Failed to register uploaded object key=qyknx2nhrif90l0v92mk2i0hpkzvzm1y.narinfo error="server returned 404: 404 page not found\n"10532026/10/01 09:57:43 INFO Upload complete. (93ms)1054=== NAME TestNARDeduplicationMetadataUploadBug1055 metadata_upload_test.go:76: Retrieved narinfo from S3:1056 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestNARDeduplicationMetadataUploadBug481543697/001/store/qyknx2nhrif90l0v92mk2i0hpkzvzm1y-file2.txt1057 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1058 Compression: zstd1059 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1060 NarSize: 1601061 References: 1062 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1063 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1064 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1065 {"version":1,"root":{"type":"regular","size":44}}1066--- PASS: TestNARDeduplicationMetadataUploadBug (2.20s)1067=== CONT TestClientErrorHandling1068=== RUN TestClientErrorHandling/InvalidStorePath1069=== PAUSE TestClientErrorHandling/InvalidStorePath1070=== RUN TestClientErrorHandling/InvalidAuthToken1071=== PAUSE TestClientErrorHandling/InvalidAuthToken1072=== RUN TestClientErrorHandling/ServerNotAvailable1073=== PAUSE TestClientErrorHandling/ServerNotAvailable1074=== CONT TestMetricsInventory10752026/10/01 09:57:43 INFO Received push request method=POST path=/api/pushes10762026/10/01 09:57:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10772026/10/01 09:57:43 INFO Uploading rnlm84y89r641wxw0f8fglsf6xrhm310-ca-test (144B)10782026/10/01 09:57:43 WARN Failed to register uploaded object key=rnlm84y89r641wxw0f8fglsf6xrhm310.ls error="server returned 404: 404 page not found\n"10792026/10/01 09:57:43 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10802026/10/01 09:57:43 WARN Failed to register uploaded object key=log/8l1h3lmr2jlb3j4ah12mkcdv2ix1zvpi-ca-test.drv error="server returned 404: 404 page not found\n"10812026/10/01 09:57:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10822026/10/01 09:57:43 INFO Signed narinfos id=1 count=110832026/10/01 09:57:43 INFO Uploading 1 narinfos10842026/10/01 09:57:43 INFO Received complete push request method=POST path=/api/pushes/1/complete10852026/10/01 09:57:43 WARN Failed to register uploaded object key=rnlm84y89r641wxw0f8fglsf6xrhm310.narinfo error="server returned 404: 404 page not found\n"10862026/10/01 09:57:43 INFO Upload complete. (179ms)1087=== NAME TestClientCADerivations1088 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientCADerivations1789541046/001/store/rnlm84y89r641wxw0f8fglsf6xrhm310-ca-test1089 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1090 Compression: zstd1091 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1092 NarSize: 1441093 References: 1094 Deriver: /nix/var/nix/builds/nix-97131-1810668750/TestClientCADerivations1789541046/001/store/8l1h3lmr2jlb3j4ah12mkcdv2ix1zvpi-ca-test.drv1095 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1096 client_ca_test.go:185: Checking for realisation files in S3...1097 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1098 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1099 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket28?endpoint=http://localhost:56816®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-97131-1810668750/TestClientCADerivations1789541046/001/store'1100 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11101--- PASS: TestClientCADerivations (2.27s)1102=== CONT TestClientPushesUseOnePush11032026/10/01 09:57:44 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/01 09:57:44 INFO Received uploads request method=POST path=/api/pending_closures11052026/10/01 09:57:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11062026/10/01 09:57:44 INFO Uploading b1970h55fbini8lbnwi3rjd0mjpcfzh0-shared-dep (136B)11072026/10/01 09:57:44 INFO Uploading zfb2j8j8g5z71qmrai9lw59pyhx1fj2d-b (248B)1108=== NAME TestPinProtectsFromGC1109 client_integration_test.go:867: Pinned store path: /nix/var/nix/builds/nix-97131-1810668750/TestPinProtectsFromGC3466840444/001/store/7k0vkvh56haqqplcvvfr5sy9481fmh89-pinned-file.txt1110 client_integration_test.go:868: Unpinned store path: /nix/var/nix/builds/nix-97131-1810668750/TestPinProtectsFromGC3466840444/001/store/md4vvxidk9gk9l42chqljd595rw9b2my-unpinned-file.txt11112026/10/01 09:57:44 WARN Failed to register uploaded object key=aqcii24rpqvpzk3hsgbb3j8f0fjli4bp.ls error="server returned 404: 404 page not found\n"11122026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11132026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/13byc5zdfnbz7zd51mq82zr0r13z08qny73306a1dgg0zis3dmfn.nar.zst error="server returned 404: 404 page not found\n"11142026/10/01 09:57:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11152026/10/01 09:57:44 WARN Failed to register uploaded object key=b1970h55fbini8lbnwi3rjd0mjpcfzh0.ls error="server returned 404: 404 page not found\n"11162026/10/01 09:57:44 WARN Failed to register uploaded object key=zfb2j8j8g5z71qmrai9lw59pyhx1fj2d.ls error="server returned 404: 404 page not found\n"11172026/10/01 09:57:44 INFO Signed narinfos id=1 count=211182026/10/01 09:57:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11192026/10/01 09:57:44 INFO Signed narinfos id=2 count=211202026/10/01 09:57:44 INFO Uploading 4 narinfos11212026/10/01 09:57:44 WARN Failed to register uploaded object key=zfb2j8j8g5z71qmrai9lw59pyhx1fj2d.narinfo error="server returned 404: 404 page not found\n"11222026/10/01 09:57:44 WARN Failed to register uploaded object key=b1970h55fbini8lbnwi3rjd0mjpcfzh0.narinfo error="server returned 404: 404 page not found\n"11232026/10/01 09:57:44 WARN Failed to register uploaded object key=aqcii24rpqvpzk3hsgbb3j8f0fjli4bp.narinfo error="server returned 404: 404 page not found\n"11242026/10/01 09:57:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11252026/10/01 09:57:44 WARN Failed to register uploaded object key=b1970h55fbini8lbnwi3rjd0mjpcfzh0.narinfo error="server returned 404: 404 page not found\n"11262026/10/01 09:57:44 INFO Completed upload id=111272026/10/01 09:57:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11282026/10/01 09:57:44 INFO Completed upload id=211292026/10/01 09:57:44 INFO Upload complete. (153ms)1130=== NAME TestClientFallsBackToClosures1131 client_pushes_test.go:112: Retrieved narinfo from S3:1132 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientFallsBackToClosures1709617266/001/store/b1970h55fbini8lbnwi3rjd0mjpcfzh0-shared-dep1133 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1134 Compression: zstd1135 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821136 NarSize: 1361137 References: 1138 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1139 client_pushes_test.go:112: Retrieved narinfo from S3:1140 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientFallsBackToClosures1709617266/001/store/aqcii24rpqvpzk3hsgbb3j8f0fjli4bp-a1141 URL: nar/13byc5zdfnbz7zd51mq82zr0r13z08qny73306a1dgg0zis3dmfn.nar.zst1142 Compression: zstd1143 NarHash: sha256:13byc5zdfnbz7zd51mq82zr0r13z08qny73306a1dgg0zis3dmfn1144 NarSize: 2481145 References: /nix/var/nix/builds/nix-97131-1810668750/TestClientFallsBackToClosures1709617266/001/store/b1970h55fbini8lbnwi3rjd0mjpcfzh0-shared-dep1146 CA: text:sha256:1fj1bnw0vxkdjjvj5f3wzljykvq3i3dq4vidii8khbrisnnxa9ic1147 client_pushes_test.go:112: Retrieved narinfo from S3:1148 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientFallsBackToClosures1709617266/001/store/zfb2j8j8g5z71qmrai9lw59pyhx1fj2d-b1149 URL: nar/13byc5zdfnbz7zd51mq82zr0r13z08qny73306a1dgg0zis3dmfn.nar.zst1150 Compression: zstd1151 NarHash: sha256:13byc5zdfnbz7zd51mq82zr0r13z08qny73306a1dgg0zis3dmfn1152 NarSize: 2481153 References: /nix/var/nix/builds/nix-97131-1810668750/TestClientFallsBackToClosures1709617266/001/store/b1970h55fbini8lbnwi3rjd0mjpcfzh0-shared-dep1154 CA: text:sha256:1fj1bnw0vxkdjjvj5f3wzljykvq3i3dq4vidii8khbrisnnxa9ic11552026/10/01 09:57:44 INFO Received push request method=POST path=/api/pushes11562026/10/01 09:57:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11572026/10/01 09:57:44 INFO Uploading 7k0vkvh56haqqplcvvfr5sy9481fmh89-pinned-file.txt (128B)11582026/10/01 09:57:44 WARN Failed to register uploaded object key=7k0vkvh56haqqplcvvfr5sy9481fmh89.ls error="server returned 404: 404 page not found\n"11592026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11602026/10/01 09:57:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11612026/10/01 09:57:44 INFO Signed narinfos id=1 count=111622026/10/01 09:57:44 INFO Uploading 1 narinfos1163--- PASS: TestClientFallsBackToClosures (2.24s)1164=== CONT TestOrphanedObjectsGCStressTest11652026/10/01 09:57:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11662026/10/01 09:57:44 WARN Failed to register uploaded object key=7k0vkvh56haqqplcvvfr5sy9481fmh89.narinfo error="server returned 404: 404 page not found\n"11672026/10/01 09:57:44 INFO Upload complete. (163ms)11682026/10/01 09:57:44 INFO Received push request method=POST path=/api/pushes11692026/10/01 09:57:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11702026/10/01 09:57:44 INFO Uploading md4vvxidk9gk9l42chqljd595rw9b2my-unpinned-file.txt (128B)11712026/10/01 09:57:44 WARN Failed to register uploaded object key=md4vvxidk9gk9l42chqljd595rw9b2my.ls error="server returned 404: 404 page not found\n"11722026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11732026/10/01 09:57:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11742026/10/01 09:57:44 INFO Signed narinfos id=2 count=111752026/10/01 09:57:44 INFO Uploading 1 narinfos11762026/10/01 09:57:44 INFO Received complete push request method=POST path=/api/pushes/2/complete11772026/10/01 09:57:44 WARN Failed to register uploaded object key=md4vvxidk9gk9l42chqljd595rw9b2my.narinfo error="server returned 404: 404 page not found\n"11782026/10/01 09:57:44 INFO Upload complete. (85ms)11792026/10/01 09:57:44 INFO Starting cleanup of old closures method=DELETE path=/api/closures11802026/10/01 09:57:44 INFO Garbage collection started11812026/10/01 09:57:44 INFO Aborted multipart uploads count=0 kept=011822026/10/01 09:57:44 WARN Force mode enabled - objects will be deleted immediately without grace period11832026/10/01 09:57:44 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=011842026/10/01 09:57:44 INFO Vacuumed table table=pending_closures11852026/10/01 09:57:44 INFO Vacuumed table table=pending_objects11862026/10/01 09:57:44 INFO Vacuumed table table=multipart_uploads11872026/10/01 09:57:44 INFO Vacuumed table table=closures11882026/10/01 09:57:44 INFO Vacuumed table table=objects11892026/10/01 09:57:44 INFO Received push request method=POST path=/api/pushes11902026/10/01 09:57:44 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11912026/10/01 09:57:44 INFO Uploading s2skq8651kvfj58wb9h0l7w3lkqr7crq-top (256B)11922026/10/01 09:57:44 INFO Uploading j6ikll4x7n6ya1laydsw7zb2f3cfxgx0-shared-dep (136B)11932026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11942026/10/01 09:57:44 WARN Failed to register uploaded object key=s2skq8651kvfj58wb9h0l7w3lkqr7crq.ls error="server returned 404: 404 page not found\n"11952026/10/01 09:57:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11962026/10/01 09:57:44 WARN Failed to register uploaded object key=nar/0fwiqxgnr2k6v6j7pqblbp2q7f95427c5qpx0rd0hcyq8zyiz8pn.nar.zst error="server returned 404: 404 page not found\n"11972026/10/01 09:57:44 WARN Failed to register uploaded object key=j6ikll4x7n6ya1laydsw7zb2f3cfxgx0.ls error="server returned 404: 404 page not found\n"11982026/10/01 09:57:44 INFO Signed narinfos id=1 count=211992026/10/01 09:57:44 INFO Uploading 2 narinfos12002026/10/01 09:57:44 INFO Received complete push request method=POST path=/api/pushes/1/complete12012026/10/01 09:57:44 WARN Failed to register uploaded object key=s2skq8651kvfj58wb9h0l7w3lkqr7crq.narinfo error="server returned 404: 404 page not found\n"12022026/10/01 09:57:44 WARN Failed to register uploaded object key=j6ikll4x7n6ya1laydsw7zb2f3cfxgx0.narinfo error="server returned 404: 404 page not found\n"12032026/10/01 09:57:44 INFO Upload complete. (235ms)1204=== NAME TestClientSharedPathCommittedMidPush1205 client_integration_test.go:816: Retrieved narinfo from S3:1206 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientSharedPathCommittedMidPush2764174440/001/store/j6ikll4x7n6ya1laydsw7zb2f3cfxgx0-shared-dep1207 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1208 Compression: zstd1209 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821210 NarSize: 1361211 References: 1212 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1213 client_integration_test.go:816: Retrieved narinfo from S3:1214 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientSharedPathCommittedMidPush2764174440/001/store/s2skq8651kvfj58wb9h0l7w3lkqr7crq-top1215 URL: nar/0fwiqxgnr2k6v6j7pqblbp2q7f95427c5qpx0rd0hcyq8zyiz8pn.nar.zst1216 Compression: zstd1217 NarHash: sha256:0fwiqxgnr2k6v6j7pqblbp2q7f95427c5qpx0rd0hcyq8zyiz8pn1218 NarSize: 2561219 References: /nix/var/nix/builds/nix-97131-1810668750/TestClientSharedPathCommittedMidPush2764174440/001/store/j6ikll4x7n6ya1laydsw7zb2f3cfxgx0-shared-dep1220 CA: text:sha256:12zq0vf06rw7z3mvpm99fc1pj9fy97lkp34wb4i27qk06xzzlm691221=== NAME TestClientMultipleUploads1222 client_integration_test.go:480: Created store path 0: /nix/var/nix/builds/nix-97131-1810668750/TestClientMultipleUploads1792455343/001/store/5p5q6grg9lq81m726c8z0hlxzjnm5cmi-test-file-0.txt1223--- PASS: TestClientSharedPathCommittedMidPush (2.23s)1224=== CONT TestGCSweepDeliversEachKeyOnce1225=== NAME TestClientMultipleUploads1226 client_integration_test.go:480: Created store path 1: /nix/var/nix/builds/nix-97131-1810668750/TestClientMultipleUploads1792455343/001/store/smany0hhhf6sd5ibw112y1rsrkyyy4z5-test-file-1.txt1227 client_integration_test.go:480: Created store path 2: /nix/var/nix/builds/nix-97131-1810668750/TestClientMultipleUploads1792455343/001/store/yn49ddnc3r6gqhyaxv6wibk3amnys6m7-test-file-2.txt12282026/10/01 09:57:45 INFO Received push request method=POST path=/api/pushes12292026/10/01 09:57:45 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12302026/10/01 09:57:45 INFO Uploading 5p5q6grg9lq81m726c8z0hlxzjnm5cmi-test-file-0.txt (160B)12312026/10/01 09:57:45 INFO Uploading yn49ddnc3r6gqhyaxv6wibk3amnys6m7-test-file-2.txt (160B)12322026/10/01 09:57:45 INFO Uploading smany0hhhf6sd5ibw112y1rsrkyyy4z5-test-file-1.txt (160B)12332026/10/01 09:57:45 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12342026/10/01 09:57:45 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12352026/10/01 09:57:45 WARN Failed to register uploaded object key=smany0hhhf6sd5ibw112y1rsrkyyy4z5.ls error="server returned 404: 404 page not found\n"12362026/10/01 09:57:45 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12372026/10/01 09:57:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12382026/10/01 09:57:45 WARN Failed to register uploaded object key=yn49ddnc3r6gqhyaxv6wibk3amnys6m7.ls error="server returned 404: 404 page not found\n"12392026/10/01 09:57:45 WARN Failed to register uploaded object key=5p5q6grg9lq81m726c8z0hlxzjnm5cmi.ls error="server returned 404: 404 page not found\n"12402026/10/01 09:57:45 INFO Signed narinfos id=1 count=312412026/10/01 09:57:45 INFO Uploading 3 narinfos12422026/10/01 09:57:45 WARN Failed to register uploaded object key=yn49ddnc3r6gqhyaxv6wibk3amnys6m7.narinfo error="server returned 404: 404 page not found\n"12432026/10/01 09:57:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12442026/10/01 09:57:45 WARN Failed to register uploaded object key=smany0hhhf6sd5ibw112y1rsrkyyy4z5.narinfo error="server returned 404: 404 page not found\n"12452026/10/01 09:57:45 WARN Failed to register uploaded object key=5p5q6grg9lq81m726c8z0hlxzjnm5cmi.narinfo error="server returned 404: 404 page not found\n"12462026/10/01 09:57:45 INFO Upload complete. (144ms)1247 client_integration_test.go:491: Uploaded 3 paths in 180.296166ms1248=== NAME TestClientWithDependencies1249 client_integration_test.go:735: Built derivation: /nix/var/nix/builds/nix-97131-1810668750/TestClientWithDependencies3704548300/001/store/x9n5ids8n31fwzswgpym77mwbg1z7812-test-script1250--- PASS: TestClientMultipleUploads (2.33s)1251=== CONT TestSkippedUploadsHandler12522026/10/01 09:57:45 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001253--- PASS: TestSkippedUploadsHandler (0.00s)1254=== CONT TestPushWaitsForSweepHoldingRow1255=== NAME TestClientWithDependencies1256 client_integration_test.go:737: Found 1 dependencies (including self)12572026/10/01 09:57:45 INFO Received push request method=POST path=/api/pushes1258--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.43s)1259=== CONT TestCompleteMultipartUnregistered12602026/10/01 09:57:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12612026/10/01 09:57:45 INFO Uploading x9n5ids8n31fwzswgpym77mwbg1z7812-test-script (136B)12622026/10/01 09:57:45 WARN Failed to register uploaded object key=x9n5ids8n31fwzswgpym77mwbg1z7812.ls error="server returned 404: 404 page not found\n"12632026/10/01 09:57:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12642026/10/01 09:57:45 WARN Failed to register uploaded object key=log/f1rfxl3mkpc93np41hrygn563ajw6wmh-test-script.drv error="server returned 404: 404 page not found\n"12652026/10/01 09:57:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12662026/10/01 09:57:45 INFO Signed narinfos id=1 count=112672026/10/01 09:57:45 INFO Uploading 1 narinfos1268=== NAME TestClientIntegration1269 client_integration_test.go:334: Created store path: /nix/var/nix/builds/nix-97131-1810668750/TestClientIntegration1878193125/002/store/mbhvp9dacl2pxv6l1zdjgsjlv79hh32q-test-file.txt12702026/10/01 09:57:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12712026/10/01 09:57:45 WARN Failed to register uploaded object key=x9n5ids8n31fwzswgpym77mwbg1z7812.narinfo error="server returned 404: 404 page not found\n"12722026/10/01 09:57:45 INFO Upload complete. (176ms)12732026/10/01 09:57:45 INFO Aborted multipart uploads count=0 kept=012742026/10/01 09:57:45 WARN Force mode enabled - objects will be deleted immediately without grace period12752026/10/01 09:57:45 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=012762026/10/01 09:57:45 INFO Vacuumed table table=pending_closures12772026/10/01 09:57:45 INFO Vacuumed table table=pending_objects12782026/10/01 09:57:45 INFO Vacuumed table table=multipart_uploads12792026/10/01 09:57:45 INFO Received push request method=POST path=/api/pushes12802026/10/01 09:57:45 INFO Vacuumed table table=closures12812026/10/01 09:57:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12822026/10/01 09:57:45 INFO Uploading mbhvp9dacl2pxv6l1zdjgsjlv79hh32q-test-file.txt (152B)1283--- PASS: TestMetricsInventory (1.92s)1284=== CONT TestPendingClosureFailureTracksEveryUpload12852026/10/01 09:57:45 INFO Vacuumed table table=objects1286=== NAME TestClientWithDependencies1287 client_integration_test.go:753: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-97131-1810668750/TestClientWithDependencies3704548300/001/store) requires matching store prefix12882026/10/01 09:57:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12892026/10/01 09:57:45 WARN Failed to register uploaded object key=mbhvp9dacl2pxv6l1zdjgsjlv79hh32q.ls error="server returned 404: 404 page not found\n"12902026/10/01 09:57:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12912026/10/01 09:57:45 INFO Signed narinfos id=1 count=112922026/10/01 09:57:45 INFO Uploading 1 narinfos12932026/10/01 09:57:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12942026/10/01 09:57:45 WARN Failed to register uploaded object key=mbhvp9dacl2pxv6l1zdjgsjlv79hh32q.narinfo error="server returned 404: 404 page not found\n"12952026/10/01 09:57:45 INFO Upload complete. (137ms)1296--- PASS: TestClientWithDependencies (2.77s)1297=== CONT TestPendingCleanupUsesOneCutoff12982026/10/01 09:57:45 INFO All 1 paths already cached1299=== NAME TestClientIntegration1300 client_integration_test.go:360: Retrieved narinfo from S3:1301 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientIntegration1878193125/002/store/mbhvp9dacl2pxv6l1zdjgsjlv79hh32q-test-file.txt1302 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1303 Compression: zstd1304 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11305 NarSize: 1521306 References: 1307 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11308 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1309 client_integration_test.go:361: Decompressed .ls content (64 bytes):1310 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}13112026/10/01 09:57:45 INFO Received push request method=POST path=/api/pushes13122026/10/01 09:57:45 INFO Object in database but missing from S3 key=mbhvp9dacl2pxv6l1zdjgsjlv79hh32q.ls13132026/10/01 09:57:45 WARN Found objects in DB but missing from S3, will re-upload count=113142026/10/01 09:57:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13152026/10/01 09:57:45 INFO Received complete push request method=POST path=/api/pushes/2/complete13162026/10/01 09:57:45 WARN Failed to register uploaded object key=mbhvp9dacl2pxv6l1zdjgsjlv79hh32q.ls error="server returned 404: 404 page not found\n"13172026/10/01 09:57:45 INFO Upload complete. (58ms)1318 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1319 client_integration_test.go:389: Decompressed .ls content (49 bytes):1320 {"version":1,"root":{"type":"regular","size":39}}13212026/10/01 09:57:46 INFO Received push request method=POST path=/api/pushes13222026/10/01 09:57:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13232026/10/01 09:57:46 WARN Failed to register uploaded object key=mbhvp9dacl2pxv6l1zdjgsjlv79hh32q.ls error="server returned 404: 404 page not found\n"13242026/10/01 09:57:46 INFO Received complete push request method=POST path=/api/pushes/3/complete13252026/10/01 09:57:46 INFO Upload complete. (59ms)1326 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1327 client_integration_test.go:405: Decompressed .ls content (49 bytes):1328 {"version":1,"root":{"type":"regular","size":39}}13292026/10/01 09:57:46 INFO Received push request method=POST path=/api/pushes13302026/10/01 09:57:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13312026/10/01 09:57:46 INFO Uploading zs7lmjh9ajrxafqns7pvgimdzb9wdgxb-lost-commit.txt (152B)13322026/10/01 09:57:46 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"13332026/10/01 09:57:46 WARN Failed to register uploaded object key=zs7lmjh9ajrxafqns7pvgimdzb9wdgxb.ls error="server returned 404: 404 page not found\n"13342026/10/01 09:57:46 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign13352026/10/01 09:57:46 INFO Signed narinfos id=4 count=113362026/10/01 09:57:46 INFO Uploading 1 narinfos13372026/10/01 09:57:46 INFO Received complete push request method=POST path=/api/pushes/4/complete13382026/10/01 09:57:46 WARN Failed to register uploaded object key=zs7lmjh9ajrxafqns7pvgimdzb9wdgxb.narinfo error="server returned 404: 404 page not found\n"13392026/10/01 09:57:46 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:57089/api/pushes/4/complete\": EOF" url=http://127.0.0.1:57089/api/pushes/4/complete13402026/10/01 09:57:46 INFO Received push request method=POST path=/api/pushes13412026/10/01 09:57:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13422026/10/01 09:57:46 INFO Uploading hlwcds86d2l6njmbmfp515iv6vfyq3nv-shared-dep (136B)13432026/10/01 09:57:46 INFO Uploading 5l34yaq2msn78csxpra6vavzzklna2pg-a (248B)13442026/10/01 09:57:46 INFO Received complete push request method=POST path=/api/pushes/4/complete13452026/10/01 09:57:46 WARN Failed to register uploaded object key=qdwqrr1z48rkzmak0a7vdb09n5fpwdyj.ls error="server returned 404: 404 page not found\n"13462026-10-01 09:57:46.373 UTC [97434] ERROR: Push does not exist: id=413472026-10-01 09:57:46.373 UTC [97434] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE13482026-10-01 09:57:46.373 UTC [97434] STATEMENT: -- name: CommitPush :exec1349 SELECT commit_push($1::bigint)1350 13512026/10/01 09:57:46 INFO Upload complete. (186ms)1352 client_integration_test.go:435: Retrieved narinfo from S3:1353 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientIntegration1878193125/002/store/zs7lmjh9ajrxafqns7pvgimdzb9wdgxb-lost-commit.txt1354 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1355 Compression: zstd1356 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1357 NarSize: 1521358 References: 1359 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1360 client_integration_test.go:438: Testing garbage collection...13612026/10/01 09:57:46 WARN Failed to register uploaded object key=hlwcds86d2l6njmbmfp515iv6vfyq3nv.ls error="server returned 404: 404 page not found\n"13622026/10/01 09:57:46 WARN Failed to register uploaded object key=5l34yaq2msn78csxpra6vavzzklna2pg.ls error="server returned 404: 404 page not found\n"13632026/10/01 09:57:46 WARN Failed to register uploaded object key=nar/0lgbnisl2vfkhn42whkmngs6ip1wcn3cbhqiziq1ijb130pi8w0q.nar.zst error="server returned 404: 404 page not found\n"13642026/10/01 09:57:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13652026/10/01 09:57:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13662026/10/01 09:57:46 INFO Signed narinfos id=1 count=313672026/10/01 09:57:46 INFO Uploading 3 narinfos13682026/10/01 09:57:46 WARN Failed to register uploaded object key=5l34yaq2msn78csxpra6vavzzklna2pg.narinfo error="server returned 404: 404 page not found\n"13692026/10/01 09:57:46 WARN Failed to register uploaded object key=qdwqrr1z48rkzmak0a7vdb09n5fpwdyj.narinfo error="server returned 404: 404 page not found\n"13702026/10/01 09:57:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures13712026/10/01 09:57:46 INFO Garbage collection started13722026/10/01 09:57:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13732026/10/01 09:57:46 WARN Failed to register uploaded object key=hlwcds86d2l6njmbmfp515iv6vfyq3nv.narinfo error="server returned 404: 404 page not found\n"13742026/10/01 09:57:46 INFO Aborted multipart uploads count=0 kept=013752026/10/01 09:57:46 WARN Force mode enabled - objects will be deleted immediately without grace period13762026/10/01 09:57:46 INFO Upload complete. (159ms)1377=== NAME TestClientPushesUseOnePush1378 client_pushes_test.go:97: Retrieved narinfo from S3:1379 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientPushesUseOnePush3722585101/001/store/hlwcds86d2l6njmbmfp515iv6vfyq3nv-shared-dep1380 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1381 Compression: zstd1382 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821383 NarSize: 1361384 References: 1385 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1386 client_pushes_test.go:97: Retrieved narinfo from S3:1387 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientPushesUseOnePush3722585101/001/store/5l34yaq2msn78csxpra6vavzzklna2pg-a1388 URL: nar/0lgbnisl2vfkhn42whkmngs6ip1wcn3cbhqiziq1ijb130pi8w0q.nar.zst1389 Compression: zstd1390 NarHash: sha256:0lgbnisl2vfkhn42whkmngs6ip1wcn3cbhqiziq1ijb130pi8w0q1391 NarSize: 2481392 References: /nix/var/nix/builds/nix-97131-1810668750/TestClientPushesUseOnePush3722585101/001/store/hlwcds86d2l6njmbmfp515iv6vfyq3nv-shared-dep1393 CA: text:sha256:119lp7phgjckhgzchzaj51vkxghbb0y2ja143gfwfdh5jsjw83vx1394 client_pushes_test.go:97: Retrieved narinfo from S3:1395 StorePath: /nix/var/nix/builds/nix-97131-1810668750/TestClientPushesUseOnePush3722585101/001/store/qdwqrr1z48rkzmak0a7vdb09n5fpwdyj-b1396 URL: nar/0lgbnisl2vfkhn42whkmngs6ip1wcn3cbhqiziq1ijb130pi8w0q.nar.zst1397 Compression: zstd1398 NarHash: sha256:0lgbnisl2vfkhn42whkmngs6ip1wcn3cbhqiziq1ijb130pi8w0q1399 NarSize: 2481400 References: /nix/var/nix/builds/nix-97131-1810668750/TestClientPushesUseOnePush3722585101/001/store/hlwcds86d2l6njmbmfp515iv6vfyq3nv-shared-dep1401 CA: text:sha256:119lp7phgjckhgzchzaj51vkxghbb0y2ja143gfwfdh5jsjw83vx1402--- PASS: TestClientPushesUseOnePush (2.40s)1403=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14042026/10/01 09:57:46 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=014052026/10/01 09:57:46 INFO Vacuumed table table=pending_closures14062026/10/01 09:57:46 INFO Vacuumed table table=pending_objects14072026/10/01 09:57:46 INFO Vacuumed table table=multipart_uploads14082026/10/01 09:57:46 INFO Vacuumed table table=closures14092026/10/01 09:57:46 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=014102026/10/01 09:57:46 INFO Vacuumed table table=objects14112026/10/01 09:57:46 INFO Received create pin request method=POST path=/api/pins/myapp14122026/10/01 09:57:46 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-97131-1810668750/TestPinProtectsFromGC3466840444/001/store/7k0vkvh56haqqplcvvfr5sy9481fmh89-pinned-file.txt narinfo_key=7k0vkvh56haqqplcvvfr5sy9481fmh89.narinfo14132026/10/01 09:57:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures14142026/10/01 09:57:46 INFO Garbage collection started14152026/10/01 09:57:46 INFO Aborted multipart uploads count=0 kept=014162026/10/01 09:57:46 WARN Force mode enabled - objects will be deleted immediately without grace period14172026/10/01 09:57:46 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=014182026/10/01 09:57:46 INFO Vacuumed table table=pending_closures14192026/10/01 09:57:46 INFO Vacuumed table table=pending_objects14202026/10/01 09:57:46 INFO Vacuumed table table=multipart_uploads14212026/10/01 09:57:46 INFO Vacuumed table table=closures14222026/10/01 09:57:46 INFO Vacuumed table table=objects14232026/10/01 09:57:46 INFO Aborted multipart uploads count=0 kept=014242026/10/01 09:57:46 WARN Force mode enabled - objects will be deleted immediately without grace period14252026/10/01 09:57:46 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=014262026/10/01 09:57:46 INFO Vacuumed table table=pending_closures14272026/10/01 09:57:46 INFO Vacuumed table table=pending_objects14282026/10/01 09:57:46 INFO Vacuumed table table=multipart_uploads14292026/10/01 09:57:46 INFO Vacuumed table table=closures14302026/10/01 09:57:47 INFO Vacuumed table table=objects1431--- PASS: TestGCSweepDeliversEachKeyOnce (2.01s)1432=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT14332026/10/01 09:57:47 INFO Received uploads request method=POST path=/api/pending_closures14342026/10/01 09:57:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14352026/10/01 09:57:47 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1436--- PASS: TestCompleteMultipartUnregistered (2.42s)1437=== CONT TestService_createPendingClosureHandler1438--- PASS: TestPushWaitsForSweepHoldingRow (2.64s)1439=== CONT TestService_cleanupPendingClosuresHandler14402026/10/01 09:57:48 INFO Received uploads request method=POST path=/api/pending_closures14412026/10/01 09:57:48 INFO Received uploads request method=POST path=/api/pending_closures14422026/10/01 09:57:48 INFO Received cleanup request method=DELETE path=/api/pending_closures14432026/10/01 09:57:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01444=== NAME TestClientIntegration1445 client_integration_test.go:445: Objects in database after GC:1446 client_integration_test.go:445: Successfully deleted all objects with GC --force14472026/10/01 09:57:48 INFO Received uploads request method=POST path=/api/pending_closures1448--- PASS: TestClientIntegration (4.86s)1449=== CONT TestService_verifyS3Integrity1450=== NAME TestPinProtectsFromGC1451 client_integration_test.go:976: Pin successfully protected closure from garbage collection1452--- PASS: TestPinProtectsFromGC (6.19s)1453=== CONT TestUploadHandlersRejectOversizedBody1454=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1455=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1456=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1457=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1458=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1459=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1460=== CONT TestUploadHandlersRejectInvalidKeys1461=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1462=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1463=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1464=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1465=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1466=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1467=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1468=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1469=== CONT TestIsValidUploadKey1470=== RUN TestIsValidUploadKey/narinfo1471=== PAUSE TestIsValidUploadKey/narinfo1472=== RUN TestIsValidUploadKey/nar_zst1473=== PAUSE TestIsValidUploadKey/nar_zst1474=== RUN TestIsValidUploadKey/nar_xz1475=== PAUSE TestIsValidUploadKey/nar_xz1476=== RUN TestIsValidUploadKey/nar_plain1477=== PAUSE TestIsValidUploadKey/nar_plain1478=== RUN TestIsValidUploadKey/listing1479=== PAUSE TestIsValidUploadKey/listing1480=== RUN TestIsValidUploadKey/build_log1481=== PAUSE TestIsValidUploadKey/build_log1482=== RUN TestIsValidUploadKey/build_log_home-manager_file1483=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1484=== RUN TestIsValidUploadKey/build_log_plus_in_name1485=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1486=== RUN TestIsValidUploadKey/build_log_question_mark1487=== PAUSE TestIsValidUploadKey/build_log_question_mark1488=== RUN TestIsValidUploadKey/build_log_equals1489=== PAUSE TestIsValidUploadKey/build_log_equals1490=== RUN TestIsValidUploadKey/realisation1491=== PAUSE TestIsValidUploadKey/realisation1492=== RUN TestIsValidUploadKey/realisation_plus_in_output1493=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1494=== RUN TestIsValidUploadKey/nix-cache-info1495=== PAUSE TestIsValidUploadKey/nix-cache-info1496=== RUN TestIsValidUploadKey/index.html1497=== PAUSE TestIsValidUploadKey/index.html1498=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1499=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1500=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1501=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1502=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1503=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1504=== RUN TestIsValidUploadKey/traversal1505=== PAUSE TestIsValidUploadKey/traversal1506=== RUN TestIsValidUploadKey/traversal_nar1507=== PAUSE TestIsValidUploadKey/traversal_nar1508=== RUN TestIsValidUploadKey/absolute1509=== PAUSE TestIsValidUploadKey/absolute1510=== RUN TestIsValidUploadKey/empty_key1511=== PAUSE TestIsValidUploadKey/empty_key1512=== RUN TestIsValidUploadKey/unknown_type1513=== PAUSE TestIsValidUploadKey/unknown_type1514=== CONT TestPendingClosureWriteTimeout1515=== RUN TestPendingClosureWriteTimeout/empty1516=== PAUSE TestPendingClosureWriteTimeout/empty1517=== RUN TestPendingClosureWriteTimeout/negative1518=== PAUSE TestPendingClosureWriteTimeout/negative1519=== RUN TestPendingClosureWriteTimeout/400_objects1520=== PAUSE TestPendingClosureWriteTimeout/400_objects1521=== RUN TestPendingClosureWriteTimeout/670k_objects1522=== PAUSE TestPendingClosureWriteTimeout/670k_objects1523=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1524=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1525=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15262026/10/01 09:57:48 INFO Received uploads request method=POST path=/api/pending_closures1527--- PASS: TestConnectWaitsForAPeerMigration (6.48s)1528=== CONT TestProxyWriteTimeout1529=== RUN TestProxyWriteTimeout/narinfo1530=== PAUSE TestProxyWriteTimeout/narinfo1531=== RUN TestProxyWriteTimeout/1_GiB_nar1532=== PAUSE TestProxyWriteTimeout/1_GiB_nar1533=== RUN TestProxyWriteTimeout/10_GiB_nar1534=== PAUSE TestProxyWriteTimeout/10_GiB_nar1535=== RUN TestProxyWriteTimeout/unknown_size1536=== PAUSE TestProxyWriteTimeout/unknown_size1537=== CONT TestGCBugBareHashReferences1538--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.36s)1539=== CONT TestParseSize1540--- PASS: TestParseSize (0.00s)1541=== CONT TestCacheConfigHandlerMaxNarSize1542--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1543=== CONT TestTombstonedObjectOfferedWithoutWaiting1544--- PASS: TestPendingClosureFailureTracksEveryUpload (3.24s)1545=== CONT TestGenerateLandingPage1546--- PASS: TestGenerateLandingPage (0.01s)1547=== CONT TestGCSweepSkipsPendingObjects15482026/10/01 09:57:49 INFO Received uploads request method=POST path=/api/pending_closures1549--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.12s)1550=== CONT TestService_readinessHandler15512026/10/01 09:57:49 INFO Received uploads request method=POST path=/api/pending_closures15522026/10/01 09:57:49 INFO Received uploads request method=POST path=/api/pending_closures15532026/10/01 09:57:49 INFO Received uploads request method=POST path=/api/pending_closures15542026/10/01 09:57:50 INFO Received cleanup request method=DELETE path=/api/pending_closures15552026/10/01 09:57:50 INFO Aborted multipart uploads count=0 kept=015562026/10/01 09:57:50 INFO Received uploads request method=POST path=/api/pending_closures15572026/10/01 09:57:50 INFO Received cleanup request method=DELETE path=/api/pending_closures15582026/10/01 09:57:50 INFO Aborted multipart uploads count=1 kept=015592026/10/01 09:57:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15602026-10-01 09:57:50.190 UTC [97547] ERROR: Closure does not exist: id=115612026-10-01 09:57:50.190 UTC [97547] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15622026-10-01 09:57:50.190 UTC [97547] STATEMENT: -- name: CommitPendingClosure :exec1563 SELECT commit_pending_closure($1::bigint)1564 1565--- PASS: TestService_cleanupPendingClosuresHandler (2.17s)1566=== CONT TestDeduplicatedObjectsRecordedAsPending15672026/10/01 09:57:50 INFO Received uploads request method=POST path=/api/pending_closures15682026/10/01 09:57:51 INFO Received uploads request method=POST path=/api/pending_closures15692026/10/01 09:57:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15702026/10/01 09:57:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjdiZTY0MTdiLTZhMGYtNDc0MS05M2Q0LWZhMmY3M2FiNjA1Y3gxNzkwODQ4NjY5ODE5NjQ0MDAw parts=1015712026/10/01 09:57:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15722026/10/01 09:57:51 INFO Completed upload id=115732026/10/01 09:57:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015742026/10/01 09:57:51 INFO Received uploads request method=POST path=/api/pending_closures15752026/10/01 09:57:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures15762026/10/01 09:57:51 INFO Aborted multipart uploads count=0 kept=015772026/10/01 09:57:51 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=015782026/10/01 09:57:51 INFO Vacuumed table table=pending_closures15792026/10/01 09:57:51 INFO Vacuumed table table=pending_objects15802026/10/01 09:57:51 INFO Vacuumed table table=multipart_uploads1581=== NAME TestOrphanedObjectsGCStressTest1582 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15832026/10/01 09:57:51 INFO Vacuumed table table=closures15842026/10/01 09:57:51 INFO Vacuumed table table=objects15852026/10/01 09:57:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001586 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1587--- PASS: TestService_createPendingClosureHandler (3.69s)1588=== CONT TestCreatePendingClosureRejectsOversizedNAR15892026/10/01 09:57:51 INFO Received uploads request method=POST path=/api/pending_closures1590--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1591=== CONT TestPushDedupSurvivesConcurrentGC15922026/10/01 09:57:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15932026/10/01 09:57:51 INFO Received uploads request method=POST path=/api/pending_closures1594--- PASS: TestGCBugBareHashReferences (3.14s)1595=== CONT TestGracefulShutdownDrainsInflight15962026/10/01 09:57:51 INFO Starting HTTP server address=127.0.0.1:5722415972026/10/01 09:57:51 INFO Shutdown signal received, draining in-flight requests timeout=10s1598--- PASS: TestTombstonedObjectOfferedWithoutWaiting (3.14s)1599=== CONT TestGCMetrics1600--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1601=== CONT TestGCAdvisoryLockBlocksConcurrentRun16022026/10/01 09:57:52 INFO Received uploads request method=POST path=/api/pending_closures16032026/10/01 09:57:52 INFO Aborted multipart uploads count=0 kept=016042026/10/01 09:57:52 WARN Force mode enabled - objects will be deleted immediately without grace period16052026/10/01 09:57:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16062026/10/01 09:57:52 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=016072026/10/01 09:57:52 INFO Vacuumed table table=pending_closures16082026/10/01 09:57:52 INFO Vacuumed table table=pending_objects16092026/10/01 09:57:52 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmQzMmRhNTdiLTYwNzctNDlkMi04NTRmLWQ1MWMyNzNmZThkZHgxNzkwODQ4NjcwNzg5NjEwMDAw parts=1016102026/10/01 09:57:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16112026/10/01 09:57:52 INFO Vacuumed table table=multipart_uploads16122026/10/01 09:57:52 INFO Vacuumed table table=closures16132026/10/01 09:57:52 INFO Completed upload id=116142026/10/01 09:57:52 INFO Vacuumed table table=objects16152026/10/01 09:57:52 INFO Received uploads request method=POST path=/api/pending_closures16162026/10/01 09:57:52 INFO Received uploads request method=POST path=/api/pending_closures16172026/10/01 09:57:52 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16182026/10/01 09:57:52 WARN Found objects in DB but missing from S3, will re-upload count=11619--- PASS: TestGCSweepSkipsPendingObjects (3.40s)1620=== CONT TestGCTaskStore_Fail1621--- PASS: TestGCTaskStore_Fail (0.00s)1622=== CONT TestServerTLSConfig1623=== RUN TestServerTLSConfig/no_client_CA1624=== PAUSE TestServerTLSConfig/no_client_CA1625=== RUN TestServerTLSConfig/missing_CA_file1626=== PAUSE TestServerTLSConfig/missing_CA_file1627=== RUN TestServerTLSConfig/not_a_PEM_file1628=== PAUSE TestServerTLSConfig/not_a_PEM_file1629=== CONT TestSweepRechecksPendingAfterLocking16302026/10/01 09:57:52 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16312026/10/01 09:57:52 INFO Completed upload id=31632--- PASS: TestService_verifyS3Integrity (3.96s)1633=== CONT TestGetExistingObjectsLocksRows16342026/10/01 09:57:52 WARN readiness check failed error="closed pool"1635--- PASS: TestService_readinessHandler (3.28s)1636=== CONT TestGCTaskStore_DeduplicateSameParams1637--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1638=== CONT TestGCTaskStore_PhaseUpdates1639--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1640=== CONT TestGCTaskStore_CompletedAllowsNewTask1641--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1642=== CONT TestObjectStatsTrigger16432026/10/01 09:57:52 INFO Received uploads request method=POST path=/api/pending_closures1644--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.51s)1645=== CONT TestService_healthCheckHandler1646=== NAME TestOrphanedObjectsGCStressTest1647 orphaned_objects_gc_test.go:509: Stress test completed successfully:1648 orphaned_objects_gc_test.go:510: - Active objects preserved: 201649 orphaned_objects_gc_test.go:511: - Objects deleted: 2101650 orphaned_objects_gc_test.go:512: - Total GC'd: 2101651--- PASS: TestOrphanedObjectsGCStressTest (8.55s)1652=== CONT TestMultipartCleanup16532026/10/01 09:57:53 INFO Received uploads request method=POST path=/api/pending_closures16542026/10/01 09:57:53 INFO Aborted multipart uploads count=0 kept=016552026/10/01 09:57:53 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=016562026/10/01 09:57:53 INFO Vacuumed table table=pending_closures16572026/10/01 09:57:53 INFO Aborted multipart uploads count=0 kept=016582026/10/01 09:57:53 INFO Vacuumed table table=pending_objects16592026/10/01 09:57:53 WARN Force mode enabled - objects will be deleted immediately without grace period16602026/10/01 09:57:53 INFO Vacuumed table table=multipart_uploads16612026/10/01 09:57:53 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=016622026/10/01 09:57:53 INFO Vacuumed table table=pending_closures16632026/10/01 09:57:53 INFO Vacuumed table table=pending_objects16642026/10/01 09:57:53 INFO Vacuumed table table=multipart_uploads16652026/10/01 09:57:53 INFO Vacuumed table table=closures16662026/10/01 09:57:53 INFO Vacuumed table table=objects1667--- PASS: TestGCMetrics (1.32s)1668=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection16692026/10/01 09:57:53 INFO Vacuumed table table=closures16702026/10/01 09:57:53 INFO Vacuumed table table=objects16712026/10/01 09:57:53 INFO Aborted multipart uploads count=0 kept=016722026/10/01 09:57:53 WARN Force mode enabled - objects will be deleted immediately without grace period16732026/10/01 09:57:53 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=016742026/10/01 09:57:53 INFO Vacuumed table table=pending_closures16752026/10/01 09:57:53 INFO Vacuumed table table=pending_objects16762026/10/01 09:57:53 INFO Vacuumed table table=multipart_uploads16772026/10/01 09:57:53 INFO Vacuumed table table=closures16782026/10/01 09:57:53 INFO Vacuumed table table=objects1679--- PASS: TestPushDedupSurvivesConcurrentGC (1.73s)1680=== CONT TestSweepSkipsRowsLockedByPush16812026/10/01 09:57:53 INFO Aborted multipart uploads count=0 kept=016822026/10/01 09:57:53 WARN Force mode enabled - objects will be deleted immediately without grace period16832026/10/01 09:57:53 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=016842026/10/01 09:57:53 INFO Vacuumed table table=pending_closures16852026/10/01 09:57:53 INFO Vacuumed table table=pending_objects16862026/10/01 09:57:53 INFO Vacuumed table table=multipart_uploads16872026/10/01 09:57:53 INFO Vacuumed table table=closures16882026/10/01 09:57:53 INFO Vacuumed table table=objects1689--- PASS: TestSweepRechecksPendingAfterLocking (1.47s)1690=== CONT TestFailedS3DeleteKeepsTombstone1691--- PASS: TestGetExistingObjectsLocksRows (1.52s)1692=== CONT TestGCTaskStore_GetReturnsLatest1693--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1694=== CONT TestService_AuthMiddleware_OIDC16952026/10/01 09:57:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57266/oidc1696--- PASS: TestObjectStatsTrigger (1.69s)1697=== CONT TestRegisterCompletedObjectNeedsPendingRow1698--- PASS: TestService_healthCheckHandler (1.58s)1699=== CONT TestForceGCDuringPushOffersSweptObject1700=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1701=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1702=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1703=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1704=== CONT TestPendingClosureFailureAbortsItsUploads17052026/10/01 09:57:54 INFO Aborted multipart uploads count=1 kept=017062026/10/01 09:57:54 INFO Received cleanup request method=DELETE path=/api/pending_closures17072026/10/01 09:57:54 INFO Aborted multipart uploads count=1 kept=01708--- PASS: TestPendingCleanupUsesOneCutoff (8.53s)1709=== CONT TestRedundantMultipartUpload17102026/10/01 09:57:54 INFO Received uploads request method=POST path=/api/pending_closures17112026/10/01 09:57:54 INFO Received cleanup request method=DELETE path=/api/pending_closures17122026/10/01 09:57:54 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket62/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17132026/10/01 09:57:54 INFO Aborted multipart uploads count=0 kept=117142026/10/01 09:57:54 INFO Received cleanup request method=DELETE path=/api/pending_closures17152026/10/01 09:57:54 INFO Aborted multipart uploads count=1 kept=01716--- PASS: TestMultipartCleanup (1.81s)1717=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit17182026/10/01 09:57:54 INFO Aborted multipart uploads count=0 kept=017192026/10/01 09:57:54 WARN Force mode enabled - objects will be deleted immediately without grace period17202026/10/01 09:57:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017212026/10/01 09:57:54 INFO Vacuumed table table=pending_closures17222026/10/01 09:57:54 INFO Vacuumed table table=pending_objects17232026/10/01 09:57:54 INFO Vacuumed table table=multipart_uploads17242026/10/01 09:57:54 INFO Vacuumed table table=closures17252026/10/01 09:57:54 INFO Vacuumed table table=objects17262026/10/01 09:57:54 INFO Aborted multipart uploads count=0 kept=017272026/10/01 09:57:54 WARN Force mode enabled - objects will be deleted immediately without grace period17282026/10/01 09:57:54 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=017292026/10/01 09:57:54 INFO Vacuumed table table=pending_closures17302026/10/01 09:57:54 INFO Vacuumed table table=pending_objects17312026/10/01 09:57:54 INFO Vacuumed table table=multipart_uploads17322026/10/01 09:57:54 INFO Vacuumed table table=closures17332026/10/01 09:57:54 INFO Vacuumed table table=objects1734--- PASS: TestSweepSkipsRowsLockedByPush (1.45s)1735=== CONT TestPush_CompleteCommitsEveryRoot17362026/10/01 09:57:54 INFO Received uploads request method=POST path=/api/pending_closures17372026/10/01 09:57:55 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"1738--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.86s)1739=== CONT TestService_ReadScope_PublicByDefault1740--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.17s)1741=== CONT TestPush_RejectsBadRequests17422026/10/01 09:57:55 INFO Received uploads request method=POST path=/api/pending_closures17432026/10/01 09:57:55 INFO Aborted multipart uploads count=0 kept=017442026/10/01 09:57:55 WARN Force mode enabled - objects will be deleted immediately without grace period17452026/10/01 09:57:55 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17462026/10/01 09:57:55 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17472026/10/01 09:57:55 WARN Rate limiter enabled after throttle name=s3-test rate=517482026/10/01 09:57:55 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1749=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1750 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101751 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001752--- PASS: TestFailedS3DeleteKeepsTombstone (1.77s)1753=== CONT TestService_Rustfstest1754--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.87s)1755=== CONT TestPresignedUploadRegisteredBeforeCommit1756=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1757=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1758=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1759=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1760=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1761=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1762=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1763=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1764=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1765--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.73s)1766=== CONT TestCompletedNarNotReofferedAcrossClosures17672026/10/01 09:57:56 INFO Received uploads request method=POST path=/api/pending_closures1768--- PASS: TestPendingClosureFailureAbortsItsUploads (1.89s)1769=== CONT TestPush_SignsNarinfosOfItsPendingObjects17702026/10/01 09:57:56 INFO Received uploads request method=POST path=/api/pending_closures17712026/10/01 09:57:56 INFO Received uploads request method=POST path=/api/pending_closures17722026/10/01 09:57:56 INFO Received push request method=POST path=/api/pushes17732026/10/01 09:57:56 INFO Received push request method=POST path=/api/pushes1774--- PASS: TestService_ReadScope_PublicByDefault (2.06s)1775=== CONT TestLeadElectsOneAndHandsOver1776=== RUN TestPush_RejectsBadRequests/no_roots1777=== PAUSE TestPush_RejectsBadRequests/no_roots1778=== RUN TestPush_RejectsBadRequests/no_objects1779=== PAUSE TestPush_RejectsBadRequests/no_objects1780=== RUN TestPush_RejectsBadRequests/bad_root1781=== PAUSE TestPush_RejectsBadRequests/bad_root1782=== RUN TestPush_RejectsBadRequests/root_not_in_objects1783=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1784=== CONT TestService_RequireScope_OIDC17852026/10/01 09:57:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57344/oidc17862026/10/01 09:57:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17872026/10/01 09:57:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17882026/10/01 09:57:58 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjBmYjg4YjlhLTI0MmQtNGFhZC1hNzRhLTNhM2UzYjE5ZGU1NXgxNzkwODQ4Njc2NjAwMzE4MDAw parts=1017892026/10/01 09:57:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjBlMmI5NTc4LWIxMjgtNGJhYS1hYzhmLWY1NWY0Zjk2MGM0MngxNzkwODQ4Njc2Mzg1NzY4MDAw parts=1217902026/10/01 09:57:58 INFO Received uploads request method=POST path=/api/pending_closures17912026/10/01 09:57:58 INFO Received uploads request method=POST path=/api/pending_closures17922026/10/01 09:57:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17932026/10/01 09:57:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjM5NzFhOTQxLTliYWMtNGNlZC1iNTM3LTYwMGY0YTNmYWI2MXgxNzkwODQ4Njc2OTA3MTQzMDAw parts=101794--- PASS: TestService_Rustfstest (3.04s)1795=== CONT TestService_AuthMiddleware17962026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures17972026/10/01 09:57:59 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17982026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures1799--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.45s)1800=== CONT TestCacheConfigHandler1801=== RUN TestCacheConfigHandler/full_config,_no_issuer1802=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1803=== RUN TestCacheConfigHandler/no_cache_url_configured1804=== PAUSE TestCacheConfigHandler/no_cache_url_configured1805=== RUN TestCacheConfigHandler/no_signing_keys1806=== PAUSE TestCacheConfigHandler/no_signing_keys1807=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1808=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1809=== CONT TestGCTaskStore_ConflictDifferentParams1810--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1811=== CONT TestService_ReadAuthMiddleware18122026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures18132026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures18142026/10/01 09:57:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18152026/10/01 09:57:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjIwMmM1ZDMwLWQxM2UtNDUxYi1iZjgyLWVjYTQwYmYyOTVjOHgxNzkwODQ4Njc5NTU3MDIzMDAw18162026/10/01 09:58:00 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjIwMmM1ZDMwLWQxM2UtNDUxYi1iZjgyLWVjYTQwYmYyOTVjOHgxNzkwODQ4Njc5NTU3MDIzMDAw error="Delete \"http://localhost:56816/bucket77/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjIwMmM1ZDMwLWQxM2UtNDUxYi1iZjgyLWVjYTQwYmYyOTVjOHgxNzkwODQ4Njc5NTU3MDIzMDAw\": injected: abort refused"18172026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18182026/10/01 09:58:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjIwMmM1ZDMwLWQxM2UtNDUxYi1iZjgyLWVjYTQwYmYyOTVjOHgxNzkwODQ4Njc5NTU3MDIzMDAw18192026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjIwMmM1ZDMwLWQxM2UtNDUxYi1iZjgyLWVjYTQwYmYyOTVjOHgxNzkwODQ4Njc5NTU3MDIzMDAw parts=11820--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (4.43s)1821=== CONT TestReadProxyRangeRequest18222026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18232026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmFlMWZjMjVlLTAzOGEtNDU1Yy05YjkyLTIxZmE5YzdkZDIyOHgxNzkwODQ4Njc2NTk5NzYxMDAw parts=1018242026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete18252026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes18262026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes18272026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=018282026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period18292026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18302026/10/01 09:58:00 INFO Signed narinfos id=1 count=11831--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (4.23s)1832=== CONT TestPush_OverlappingRootsStoreOneRowPerKey18332026/10/01 09:58:00 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=018342026/10/01 09:58:00 INFO Vacuumed table table=pending_closures18352026/10/01 09:58:00 INFO Vacuumed table table=pending_objects18362026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18372026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads18382026/10/01 09:58:00 INFO Vacuumed table table=closures18392026/10/01 09:58:00 INFO Vacuumed table table=objects18402026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmRjODQzNTY3LWEyZjItNDQ1My1iZmQwLTQzYTY5ZTlhNjBhY3gxNzkwODQ4Njc2OTA3MjI2MDAw parts=1018412026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18422026/10/01 09:58:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjRiZDRkZTU0LTI1ZGYtNGY1Yi04ZWEwLTUwYjE1OTg4ZDJjN3gxNzkwODQ4Njc4NDYzNjI5MDAw error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18432026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LjMxNjA5ZDBiLWMxYTUtNGEyNS04YTVlLTlmYTIwYzgyMDQ3OXgxNzkwODQ4Njc4NDE2MDE0MDAw parts=1218442026/10/01 09:58:00 INFO Received cleanup request method=DELETE path=/api/pending_closures18452026/10/01 09:58:00 INFO Aborted multipart uploads count=1 kept=01846--- PASS: TestRedundantMultipartUpload (6.52s)1847=== CONT TestReadRedirectUsesPublicS3URL18482026/10/01 09:58:01 INFO lead: acquired remote=192.0.2.1:12341849=== RUN TestService_RequireScope_OIDC/builder_may_write1850=== PAUSE TestService_RequireScope_OIDC/builder_may_write1851=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1852=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1853=== RUN TestService_RequireScope_OIDC/ops_may_admin1854=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1855=== RUN TestService_RequireScope_OIDC/ops_may_not_write1856=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1857=== RUN TestService_RequireScope_OIDC/reader_may_not_write1858=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1859=== RUN TestService_RequireScope_OIDC/static_token_may_admin1860=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1861=== RUN TestService_RequireScope_OIDC/static_token_may_write1862=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1863=== RUN TestService_RequireScope_OIDC/reader_may_read1864=== PAUSE TestService_RequireScope_OIDC/reader_may_read1865=== RUN TestService_RequireScope_OIDC/writer_implies_read1866=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1867=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1868=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1869=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18702026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18712026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmZiYzgxODU0LWNjMDctNGY3Ni05NDNlLTYwOGRjYzEzYjAwYXgxNzkwODQ4Njc5ODM2MTY1MDAw parts=1218722026/10/01 09:58:02 INFO Received uploads request method=POST path=/api/pending_closures1873--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.33s)1874=== CONT TestCacheStatsHandler18752026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18762026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmIxNGNlN2VjLWRlMDgtNGY1Ni1hZTZiLWJiMjU5ODZkN2I2N3gxNzkwODQ4NjgwMjQzNzY5MDAw parts=1018772026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/2/complete1878--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.65s)1879=== CONT TestLeadEndsOnShutdown18802026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18812026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJhOGZlOTUtNWFmMC00MDhmLThiNGItMjE0MGViYmEwODc1LmVlNDY4YzA4LTJhYjMtNGNjYy05ZTdjLTcxZDIxMDE5OTA4YngxNzkwODQ4Njc2OTA2NjY4MDAw parts=1018822026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1883--- PASS: TestPush_CompleteCommitsEveryRoot (7.73s)1884=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18852026/10/01 09:58:02 INFO lead: released remote=192.0.2.1:123418862026/10/01 09:58:02 INFO lead: acquired remote=192.0.2.1:12341887--- PASS: TestService_ReadAuthMiddleware (3.78s)1888=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18892026/10/01 09:58:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1890--- PASS: TestService_AuthMiddleware (4.43s)1891=== CONT TestGCEndsOnShutdown/before_the_run1892--- PASS: TestReadProxyRangeRequest (3.29s)1893=== CONT TestResolveDBConnectionString/flag_wins1894=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1895=== CONT TestResolveDBConnectionString/file_when_flag_empty1896=== CONT TestResolveDBConnectionString/nothing_configured1897=== CONT TestResolveDBConnectionString/missing_file_is_an_error1898=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1899=== CONT TestIsValidCachePath/traversal_parent1900=== CONT TestIsValidCachePath/index.html1901=== CONT TestIsValidCachePath/invalid_char_e1902=== CONT TestIsValidCachePath/nix-cache-info1903=== CONT TestIsValidCachePath/log1904=== CONT TestIsValidCachePath/ls1905=== CONT TestIsValidCachePath/short_hash1906=== CONT TestIsValidCachePath/realisation1907=== CONT TestIsValidCachePath/nar_uncompressed1908=== CONT TestIsValidCachePath/nar_zst1909=== CONT TestIsValidCachePath/leading_slash1910=== CONT TestIsValidCachePath/nar_xz1911=== CONT TestIsValidCachePath/wrong_extension1912=== CONT TestIsValidCachePath/nar_bz21913=== CONT TestIsValidCachePath/random_path1914=== CONT TestIsValidCachePath/empty1915=== CONT TestIsValidCachePath/invalid_char_u1916=== CONT TestIsValidCachePath/narinfo1917=== CONT TestIsValidCachePath/traversal_in_middle1918=== CONT TestParseSingleRange/none1919--- PASS: TestIsValidCachePath (0.00s)1920 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1921 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1922 --- PASS: TestIsValidCachePath/index.html (0.00s)1923 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1924 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1925 --- PASS: TestIsValidCachePath/log (0.00s)1926 --- PASS: TestIsValidCachePath/ls (0.00s)1927 --- PASS: TestIsValidCachePath/short_hash (0.00s)1928 --- PASS: TestIsValidCachePath/realisation (0.00s)1929 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1930 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1931 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1932 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1933 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1934 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1935 --- PASS: TestIsValidCachePath/random_path (0.00s)1936 --- PASS: TestIsValidCachePath/empty (0.00s)1937 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1938 --- PASS: TestIsValidCachePath/narinfo (0.00s)1939 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1940=== CONT TestParseSingleRange/start_far_past_EOF1941=== CONT TestParseSingleRange/start_past_EOF1942=== CONT TestParseSingleRange/single_byte1943=== CONT TestParseSingleRange/suffix1944=== CONT TestParseSingleRange/suffix_exceeds_size1945=== CONT TestParseSingleRange/open-ended1946=== CONT TestParseSingleRange/closed1947=== CONT TestParseSingleRange/malformed_end_before_start1948=== CONT TestParseSingleRange/end_clamped_to_size1949=== CONT TestParseSingleRange/malformed_no_dash1950=== CONT TestParseSingleRange/multi-range_ignored1951=== CONT TestParseSingleRange/malformed_both_empty1952=== CONT TestParseSingleRange/unknown_unit1953=== CONT TestClientErrorHandling/InvalidAuthToken1954--- PASS: TestParseSingleRange (0.00s)1955 --- PASS: TestParseSingleRange/none (0.00s)1956 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1957 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1958 --- PASS: TestParseSingleRange/single_byte (0.00s)1959 --- PASS: TestParseSingleRange/suffix (0.00s)1960 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1961 --- PASS: TestParseSingleRange/open-ended (0.00s)1962 --- PASS: TestParseSingleRange/closed (0.00s)1963 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1964 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1965 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1966 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1967 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1968 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1969--- PASS: TestResolveDBConnectionString (0.03s)1970 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1971 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1972 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1973 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1974 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)19752026/10/01 09:58:03 INFO Received push request method=POST path=/api/pushes1976--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.39s)1977=== CONT TestClientErrorHandling/ServerNotAvailable19782026/10/01 09:58:03 INFO lead: released remote=192.0.2.1:12341979--- PASS: TestLeadElectsOneAndHandsOver (6.71s)1980=== CONT TestClientErrorHandling/InvalidStorePath1981--- PASS: TestReadRedirectUsesPublicS3URL (3.16s)1982=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19832026/10/01 09:58:04 INFO Received uploads request method=POST path=/19842026/10/01 09:58:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19852026/10/01 09:58:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.361742ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19862026/10/01 09:58:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.196941ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1987--- PASS: TestCacheStatsHandler (2.21s)1988=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19892026/10/01 09:58:04 INFO Received request for more parts method=POST path=/19902026/10/01 09:58:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19912026/10/01 09:58:04 WARN mTLS auth: bound subjects configured but subject DN unavailable19922026/10/01 09:58:04 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1993--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.55s)1994=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19952026/10/01 09:58:04 INFO Received complete multipart upload request method=POST path=/1996=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19972026/10/01 09:58:04 INFO Received uploads request method=POST path=/1998=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19992026/10/01 09:58:04 INFO Received request for more parts method=POST path=/2000=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20012026/10/01 09:58:04 INFO Received complete multipart upload request method=POST path=/2002=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20032026/10/01 09:58:04 INFO Received uploads request method=POST path=/2004=== CONT TestIsValidUploadKey/nar_xz2005--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2006 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2007 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2008 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2009 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2010=== CONT TestIsValidUploadKey/unknown_type2011=== CONT TestIsValidUploadKey/absolute2012=== CONT TestIsValidUploadKey/traversal_nar2013=== CONT TestIsValidUploadKey/empty_key2014=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2015=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2016=== CONT TestIsValidUploadKey/traversal2017=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2018=== CONT TestIsValidUploadKey/nix-cache-info2019=== CONT TestIsValidUploadKey/index.html2020=== CONT TestIsValidUploadKey/realisation2021=== CONT TestIsValidUploadKey/build_log_equals2022=== CONT TestIsValidUploadKey/realisation_plus_in_output2023=== CONT TestIsValidUploadKey/build_log_question_mark2024=== CONT TestIsValidUploadKey/build_log_plus_in_name2025=== CONT TestIsValidUploadKey/build_log_home-manager_file2026=== CONT TestIsValidUploadKey/build_log2027=== CONT TestIsValidUploadKey/nar_plain2028=== CONT TestIsValidUploadKey/listing2029=== CONT TestIsValidUploadKey/nar_zst2030=== CONT TestIsValidUploadKey/narinfo2031--- PASS: TestIsValidUploadKey (0.00s)2032 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2033 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2034 --- PASS: TestIsValidUploadKey/absolute (0.00s)2035 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2036 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2037 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2038 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2039 --- PASS: TestIsValidUploadKey/traversal (0.00s)2040 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2041 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2042 --- PASS: TestIsValidUploadKey/index.html (0.00s)2043 --- PASS: TestIsValidUploadKey/realisation (0.00s)2044 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2045 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2046 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2047 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2048 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2049 --- PASS: TestIsValidUploadKey/build_log (0.00s)2050 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2051 --- PASS: TestIsValidUploadKey/listing (0.00s)2052 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2053 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2054=== CONT TestPendingClosureWriteTimeout/400_objects2055=== CONT TestPendingClosureWriteTimeout/670k_objects2056=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20572026/10/01 09:58:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=850.089899ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20582026/10/01 09:58:04 INFO Aborted multipart uploads count=0 kept=020592026/10/01 09:58:04 WARN Force mode enabled - objects will be deleted immediately without grace period20602026-10-01 09:58:04.863 UTC [97746] ERROR: canceling statement due to user request20612026-10-01 09:58:04.863 UTC [97746] STATEMENT: -- name: MarkStaleObjects :execrows2062 WITH RECURSIVE ct AS (2063 SELECT timezone('UTC', now()) AS now2064 ),2065 closure_reach AS (2066 -- Start with all closure keys2067 SELECT o.key, o.refs2068 FROM objects o2069 INNER JOIN closures c ON o.key = c.key2070 UNION2071 -- Recursively add all referenced objects2072 SELECT o.key, o.refs2073 FROM objects o2074 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2075 ),2076 reachable_objects AS (2077 SELECT DISTINCT key FROM closure_reach2078 ),2079 stale_objects AS (2080 SELECT o.key2081 FROM objects AS o, ct2082 WHERE2083 NOT EXISTS (2084 SELECT 12085 FROM reachable_objects ro2086 WHERE ro.key = o.key2087 )2088 AND NOT EXISTS (2089 SELECT 12090 FROM pending_objects AS po2091 WHERE po.key = o.key2092 )2093 AND o.deleted_at IS NULL -- Only mark fresh objects2094 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2095 FOR UPDATE2096 )2097 UPDATE objects2098 SET2099 deleted_at = ct.now,2100 first_deleted_at = COALESCE(first_deleted_at, ct.now)2101 FROM stale_objects, ct2102 WHERE objects.key = stale_objects.key2103 2104=== CONT TestPendingClosureWriteTimeout/negative2105=== CONT TestPendingClosureWriteTimeout/empty2106=== CONT TestProxyWriteTimeout/narinfo2107=== CONT TestProxyWriteTimeout/1_GiB_nar2108=== CONT TestProxyWriteTimeout/10_GiB_nar2109=== CONT TestProxyWriteTimeout/unknown_size2110=== CONT TestServerTLSConfig/missing_CA_file2111=== CONT TestServerTLSConfig/not_a_PEM_file2112--- PASS: TestProxyWriteTimeout (0.00s)2113 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2114 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2115 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2116 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2117=== CONT TestServerTLSConfig/no_client_CA2118=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2119=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2120--- PASS: TestServerTLSConfig (0.00s)2121 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2122 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2123 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)21242026/10/01 09:58:05 INFO lead: acquired remote=192.0.2.1:123421252026/10/01 09:58:05 INFO Aborted multipart uploads count=0 kept=021262026/10/01 09:58:05 WARN Force mode enabled - objects will be deleted immediately without grace period21272026/10/01 09:58:05 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:56816/bucket91/?delete=\": context canceled"2128=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2129=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2130=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21312026/10/01 09:58:05 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]2132=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21332026/10/01 09:58:05 WARN Authentication failed token_preview=eyJhbGciOi...y8vfdkosrA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2134=== CONT TestPush_RejectsBadRequests/no_roots21352026/10/01 09:58:05 INFO Received push request method=POST path=/api/pushes2136=== CONT TestPush_RejectsBadRequests/root_not_in_objects21372026/10/01 09:58:05 INFO Received push request method=POST path=/api/pushes2138=== CONT TestPush_RejectsBadRequests/no_objects21392026/10/01 09:58:05 INFO Received push request method=POST path=/api/pushes2140=== CONT TestPush_RejectsBadRequests/bad_root21412026/10/01 09:58:05 INFO Received push request method=POST path=/api/pushes2142=== CONT TestCacheConfigHandler/no_signing_keys2143=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2144=== CONT TestCacheConfigHandler/full_config,_no_issuer2145=== CONT TestCacheConfigHandler/no_cache_url_configured2146=== CONT TestService_RequireScope_OIDC/builder_may_write2147--- PASS: TestCacheConfigHandler (0.00s)2148 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2149 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2150 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2151 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2152=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2153=== CONT TestService_RequireScope_OIDC/writer_implies_read2154=== CONT TestService_RequireScope_OIDC/reader_may_read2155=== CONT TestService_RequireScope_OIDC/static_token_may_write2156=== CONT TestService_RequireScope_OIDC/static_token_may_admin2157=== CONT TestService_RequireScope_OIDC/ops_may_not_write2158=== CONT TestService_RequireScope_OIDC/reader_may_not_write2159=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2160=== CONT TestService_RequireScope_OIDC/ops_may_admin2161--- PASS: TestPush_RejectsBadRequests (2.40s)2162 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2163 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2164 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2165 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2166--- PASS: TestService_AuthMiddleware_OIDC (1.76s)2167 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2168 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2169 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2170 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2171--- PASS: TestService_RequireScope_OIDC (4.50s)2172 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2173 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2174 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2175 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2176 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2177 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2178 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2179 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2180 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2181 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2182--- PASS: TestGCEndsOnShutdown (0.01s)2183 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.32s)2184 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.46s)2185 --- PASS: TestGCEndsOnShutdown/before_the_run (2.42s)21862026/10/01 09:58:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.732310806s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21872026/10/01 09:58:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21882026/10/01 09:58:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21892026/10/01 09:58:06 INFO lead: released remote=192.0.2.1:12342190--- PASS: TestLeadEndsOnShutdown (3.75s)21912026/10/01 09:58:06 INFO Received uploads request method=POST path=/api/pending_closures21922026/10/01 09:58:06 INFO Received uploads request method=POST path=/api/pending_closures21932026/10/01 09:58:06 INFO Aborted multipart uploads count=0 kept=021942026/10/01 09:58:06 WARN Force mode enabled - objects will be deleted immediately without grace period21952026/10/01 09:58:06 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=021962026/10/01 09:58:06 INFO Vacuumed table table=pending_closures21972026/10/01 09:58:06 INFO Vacuumed table table=pending_objects21982026/10/01 09:58:06 INFO Vacuumed table table=multipart_uploads21992026/10/01 09:58:06 INFO Vacuumed table table=closures22002026/10/01 09:58:06 INFO Vacuumed table table=objects22012026/10/01 09:58:06 INFO Received uploads request method=POST path=/api/pending_closures22022026/10/01 09:58:06 INFO Aborted multipart uploads count=0 kept=022032026/10/01 09:58:06 WARN Force mode enabled - objects will be deleted immediately without grace period22042026/10/01 09:58:06 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=022052026/10/01 09:58:06 INFO Vacuumed table table=pending_closures22062026/10/01 09:58:06 INFO Vacuumed table table=pending_objects22072026/10/01 09:58:06 INFO Vacuumed table table=multipart_uploads22082026/10/01 09:58:06 INFO Vacuumed table table=closures22092026/10/01 09:58:06 INFO Vacuumed table table=objects2210--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2211 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.57s)2212 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.77s)2213--- PASS: TestPendingClosureWriteTimeout (0.00s)2214 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2215 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2216 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2217 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2218 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.30s)22192026/10/01 09:58:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/10/01 09:58:07 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.415225ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22212026/10/01 09:58:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=371.171396ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/10/01 09:58:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.190942ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2223--- PASS: TestUploadHandlersRejectOversizedBody (0.07s)2224 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.27s)2225 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.28s)2226 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.30s)22272026/10/01 09:58:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.653779514s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/10/01 09:58:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22292026/10/01 09:58:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/10/01 09:58:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.426524ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/10/01 09:58:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=438.07635ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/10/01 09:58:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=834.627978ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/01 09:58:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.52283309s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/10/01 09:58:13 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22352026/10/01 09:58:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.57976ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22362026/10/01 09:58:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.926429ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22372026/10/01 09:58:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=760.523472ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22382026/10/01 09:58:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.726989233s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2239--- PASS: TestClientErrorHandling (0.00s)2240 --- PASS: TestClientErrorHandling/InvalidStorePath (2.03s)2241 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.61s)2242 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.14s)2243PASS2244{"timestamp":"2026-10-01T09:58:16.948142Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57118","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}2245{"timestamp":"2026-10-01T09:58:16.948544Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57098","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}2246{"timestamp":"2026-10-01T09:58:16.950419Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57117","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}22472026-10-01 09:58:17.099 UTC [97177] LOG: received smart shutdown request22482026-10-01 09:58:17.100 UTC [97177] LOG: background worker "logical replication launcher" (PID 97187) exited with exit code 122492026-10-01 09:58:17.103 UTC [97182] LOG: shutting down22502026-10-01 09:58:17.103 UTC [97182] LOG: checkpoint starting: shutdown immediate22512026-10-01 09:58:18.407 UTC [97182] LOG: checkpoint complete: wrote 12574 buffers (76.7%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.696 s, sync=0.565 s, total=1.304 s; sync files=33361, longest=0.001 s, average=0.001 s; distance=475127 kB, estimate=475127 kB; lsn=0/1E78ABA8, redo lsn=0/1E78ABA822522026-10-01 09:58:18.413 UTC [97177] LOG: database system is shut down2253Running OIDC tests...2254=== RUN TestAudienceForIssuer2255=== PAUSE TestAudienceForIssuer2256=== RUN TestHTTPClientForHasTimeouts2257=== PAUSE TestHTTPClientForHasTimeouts2258=== RUN TestGlobMatch2259=== PAUSE TestGlobMatch2260=== RUN TestValidateToken_ValidToken2261=== PAUSE TestValidateToken_ValidToken2262=== RUN TestValidateToken_WrongAudience2263=== PAUSE TestValidateToken_WrongAudience2264=== RUN TestValidateToken_Expired2265=== PAUSE TestValidateToken_Expired2266=== RUN TestValidateToken_BoundClaimsMismatch2267=== PAUSE TestValidateToken_BoundClaimsMismatch2268=== RUN TestValidateToken_BoundSubjectMismatch2269=== PAUSE TestValidateToken_BoundSubjectMismatch2270=== RUN TestValidateToken_MultipleProviders2271=== PAUSE TestValidateToken_MultipleProviders2272=== RUN TestValidateToken_NoMatchingProvider2273=== PAUSE TestValidateToken_NoMatchingProvider2274=== RUN TestValidateToken_KubernetesServiceAccount2275=== PAUSE TestValidateToken_KubernetesServiceAccount2276=== RUN TestNewValidator_KubernetesRequiresCA2277=== PAUSE TestNewValidator_KubernetesRequiresCA2278=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2279=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2280=== RUN TestPins_ReservedForMatchingRule2281=== PAUSE TestPins_ReservedForMatchingRule2282=== RUN TestPins_TopLevelShorthand2283=== PAUSE TestPins_TopLevelShorthand2284=== RUN TestPins_ConfigValidation2285=== PAUSE TestPins_ConfigValidation2286=== RUN TestScopes_LegacyProviderDefaultsToWrite2287=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2288=== RUN TestScopes_Rules2289=== PAUSE TestScopes_Rules2290=== RUN TestScopes_ConfigValidation2291=== PAUSE TestScopes_ConfigValidation2292=== CONT TestAudienceForIssuer2293=== CONT TestValidateToken_NoMatchingProvider2294--- PASS: TestAudienceForIssuer (0.00s)2295=== CONT TestValidateToken_ValidToken2296=== CONT TestGlobMatch2297=== RUN TestGlobMatch/foo_foo2298=== PAUSE TestGlobMatch/foo_foo2299=== RUN TestGlobMatch/foo_bar2300=== CONT TestValidateToken_WrongAudience2301=== CONT TestHTTPClientForHasTimeouts2302=== CONT TestPins_ConfigValidation2303=== CONT TestValidateToken_BoundSubjectMismatch2304=== CONT TestValidateToken_MultipleProviders2305=== CONT TestPins_ReservedForMatchingRule2306=== CONT TestScopes_Rules2307=== PAUSE TestGlobMatch/foo_bar2308=== RUN TestGlobMatch/*_2309=== PAUSE TestGlobMatch/*_2310=== RUN TestGlobMatch/*_anything2311=== PAUSE TestGlobMatch/*_anything2312=== RUN TestGlobMatch/foo*_foo2313=== PAUSE TestGlobMatch/foo*_foo2314=== RUN TestGlobMatch/foo*_foobar2315=== PAUSE TestGlobMatch/foo*_foobar2316=== RUN TestGlobMatch/foo*_bar2317=== PAUSE TestGlobMatch/foo*_bar2318=== RUN TestGlobMatch/*bar_bar2319=== PAUSE TestGlobMatch/*bar_bar2320=== RUN TestGlobMatch/*bar_foobar2321=== PAUSE TestGlobMatch/*bar_foobar2322=== RUN TestGlobMatch/*bar_foo2323=== PAUSE TestGlobMatch/*bar_foo2324=== RUN TestGlobMatch/foo*bar_foobar2325=== PAUSE TestGlobMatch/foo*bar_foobar2326=== RUN TestGlobMatch/foo*bar_foo123bar2327=== PAUSE TestGlobMatch/foo*bar_foo123bar2328=== RUN TestGlobMatch/foo*bar_foobarbaz2329=== PAUSE TestGlobMatch/foo*bar_foobarbaz2330=== RUN TestGlobMatch/*/*_foo/bar2331=== PAUSE TestGlobMatch/*/*_foo/bar2332=== RUN TestGlobMatch/*/*_foo2333=== PAUSE TestGlobMatch/*/*_foo2334=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2335=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2336=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02337=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02338=== RUN TestGlobMatch/refs/*/main_refs/heads/main2339=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2340=== RUN TestGlobMatch/fo?_foo2341=== PAUSE TestGlobMatch/fo?_foo2342=== RUN TestGlobMatch/fo?_fo2343=== PAUSE TestGlobMatch/fo?_fo2344=== RUN TestGlobMatch/fo?_fooo2345=== PAUSE TestGlobMatch/fo?_fooo2346=== RUN TestGlobMatch/?oo_foo2347=== PAUSE TestGlobMatch/?oo_foo2348=== RUN TestGlobMatch/?oo_boo2349=== PAUSE TestGlobMatch/?oo_boo2350=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2351=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2352=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2353=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2354=== CONT TestPins_TopLevelShorthand2355--- PASS: TestPins_ConfigValidation (0.00s)2356=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23572026/10/01 09:58:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232358--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2359=== CONT TestScopes_LegacyProviderDefaultsToWrite23602026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57525/oidc2361=== CONT TestNewValidator_KubernetesRequiresCA2362--- PASS: TestPins_TopLevelShorthand (0.05s)23632026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57527/oidc2364--- PASS: TestScopes_Rules (0.07s)2365=== CONT TestValidateToken_BoundClaimsMismatch23662026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57529/oidc2367--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)2368=== CONT TestScopes_ConfigValidation2369--- PASS: TestScopes_ConfigValidation (0.00s)2370=== CONT TestValidateToken_Expired23712026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57531/oidc2372=== CONT TestValidateToken_KubernetesServiceAccount2373--- PASS: TestPins_ReservedForMatchingRule (0.12s)23742026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57533/oidc2375--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2376=== CONT TestGlobMatch/*_2377=== CONT TestGlobMatch/foo*bar_foobarbaz2378=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2379=== CONT TestGlobMatch/?oo_boo2380=== CONT TestGlobMatch/?oo_foo2381=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2382=== CONT TestGlobMatch/fo?_fo2383=== CONT TestGlobMatch/fo?_fooo2384=== CONT TestGlobMatch/fo?_foo2385=== CONT TestGlobMatch/refs/*/main_refs/heads/main2386=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02387=== CONT TestGlobMatch/*/*_foo2388=== CONT TestGlobMatch/*/*_foo/bar2389=== CONT TestGlobMatch/*bar_foobar2390=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2391=== CONT TestGlobMatch/foo*bar_foo123bar2392=== CONT TestGlobMatch/*bar_foo2393=== CONT TestGlobMatch/foo*bar_foobar2394=== CONT TestGlobMatch/*bar_bar2395=== CONT TestGlobMatch/*_anything2396=== CONT TestGlobMatch/foo*_bar2397=== CONT TestGlobMatch/foo*_foo2398=== CONT TestGlobMatch/foo_bar2399=== CONT TestGlobMatch/foo*_foobar2400=== CONT TestGlobMatch/foo_foo2401--- PASS: TestGlobMatch (0.00s)2402 --- PASS: TestGlobMatch/*_ (0.00s)2403 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2404 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2405 --- PASS: TestGlobMatch/?oo_boo (0.00s)2406 --- PASS: TestGlobMatch/?oo_foo (0.00s)2407 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/fo?_fo (0.00s)2409 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2410 --- PASS: TestGlobMatch/fo?_foo (0.00s)2411 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2412 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2413 --- PASS: TestGlobMatch/*/*_foo (0.00s)2414 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2416 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2418 --- PASS: TestGlobMatch/*bar_foo (0.00s)2419 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/*bar_bar (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/foo*_bar (0.00s)2423 --- PASS: TestGlobMatch/foo*_foo (0.00s)2424 --- PASS: TestGlobMatch/foo_bar (0.00s)2425 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2426 --- PASS: TestGlobMatch/foo_foo (0.00s)24272026/10/01 09:58:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57524/oidc2428--- PASS: TestValidateToken_NoMatchingProvider (0.16s)2429--- PASS: TestHTTPClientForHasTimeouts (0.20s)24302026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57540/oidc24312026/10/01 09:58:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:575382432--- PASS: TestValidateToken_BoundClaimsMismatch (0.15s)24332026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57542/oidc2434--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)2435--- PASS: TestValidateToken_Expired (0.15s)24362026/10/01 09:58:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57535/oidc24372026/10/01 09:58:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57544/oidc2438--- PASS: TestValidateToken_MultipleProviders (0.24s)24392026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57547/oidc2440--- PASS: TestValidateToken_WrongAudience (0.25s)24412026/10/01 09:58:21 http: TLS handshake error from 127.0.0.1:57550: remote error: tls: bad certificate2442--- PASS: TestNewValidator_KubernetesRequiresCA (0.22s)24432026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57551/oidc2444--- PASS: TestValidateToken_ValidToken (0.39s)2445PASS2446Running signing tests...2447=== RUN TestGenerateFingerprint2448=== PAUSE TestGenerateFingerprint2449=== RUN TestParseSigningKey2450=== PAUSE TestParseSigningKey2451=== RUN TestSignMessage2452=== PAUSE TestSignMessage2453=== RUN TestSignNarinfo2454=== PAUSE TestSignNarinfo2455=== CONT TestGenerateFingerprint2456=== CONT TestSignNarinfo2457=== CONT TestSignMessage2458=== RUN TestGenerateFingerprint/basic_with_references2459=== CONT TestParseSigningKey2460=== PAUSE TestGenerateFingerprint/basic_with_references2461=== RUN TestParseSigningKey/valid_32-byte_key2462=== RUN TestGenerateFingerprint/no_references2463=== PAUSE TestParseSigningKey/valid_32-byte_key2464=== PAUSE TestGenerateFingerprint/no_references2465=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2466=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2467=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2468=== RUN TestParseSigningKey/no_colon2469=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2470=== PAUSE TestParseSigningKey/no_colon2471=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2472=== RUN TestParseSigningKey/empty_name2473=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2474=== PAUSE TestParseSigningKey/empty_name2475=== RUN TestGenerateFingerprint/invalid_nar_hash_length2476=== RUN TestParseSigningKey/invalid_base642477=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2478=== PAUSE TestParseSigningKey/invalid_base642479=== RUN TestGenerateFingerprint/invalid_store_path_prefix2480=== RUN TestParseSigningKey/wrong_length2481=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2482=== PAUSE TestParseSigningKey/wrong_length2483=== RUN TestGenerateFingerprint/invalid_reference_prefix2484=== CONT TestParseSigningKey/no_colon2485=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2486=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2487=== CONT TestGenerateFingerprint/basic_with_references2488=== CONT TestParseSigningKey/empty_name2489=== CONT TestParseSigningKey/invalid_base642490=== CONT TestParseSigningKey/wrong_length2491=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2492=== CONT TestParseSigningKey/valid_32-byte_key2493=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2494=== CONT TestGenerateFingerprint/invalid_reference_prefix2495=== CONT TestGenerateFingerprint/invalid_store_path_prefix2496=== CONT TestGenerateFingerprint/invalid_nar_hash_length2497=== CONT TestGenerateFingerprint/no_references2498--- PASS: TestGenerateFingerprint (0.00s)2499 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2500 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2501 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2502 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2503 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2504 --- PASS: TestGenerateFingerprint/no_references (0.00s)2505 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2506--- PASS: TestParseSigningKey (0.00s)2507 --- PASS: TestParseSigningKey/no_colon (0.00s)2508 --- PASS: TestParseSigningKey/empty_name (0.00s)2509 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2510 --- PASS: TestParseSigningKey/wrong_length (0.00s)2511 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2512 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2513--- PASS: TestSignMessage (0.01s)2514--- PASS: TestSignNarinfo (0.01s)2515PASS2516Running hook tests...2517=== RUN TestSendPathsEmpty2518=== PAUSE TestSendPathsEmpty2519=== RUN TestQueueEnqueueAndFetch2520=== PAUSE TestQueueEnqueueAndFetch2521=== RUN TestQueueDeduplication2522=== PAUSE TestQueueDeduplication2523=== RUN TestQueueRemove2524=== PAUSE TestQueueRemove2525=== RUN TestQueueFetchBatchLimit2526=== PAUSE TestQueueFetchBatchLimit2527=== RUN TestQueueRetryMovesToBack2528=== PAUSE TestQueueRetryMovesToBack2529=== RUN TestQueueFetchRemoveLifecycle2530=== PAUSE TestQueueFetchRemoveLifecycle2531=== RUN TestQueueConcurrentWriters2532=== PAUSE TestQueueConcurrentWriters2533=== RUN TestQueueEnqueueWaitsOutSlowWriter2534=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2535=== RUN TestQueueRemoveLargeClosure2536=== PAUSE TestQueueRemoveLargeClosure2537=== RUN TestServerClientIntegration2538=== PAUSE TestServerClientIntegration2539=== RUN TestServerQueueError2540=== PAUSE TestServerQueueError2541=== RUN TestServerRefusesOversizedAndNonStoreRequests2542=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2543=== RUN TestGetListenerSocketActivation2544 server_test.go:317: === RUN TestGetListenerSocketActivation2545 --- PASS: TestGetListenerSocketActivation (0.00s)2546 PASS2547 2548--- PASS: TestGetListenerSocketActivation (1.11s)2549=== RUN TestServerStalledClientDoesNotBlockShutdown2550=== PAUSE TestServerStalledClientDoesNotBlockShutdown2551=== RUN TestServerBacksOffOnAcceptErrors2552=== PAUSE TestServerBacksOffOnAcceptErrors2553=== RUN TestDrainIsolatesPoisonPath2554=== PAUSE TestDrainIsolatesPoisonPath2555=== RUN TestRunNotBlockedByPoisonHead2556=== PAUSE TestRunNotBlockedByPoisonHead2557=== RUN TestDrainGivesUpWhenServerDown2558=== PAUSE TestDrainGivesUpWhenServerDown2559=== RUN TestFailedPathPrunedByLaterClosure2560=== PAUSE TestFailedPathPrunedByLaterClosure2561=== RUN TestWorkerUploadsAndRemoves2562=== PAUSE TestWorkerUploadsAndRemoves2563=== RUN TestWorkerSkipsGCdPaths2564=== PAUSE TestWorkerSkipsGCdPaths2565=== RUN TestWorkerPrunesClosureDeps2566=== PAUSE TestWorkerPrunesClosureDeps2567=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2568=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2569=== RUN TestDrainTimeout2570=== PAUSE TestDrainTimeout2571=== RUN TestDrainTimeoutDuringIsolation2572=== PAUSE TestDrainTimeoutDuringIsolation2573=== RUN TestShutdownFinishesInFlightPush2574=== PAUSE TestShutdownFinishesInFlightPush2575=== RUN TestWorkerRemoveFailureIsNotProgress2576=== PAUSE TestWorkerRemoveFailureIsNotProgress2577=== RUN TestWorkerKeepsPathItCannotStat2578=== PAUSE TestWorkerKeepsPathItCannotStat2579=== CONT TestServerStalledClientDoesNotBlockShutdown2580=== CONT TestQueueEnqueueWaitsOutSlowWriter2581=== CONT TestQueueRetryMovesToBack2582=== CONT TestShutdownFinishesInFlightPush2583=== CONT TestSendPathsEmpty2584=== CONT TestWorkerSkipsGCdPaths2585=== CONT TestServerBacksOffOnAcceptErrors2586=== CONT TestServerRefusesOversizedAndNonStoreRequests2587=== CONT TestDrainTimeoutDuringIsolation2588=== CONT TestDrainTimeout2589=== RUN TestShutdownFinishesInFlightPush/completes2590--- PASS: TestSendPathsEmpty (0.00s)2591=== CONT TestWorkerPrunesClosureDeps2592=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2593=== PAUSE TestShutdownFinishesInFlightPush/completes2594=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout25952026/10/01 09:58:25 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2596=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short25972026/10/01 09:58:25 ERROR Accept failed error="too many open files"2598=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2599=== CONT TestQueueRemoveLargeClosure2600=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2601=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2602=== CONT TestServerQueueError26032026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store store=/nix/store26042026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26052026/10/01 09:58:25 ERROR Failed to queue paths error="permission denied" count=126062026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2607--- PASS: TestServerQueueError (0.00s)2608=== CONT TestServerClientIntegration26092026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26102026/10/01 09:58:25 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2611--- PASS: TestServerClientIntegration (0.00s)2612=== CONT TestQueueConcurrentWriters26132026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26142026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26152026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26162026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26172026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26182026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26192026/10/01 09:58:25 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26202026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26212026/10/01 09:58:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26222026/10/01 09:58:25 ERROR Failed to decode request error="unexpected EOF"2623--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2624=== CONT TestQueueFetchRemoveLifecycle26252026/10/01 09:58:25 ERROR Accept failed error="too many open files"26262026/10/01 09:58:25 INFO Uploading batch count=226272026/10/01 09:58:25 INFO Upload queue status pending=326282026/10/01 09:58:25 INFO Upload queue status pending=226292026/10/01 09:58:25 INFO Uploading batch count=126302026/10/01 09:58:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerSkipsGCdPaths1471292541/002/nonexistent26312026/10/01 09:58:25 INFO Uploading batch count=22632--- PASS: TestQueueRetryMovesToBack (0.02s)2633=== CONT TestWorkerUploadsAndRemoves2634--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2635=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure26362026/10/01 09:58:25 ERROR Accept failed error="too many open files"26372026/10/01 09:58:25 INFO Upload queue status pending=226382026/10/01 09:58:25 INFO Uploading batch count=226392026/10/01 09:58:25 INFO Upload queue status pending=226402026/10/01 09:58:25 INFO Uploading batch count=22641--- PASS: TestWorkerSkipsGCdPaths (0.03s)2642=== CONT TestWorkerRemoveFailureIsNotProgress2643=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2644=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2645=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2646=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2647=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2648=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2649=== CONT TestQueueDeduplication2650--- PASS: TestWorkerPrunesClosureDeps (0.04s)2651=== CONT TestQueueFetchBatchLimit26522026/10/01 09:58:25 ERROR Accept failed error="too many open files"2653=== CONT TestWorkerKeepsPathItCannotStat2654--- PASS: TestQueueDeduplication (0.00s)2655--- PASS: TestQueueFetchBatchLimit (0.01s)2656=== CONT TestFailedPathPrunedByLaterClosure2657--- PASS: TestWorkerUploadsAndRemoves (0.03s)2658=== CONT TestQueueRemove2659--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.03s)2660=== CONT TestDrainGivesUpWhenServerDown26612026/10/01 09:58:25 INFO Uploading batch count=126622026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=126632026/10/01 09:58:25 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa error="lstat /nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa: permission denied"26642026/10/01 09:58:25 INFO Uploading batch count=126652026/10/01 09:58:25 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa error="lstat /nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa: permission denied"26662026/10/01 09:58:25 INFO Uploading batch count=126672026/10/01 09:58:25 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa error="lstat /nix/var/nix/builds/nix-97131-1810668750/TestWorkerKeepsPathItCannotStat3775068055/002/locked/aaa: permission denied"2668--- PASS: TestQueueRemove (0.01s)2669=== CONT TestDrainIsolatesPoisonPath26702026/10/01 09:58:25 INFO Uploading batch count=226712026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=226722026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/a26732026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=126742026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/b2675--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2676=== CONT TestQueueEnqueueAndFetch2677--- PASS: TestWorkerKeepsPathItCannotStat (0.01s)2678=== CONT TestRunNotBlockedByPoisonHead26792026/10/01 09:58:25 INFO Uploading batch count=226802026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=226812026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/c26822026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/d26832026/10/01 09:58:25 INFO Uploading batch count=226842026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=226852026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/e26862026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainGivesUpWhenServerDown107810877/002/f26872026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=1026882026/10/01 09:58:25 INFO Uploading batch count=426892026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=426902026/10/01 09:58:25 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-97131-1810668750/TestDrainIsolatesPoisonPath3995520757/002/bbb2691--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2692=== CONT TestShutdownFinishesInFlightPush/completes26932026/10/01 09:58:25 INFO Upload queue status pending=32694--- PASS: TestQueueEnqueueAndFetch (0.01s)2695=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26962026/10/01 09:58:25 INFO Uploading batch count=126972026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=126982026/10/01 09:58:25 INFO Uploading batch count=126992026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127002026/10/01 09:58:25 INFO Uploading batch count=127012026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127022026/10/01 09:58:25 INFO Uploading batch count=127032026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127042026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=127052026/10/01 09:58:25 INFO Upload queue status pending=22706--- PASS: TestDrainIsolatesPoisonPath (0.01s)2707=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27082026/10/01 09:58:25 INFO Uploading batch count=227092026/10/01 09:58:25 INFO Upload queue status pending=227102026/10/01 09:58:25 INFO Uploading batch count=227112026/10/01 09:58:25 INFO Uploading batch count=427122026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=427132026/10/01 09:58:25 ERROR Accept failed error="too many open files"2714--- PASS: TestQueueConcurrentWriters (0.14s)2715=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27162026/10/01 09:58:25 INFO Uploading batch count=427172026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=427182026/10/01 09:58:25 ERROR Accept failed error="too many open files"2719=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27202026/10/01 09:58:25 INFO Uploading batch count=227212026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227222026/10/01 09:58:25 INFO Uploading batch count=227232026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227242026/10/01 09:58:25 INFO Uploading batch count=227252026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227262026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=22727=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27282026/10/01 09:58:25 INFO Uploading batch count=227292026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=227302026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127312026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127322026/10/01 09:58:25 INFO Uploading batch count=227332026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=227342026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127352026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127362026/10/01 09:58:25 INFO Uploading batch count=227372026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=227382026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127392026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127402026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=22741=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27422026/10/01 09:58:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerRemoveFailureIsNotProgresscollected_path1975371212/001/nonexistent27432026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127442026/10/01 09:58:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerRemoveFailureIsNotProgresscollected_path1975371212/001/nonexistent27452026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127462026/10/01 09:58:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-97131-1810668750/TestWorkerRemoveFailureIsNotProgresscollected_path1975371212/001/nonexistent27472026/10/01 09:58:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=12749--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2750 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.01s)2751 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.01s)2752 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.01s)27532026/10/01 09:58:25 ERROR Failed to decode request error="read unix /nix/var/nix/builds/nix-97131-1810668750/hook2115318049/test.sock->: i/o timeout"27542026/10/01 09:58:25 ERROR Failed to write response error="write unix /nix/var/nix/builds/nix-97131-1810668750/hook2115318049/test.sock->: i/o timeout"2755--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27562026/10/01 09:58:25 ERROR Upload failed error="context canceled" count=227572026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=42758--- PASS: TestDrainTimeout (0.22s)27592026/10/01 09:58:25 ERROR Upload failed error="context canceled" count=227602026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=22761--- PASS: TestShutdownFinishesInFlightPush (0.00s)2762 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2763 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.21s)27642026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=427652026/10/01 09:58:25 ERROR Accept failed error="too many open files"27662026/10/01 09:58:26 ERROR Drain finished with paths left in queue remaining=32767--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2768 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.21s)2769 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.31s)27702026/10/01 09:58:26 ERROR Accept failed error="too many open files"2771--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27722026/10/01 09:58:26 INFO Uploading batch count=127732026/10/01 09:58:26 INFO Uploading batch count=127742026/10/01 09:58:26 INFO Uploading batch count=127752026/10/01 09:58:26 ERROR Upload failed error="upload failed" count=127762026/10/01 09:58:26 INFO Uploading batch count=127772026/10/01 09:58:26 ERROR Upload failed error="upload failed" count=127782026/10/01 09:58:26 INFO Uploading batch count=127792026/10/01 09:58:26 ERROR Upload failed error="upload failed" count=127802026/10/01 09:58:26 INFO Uploading batch count=127812026/10/01 09:58:26 ERROR Upload failed error="upload failed" count=127822026/10/01 09:58:26 ERROR Drain finished with paths left in queue remaining=12783--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2784--- PASS: TestQueueRemoveLargeClosure (1.18s)2785--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.02s)2786PASS2787Running niks3-hook command tests...2788=== RUN TestServeSecondSignalEndsDrain2789=== PAUSE TestServeSecondSignalEndsDrain2790=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2791=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2792=== CONT TestServeSecondSignalEndsDrain2793=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2794--- PASS: TestServeSecondSignalEndsDrain (0.07s)27952026/10/01 09:58:33 INFO Upload queue status pending=127962026/10/01 09:58:33 INFO Uploading batch count=12797--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)2798PASS2799Running rate limiter tests...2800=== RUN TestAdaptiveRateLimiter_ThreadSafety2801=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2802=== CONT TestAdaptiveRateLimiter_ThreadSafety28032026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=7028042026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=4928052026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=34.328062026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=24.00999999999999828072026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=16.80728082026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=11.76489999999999928092026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=8.2354328102026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=5.76480099999999928112026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528122026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528132026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=6.200463500000001528142026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528152026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528162026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528172026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528182026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528192026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528202026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528212026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528222026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528232026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528242026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528252026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528262026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528272026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528282026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528292026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528302026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528312026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528322026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528332026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528342026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528352026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528362026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528372026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528382026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528392026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528402026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528412026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528422026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528432026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528442026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528452026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528462026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528472026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528482026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528492026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528502026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528512026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528522026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528532026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528542026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528552026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528562026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528572026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528582026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=8.25281691850000428592026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=5.77697184295000328602026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528612026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528622026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528632026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=6.200463500000001528642026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528652026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528662026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528672026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528682026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528692026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528702026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528712026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528722026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528732026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528742026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528752026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528762026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528772026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528782026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528792026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=5.12435000000000128802026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528812026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528822026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528832026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528842026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528852026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528862026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528872026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=9.07809861035000628882026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=6.35466902724500428892026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528902026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528912026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528922026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528932026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528942026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528952026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528962026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528972026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528982026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=528992026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=529002026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=529012026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=529022026/10/01 09:58:34 WARN Rate limiter backed off name=test rate=52903--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.11s)2904PASS