niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #342
· 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.35s)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 TestDoServerRequestAttachesToken128=== CONT TestScriptTokenCachesUntilRefresh129=== CONT TestCompletePendingClosure_NotFoundWithoutKey130=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer131=== CONT TestScriptTokenDoesNotWaitForItsChildren132=== CONT TestDumpPathWriterError133=== CONT TestScriptTokenBadJSON134=== CONT TestScriptTokenEmptyCommand135=== CONT TestScriptTokenEmptyToken136=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs137=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs138=== CONT TestScriptTokenScriptFails139=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout140--- PASS: TestScriptTokenEmptyCommand (0.00s)141=== CONT TestParsePathInfoJSON142=== RUN TestParsePathInfoJSON/Nix_format143=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout144=== CONT TestEncodeNixBase32WithRealHash145=== PAUSE TestParsePathInfoJSON/Nix_format146=== RUN TestParsePathInfoJSON/Lix_format147=== CONT TestGetStorePathHash148=== RUN TestGetStorePathHash/valid_store_path149=== CONT TestConvertHashToNix32150=== PAUSE TestParsePathInfoJSON/Lix_format151--- PASS: TestEncodeNixBase32WithRealHash (0.00s)152--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)153=== PAUSE TestGetStorePathHash/valid_store_path154=== RUN TestConvertHashToNix32/SRI_format_to_Nix32155=== RUN TestGetStorePathHash/basename_without_hyphen_should_error156=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32157=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error158=== RUN TestParsePathInfoJSON/empty_input159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestParsePathInfoJSON/empty_input161=== PAUSE TestConvertHashToNix32/already_Nix32_format162=== RUN TestConvertHashToNix32/invalid_format163=== RUN TestParsePathInfoJSON/whitespace_only164=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error165=== PAUSE TestConvertHashToNix32/invalid_format166=== PAUSE TestParsePathInfoJSON/whitespace_only167=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent168=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error169=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier170=== CONT TestStreamPushRequestLine171=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error172=== RUN TestParsePathInfoJSON/invalid_JSON173=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error174=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier175=== CONT TestPathInfoCACompatibility176=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up177=== PAUSE TestParsePathInfoJSON/invalid_JSON178=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up179=== RUN TestPathInfoCACompatibility/null_ca_field180--- PASS: TestDoServerRequestAttachesToken (0.01s)181=== CONT TestParsePathInfoJSONMultiplePaths182=== PAUSE TestPathInfoCACompatibility/null_ca_field183=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== CONT TestRateLimiterFeedback185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== RUN TestRateLimiterFeedback/429_enables_limiter187=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text188=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive190=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== PAUSE TestRateLimiterFeedback/429_enables_limiter193=== RUN TestPathInfoCACompatibility/new_structured_format_-_text194=== RUN TestRateLimiterFeedback/503_enables_limiter195=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths196=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text197=== CONT TestPathInfoHashCompatibility198=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)199=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)200=== PAUSE TestRateLimiterFeedback/503_enables_limiter201=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon202=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter203=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter204=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method205=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method206=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon207=== CONT TestEncodeNixBase32208=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI209=== RUN TestEncodeNixBase32/test_string_hash210=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter211=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter212=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI213=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512214=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512215=== PAUSE TestEncodeNixBase32/test_string_hash216=== CONT TestSetClientTLSDoesNotMutateDefaultTransport217=== RUN TestEncodeNixBase32/empty_input218=== PAUSE TestEncodeNixBase32/empty_input219=== CONT TestScriptTokenNoExpiryRerunsEveryCall220=== CONT TestFileTokenMissing221--- PASS: TestScriptTokenScriptFails (0.01s)222=== CONT TestFileTokenReadsAndCaches223--- PASS: TestFileTokenReadsAndCaches (0.00s)224=== CONT TestFileTokenEmpty225--- PASS: TestFileTokenMissing (0.00s)226=== CONT TestSetClientTLSErrors227--- PASS: TestFileTokenEmpty (0.00s)228=== CONT TestDumpPathSingleFile229--- PASS: TestScriptTokenBadJSON (0.01s)230=== CONT TestSetClientTLS231=== RUN TestSetClientTLSErrors/missing_cert_file232=== PAUSE TestSetClientTLSErrors/missing_cert_file233=== RUN TestSetClientTLSErrors/missing_key_file234=== PAUSE TestSetClientTLSErrors/missing_key_file235=== RUN TestSetClientTLSErrors/missing_ca_file236=== PAUSE TestSetClientTLSErrors/missing_ca_file237=== RUN TestSetClientTLSErrors/invalid_ca_file238=== PAUSE TestSetClientTLSErrors/invalid_ca_file239=== CONT TestStreamPushStopsOnCancel240=== RUN TestStreamPushStopsOnCancel/waiting_for_input241--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)242=== CONT TestStaticToken243=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input244--- PASS: TestStaticToken (0.00s)245=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot246=== CONT TestStreamPushReportsSignatures247=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot248=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot249=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot250=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot251=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot252=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot253--- PASS: TestScriptTokenEmptyToken (0.02s)254=== CONT TestClientSignaturesByStorePath255=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot256=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken257--- PASS: TestClientSignaturesByStorePath (0.00s)258=== CONT TestShellSplit259=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken260=== CONT TestStreamPushGivesUpOnDeadServer261--- PASS: TestShellSplit (0.00s)262=== CONT TestStreamPushBatchesUnderLoad263=== RUN TestStreamPushBatchesUnderLoad/together264=== PAUSE TestStreamPushBatchesUnderLoad/together265=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time266=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time267=== CONT TestStreamPushIsolatesFailures268--- PASS: TestStreamPushReportsSignatures (0.00s)269=== CONT TestStreamPushReportsEveryPath270--- PASS: TestStreamPushIsolatesFailures (0.00s)271=== CONT TestShellSplitErrors272--- PASS: TestShellSplitErrors (0.00s)273=== CONT TestTruncatedNARDumpIsNotCompleted274--- PASS: TestStreamPushReportsEveryPath (0.00s)275=== CONT TestPartSizeForNAR276=== RUN TestPartSizeForNAR/zero_stays_at_minimum277=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum278=== RUN TestPartSizeForNAR/small_stays_at_minimum279=== PAUSE TestPartSizeForNAR/small_stays_at_minimum280=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum281=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum282=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts283--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)284=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica285=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts286=== RUN TestPartSizeForNAR/1_TiB287=== PAUSE TestPartSizeForNAR/1_TiB288=== RUN TestPartSizeForNAR/5_TiB_S3_max_object289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== RUN TestPartSizeForNAR/capped_at_5_GiB291=== PAUSE TestPartSizeForNAR/capped_at_5_GiB292=== CONT TestFilterOversizedClosures293=== RUN TestFilterOversizedClosures/no_limit_keeps_everything294=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything295=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped296=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped297=== RUN TestSetClientTLS/rejects_connection_without_client_cert298=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert299=== RUN TestFilterOversizedClosures/all_closures_skipped300=== PAUSE TestFilterOversizedClosures/all_closures_skipped301=== CONT TestRegisterUploadedObjectReusesConnections302=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA303=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA304=== RUN TestSetClientTLS/preserves_debug_logging_transport305=== PAUSE TestSetClientTLS/preserves_debug_logging_transport306=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure307--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)308=== CONT TestUploadMultipart_ProducerErrorIsNotEOF309=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part310=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part311=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary312=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary313=== CONT TestSupersededNARStillUploadsListing314=== RUN TestSupersededNARStillUploadsListing/small_NAR315=== PAUSE TestSupersededNARStillUploadsListing/small_NAR316=== RUN TestSupersededNARStillUploadsListing/dump_cut_short317=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short318=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails319=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails320=== CONT TestDumpPathMatchesNix321--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)322=== CONT TestCaseHackSuffix323--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)324=== CONT TestUploadMultipart_SupersededByPeer325=== RUN TestUploadMultipart_SupersededByPeer/exists326=== PAUSE TestUploadMultipart_SupersededByPeer/exists327=== RUN TestUploadMultipart_SupersededByPeer/missing328=== PAUSE TestUploadMultipart_SupersededByPeer/missing329=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun330--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)331=== CONT TestUploadMultipart_FailedPartBufferNotReused332--- PASS: TestDumpPathWriterError (0.07s)333=== CONT TestResolveStorePath334--- PASS: TestResolveStorePath (0.00s)335=== CONT TestDoWithRetry_BodyReplayedViaGetBody336--- PASS: TestDumpPathSingleFile (0.06s)337=== CONT TestDoWithRetry_FinalResponseBodyReadable338--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)339=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess340--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)341=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry342--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)343=== CONT TestUploadMultipart_PartsInParallel344--- PASS: TestStreamPushRequestLine (0.10s)345=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout346--- PASS: TestCaseHackSuffix (0.09s)347=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs348=== CONT TestConvertHashToNix32/already_Nix32_format349--- PASS: TestDumpPathMatchesNix (0.14s)350=== CONT TestConvertHashToNix32/invalid_format351=== CONT TestConvertHashToNix32/SRI_format_to_Nix32352--- PASS: TestConvertHashToNix32 (0.00s)353 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)354 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)355 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)356=== CONT TestGetStorePathHash/valid_store_path357=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error358=== CONT TestGetStorePathHash/basename_without_hyphen_should_error359=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error360=== CONT TestParsePathInfoJSON/Nix_format361--- PASS: TestGetStorePathHash (0.00s)362 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)364 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)365 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)366=== CONT TestParsePathInfoJSON/whitespace_only367=== CONT TestParsePathInfoJSON/invalid_JSON368=== CONT TestParsePathInfoJSON/Lix_format369=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up370=== CONT TestParsePathInfoJSON/empty_input371=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier372--- PASS: TestParsePathInfoJSON (0.01s)373 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)374 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)375 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)376 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)377 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)378=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths379=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths380--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)381 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)382 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)383=== CONT TestPathInfoCACompatibility/null_ca_field384--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)385 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)386 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)387=== CONT TestPathInfoCACompatibility/new_structured_format_-_text388=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method389=== CONT TestPathInfoCACompatibility/old_string_format_-_text390=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive391--- PASS: TestPathInfoCACompatibility (0.00s)392 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)393 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)394 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)395 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)396 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)397=== CONT TestRateLimiterFeedback/503_enables_limiter398=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)399=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter400=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter401=== CONT TestRateLimiterFeedback/429_enables_limiter402=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512403=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI404--- PASS: TestRateLimiterFeedback (0.00s)405 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)406 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)407 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)408 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)409=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon410=== CONT TestEncodeNixBase32/test_string_hash411=== CONT TestEncodeNixBase32/empty_input412--- PASS: TestPathInfoHashCompatibility (0.00s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)416 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)417=== CONT TestSetClientTLSErrors/missing_cert_file418--- PASS: TestEncodeNixBase32 (0.00s)419 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)420 --- PASS: TestEncodeNixBase32/empty_input (0.00s)421=== CONT TestSetClientTLSErrors/invalid_ca_file422=== CONT TestSetClientTLSErrors/missing_ca_file423=== CONT TestSetClientTLSErrors/missing_key_file424=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time425--- PASS: TestSetClientTLSErrors (0.00s)426 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)427 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)428 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)429 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)430=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken431--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.17s)432=== CONT TestStreamPushBatchesUnderLoad/together433=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot434--- PASS: TestStreamPushBatchesUnderLoad (0.00s)435 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)436 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)437--- PASS: TestRegisterUploadedObjectReusesConnections (0.19s)438=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot439=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot440=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot441=== CONT TestStreamPushStopsOnCancel/waiting_for_input442=== CONT TestPartSizeForNAR/small_stays_at_minimum443=== CONT TestPartSizeForNAR/1_TiB444=== CONT TestPartSizeForNAR/capped_at_5_GiB445=== CONT TestPartSizeForNAR/5_TiB_S3_max_object446=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum447=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts448=== CONT TestPartSizeForNAR/zero_stays_at_minimum449=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped450--- PASS: TestPartSizeForNAR (0.00s)451 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)452 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)453 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)454 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)455 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)456 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)457 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)458=== CONT TestFilterOversizedClosures/all_closures_skipped459=== CONT TestFilterOversizedClosures/no_limit_keeps_everything460=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA461--- PASS: TestFilterOversizedClosures (0.00s)462 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)463 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)464 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)465=== CONT TestSetClientTLS/preserves_debug_logging_transport466=== CONT TestSetClientTLS/rejects_connection_without_client_cert467=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary468=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part469--- PASS: TestSetClientTLS (0.01s)470 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)471 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)472 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)473--- PASS: TestStreamPushStopsOnCancel (0.00s)474 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)475 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)476 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)480=== CONT TestSupersededNARStillUploadsListing/small_NAR481=== CONT TestUploadMultipart_SupersededByPeer/missing482=== CONT TestUploadMultipart_SupersededByPeer/exists483--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)484 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)485 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)486=== CONT TestSupersededNARStillUploadsListing/dump_cut_short487=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.02s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.03s)491--- PASS: TestTruncatedNARDumpIsNotCompleted (0.39s)492--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.63s)493--- PASS: TestUploadMultipart_PartsInParallel (0.66s)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.60s)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.04s)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-58869-1726934962/postgres973937341/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-58869-1726934962/postgres973937341/data -l logfile start531532/nix/var/nix/builds/nix-58869-1726934962/postgres973937341:5432 - no response5332026-10-01 10:33:54.388 UTC [58914] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5342026-10-01 10:33:54.388 UTC [58914] LOG: listening on Unix socket "/nix/var/nix/builds/nix-58869-1726934962/postgres973937341/.s.PGSQL.5432"5352026-10-01 10:33:54.390 UTC [58921] LOG: database system was shut down at 2026-10-01 10:33:54 UTC5362026-10-01 10:33:54.391 UTC [58914] LOG: database system is ready to accept connections537/nix/var/nix/builds/nix-58869-1726934962/postgres973937341:5432 - accepting connections538{"timestamp":"2026-10-01T10:33:54.607911Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"336dd0c3-d882-4b22-86e3-9d284306ac4d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/10/01 10:33:54 INFO lead: acquired remote=192.0.2.1:12345872026/10/01 10:33:55 INFO lead: released remote=192.0.2.1:12345882026/10/01 10:33:55 INFO lead: acquired remote=192.0.2.1:12345892026/10/01 10:33:57 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.34s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/10/01 10:33:57 INFO lead: acquired remote=192.0.2.1:12345952026-10-01 10:33:58.407 UTC [58958] FATAL: terminating connection due to administrator command5962026/10/01 10:33:58 INFO lead: acquired remote=192.0.2.1:12345972026/10/01 10:33:59 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/10/01 10:33:59 INFO lead: released remote=192.0.2.1:12345992026/10/01 10:33:59 INFO lead: released remote=192.0.2.1:1234600--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)601=== RUN TestGCAdvisoryLockBlocksConcurrentRun602=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun603=== RUN TestGCBugBareHashReferences604=== PAUSE TestGCBugBareHashReferences605=== RUN TestGCMetrics606=== PAUSE TestGCMetrics607=== RUN TestPushDedupSurvivesConcurrentGC608=== PAUSE TestPushDedupSurvivesConcurrentGC609=== RUN TestDeduplicatedObjectsRecordedAsPending610=== PAUSE TestDeduplicatedObjectsRecordedAsPending611=== RUN TestGCSweepSkipsPendingObjects612=== PAUSE TestGCSweepSkipsPendingObjects613=== RUN TestTombstonedObjectOfferedWithoutWaiting614=== PAUSE TestTombstonedObjectOfferedWithoutWaiting615=== RUN TestGCSweepDeliversEachKeyOnce616=== PAUSE TestGCSweepDeliversEachKeyOnce617=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection618=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== RUN TestForceGCDuringPushOffersSweptObject620=== PAUSE TestForceGCDuringPushOffersSweptObject621=== RUN TestFailedS3DeleteKeepsTombstone622=== PAUSE TestFailedS3DeleteKeepsTombstone623=== RUN TestSweepSkipsRowsLockedByPush624=== PAUSE TestSweepSkipsRowsLockedByPush625=== RUN TestRegisterCompletedObjectNeedsPendingRow626=== PAUSE TestRegisterCompletedObjectNeedsPendingRow627=== RUN TestGetExistingObjectsLocksRows628=== PAUSE TestGetExistingObjectsLocksRows629=== RUN TestSweepRechecksPendingAfterLocking630=== PAUSE TestSweepRechecksPendingAfterLocking631=== RUN TestPushWaitsForSweepHoldingRow632=== PAUSE TestPushWaitsForSweepHoldingRow633=== RUN TestCommitRacingPendingCleanupKeepsObjects634=== PAUSE TestCommitRacingPendingCleanupKeepsObjects635=== RUN TestGCEndsOnShutdown636=== PAUSE TestGCEndsOnShutdown637=== RUN TestGCTaskStore_StartNew638=== PAUSE TestGCTaskStore_StartNew639=== RUN TestGCTaskStore_DeduplicateSameParams640=== PAUSE TestGCTaskStore_DeduplicateSameParams641=== RUN TestGCTaskStore_ConflictDifferentParams642=== PAUSE TestGCTaskStore_ConflictDifferentParams643=== RUN TestGCTaskStore_GetEmpty644=== PAUSE TestGCTaskStore_GetEmpty645=== RUN TestGCTaskStore_GetReturnsLatest646=== PAUSE TestGCTaskStore_GetReturnsLatest647=== RUN TestGCTaskStore_CompletedAllowsNewTask648=== PAUSE TestGCTaskStore_CompletedAllowsNewTask649=== RUN TestGCTaskStore_PhaseUpdates650=== PAUSE TestGCTaskStore_PhaseUpdates651=== RUN TestGCTaskStore_Fail652=== PAUSE TestGCTaskStore_Fail653=== RUN TestGracefulShutdownDrainsInflight654=== PAUSE TestGracefulShutdownDrainsInflight655=== RUN TestService_healthCheckHandler656=== PAUSE TestService_healthCheckHandler657=== RUN TestService_readinessHandler658=== PAUSE TestService_readinessHandler659=== RUN TestGenerateLandingPage660=== PAUSE TestGenerateLandingPage661=== RUN TestCacheConfigHandlerMaxNarSize662=== PAUSE TestCacheConfigHandlerMaxNarSize663=== RUN TestCreatePendingClosureRejectsOversizedNAR664=== PAUSE TestCreatePendingClosureRejectsOversizedNAR665=== RUN TestNARDeduplicationMetadataUploadBug666=== PAUSE TestNARDeduplicationMetadataUploadBug667=== RUN TestMetricsInventory668=== PAUSE TestMetricsInventory669=== RUN TestService_NativeMTLS670=== PAUSE TestService_NativeMTLS671=== RUN TestServerTLSConfig672=== PAUSE TestServerTLSConfig673=== RUN TestMultipartCleanup674=== PAUSE TestMultipartCleanup675=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded677=== RUN TestPendingCleanupUsesOneCutoff678=== PAUSE TestPendingCleanupUsesOneCutoff679=== RUN TestPendingClosureFailureTracksEveryUpload680=== PAUSE TestPendingClosureFailureTracksEveryUpload681=== RUN TestPendingClosureFailureAbortsItsUploads682=== PAUSE TestPendingClosureFailureAbortsItsUploads683=== RUN TestObjectStatsTrigger684=== PAUSE TestObjectStatsTrigger685=== RUN TestReconnectLeavesObjectsUnlocked686=== PAUSE TestReconnectLeavesObjectsUnlocked687=== RUN TestOrphanedObjectsGC688=== PAUSE TestOrphanedObjectsGC689=== RUN TestOrphanedObjectsGCStressTest690=== PAUSE TestOrphanedObjectsGCStressTest691=== RUN TestCreatePin_ReservedPins692=== PAUSE TestCreatePin_ReservedPins693=== RUN TestConcurrentPinUpdatesAgree694=== PAUSE TestConcurrentPinUpdatesAgree695=== RUN TestCreatePinRejectsBadInput696=== PAUSE TestCreatePinRejectsBadInput697=== RUN TestDeletePinKeepsRowWhenS3Fails698=== PAUSE TestDeletePinKeepsRowWhenS3Fails699=== RUN TestPresentReportsOnlyClosureRoots700=== PAUSE TestPresentReportsOnlyClosureRoots701=== RUN TestPresentNotReportedWhileGCDeletesClosure702=== PAUSE TestPresentNotReportedWhileGCDeletesClosure703=== RUN TestParseSingleRange704=== PAUSE TestParseSingleRange705=== RUN TestProxyHeadersOnlyTrustedOnSocket706=== PAUSE TestProxyHeadersOnlyTrustedOnSocket707=== RUN TestIsValidCachePath708=== PAUSE TestIsValidCachePath709=== RUN TestReadProxyNarinfo710=== PAUSE TestReadProxyNarinfo711=== RUN TestReadProxyNarinfoAlreadyDecompressed712=== PAUSE TestReadProxyNarinfoAlreadyDecompressed713=== RUN TestReadProxyNarStreaming714=== PAUSE TestReadProxyNarStreaming715=== RUN TestReadProxy404716=== PAUSE TestReadProxy404717=== RUN TestReadProxyInvalidPath718=== PAUSE TestReadProxyInvalidPath719=== RUN TestReadProxyHead720=== PAUSE TestReadProxyHead721=== RUN TestReadProxyOutlastsServerWriteTimeout722=== PAUSE TestReadProxyOutlastsServerWriteTimeout723=== RUN TestReadProxyConditionalGet724=== PAUSE TestReadProxyConditionalGet725=== RUN TestReadProxyRootRedirectsToIndexHTML726=== PAUSE TestReadProxyRootRedirectsToIndexHTML727=== RUN TestReadProxyDisabled728=== PAUSE TestReadProxyDisabled729=== RUN TestReadRedirectNar730=== PAUSE TestReadRedirectNar731=== RUN TestReadRedirectKeepsNarinfoProxied732=== PAUSE TestReadRedirectKeepsNarinfoProxied733=== RUN TestReadProxyRangeRequest734=== PAUSE TestReadProxyRangeRequest735=== RUN TestReadRedirectUsesPublicS3URL736=== PAUSE TestReadRedirectUsesPublicS3URL737=== RUN TestPush_OverlappingRootsStoreOneRowPerKey738=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey739=== RUN TestPush_CompleteCommitsEveryRoot740=== PAUSE TestPush_CompleteCommitsEveryRoot741=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit742=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit743=== RUN TestPush_RejectsBadRequests744=== PAUSE TestPush_RejectsBadRequests745=== RUN TestPush_SignsNarinfosOfItsPendingObjects746=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects747=== RUN TestRedundantMultipartUpload748=== PAUSE TestRedundantMultipartUpload749=== RUN TestCompleteMultipartUpload_ErrorButObjectExists750=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists751=== RUN TestCompletedNarNotReofferedAcrossClosures752=== PAUSE TestCompletedNarNotReofferedAcrossClosures753=== RUN TestPresignedUploadRegisteredBeforeCommit754=== PAUSE TestPresignedUploadRegisteredBeforeCommit755=== RUN TestService_Rustfstest756=== PAUSE TestService_Rustfstest757=== RUN TestParseSize758=== PAUSE TestParseSize759=== RUN TestSkippedUploadsHandler760=== PAUSE TestSkippedUploadsHandler761=== RUN TestSystemdListenerNotActivated762--- PASS: TestSystemdListenerNotActivated (0.00s)763=== RUN TestWatchdogBeatsWhenHealthy764--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)765=== RUN TestWatchdogSkipsWhenUnhealthy7662026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 10:34:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 10:34:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 10:34:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"776--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)777=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== RUN TestProxyWriteTimeout780=== PAUSE TestProxyWriteTimeout781=== RUN TestPendingClosureWriteTimeout782=== PAUSE TestPendingClosureWriteTimeout783=== RUN TestIsValidUploadKey784=== PAUSE TestIsValidUploadKey785=== RUN TestUploadHandlersRejectInvalidKeys786=== PAUSE TestUploadHandlersRejectInvalidKeys787=== RUN TestUploadHandlersRejectOversizedBody788=== PAUSE TestUploadHandlersRejectOversizedBody789=== RUN TestService_cleanupPendingClosuresHandler790=== PAUSE TestService_cleanupPendingClosuresHandler791=== RUN TestService_createPendingClosureHandler792=== PAUSE TestService_createPendingClosureHandler793=== RUN TestService_verifyS3Integrity794=== PAUSE TestService_verifyS3Integrity795=== RUN TestCompleteMultipartUnregistered796=== PAUSE TestCompleteMultipartUnregistered797=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT798=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestPendingCleanupUsesOneCutoff800=== CONT TestNARDeduplicationMetadataUploadBug801=== CONT TestService_AuthMiddleware_MTLSBoundSubjects802=== CONT TestGCSweepDeliversEachKeyOnce803=== CONT TestClientErrorHandling804=== RUN TestClientErrorHandling/InvalidStorePath805=== PAUSE TestClientErrorHandling/InvalidStorePath806=== RUN TestClientErrorHandling/InvalidAuthToken807=== PAUSE TestClientErrorHandling/InvalidAuthToken808=== CONT TestClientMultipleUploads809=== CONT TestDeduplicatedObjectsRecordedAsPending810=== RUN TestClientErrorHandling/ServerNotAvailable811=== CONT TestPinProtectsFromGC812=== CONT TestPushDedupSurvivesConcurrentGC813=== CONT TestCacheStatsHandler814=== PAUSE TestClientErrorHandling/ServerNotAvailable815=== CONT TestClientCADerivations8162026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures8172026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures8182026/10/01 10:34:00 INFO Received cleanup request method=DELETE path=/api/pending_closures819--- PASS: TestCacheStatsHandler (0.80s)820=== CONT TestService_ReadAuthMiddleware821=== NAME TestNARDeduplicationMetadataUploadBug822 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-58869-1726934962/TestNARDeduplicationMetadataUploadBug2490853947/001/store/47vxbcnc49lk40dmk4ia40b8ny78d1hj-file1.txt8232026/10/01 10:34:00 INFO Received push request method=POST path=/api/pushes8242026/10/01 10:34:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8252026/10/01 10:34:00 INFO Uploading 47vxbcnc49lk40dmk4ia40b8ny78d1hj-file1.txt (160B)8262026/10/01 10:34:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8272026/10/01 10:34:00 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8282026/10/01 10:34:00 WARN Failed to register uploaded object key=47vxbcnc49lk40dmk4ia40b8ny78d1hj.ls error="server returned 404: 404 page not found\n"8292026/10/01 10:34:00 INFO Signed narinfos id=1 count=18302026/10/01 10:34:00 INFO Uploading 1 narinfos8312026/10/01 10:34:00 INFO Received complete push request method=POST path=/api/pushes/1/complete8322026/10/01 10:34:00 WARN Failed to register uploaded object key=47vxbcnc49lk40dmk4ia40b8ny78d1hj.narinfo error="server returned 404: 404 page not found\n"8332026/10/01 10:34:00 INFO Upload complete. (67ms)834 metadata_upload_test.go:54: Retrieved narinfo from S3:835 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestNARDeduplicationMetadataUploadBug2490853947/001/store/47vxbcnc49lk40dmk4ia40b8ny78d1hj-file1.txt836 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst837 Compression: zstd838 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf839 NarSize: 160840 References: 841 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf842 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)843 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):844 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}8452026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures846--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.95s)847=== CONT TestClientSharedPathCommittedMidPush848=== NAME TestNARDeduplicationMetadataUploadBug849 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-58869-1726934962/TestNARDeduplicationMetadataUploadBug2490853947/001/store/73i6iw43r7jzlk9cwp89bd60zviz37vh-file2.txt8502026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes8512026/10/01 10:34:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)8522026/10/01 10:34:01 WARN Failed to register uploaded object key=73i6iw43r7jzlk9cwp89bd60zviz37vh.ls error="server returned 404: 404 page not found\n"8532026/10/01 10:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8542026/10/01 10:34:01 INFO Signed narinfos id=2 count=18552026/10/01 10:34:01 INFO Uploading 1 narinfos8562026/10/01 10:34:01 INFO Received complete push request method=POST path=/api/pushes/2/complete8572026/10/01 10:34:01 WARN Failed to register uploaded object key=73i6iw43r7jzlk9cwp89bd60zviz37vh.narinfo error="server returned 404: 404 page not found\n"8582026/10/01 10:34:01 INFO Upload complete. (97ms)859 metadata_upload_test.go:76: Retrieved narinfo from S3:860 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestNARDeduplicationMetadataUploadBug2490853947/001/store/73i6iw43r7jzlk9cwp89bd60zviz37vh-file2.txt861 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst862 Compression: zstd863 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf864 NarSize: 160865 References: 866 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf867 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)868 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):869 {"version":1,"root":{"type":"regular","size":44}}8702026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures871--- PASS: TestNARDeduplicationMetadataUploadBug (1.18s)872=== CONT TestCacheConfigHandler873=== RUN TestCacheConfigHandler/full_config,_no_issuer874=== PAUSE TestCacheConfigHandler/full_config,_no_issuer875=== RUN TestCacheConfigHandler/no_cache_url_configured876=== PAUSE TestCacheConfigHandler/no_cache_url_configured877=== RUN TestCacheConfigHandler/no_signing_keys878=== PAUSE TestCacheConfigHandler/no_signing_keys879=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator880=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator881=== CONT TestClientWithDependencies8822026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=08832026/10/01 10:34:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08842026/10/01 10:34:01 INFO Vacuumed table table=pending_closures8852026/10/01 10:34:01 INFO Vacuumed table table=pending_objects8862026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads8872026/10/01 10:34:01 INFO Vacuumed table table=closures8882026/10/01 10:34:01 INFO Vacuumed table table=objects8892026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=08902026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period8912026/10/01 10:34:01 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=08922026/10/01 10:34:01 INFO Vacuumed table table=pending_closures8932026/10/01 10:34:01 INFO Vacuumed table table=pending_objects8942026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads8952026/10/01 10:34:01 INFO Vacuumed table table=closures8962026/10/01 10:34:01 INFO Vacuumed table table=objects897--- PASS: TestPushDedupSurvivesConcurrentGC (1.29s)898=== CONT TestService_RequireScope_OIDC8992026/10/01 10:34:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63554/oidc9002026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=09012026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period9022026/10/01 10:34:01 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=09032026/10/01 10:34:01 INFO Vacuumed table table=pending_closures9042026/10/01 10:34:01 INFO Vacuumed table table=pending_objects9052026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads9062026/10/01 10:34:01 INFO Vacuumed table table=closures9072026/10/01 10:34:01 INFO Vacuumed table table=objects908--- PASS: TestGCSweepDeliversEachKeyOnce (1.54s)909=== CONT TestGCTaskStore_StartNew910--- PASS: TestGCTaskStore_StartNew (0.00s)911=== CONT TestCreatePendingClosureRejectsOversizedNAR9122026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures913--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)914=== CONT TestService_ReadScope_PublicByDefault915=== NAME TestClientCADerivations916 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-58869-1726934962/TestClientCADerivations2992799591/001/store/7w1y3fdlrmm9pacvix9ri2i6xgqqjpgy-ca-test917 client_ca_test.go:139: Found 1 dependencies (including self)918=== NAME TestClientMultipleUploads919 client_integration_test.go:480: Created store path 0: /nix/var/nix/builds/nix-58869-1726934962/TestClientMultipleUploads220063144/001/store/c724839p4n4js62aqibrpilgk1312cmg-test-file-0.txt9202026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes921 client_integration_test.go:480: Created store path 1: /nix/var/nix/builds/nix-58869-1726934962/TestClientMultipleUploads220063144/001/store/ardc36acji3bsw9daw085b6w29lm2mnv-test-file-1.txt9222026/10/01 10:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9232026/10/01 10:34:01 WARN mTLS auth: bound subjects configured but subject DN unavailable9242026/10/01 10:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"9252026/10/01 10:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9262026/10/01 10:34:01 INFO Uploading 7w1y3fdlrmm9pacvix9ri2i6xgqqjpgy-ca-test (144B)927--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.79s)928=== CONT TestMetricsInventory9292026/10/01 10:34:01 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9302026/10/01 10:34:01 WARN Failed to register uploaded object key=7w1y3fdlrmm9pacvix9ri2i6xgqqjpgy.ls error="server returned 404: 404 page not found\n"9312026/10/01 10:34:01 WARN Failed to register uploaded object key=log/mw8g33vbh6vz9jpdbkqhaav9mdlw6gly-ca-test.drv error="server returned 404: 404 page not found\n"9322026/10/01 10:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9332026/10/01 10:34:01 INFO Signed narinfos id=1 count=19342026/10/01 10:34:01 INFO Uploading 1 narinfos9352026/10/01 10:34:01 INFO Received complete push request method=POST path=/api/pushes/1/complete9362026/10/01 10:34:01 WARN Failed to register uploaded object key=7w1y3fdlrmm9pacvix9ri2i6xgqqjpgy.narinfo error="server returned 404: 404 page not found\n"937=== NAME TestClientMultipleUploads938 client_integration_test.go:480: Created store path 2: /nix/var/nix/builds/nix-58869-1726934962/TestClientMultipleUploads220063144/001/store/falqgrdd4ppylld5rbd3vsan6lfkcv10-test-file-2.txt9392026/10/01 10:34:01 INFO Upload complete. (166ms)940=== NAME TestClientCADerivations941 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientCADerivations2992799591/001/store/7w1y3fdlrmm9pacvix9ri2i6xgqqjpgy-ca-test942 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst943 Compression: zstd944 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n945 NarSize: 144946 References: 947 Deriver: /nix/var/nix/builds/nix-58869-1726934962/TestClientCADerivations2992799591/001/store/mw8g33vbh6vz9jpdbkqhaav9mdlw6gly-ca-test.drv948 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n949 client_ca_test.go:185: Checking for realisation files in S3...950 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations951 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache952 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket8?endpoint=http://localhost:63495®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-58869-1726934962/TestClientCADerivations2992799591/001/store'953 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 19542026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes9552026/10/01 10:34:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9562026/10/01 10:34:02 INFO Uploading c724839p4n4js62aqibrpilgk1312cmg-test-file-0.txt (160B)9572026/10/01 10:34:02 INFO Uploading falqgrdd4ppylld5rbd3vsan6lfkcv10-test-file-2.txt (160B)9582026/10/01 10:34:02 INFO Uploading ardc36acji3bsw9daw085b6w29lm2mnv-test-file-1.txt (160B)9592026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9602026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9612026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"962--- PASS: TestClientCADerivations (1.95s)963=== CONT TestReadProxyConditionalGet9642026/10/01 10:34:02 WARN Failed to register uploaded object key=c724839p4n4js62aqibrpilgk1312cmg.ls error="server returned 404: 404 page not found\n"9652026/10/01 10:34:02 WARN Failed to register uploaded object key=ardc36acji3bsw9daw085b6w29lm2mnv.ls error="server returned 404: 404 page not found\n"9662026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9672026/10/01 10:34:02 WARN Failed to register uploaded object key=falqgrdd4ppylld5rbd3vsan6lfkcv10.ls error="server returned 404: 404 page not found\n"9682026/10/01 10:34:02 INFO Signed narinfos id=1 count=39692026/10/01 10:34:02 INFO Uploading 3 narinfos9702026/10/01 10:34:02 WARN Failed to register uploaded object key=falqgrdd4ppylld5rbd3vsan6lfkcv10.narinfo error="server returned 404: 404 page not found\n"9712026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete9722026/10/01 10:34:02 WARN Failed to register uploaded object key=c724839p4n4js62aqibrpilgk1312cmg.narinfo error="server returned 404: 404 page not found\n"9732026/10/01 10:34:02 WARN Failed to register uploaded object key=ardc36acji3bsw9daw085b6w29lm2mnv.narinfo error="server returned 404: 404 page not found\n"9742026/10/01 10:34:02 INFO Upload complete. (102ms)975=== NAME TestClientMultipleUploads976 client_integration_test.go:491: Uploaded 3 paths in 135.874125ms977--- PASS: TestClientMultipleUploads (2.05s)978=== CONT TestGenerateLandingPage979--- PASS: TestGenerateLandingPage (0.01s)980=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT981=== NAME TestPinProtectsFromGC982 client_integration_test.go:867: Pinned store path: /nix/var/nix/builds/nix-58869-1726934962/TestPinProtectsFromGC2392528453/001/store/rdg95kpyi1qm0mlns75mrhgr4japj3d5-pinned-file.txt983 client_integration_test.go:868: Unpinned store path: /nix/var/nix/builds/nix-58869-1726934962/TestPinProtectsFromGC2392528453/001/store/yaw4j02grd753yj28qsfjb5gajcijy24-unpinned-file.txt984--- PASS: TestService_ReadAuthMiddleware (1.33s)985=== CONT TestService_readinessHandler9862026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes9872026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9882026/10/01 10:34:02 INFO Uploading rdg95kpyi1qm0mlns75mrhgr4japj3d5-pinned-file.txt (128B)9892026/10/01 10:34:02 WARN Failed to register uploaded object key=rdg95kpyi1qm0mlns75mrhgr4japj3d5.ls error="server returned 404: 404 page not found\n"9902026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9912026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9922026/10/01 10:34:02 INFO Signed narinfos id=1 count=19932026/10/01 10:34:02 INFO Uploading 1 narinfos9942026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete9952026/10/01 10:34:02 WARN Failed to register uploaded object key=rdg95kpyi1qm0mlns75mrhgr4japj3d5.narinfo error="server returned 404: 404 page not found\n"9962026/10/01 10:34:02 INFO Upload complete. (112ms)9972026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes9982026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9992026/10/01 10:34:02 INFO Uploading yaw4j02grd753yj28qsfjb5gajcijy24-unpinned-file.txt (128B)10002026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10012026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10022026/10/01 10:34:02 WARN Failed to register uploaded object key=yaw4j02grd753yj28qsfjb5gajcijy24.ls error="server returned 404: 404 page not found\n"10032026/10/01 10:34:02 INFO Signed narinfos id=2 count=110042026/10/01 10:34:02 INFO Uploading 1 narinfos10052026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/2/complete10062026/10/01 10:34:02 WARN Failed to register uploaded object key=yaw4j02grd753yj28qsfjb5gajcijy24.narinfo error="server returned 404: 404 page not found\n"10072026/10/01 10:34:02 INFO Upload complete. (86ms)10082026/10/01 10:34:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures10092026/10/01 10:34:02 INFO Garbage collection started10102026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=010112026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period10122026/10/01 10:34:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010132026/10/01 10:34:02 INFO Vacuumed table table=pending_closures10142026/10/01 10:34:02 INFO Vacuumed table table=pending_objects10152026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads10162026/10/01 10:34:02 INFO Vacuumed table table=closures10172026/10/01 10:34:02 INFO Vacuumed table table=objects10182026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes10192026/10/01 10:34:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10202026/10/01 10:34:02 INFO Uploading wjj9x0zsviwca0yvj9bf7zmzqv09vr6x-top (256B)10212026/10/01 10:34:02 INFO Uploading 5vbfpxvx92zgvdvag0bpp8vjbk0pjvfz-shared-dep (136B)10222026/10/01 10:34:02 WARN Failed to register uploaded object key=5vbfpxvx92zgvdvag0bpp8vjbk0pjvfz.ls error="server returned 404: 404 page not found\n"10232026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10242026/10/01 10:34:02 WARN Failed to register uploaded object key=wjj9x0zsviwca0yvj9bf7zmzqv09vr6x.ls error="server returned 404: 404 page not found\n"10252026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10262026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0pqjkwq2c1rd5jkwsqqry870m7z53aryz10pbxw09mh4028m0yja.nar.zst error="server returned 404: 404 page not found\n"10272026/10/01 10:34:02 INFO Signed narinfos id=1 count=210282026/10/01 10:34:02 INFO Uploading 2 narinfos10292026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete10302026/10/01 10:34:02 WARN Failed to register uploaded object key=wjj9x0zsviwca0yvj9bf7zmzqv09vr6x.narinfo error="server returned 404: 404 page not found\n"10312026/10/01 10:34:02 WARN Failed to register uploaded object key=5vbfpxvx92zgvdvag0bpp8vjbk0pjvfz.narinfo error="server returned 404: 404 page not found\n"10322026/10/01 10:34:02 INFO Upload complete. (101ms)1033=== NAME TestClientSharedPathCommittedMidPush1034 client_integration_test.go:816: Retrieved narinfo from S3:1035 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientSharedPathCommittedMidPush3495623595/001/store/5vbfpxvx92zgvdvag0bpp8vjbk0pjvfz-shared-dep1036 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1037 Compression: zstd1038 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821039 NarSize: 1361040 References: 1041 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1042 client_integration_test.go:816: Retrieved narinfo from S3:1043 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientSharedPathCommittedMidPush3495623595/001/store/wjj9x0zsviwca0yvj9bf7zmzqv09vr6x-top1044 URL: nar/0pqjkwq2c1rd5jkwsqqry870m7z53aryz10pbxw09mh4028m0yja.nar.zst1045 Compression: zstd1046 NarHash: sha256:0pqjkwq2c1rd5jkwsqqry870m7z53aryz10pbxw09mh4028m0yja1047 NarSize: 2561048 References: /nix/var/nix/builds/nix-58869-1726934962/TestClientSharedPathCommittedMidPush3495623595/001/store/5vbfpxvx92zgvdvag0bpp8vjbk0pjvfz-shared-dep1049 CA: text:sha256:0r1s7gvgkbba2da5x7asc79lgxicqa5gv1skmaqx056n6c3znyhb1050=== RUN TestService_RequireScope_OIDC/builder_may_write1051=== PAUSE TestService_RequireScope_OIDC/builder_may_write1052=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1053=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1054=== RUN TestService_RequireScope_OIDC/ops_may_admin1055=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1056=== RUN TestService_RequireScope_OIDC/ops_may_not_write1057=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1058=== RUN TestService_RequireScope_OIDC/reader_may_not_write1059=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1060=== RUN TestService_RequireScope_OIDC/static_token_may_admin1061=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1062=== RUN TestService_RequireScope_OIDC/static_token_may_write1063=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1064=== RUN TestService_RequireScope_OIDC/reader_may_read1065=== PAUSE TestService_RequireScope_OIDC/reader_may_read1066=== RUN TestService_RequireScope_OIDC/writer_implies_read1067=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1068=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1069=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1070=== CONT TestService_verifyS3Integrity1071--- PASS: TestClientSharedPathCommittedMidPush (1.76s)1072=== CONT TestService_healthCheckHandler1073=== NAME TestClientWithDependencies1074 client_integration_test.go:735: Built derivation: /nix/var/nix/builds/nix-58869-1726934962/TestClientWithDependencies1082259099/001/store/iawk40l9r7pssf6w84n2ljqjm8hv9n2c-test-script1075 client_integration_test.go:737: Found 1 dependencies (including self)1076--- PASS: TestService_ReadScope_PublicByDefault (1.29s)1077=== CONT TestService_createPendingClosureHandler10782026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes10792026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10802026/10/01 10:34:02 INFO Uploading iawk40l9r7pssf6w84n2ljqjm8hv9n2c-test-script (136B)10812026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10822026/10/01 10:34:02 WARN Failed to register uploaded object key=iawk40l9r7pssf6w84n2ljqjm8hv9n2c.ls error="server returned 404: 404 page not found\n"10832026/10/01 10:34:02 WARN Failed to register uploaded object key=log/8k9nlrx2rh2jfybmxf0j9i2pzypa2nwj-test-script.drv error="server returned 404: 404 page not found\n"10842026/10/01 10:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10852026/10/01 10:34:03 INFO Signed narinfos id=1 count=110862026/10/01 10:34:03 INFO Uploading 1 narinfos10872026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete10882026/10/01 10:34:03 WARN Failed to register uploaded object key=iawk40l9r7pssf6w84n2ljqjm8hv9n2c.narinfo error="server returned 404: 404 page not found\n"10892026/10/01 10:34:03 INFO Upload complete. (117ms)10902026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=010912026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/01 10:34:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010932026/10/01 10:34:03 INFO Vacuumed table table=pending_closures10942026/10/01 10:34:03 INFO Vacuumed table table=pending_objects10952026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads10962026/10/01 10:34:03 INFO Vacuumed table table=closures10972026/10/01 10:34:03 INFO Vacuumed table table=objects1098=== NAME TestClientWithDependencies1099 client_integration_test.go:753: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-58869-1726934962/TestClientWithDependencies1082259099/001/store) requires matching store prefix1100--- PASS: TestMetricsInventory (1.26s)1101=== CONT TestCompleteMultipartUnregistered1102--- PASS: TestClientWithDependencies (1.89s)1103=== CONT TestGCTaskStore_Fail1104--- PASS: TestGCTaskStore_Fail (0.00s)1105=== CONT TestService_cleanupPendingClosuresHandler1106--- PASS: TestReadProxyConditionalGet (1.26s)1107=== CONT TestGCTaskStore_PhaseUpdates1108--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1109=== CONT TestIsValidUploadKey1110=== RUN TestIsValidUploadKey/narinfo1111=== PAUSE TestIsValidUploadKey/narinfo1112=== RUN TestIsValidUploadKey/nar_zst1113=== PAUSE TestIsValidUploadKey/nar_zst1114=== RUN TestIsValidUploadKey/nar_xz1115=== PAUSE TestIsValidUploadKey/nar_xz1116=== RUN TestIsValidUploadKey/nar_plain1117=== PAUSE TestIsValidUploadKey/nar_plain1118=== RUN TestIsValidUploadKey/listing1119=== PAUSE TestIsValidUploadKey/listing1120=== RUN TestIsValidUploadKey/build_log1121=== PAUSE TestIsValidUploadKey/build_log1122=== RUN TestIsValidUploadKey/build_log_home-manager_file1123=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1124=== RUN TestIsValidUploadKey/build_log_plus_in_name1125=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1126=== RUN TestIsValidUploadKey/build_log_question_mark1127=== PAUSE TestIsValidUploadKey/build_log_question_mark1128=== RUN TestIsValidUploadKey/build_log_equals1129=== PAUSE TestIsValidUploadKey/build_log_equals1130=== RUN TestIsValidUploadKey/realisation1131=== PAUSE TestIsValidUploadKey/realisation1132=== RUN TestIsValidUploadKey/realisation_plus_in_output1133=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1134=== RUN TestIsValidUploadKey/nix-cache-info1135=== PAUSE TestIsValidUploadKey/nix-cache-info1136=== RUN TestIsValidUploadKey/index.html1137=== PAUSE TestIsValidUploadKey/index.html1138=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1139=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1140=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1141=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1142=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1143=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1144=== RUN TestIsValidUploadKey/traversal1145=== PAUSE TestIsValidUploadKey/traversal1146=== RUN TestIsValidUploadKey/traversal_nar1147=== PAUSE TestIsValidUploadKey/traversal_nar1148=== RUN TestIsValidUploadKey/absolute1149=== PAUSE TestIsValidUploadKey/absolute1150=== RUN TestIsValidUploadKey/empty_key1151=== PAUSE TestIsValidUploadKey/empty_key1152=== RUN TestIsValidUploadKey/unknown_type1153=== PAUSE TestIsValidUploadKey/unknown_type1154=== CONT TestUploadHandlersRejectInvalidKeys1155=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1156=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1157=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1158=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1159=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1160=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1161=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1162=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1163=== CONT TestProxyWriteTimeout1164=== RUN TestProxyWriteTimeout/narinfo1165=== PAUSE TestProxyWriteTimeout/narinfo1166=== RUN TestProxyWriteTimeout/1_GiB_nar1167=== PAUSE TestProxyWriteTimeout/1_GiB_nar1168=== RUN TestProxyWriteTimeout/10_GiB_nar1169=== PAUSE TestProxyWriteTimeout/10_GiB_nar1170=== RUN TestProxyWriteTimeout/unknown_size1171=== PAUSE TestProxyWriteTimeout/unknown_size1172=== CONT TestCacheConfigHandlerMaxNarSize1173--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1174=== CONT TestGCTaskStore_GetReturnsLatest1175--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1176=== CONT TestGCTaskStore_GetEmpty1177--- PASS: TestGCTaskStore_GetEmpty (0.00s)1178=== CONT TestGCTaskStore_ConflictDifferentParams1179=== CONT TestGCTaskStore_DeduplicateSameParams1180=== CONT TestGracefulShutdownDrainsInflight1181--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1182--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)11832026/10/01 10:34:03 INFO Starting HTTP server address=127.0.0.1:6366111842026/10/01 10:34:03 INFO Shutdown signal received, draining in-flight requests timeout=10s1185=== CONT TestPendingClosureWriteTimeout1186=== RUN TestPendingClosureWriteTimeout/empty1187--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1188=== PAUSE TestPendingClosureWriteTimeout/empty1189=== RUN TestPendingClosureWriteTimeout/400_objects1190=== PAUSE TestPendingClosureWriteTimeout/400_objects1191=== RUN TestPendingClosureWriteTimeout/670k_objects1192=== PAUSE TestPendingClosureWriteTimeout/670k_objects1193=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1194=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1195=== CONT TestConnectWaitsForAPeerMigration11962026/10/01 10:34:03 INFO Received uploads request method=POST path=/api/pending_closures1197--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.34s)1198=== CONT TestGCMetrics11992026/10/01 10:34:03 WARN readiness check failed error="closed pool"1200--- PASS: TestService_readinessHandler (1.37s)1201=== CONT TestGCBugBareHashReferences12022026/10/01 10:34:03 INFO Received uploads request method=POST path=/api/pending_closures1203--- PASS: TestService_healthCheckHandler (1.20s)1204=== CONT TestGCAdvisoryLockBlocksConcurrentRun12052026/10/01 10:34:04 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/01 10:34:04 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/01 10:34:04 INFO Received uploads request method=POST path=/api/pending_closures12082026/10/01 10:34:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=012092026/10/01 10:34:04 INFO Received create pin request method=POST path=/api/pins/myapp12102026/10/01 10:34:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-58869-1726934962/TestPinProtectsFromGC2392528453/001/store/rdg95kpyi1qm0mlns75mrhgr4japj3d5-pinned-file.txt narinfo_key=rdg95kpyi1qm0mlns75mrhgr4japj3d5.narinfo12112026/10/01 10:34:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures12122026/10/01 10:34:04 INFO Garbage collection started12132026/10/01 10:34:04 INFO Aborted multipart uploads count=0 kept=012142026/10/01 10:34:04 WARN Force mode enabled - objects will be deleted immediately without grace period12152026/10/01 10:34:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012162026/10/01 10:34:04 INFO Vacuumed table table=pending_closures12172026/10/01 10:34:04 INFO Vacuumed table table=pending_objects12182026/10/01 10:34:04 INFO Vacuumed table table=multipart_uploads12192026/10/01 10:34:04 INFO Vacuumed table table=closures12202026/10/01 10:34:04 INFO Vacuumed table table=objects12212026/10/01 10:34:04 INFO Received cleanup request method=DELETE path=/api/pending_closures12222026/10/01 10:34:04 INFO Aborted multipart uploads count=0 kept=012232026/10/01 10:34:04 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/01 10:34:04 INFO Received cleanup request method=DELETE path=/api/pending_closures12252026/10/01 10:34:04 INFO Aborted multipart uploads count=1 kept=012262026/10/01 10:34:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12272026-10-01 10:34:04.739 UTC [59134] ERROR: Closure does not exist: id=112282026-10-01 10:34:04.739 UTC [59134] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE12292026-10-01 10:34:04.739 UTC [59134] STATEMENT: -- name: CommitPendingClosure :exec1230 SELECT commit_pending_closure($1::bigint)1231 1232--- PASS: TestService_cleanupPendingClosuresHandler (1.61s)1233=== CONT TestLeadEndsOnShutdown12342026/10/01 10:34:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12352026/10/01 10:34:04 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1236--- PASS: TestCompleteMultipartUnregistered (1.80s)1237=== CONT TestLeadElectsOneAndHandsOver12382026/10/01 10:34:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12392026/10/01 10:34:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LmI5NDViOTBhLWFiMzEtNDc1Mi05NjZiLWRiNzY3Mzg3YjBjMXgxNzkwODUwODQzODA2ODY5MDAw parts=1012402026/10/01 10:34:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12412026/10/01 10:34:05 INFO Completed upload id=112422026/10/01 10:34:05 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/01 10:34:05 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/01 10:34:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12452026/10/01 10:34:05 WARN Found objects in DB but missing from S3, will re-upload count=112462026/10/01 10:34:05 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12472026/10/01 10:34:05 INFO Completed upload id=31248--- PASS: TestService_verifyS3Integrity (2.36s)1249=== CONT TestClientIntegration12502026/10/01 10:34:05 INFO Aborted multipart uploads count=0 kept=012512026/10/01 10:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/01 10:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012532026/10/01 10:34:05 INFO Vacuumed table table=pending_closures12542026/10/01 10:34:05 INFO Vacuumed table table=pending_objects12552026/10/01 10:34:05 INFO Vacuumed table table=multipart_uploads12562026/10/01 10:34:05 INFO Vacuumed table table=closures12572026/10/01 10:34:05 INFO Vacuumed table table=objects1258--- PASS: TestGCMetrics (1.76s)1259=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12602026/10/01 10:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12612026/10/01 10:34:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LmNhNjI0M2JlLWVkNTUtNDBmZC1hYjNkLWUzMGU0ZGRlNGFlMngxNzkwODUwODQ0MjEzMDcwMDAw parts=1012622026/10/01 10:34:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12632026/10/01 10:34:05 INFO Completed upload id=112642026/10/01 10:34:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012652026/10/01 10:34:05 INFO Received uploads request method=POST path=/api/pending_closures12662026/10/01 10:34:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures12672026/10/01 10:34:05 INFO Aborted multipart uploads count=0 kept=012682026/10/01 10:34:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012692026/10/01 10:34:05 INFO Vacuumed table table=pending_closures12702026/10/01 10:34:05 INFO Vacuumed table table=pending_objects12712026/10/01 10:34:05 INFO Vacuumed table table=multipart_uploads12722026/10/01 10:34:05 INFO Vacuumed table table=closures12732026/10/01 10:34:05 INFO Vacuumed table table=objects12742026/10/01 10:34:05 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001275--- PASS: TestService_createPendingClosureHandler (2.60s)1276=== CONT TestResolveDBConnectionString1277=== RUN TestResolveDBConnectionString/flag_wins1278=== PAUSE TestResolveDBConnectionString/flag_wins1279=== RUN TestResolveDBConnectionString/file_when_flag_empty1280=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1281=== RUN TestResolveDBConnectionString/missing_file_is_an_error1282=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1283=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1284=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1285=== RUN TestResolveDBConnectionString/nothing_configured1286=== PAUSE TestResolveDBConnectionString/nothing_configured1287=== CONT TestConnectSerialisesConcurrentMigrations1288--- PASS: TestGCBugBareHashReferences (2.03s)1289=== CONT TestIsValidCachePath1290=== RUN TestIsValidCachePath/narinfo1291=== PAUSE TestIsValidCachePath/narinfo1292=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1293=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1294=== RUN TestIsValidCachePath/nar_zst1295=== PAUSE TestIsValidCachePath/nar_zst1296=== RUN TestIsValidCachePath/nar_xz1297=== PAUSE TestIsValidCachePath/nar_xz1298=== RUN TestIsValidCachePath/nar_bz21299=== PAUSE TestIsValidCachePath/nar_bz21300=== RUN TestIsValidCachePath/nar_uncompressed1301=== PAUSE TestIsValidCachePath/nar_uncompressed1302=== RUN TestIsValidCachePath/ls1303=== PAUSE TestIsValidCachePath/ls1304=== RUN TestIsValidCachePath/log1305=== PAUSE TestIsValidCachePath/log1306=== RUN TestIsValidCachePath/realisation1307=== PAUSE TestIsValidCachePath/realisation1308=== RUN TestIsValidCachePath/nix-cache-info1309=== PAUSE TestIsValidCachePath/nix-cache-info1310=== RUN TestIsValidCachePath/index.html1311=== PAUSE TestIsValidCachePath/index.html1312=== RUN TestIsValidCachePath/traversal_parent1313=== PAUSE TestIsValidCachePath/traversal_parent1314=== RUN TestIsValidCachePath/traversal_in_middle1315=== PAUSE TestIsValidCachePath/traversal_in_middle1316=== RUN TestIsValidCachePath/invalid_char_e1317=== PAUSE TestIsValidCachePath/invalid_char_e1318=== RUN TestIsValidCachePath/invalid_char_u1319=== PAUSE TestIsValidCachePath/invalid_char_u1320=== RUN TestIsValidCachePath/random_path1321=== PAUSE TestIsValidCachePath/random_path1322=== RUN TestIsValidCachePath/empty1323=== PAUSE TestIsValidCachePath/empty1324=== RUN TestIsValidCachePath/leading_slash1325=== PAUSE TestIsValidCachePath/leading_slash1326=== RUN TestIsValidCachePath/wrong_extension1327=== PAUSE TestIsValidCachePath/wrong_extension1328=== RUN TestIsValidCachePath/short_hash1329=== PAUSE TestIsValidCachePath/short_hash1330=== CONT TestReadProxyDisabled13312026/10/01 10:34:05 INFO lead: acquired remote=192.0.2.1:123413322026/10/01 10:34:05 INFO lead: acquired remote=192.0.2.1:12341333=== NAME TestClientIntegration1334 client_integration_test.go:334: Created store path: /nix/var/nix/builds/nix-58869-1726934962/TestClientIntegration4140936640/002/store/gz7vbmwimysi5w7f33rgzjqskc7r3gad-test-file.txt13352026-10-01 10:34:06.464 UTC [59171] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"13362026-10-01 10:34:06.464 UTC [59171] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.13372026-10-01 10:34:06.464 UTC [59171] STATEMENT: CREATE TABLE goose_db_version (1338 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1339 version_id bigint NOT NULL,1340 is_applied boolean NOT NULL,1341 tstamp timestamp NOT NULL DEFAULT now()1342 )13432026/10/01 10:34:06 INFO Received push request method=POST path=/api/pushes1344=== NAME TestPinProtectsFromGC1345 client_integration_test.go:976: Pin successfully protected closure from garbage collection13462026/10/01 10:34:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13472026/10/01 10:34:06 INFO Uploading gz7vbmwimysi5w7f33rgzjqskc7r3gad-test-file.txt (152B)13482026/10/01 10:34:06 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13492026/10/01 10:34:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13502026/10/01 10:34:06 WARN Failed to register uploaded object key=gz7vbmwimysi5w7f33rgzjqskc7r3gad.ls error="server returned 404: 404 page not found\n"13512026/10/01 10:34:06 INFO Signed narinfos id=1 count=113522026/10/01 10:34:06 INFO Uploading 1 narinfos13532026/10/01 10:34:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13542026/10/01 10:34:06 WARN Failed to register uploaded object key=gz7vbmwimysi5w7f33rgzjqskc7r3gad.narinfo error="server returned 404: 404 page not found\n"1355--- PASS: TestPinProtectsFromGC (6.50s)1356=== CONT TestReadProxyHead13572026/10/01 10:34:06 INFO Upload complete. (79ms)13582026/10/01 10:34:06 INFO All 1 paths already cached1359=== NAME TestClientIntegration1360 client_integration_test.go:360: Retrieved narinfo from S3:1361 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientIntegration4140936640/002/store/gz7vbmwimysi5w7f33rgzjqskc7r3gad-test-file.txt1362 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1363 Compression: zstd1364 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11365 NarSize: 1521366 References: 1367 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11368 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1369 client_integration_test.go:361: Decompressed .ls content (64 bytes):1370 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}13712026/10/01 10:34:06 INFO Aborted multipart uploads count=1 kept=013722026/10/01 10:34:06 INFO Received cleanup request method=DELETE path=/api/pending_closures13732026/10/01 10:34:06 INFO Aborted multipart uploads count=1 kept=013742026/10/01 10:34:06 INFO Received push request method=POST path=/api/pushes13752026/10/01 10:34:06 INFO Object in database but missing from S3 key=gz7vbmwimysi5w7f33rgzjqskc7r3gad.ls13762026/10/01 10:34:06 WARN Found objects in DB but missing from S3, will re-upload count=113772026/10/01 10:34:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13782026/10/01 10:34:06 INFO Received complete push request method=POST path=/api/pushes/2/complete1379--- PASS: TestPendingCleanupUsesOneCutoff (6.65s)1380=== CONT TestReadProxyOutlastsServerWriteTimeout13812026/10/01 10:34:06 WARN Failed to register uploaded object key=gz7vbmwimysi5w7f33rgzjqskc7r3gad.ls error="server returned 404: 404 page not found\n"13822026/10/01 10:34:06 INFO Upload complete. (62ms)1383=== NAME TestClientIntegration1384 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1385 client_integration_test.go:389: Decompressed .ls content (49 bytes):1386 {"version":1,"root":{"type":"regular","size":39}}13872026/10/01 10:34:06 INFO Received push request method=POST path=/api/pushes13882026/10/01 10:34:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13892026/10/01 10:34:06 INFO lead: released remote=192.0.2.1:12341390--- PASS: TestLeadEndsOnShutdown (2.08s)1391=== CONT TestReadProxyInvalidPath13922026/10/01 10:34:06 INFO Received complete push request method=POST path=/api/pushes/3/complete13932026/10/01 10:34:06 WARN Failed to register uploaded object key=gz7vbmwimysi5w7f33rgzjqskc7r3gad.ls error="server returned 404: 404 page not found\n"13942026/10/01 10:34:06 INFO Upload complete. (68ms)1395=== NAME TestClientIntegration1396 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1397 client_integration_test.go:405: Decompressed .ls content (49 bytes):1398 {"version":1,"root":{"type":"regular","size":39}}1399--- PASS: TestReadProxyDisabled (1.40s)1400=== CONT TestReadProxy40414012026/10/01 10:34:07 INFO Received push request method=POST path=/api/pushes14022026/10/01 10:34:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14032026/10/01 10:34:07 INFO Uploading 7aj5swg2p2mz3dywc7d34ak690is9vqz-lost-commit.txt (152B)14042026/10/01 10:34:07 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14052026/10/01 10:34:07 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14062026/10/01 10:34:07 WARN Failed to register uploaded object key=7aj5swg2p2mz3dywc7d34ak690is9vqz.ls error="server returned 404: 404 page not found\n"14072026/10/01 10:34:07 INFO Signed narinfos id=4 count=114082026/10/01 10:34:07 INFO Uploading 1 narinfos14092026/10/01 10:34:07 INFO Received complete push request method=POST path=/api/pushes/4/complete14102026/10/01 10:34:07 WARN Failed to register uploaded object key=7aj5swg2p2mz3dywc7d34ak690is9vqz.narinfo error="server returned 404: 404 page not found\n"14112026/10/01 10:34:07 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:63713/api/pushes/4/complete\": EOF" url=http://127.0.0.1:63713/api/pushes/4/complete14122026/10/01 10:34:07 INFO Received complete push request method=POST path=/api/pushes/4/complete14132026-10-01 10:34:07.150 UTC [59166] ERROR: Push does not exist: id=414142026-10-01 10:34:07.150 UTC [59166] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE14152026-10-01 10:34:07.150 UTC [59166] STATEMENT: -- name: CommitPush :exec1416 SELECT commit_push($1::bigint)1417 14182026/10/01 10:34:07 INFO Upload complete. (199ms)1419=== NAME TestClientIntegration1420 client_integration_test.go:435: Retrieved narinfo from S3:1421 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientIntegration4140936640/002/store/7aj5swg2p2mz3dywc7d34ak690is9vqz-lost-commit.txt1422 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1423 Compression: zstd1424 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1425 NarSize: 1521426 References: 1427 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1428 client_integration_test.go:438: Testing garbage collection...14292026/10/01 10:34:07 INFO lead: released remote=192.0.2.1:123414302026/10/01 10:34:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures14312026/10/01 10:34:07 INFO Garbage collection started14322026/10/01 10:34:07 INFO Aborted multipart uploads count=0 kept=014332026/10/01 10:34:07 WARN Force mode enabled - objects will be deleted immediately without grace period14342026/10/01 10:34:07 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"14352026/10/01 10:34:07 INFO lead: acquired remote=192.0.2.1:12341436--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (3.24s)1437=== CONT TestReadProxyNarinfoAlreadyDecompressed14382026/10/01 10:34:07 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=014392026/10/01 10:34:07 INFO Vacuumed table table=pending_closures14402026/10/01 10:34:07 INFO Vacuumed table table=pending_objects14412026/10/01 10:34:07 INFO Vacuumed table table=multipart_uploads14422026/10/01 10:34:07 INFO Vacuumed table table=closures14432026/10/01 10:34:07 INFO Vacuumed table table=objects1444--- PASS: TestConnectSerialisesConcurrentMigrations (1.98s)1445=== CONT TestReadProxyNarinfo1446--- PASS: TestReadProxyHead (1.34s)1447=== CONT TestReadProxyNarStreaming14482026/10/01 10:34:08 INFO lead: released remote=192.0.2.1:12341449--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.05s)1450=== CONT TestProxyHeadersOnlyTrustedOnSocket1451--- PASS: TestLeadElectsOneAndHandsOver (3.35s)1452=== CONT TestParseSingleRange1453=== RUN TestParseSingleRange/none1454=== PAUSE TestParseSingleRange/none1455=== RUN TestParseSingleRange/unknown_unit1456=== PAUSE TestParseSingleRange/unknown_unit1457=== RUN TestParseSingleRange/multi-range_ignored1458=== PAUSE TestParseSingleRange/multi-range_ignored1459=== RUN TestParseSingleRange/malformed_no_dash1460=== PAUSE TestParseSingleRange/malformed_no_dash1461=== RUN TestParseSingleRange/malformed_both_empty1462=== PAUSE TestParseSingleRange/malformed_both_empty1463=== RUN TestParseSingleRange/malformed_end_before_start1464=== PAUSE TestParseSingleRange/malformed_end_before_start1465=== RUN TestParseSingleRange/closed1466=== PAUSE TestParseSingleRange/closed1467=== RUN TestParseSingleRange/open-ended1468=== PAUSE TestParseSingleRange/open-ended1469=== RUN TestParseSingleRange/end_clamped_to_size1470=== PAUSE TestParseSingleRange/end_clamped_to_size1471=== RUN TestParseSingleRange/suffix1472=== PAUSE TestParseSingleRange/suffix1473=== RUN TestParseSingleRange/suffix_exceeds_size1474=== PAUSE TestParseSingleRange/suffix_exceeds_size1475=== RUN TestParseSingleRange/single_byte1476=== PAUSE TestParseSingleRange/single_byte1477=== RUN TestParseSingleRange/start_past_EOF1478=== PAUSE TestParseSingleRange/start_past_EOF1479=== RUN TestParseSingleRange/start_far_past_EOF1480=== PAUSE TestParseSingleRange/start_far_past_EOF1481=== CONT TestPresentNotReportedWhileGCDeletesClosure1482--- PASS: TestReadProxyInvalidPath (1.55s)1483=== CONT TestPresentReportsOnlyClosureRoots14842026/10/01 10:34:08 WARN Rate limiter enabled after throttle name=s3-test rate=514852026/10/01 10:34:08 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14862026/10/01 10:34:08 WARN Rate limiter backed off name=s3-test rate=514872026/10/01 10:34:08 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1488=== CONT TestDeletePinKeepsRowWhenS3Fails1489--- PASS: TestReadProxy404 (1.94s)1490--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.75s)1491=== CONT TestPush_RejectsBadRequests14922026/10/01 10:34:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01493=== NAME TestClientIntegration1494 client_integration_test.go:445: Objects in database after GC:1495 client_integration_test.go:445: Successfully deleted all objects with GC --force1496--- PASS: TestClientIntegration (4.13s)1497=== CONT TestSkippedUploadsHandler14982026/10/01 10:34:09 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001499--- PASS: TestSkippedUploadsHandler (0.00s)1500=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15012026/10/01 10:34:09 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1502--- PASS: TestReadProxyNarStreaming (1.79s)1503=== CONT TestService_Rustfstest1504--- PASS: TestConnectWaitsForAPeerMigration (6.40s)1505=== CONT TestPresignedUploadRegisteredBeforeCommit15062026/10/01 10:34:09 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161507--- PASS: TestReadProxyNarinfo (2.40s)1508=== CONT TestCompletedNarNotReofferedAcrossClosures15092026/10/01 10:34:10 INFO Starting HTTP server address=/nix/var/nix/builds/nix-58869-1726934962/TestProxyHeadersOnlyTrustedOnSocket456944964/001/proxy.sock15102026/10/01 10:34:10 INFO Starting HTTP server address=127.0.0.1:6382115112026/10/01 10:34:10 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15122026/10/01 10:34:10 INFO Shutdown signal received, draining in-flight requests timeout=10s1513--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.99s)1514=== CONT TestParseSize1515--- PASS: TestParseSize (0.00s)1516=== CONT TestService_AuthMiddleware_MTLSProxyHeader1517--- PASS: TestPresentReportsOnlyClosureRoots (2.06s)1518=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1519--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.31s)1520=== CONT TestService_AuthMiddleware_OIDC15212026/10/01 10:34:10 INFO Received create pin request method=POST path=/api/pins/app15222026/10/01 10:34:10 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15232026/10/01 10:34:10 INFO Received delete pin request method=DELETE path=/api/pins/app15242026/10/01 10:34:10 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15252026/10/01 10:34:10 INFO Received delete pin request method=DELETE path=/api/pins/app15262026/10/01 10:34:10 INFO Deleted pin name=app1527--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.73s)1528=== CONT TestRedundantMultipartUpload15292026/10/01 10:34:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63836/oidc1530=== RUN TestPush_RejectsBadRequests/no_roots1531=== PAUSE TestPush_RejectsBadRequests/no_roots1532=== RUN TestPush_RejectsBadRequests/no_objects1533=== PAUSE TestPush_RejectsBadRequests/no_objects1534=== RUN TestPush_RejectsBadRequests/bad_root1535=== PAUSE TestPush_RejectsBadRequests/bad_root1536=== RUN TestPush_RejectsBadRequests/root_not_in_objects1537=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1538=== CONT TestService_AuthMiddleware15392026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15402026/10/01 10:34:11 INFO Received uploads request method=POST path=/api/pending_closures15412026/10/01 10:34:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15422026/10/01 10:34:11 INFO Received uploads request method=POST path=/api/pending_closures1543--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.51s)1544=== CONT TestClientPushesUseOnePush15452026/10/01 10:34:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1546--- PASS: TestService_Rustfstest (1.73s)1547=== CONT TestReconnectLeavesObjectsUnlocked15482026/10/01 10:34:11 INFO Received uploads request method=POST path=/api/pending_closures1549--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.76s)1550=== CONT TestConcurrentPinUpdatesAgree15512026/10/01 10:34:12 INFO Received uploads request method=POST path=/api/pending_closures1552--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.70s)1553=== CONT TestCreatePin_ReservedPins15542026/10/01 10:34:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1555--- PASS: TestService_AuthMiddleware (1.72s)1556=== CONT TestCreatePinRejectsBadInput15572026/10/01 10:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15582026/10/01 10:34:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1Ljg1MmFlNjExLWMwODMtNGQ5MC05MGUwLWYyMjQ2ZWMxZGNkNHgxNzkwODUwODUyMjUyMjYxMDAw15592026/10/01 10:34:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63875/oidc15602026/10/01 10:34:12 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1Ljg1MmFlNjExLWMwODMtNGQ5MC05MGUwLWYyMjQ2ZWMxZGNkNHgxNzkwODUwODUyMjUyMjYxMDAw error="Delete \"http://localhost:63495/bucket53/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1Ljg1MmFlNjExLWMwODMtNGQ5MC05MGUwLWYyMjQ2ZWMxZGNkNHgxNzkwODUwODUyMjUyMjYxMDAw\": injected: abort refused"15612026/10/01 10:34:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15622026/10/01 10:34:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1Ljg1MmFlNjExLWMwODMtNGQ5MC05MGUwLWYyMjQ2ZWMxZGNkNHgxNzkwODUwODUyMjUyMjYxMDAw15632026/10/01 10:34:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1Ljg1MmFlNjExLWMwODMtNGQ5MC05MGUwLWYyMjQ2ZWMxZGNkNHgxNzkwODUwODUyMjUyMjYxMDAw parts=11564--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.20s)1565=== CONT TestOrphanedObjectsGCStressTest1566=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1567=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1568=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1569=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1570=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1571=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1572=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1573=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1574=== CONT TestOrphanedObjectsGC15752026/10/01 10:34:13 INFO Received uploads request method=POST path=/api/pending_closures15762026/10/01 10:34:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15772026/10/01 10:34:13 INFO Received uploads request method=POST path=/api/pending_closures15782026/10/01 10:34:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjQ3ZWVlMmZmLTE2MjgtNDgwNy1hZGNhLTI3ZjNjM2M1Y2RkYXgxNzkwODUwODUxNjQ4NDE5MDAw parts=1215792026/10/01 10:34:13 INFO Received uploads request method=POST path=/api/pending_closures1580--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.30s)1581=== CONT TestObjectStatsTrigger1582--- PASS: TestReconnectLeavesObjectsUnlocked (2.13s)1583=== CONT TestClientFallsBackToClosures15842026/10/01 10:34:13 INFO Received push request method=POST path=/api/pushes15852026/10/01 10:34:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15862026/10/01 10:34:13 INFO Uploading 6na460sahip4h6hlghcjfv9py41bgwgc-shared-dep (136B)15872026/10/01 10:34:13 INFO Uploading pm4xrs9igvnvk1djfdcgxj5wji23sm8y-a (248B)15882026/10/01 10:34:13 WARN Failed to register uploaded object key=6na460sahip4h6hlghcjfv9py41bgwgc.ls error="server returned 404: 404 page not found\n"15892026/10/01 10:34:13 WARN Failed to register uploaded object key=53g8hc16y9lxasv0jkm0c5zivqh4xxp2.ls error="server returned 404: 404 page not found\n"15902026/10/01 10:34:13 WARN Failed to register uploaded object key=nar/000r10sbqmdjglhhcbr6gkb07vrb97hrbic252v4d0152vj9n7bs.nar.zst error="server returned 404: 404 page not found\n"15912026/10/01 10:34:13 WARN Failed to register uploaded object key=pm4xrs9igvnvk1djfdcgxj5wji23sm8y.ls error="server returned 404: 404 page not found\n"15922026/10/01 10:34:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15932026/10/01 10:34:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15942026/10/01 10:34:13 INFO Signed narinfos id=1 count=315952026/10/01 10:34:13 INFO Uploading 3 narinfos15962026/10/01 10:34:13 WARN Failed to register uploaded object key=pm4xrs9igvnvk1djfdcgxj5wji23sm8y.narinfo error="server returned 404: 404 page not found\n"15972026/10/01 10:34:13 WARN Failed to register uploaded object key=6na460sahip4h6hlghcjfv9py41bgwgc.narinfo error="server returned 404: 404 page not found\n"15982026/10/01 10:34:13 INFO Received complete push request method=POST path=/api/pushes/1/complete15992026/10/01 10:34:13 WARN Failed to register uploaded object key=53g8hc16y9lxasv0jkm0c5zivqh4xxp2.narinfo error="server returned 404: 404 page not found\n"16002026/10/01 10:34:13 INFO Upload complete. (163ms)1601=== NAME TestClientPushesUseOnePush1602 client_pushes_test.go:97: Retrieved narinfo from S3:1603 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientPushesUseOnePush2312616106/001/store/6na460sahip4h6hlghcjfv9py41bgwgc-shared-dep1604 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1605 Compression: zstd1606 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821607 NarSize: 1361608 References: 1609 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1610 client_pushes_test.go:97: Retrieved narinfo from S3:1611 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientPushesUseOnePush2312616106/001/store/pm4xrs9igvnvk1djfdcgxj5wji23sm8y-a1612 URL: nar/000r10sbqmdjglhhcbr6gkb07vrb97hrbic252v4d0152vj9n7bs.nar.zst1613 Compression: zstd1614 NarHash: sha256:000r10sbqmdjglhhcbr6gkb07vrb97hrbic252v4d0152vj9n7bs1615 NarSize: 2481616 References: /nix/var/nix/builds/nix-58869-1726934962/TestClientPushesUseOnePush2312616106/001/store/6na460sahip4h6hlghcjfv9py41bgwgc-shared-dep1617 CA: text:sha256:0ld6pp1fy07zb84dyy2l3kkfb5nsyakq2ni9qb9bk5jjd9a0fj971618 client_pushes_test.go:97: Retrieved narinfo from S3:1619 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientPushesUseOnePush2312616106/001/store/53g8hc16y9lxasv0jkm0c5zivqh4xxp2-b1620 URL: nar/000r10sbqmdjglhhcbr6gkb07vrb97hrbic252v4d0152vj9n7bs.nar.zst1621 Compression: zstd1622 NarHash: sha256:000r10sbqmdjglhhcbr6gkb07vrb97hrbic252v4d0152vj9n7bs1623 NarSize: 2481624 References: /nix/var/nix/builds/nix-58869-1726934962/TestClientPushesUseOnePush2312616106/001/store/6na460sahip4h6hlghcjfv9py41bgwgc-shared-dep1625 CA: text:sha256:0ld6pp1fy07zb84dyy2l3kkfb5nsyakq2ni9qb9bk5jjd9a0fj9716262026/10/01 10:34:13 INFO Received create pin request method=POST path=/api/pins/app16272026/10/01 10:34:13 INFO Received create pin request method=POST path=/api/pins/app1628--- PASS: TestClientPushesUseOnePush (2.64s)1629=== CONT TestUploadHandlersRejectOversizedBody1630=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1631=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1632=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1633=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1634=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1635=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1636=== CONT TestMultipartCleanup16372026/10/01 10:34:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16382026/10/01 10:34:14 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo16392026/10/01 10:34:14 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1640--- PASS: TestConcurrentPinUpdatesAgree (2.44s)1641=== CONT TestReadRedirectUsesPublicS3URL16422026/10/01 10:34:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjhkMDUwNjRmLTU1NDEtNDg0NS04MDc0LTg5Yzg1NGY1OWY4OXgxNzkwODUwODUzMDg5ODcxMDAw parts=1216432026/10/01 10:34:14 INFO Received uploads request method=POST path=/api/pending_closures16442026/10/01 10:34:14 INFO Received uploads request method=POST path=/api/pending_closures16452026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16462026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16472026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16482026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16492026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16502026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16512026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16522026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16532026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16542026/10/01 10:34:14 INFO Received create pin request method=POST path=/api/pins/deploy16552026/10/01 10:34:14 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1656--- PASS: TestCreatePinRejectsBadInput (2.37s)1657=== CONT TestPendingClosureFailureTracksEveryUpload1658=== NAME TestOrphanedObjectsGC1659 orphaned_objects_gc_test.go:290: GC Test Summary:1660 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1661 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1662 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1663 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1664 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1665--- PASS: TestOrphanedObjectsGC (2.19s)1666=== CONT TestReadRedirectNar16672026/10/01 10:34:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16682026/10/01 10:34:15 WARN Refused reserved pin name=worker-x86_64-linux16692026/10/01 10:34:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16702026/10/01 10:34:15 INFO Received create pin request method=POST path=/api/pins/my-app16712026/10/01 10:34:15 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1672--- PASS: TestCreatePin_ReservedPins (2.71s)1673=== CONT TestPendingClosureFailureAbortsItsUploads1674--- PASS: TestObjectStatsTrigger (2.23s)1675=== CONT TestReadRedirectKeepsNarinfoProxied16762026/10/01 10:34:15 WARN Rate limiter enabled after throttle name=s3-test rate=516772026/10/01 10:34:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1678=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1679 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101680 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001681--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.62s)1682=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16832026/10/01 10:34:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16842026/10/01 10:34:16 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LmNlYWI4NzIzLWUzMDktNDJmMy1hZTU1LTI3MmMxNzk4ZjEyYXgxNzkwODUwODU0NDk0Njc5MDAw error="Get \"http://127.0.0.1:1/bucket56/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"16852026/10/01 10:34:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjY2MTljNDgzLTAwOTQtNDdhMC05Y2ViLWUzNjBkNDc5ZmQ4YXgxNzkwODUwODU0NDU5MTk5MDAw parts=1216862026/10/01 10:34:16 INFO Received cleanup request method=DELETE path=/api/pending_closures16872026/10/01 10:34:16 INFO Aborted multipart uploads count=1 kept=016882026/10/01 10:34:16 INFO Received uploads request method=POST path=/api/pending_closures1689--- PASS: TestRedundantMultipartUpload (5.41s)1690=== CONT TestReadProxyRootRedirectsToIndexHTML16912026/10/01 10:34:16 INFO Received cleanup request method=DELETE path=/api/pending_closures16922026/10/01 10:34:16 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket66/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16932026/10/01 10:34:16 INFO Aborted multipart uploads count=0 kept=116942026/10/01 10:34:16 INFO Received cleanup request method=DELETE path=/api/pending_closures16952026/10/01 10:34:16 INFO Received uploads request method=POST path=/api/pending_closures16962026/10/01 10:34:16 INFO Aborted multipart uploads count=1 kept=01697--- PASS: TestMultipartCleanup (2.30s)1698=== CONT TestService_NativeMTLS16992026/10/01 10:34:16 INFO Received uploads request method=POST path=/api/pending_closures17002026/10/01 10:34:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17012026/10/01 10:34:16 INFO Uploading 23655ajk6af850m57n1dhw4676b2j5fc-a (248B)17022026/10/01 10:34:16 INFO Uploading drcx8j51w6lsxwc20p19b9jgqvzpvpd4-shared-dep (136B)17032026/10/01 10:34:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17042026/10/01 10:34:16 WARN Failed to register uploaded object key=nar/0nw3kf536gxfhpsgiwfl7k3vgdg91yfk6n3baykbykfzfa71q0w6.nar.zst error="server returned 404: 404 page not found\n"17052026/10/01 10:34:16 WARN Failed to register uploaded object key=8y5jw5bvx2lh7y29mb6wwxfcvhvr30ch.ls error="server returned 404: 404 page not found\n"17062026/10/01 10:34:16 WARN Failed to register uploaded object key=23655ajk6af850m57n1dhw4676b2j5fc.ls error="server returned 404: 404 page not found\n"17072026/10/01 10:34:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17082026/10/01 10:34:16 WARN Failed to register uploaded object key=drcx8j51w6lsxwc20p19b9jgqvzpvpd4.ls error="server returned 404: 404 page not found\n"17092026/10/01 10:34:16 INFO Signed narinfos id=2 count=217102026/10/01 10:34:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17112026/10/01 10:34:16 INFO Signed narinfos id=1 count=217122026/10/01 10:34:16 INFO Uploading 4 narinfos17132026/10/01 10:34:16 WARN Failed to register uploaded object key=23655ajk6af850m57n1dhw4676b2j5fc.narinfo error="server returned 404: 404 page not found\n"17142026/10/01 10:34:16 WARN Failed to register uploaded object key=8y5jw5bvx2lh7y29mb6wwxfcvhvr30ch.narinfo error="server returned 404: 404 page not found\n"17152026/10/01 10:34:16 WARN Failed to register uploaded object key=drcx8j51w6lsxwc20p19b9jgqvzpvpd4.narinfo error="server returned 404: 404 page not found\n"17162026/10/01 10:34:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17172026/10/01 10:34:16 WARN Failed to register uploaded object key=drcx8j51w6lsxwc20p19b9jgqvzpvpd4.narinfo error="server returned 404: 404 page not found\n"17182026/10/01 10:34:16 INFO Completed upload id=217192026/10/01 10:34:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17202026/10/01 10:34:16 INFO Completed upload id=117212026/10/01 10:34:16 INFO Upload complete. (165ms)1722=== NAME TestClientFallsBackToClosures1723 client_pushes_test.go:112: Retrieved narinfo from S3:1724 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientFallsBackToClosures3311815320/001/store/drcx8j51w6lsxwc20p19b9jgqvzpvpd4-shared-dep1725 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1726 Compression: zstd1727 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821728 NarSize: 1361729 References: 1730 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1731 client_pushes_test.go:112: Retrieved narinfo from S3:1732 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientFallsBackToClosures3311815320/001/store/23655ajk6af850m57n1dhw4676b2j5fc-a1733 URL: nar/0nw3kf536gxfhpsgiwfl7k3vgdg91yfk6n3baykbykfzfa71q0w6.nar.zst1734 Compression: zstd1735 NarHash: sha256:0nw3kf536gxfhpsgiwfl7k3vgdg91yfk6n3baykbykfzfa71q0w61736 NarSize: 2481737 References: /nix/var/nix/builds/nix-58869-1726934962/TestClientFallsBackToClosures3311815320/001/store/drcx8j51w6lsxwc20p19b9jgqvzpvpd4-shared-dep1738 CA: text:sha256:1gkk394lv5r6wpkx7pmnyv6cq99bzsfxa3lvzsqimlxjbd1x59nc1739 client_pushes_test.go:112: Retrieved narinfo from S3:1740 StorePath: /nix/var/nix/builds/nix-58869-1726934962/TestClientFallsBackToClosures3311815320/001/store/8y5jw5bvx2lh7y29mb6wwxfcvhvr30ch-b1741 URL: nar/0nw3kf536gxfhpsgiwfl7k3vgdg91yfk6n3baykbykfzfa71q0w6.nar.zst1742 Compression: zstd1743 NarHash: sha256:0nw3kf536gxfhpsgiwfl7k3vgdg91yfk6n3baykbykfzfa71q0w61744 NarSize: 2481745 References: /nix/var/nix/builds/nix-58869-1726934962/TestClientFallsBackToClosures3311815320/001/store/drcx8j51w6lsxwc20p19b9jgqvzpvpd4-shared-dep1746 CA: text:sha256:1gkk394lv5r6wpkx7pmnyv6cq99bzsfxa3lvzsqimlxjbd1x59nc1747--- PASS: TestClientFallsBackToClosures (2.83s)1748=== CONT TestServerTLSConfig1749=== RUN TestServerTLSConfig/no_client_CA1750=== PAUSE TestServerTLSConfig/no_client_CA1751=== RUN TestServerTLSConfig/missing_CA_file1752=== PAUSE TestServerTLSConfig/missing_CA_file1753=== RUN TestServerTLSConfig/not_a_PEM_file1754=== PAUSE TestServerTLSConfig/not_a_PEM_file1755=== CONT TestSweepSkipsRowsLockedByPush1756--- PASS: TestReadRedirectUsesPublicS3URL (2.32s)1757=== CONT TestGCEndsOnShutdown1758=== RUN TestGCEndsOnShutdown/before_the_run1759=== PAUSE TestGCEndsOnShutdown/before_the_run1760=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1761=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1762=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1763=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1764=== CONT TestGCTaskStore_CompletedAllowsNewTask1765--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1766=== CONT TestPushWaitsForSweepHoldingRow17672026/10/01 10:34:17 INFO Received uploads request method=POST path=/api/pending_closures1768--- PASS: TestReadRedirectNar (2.52s)1769=== CONT TestSweepRechecksPendingAfterLocking1770--- PASS: TestPendingClosureFailureTracksEveryUpload (2.83s)1771=== CONT TestCommitRacingPendingCleanupKeepsObjects17722026/10/01 10:34:17 INFO Received uploads request method=POST path=/api/pending_closures1773--- PASS: TestPendingClosureFailureAbortsItsUploads (2.72s)1774=== CONT TestGetExistingObjectsLocksRows1775--- PASS: TestReadRedirectKeepsNarinfoProxied (2.65s)1776=== CONT TestPush_CompleteCommitsEveryRoot17772026/10/01 10:34:18 INFO Received uploads request method=POST path=/api/pending_closures1778--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.73s)1779=== CONT TestPush_SignsNarinfosOfItsPendingObjects1780--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.65s)1781=== CONT TestFailedS3DeleteKeepsTombstone17822026/10/01 10:34:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17832026/10/01 10:34:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1784--- PASS: TestService_NativeMTLS (2.67s)1785=== CONT TestRegisterCompletedObjectNeedsPendingRow17862026/10/01 10:34:19 INFO Aborted multipart uploads count=0 kept=017872026/10/01 10:34:19 WARN Force mode enabled - objects will be deleted immediately without grace period17882026/10/01 10:34:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017892026/10/01 10:34:19 INFO Vacuumed table table=pending_closures17902026/10/01 10:34:19 INFO Vacuumed table table=pending_objects17912026/10/01 10:34:19 INFO Vacuumed table table=multipart_uploads17922026/10/01 10:34:19 INFO Vacuumed table table=closures17932026/10/01 10:34:19 INFO Vacuumed table table=objects17942026/10/01 10:34:19 INFO Aborted multipart uploads count=0 kept=017952026/10/01 10:34:19 WARN Force mode enabled - objects will be deleted immediately without grace period17962026/10/01 10:34:19 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=017972026/10/01 10:34:19 INFO Vacuumed table table=pending_closures17982026/10/01 10:34:19 INFO Vacuumed table table=pending_objects17992026/10/01 10:34:19 INFO Vacuumed table table=multipart_uploads18002026/10/01 10:34:19 INFO Vacuumed table table=closures18012026/10/01 10:34:19 INFO Vacuumed table table=objects1802--- PASS: TestSweepSkipsRowsLockedByPush (3.05s)1803=== CONT TestForceGCDuringPushOffersSweptObject1804=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1805=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1806=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1807=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1808=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit18092026/10/01 10:34:19 INFO Received uploads request method=POST path=/api/pending_closures1810--- PASS: TestPushWaitsForSweepHoldingRow (3.43s)1811=== CONT TestPush_OverlappingRootsStoreOneRowPerKey18122026/10/01 10:34:20 INFO Aborted multipart uploads count=0 kept=018132026/10/01 10:34:20 WARN Force mode enabled - objects will be deleted immediately without grace period1814=== NAME TestOrphanedObjectsGCStressTest1815 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18162026/10/01 10:34:20 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=018172026/10/01 10:34:20 INFO Vacuumed table table=pending_closures18182026/10/01 10:34:20 INFO Vacuumed table table=pending_objects1819 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18202026/10/01 10:34:20 INFO Vacuumed table table=multipart_uploads18212026/10/01 10:34:20 INFO Vacuumed table table=closures18222026/10/01 10:34:20 INFO Vacuumed table table=objects1823--- PASS: TestSweepRechecksPendingAfterLocking (3.27s)1824=== CONT TestTombstonedObjectOfferedWithoutWaiting18252026/10/01 10:34:21 INFO Aborted multipart uploads count=0 kept=018262026/10/01 10:34:21 WARN Force mode enabled - objects will be deleted immediately without grace period18272026/10/01 10:34:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018282026/10/01 10:34:21 INFO Vacuumed table table=pending_closures18292026/10/01 10:34:21 INFO Vacuumed table table=pending_objects18302026/10/01 10:34:21 INFO Vacuumed table table=multipart_uploads18312026/10/01 10:34:21 INFO Vacuumed table table=closures18322026/10/01 10:34:21 INFO Vacuumed table table=objects1833--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.53s)1834=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1835--- PASS: TestGetExistingObjectsLocksRows (3.48s)1836=== CONT TestGCSweepSkipsPendingObjects18372026/10/01 10:34:21 INFO Received push request method=POST path=/api/pushes18382026/10/01 10:34:21 INFO Received push request method=POST path=/api/pushes18392026/10/01 10:34:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18402026/10/01 10:34:22 INFO Signed narinfos id=1 count=11841--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.54s)1842=== CONT TestReadProxyRangeRequest18432026/10/01 10:34:22 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/01 10:34:22 INFO Aborted multipart uploads count=0 kept=018452026/10/01 10:34:22 WARN Force mode enabled - objects will be deleted immediately without grace period18462026/10/01 10:34:22 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."18472026/10/01 10:34:22 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1848--- PASS: TestFailedS3DeleteKeepsTombstone (3.87s)1849=== CONT TestClientErrorHandling/InvalidStorePath1850--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.81s)1851=== CONT TestClientErrorHandling/InvalidAuthToken18522026/10/01 10:34:23 INFO Received push request method=POST path=/api/pushes18532026/10/01 10:34:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18542026/10/01 10:34:23 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjBhMTExZDA0LTAyYWEtNDUxMy04YWVjLTQyNWZjYjA1N2ZlZngxNzkwODUwODYxNTgzODMzMDAw parts=1018552026/10/01 10:34:24 INFO Received push request method=POST path=/api/pushes1856--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.00s)1857=== CONT TestClientErrorHandling/ServerNotAvailable18582026/10/01 10:34:24 INFO Received uploads request method=POST path=/api/pending_closures1859--- PASS: TestTombstonedObjectOfferedWithoutWaiting (3.80s)1860=== CONT TestCacheConfigHandler/full_config,_no_issuer1861=== CONT TestCacheConfigHandler/no_cache_url_configured1862=== CONT TestCacheConfigHandler/no_signing_keys1863=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1864=== CONT TestService_RequireScope_OIDC/ops_may_admin1865--- PASS: TestCacheConfigHandler (0.00s)1866 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1867 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1868 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1869 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1870=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1871=== CONT TestService_RequireScope_OIDC/writer_implies_read1872=== CONT TestService_RequireScope_OIDC/reader_may_read1873=== CONT TestService_RequireScope_OIDC/static_token_may_write1874=== CONT TestService_RequireScope_OIDC/static_token_may_admin1875=== CONT TestService_RequireScope_OIDC/reader_may_not_write1876=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1877=== CONT TestService_RequireScope_OIDC/ops_may_not_write1878=== CONT TestService_RequireScope_OIDC/builder_may_write1879=== CONT TestIsValidUploadKey/nar_zst1880=== CONT TestIsValidUploadKey/realisation_plus_in_output1881=== CONT TestIsValidUploadKey/unknown_type1882=== CONT TestIsValidUploadKey/absolute1883=== CONT TestIsValidUploadKey/empty_key1884=== CONT TestIsValidUploadKey/traversal1885=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1886=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1887=== CONT TestIsValidUploadKey/traversal_nar1888=== CONT TestIsValidUploadKey/index.html1889=== CONT TestIsValidUploadKey/nix-cache-info1890=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1891=== CONT TestIsValidUploadKey/build_log1892=== CONT TestIsValidUploadKey/realisation1893=== CONT TestIsValidUploadKey/build_log_question_mark1894=== CONT TestIsValidUploadKey/build_log_equals1895=== CONT TestIsValidUploadKey/build_log_home-manager_file1896=== CONT TestIsValidUploadKey/listing1897=== CONT TestIsValidUploadKey/build_log_plus_in_name1898=== CONT TestIsValidUploadKey/nar_xz1899=== CONT TestIsValidUploadKey/nar_plain1900=== CONT TestIsValidUploadKey/narinfo1901=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1902--- PASS: TestIsValidUploadKey (0.00s)1903 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1904 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1905 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1906 --- PASS: TestIsValidUploadKey/absolute (0.00s)1907 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1908 --- PASS: TestIsValidUploadKey/traversal (0.00s)1909 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1910 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1911 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1912 --- PASS: TestIsValidUploadKey/index.html (0.00s)1913 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1914 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1915 --- PASS: TestIsValidUploadKey/build_log (0.00s)1916 --- PASS: TestIsValidUploadKey/realisation (0.00s)1917 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1918 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1919 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1920 --- PASS: TestIsValidUploadKey/listing (0.00s)1921 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1922 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1923 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1924 --- PASS: TestIsValidUploadKey/narinfo (0.00s)19252026/10/01 10:34:24 INFO Received complete multipart upload request method=POST path=/1926=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19272026/10/01 10:34:24 INFO Received request for more parts method=POST path=/1928=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19292026/10/01 10:34:24 INFO Received uploads request method=POST path=/1930=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19312026/10/01 10:34:24 INFO Received uploads request method=POST path=/1932=== CONT TestProxyWriteTimeout/1_GiB_nar1933--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1934 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1935 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1936 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1937 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1938=== CONT TestProxyWriteTimeout/unknown_size1939=== CONT TestProxyWriteTimeout/10_GiB_nar1940=== CONT TestProxyWriteTimeout/narinfo1941=== CONT TestPendingClosureWriteTimeout/empty1942=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1943--- PASS: TestProxyWriteTimeout (0.00s)1944 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1945 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1946 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1947 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1948--- PASS: TestService_RequireScope_OIDC (1.42s)1949 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)19592026/10/01 10:34:24 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/present19602026/10/01 10:34:24 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.357766ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19612026/10/01 10:34:24 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.598882ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19622026/10/01 10:34:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19632026/10/01 10:34:25 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjJhMmE2MmU5LTNjYTMtNGQzZi05MTdjLTA1YzYxOTIzOWMzY3gxNzkwODUwODYxNTgzMTQxMDAw parts=1019642026/10/01 10:34:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1965=== NAME TestOrphanedObjectsGCStressTest1966 orphaned_objects_gc_test.go:509: Stress test completed successfully:1967 orphaned_objects_gc_test.go:510: - Active objects preserved: 201968 orphaned_objects_gc_test.go:511: - Objects deleted: 2101969 orphaned_objects_gc_test.go:512: - Total GC'd: 21019702026/10/01 10:34:25 INFO Received uploads request method=POST path=/api/pending_closures1971--- PASS: TestOrphanedObjectsGCStressTest (12.55s)1972=== CONT TestPendingClosureWriteTimeout/670k_objects1973=== CONT TestPendingClosureWriteTimeout/400_objects1974=== CONT TestResolveDBConnectionString/file_when_flag_empty1975=== CONT TestResolveDBConnectionString/nothing_configured1976=== CONT TestResolveDBConnectionString/missing_file_is_an_error1977=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1978=== CONT TestResolveDBConnectionString/flag_wins1979=== CONT TestIsValidCachePath/narinfo1980=== CONT TestIsValidCachePath/leading_slash1981=== CONT TestIsValidCachePath/empty1982=== CONT TestIsValidCachePath/random_path1983=== CONT TestIsValidCachePath/invalid_char_u1984=== CONT TestIsValidCachePath/wrong_extension1985=== CONT TestIsValidCachePath/short_hash1986=== CONT TestIsValidCachePath/traversal_parent1987=== CONT TestIsValidCachePath/invalid_char_e1988=== CONT TestIsValidCachePath/traversal_in_middle1989=== CONT TestIsValidCachePath/realisation1990=== CONT TestIsValidCachePath/nix-cache-info1991=== CONT TestIsValidCachePath/log1992=== CONT TestIsValidCachePath/ls1993=== CONT TestIsValidCachePath/nar_uncompressed1994=== CONT TestIsValidCachePath/nar_xz1995=== CONT TestIsValidCachePath/nar_zst1996=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1997=== CONT TestIsValidCachePath/nar_bz21998=== CONT TestIsValidCachePath/index.html1999=== CONT TestParseSingleRange/none2000--- PASS: TestIsValidCachePath (0.00s)2001 --- PASS: TestIsValidCachePath/narinfo (0.00s)2002 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2003 --- PASS: TestIsValidCachePath/empty (0.00s)2004 --- PASS: TestIsValidCachePath/random_path (0.00s)2005 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2006 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2007 --- PASS: TestIsValidCachePath/short_hash (0.00s)2008 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2009 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2010 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2011 --- PASS: TestIsValidCachePath/realisation (0.00s)2012 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2013 --- PASS: TestIsValidCachePath/log (0.00s)2014 --- PASS: TestIsValidCachePath/ls (0.00s)2015 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2016 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2017 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2018 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2019 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2020 --- PASS: TestIsValidCachePath/index.html (0.00s)2021=== CONT TestParseSingleRange/closed2022=== CONT TestParseSingleRange/start_past_EOF2023=== CONT TestParseSingleRange/single_byte2024=== CONT TestParseSingleRange/start_far_past_EOF2025=== CONT TestParseSingleRange/suffix2026=== CONT TestParseSingleRange/end_clamped_to_size2027=== CONT TestParseSingleRange/open-ended2028=== CONT TestParseSingleRange/malformed_no_dash2029=== CONT TestParseSingleRange/suffix_exceeds_size2030=== CONT TestParseSingleRange/malformed_both_empty2031=== CONT TestParseSingleRange/unknown_unit2032=== CONT TestParseSingleRange/malformed_end_before_start2033=== CONT TestParseSingleRange/multi-range_ignored2034=== CONT TestPush_RejectsBadRequests/no_roots2035--- PASS: TestParseSingleRange (0.00s)2036 --- PASS: TestParseSingleRange/none (0.00s)2037 --- PASS: TestParseSingleRange/closed (0.00s)2038 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2039 --- PASS: TestParseSingleRange/single_byte (0.00s)2040 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2041 --- PASS: TestParseSingleRange/suffix (0.00s)2042 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2043 --- PASS: TestParseSingleRange/open-ended (0.00s)2044 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2045 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2046 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2047 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2048 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2049 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)20502026/10/01 10:34:25 INFO Received push request method=POST path=/api/pushes2051=== CONT TestPush_RejectsBadRequests/no_objects20522026/10/01 10:34:25 INFO Received push request method=POST path=/api/pushes2053=== CONT TestPush_RejectsBadRequests/bad_root20542026/10/01 10:34:25 INFO Received push request method=POST path=/api/pushes2055=== CONT TestPush_RejectsBadRequests/root_not_in_objects20562026/10/01 10:34:25 INFO Received push request method=POST path=/api/pushes2057=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2058=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20592026/10/01 10:34:25 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]2060=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2061=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20622026/10/01 10:34:25 WARN Authentication failed token_preview=eyJhbGciOi...zY6ASuhUkg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2063=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20642026/10/01 10:34:25 INFO Received uploads request method=POST path=/2065--- PASS: TestResolveDBConnectionString (0.02s)2066 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2067 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2068 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2069 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2070 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)20712026/10/01 10:34:25 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjNiZjI3YzliLTQxNWQtNDViOC05NzJmLWJlOGUyODhkNTg1MHgxNzkwODUwODYzMjE2NjIwMDAw parts=102072--- PASS: TestPush_RejectsBadRequests (1.90s)2073 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2074 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2075 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2076 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2077--- PASS: TestService_AuthMiddleware_OIDC (2.34s)2078 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2079 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2080 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2081 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20822026/10/01 10:34:25 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=785.2078ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2083--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (4.19s)2084=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20852026/10/01 10:34:25 INFO Received request for more parts method=POST path=/20862026/10/01 10:34:25 INFO Received uploads request method=POST path=/api/pending_closures20872026/10/01 10:34:25 INFO Aborted multipart uploads count=0 kept=020882026/10/01 10:34:25 WARN Force mode enabled - objects will be deleted immediately without grace period20892026/10/01 10:34:25 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=020902026/10/01 10:34:25 INFO Vacuumed table table=pending_closures20912026/10/01 10:34:25 INFO Vacuumed table table=pending_objects20922026/10/01 10:34:25 INFO Vacuumed table table=multipart_uploads20932026/10/01 10:34:25 INFO Vacuumed table table=closures20942026/10/01 10:34:25 INFO Vacuumed table table=objects2095--- PASS: TestGCSweepSkipsPendingObjects (4.40s)2096=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20972026/10/01 10:34:25 INFO Received complete multipart upload request method=POST path=/2098=== CONT TestServerTLSConfig/no_client_CA2099=== CONT TestServerTLSConfig/not_a_PEM_file2100=== CONT TestServerTLSConfig/missing_CA_file2101--- PASS: TestServerTLSConfig (0.00s)2102 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2103 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)2104 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2105=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2106--- PASS: TestReadProxyRangeRequest (3.87s)2107=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2108=== CONT TestGCEndsOnShutdown/before_the_run21092026/10/01 10:34:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.663440432s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2110=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows21112026/10/01 10:34:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21122026/10/01 10:34:26 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjgxMjdlM2Y4LTQ4NjAtNDE4Ny1iYzZmLTA0ZTI0ZGIzNWRjZXgxNzkwODUwODYxNTgzODMyMDAw parts=1021132026/10/01 10:34:26 INFO Received complete push request method=POST path=/api/pushes/1/complete21142026/10/01 10:34:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2115--- PASS: TestPush_CompleteCommitsEveryRoot (8.54s)2116=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21172026/10/01 10:34:26 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjMzNjY2NWQ4LWE4NDgtNGQ0Ny05YjBlLTc0MThmNzkwNDM5MngxNzkwODUwODYzMjE0ODkxMDAw parts=1021182026/10/01 10:34:26 INFO Received complete push request method=POST path=/api/pushes/1/complete21192026/10/01 10:34:26 INFO Received push request method=POST path=/api/pushes21202026/10/01 10:34:26 INFO Aborted multipart uploads count=0 kept=021212026/10/01 10:34:26 WARN Force mode enabled - objects will be deleted immediately without grace period21222026/10/01 10:34:26 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=021232026/10/01 10:34:26 INFO Vacuumed table table=pending_closures21242026/10/01 10:34:26 INFO Vacuumed table table=pending_objects21252026/10/01 10:34:26 INFO Vacuumed table table=multipart_uploads21262026/10/01 10:34:26 INFO Vacuumed table table=closures21272026/10/01 10:34:26 INFO Vacuumed table table=objects21282026/10/01 10:34:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21292026/10/01 10:34:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21302026/10/01 10:34:27 INFO Received uploads request method=POST path=/api/pending_closures21312026/10/01 10:34:27 INFO Aborted multipart uploads count=0 kept=021322026/10/01 10:34:27 WARN Force mode enabled - objects will be deleted immediately without grace period21332026/10/01 10:34:27 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-config21342026-10-01 10:34:27.887 UTC [59508] ERROR: canceling statement due to user request21352026-10-01 10:34:27.887 UTC [59508] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block21362026-10-01 10:34:27.887 UTC [59508] STATEMENT: -- name: MarkStaleObjects :execrows2137 WITH RECURSIVE ct AS (2138 SELECT timezone('UTC', now()) AS now2139 ),2140 closure_reach AS (2141 -- Start with all closure keys2142 SELECT o.key, o.refs2143 FROM objects o2144 INNER JOIN closures c ON o.key = c.key2145 UNION2146 -- Recursively add all referenced objects2147 SELECT o.key, o.refs2148 FROM objects o2149 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2150 ),2151 reachable_objects AS (2152 SELECT DISTINCT key FROM closure_reach2153 ),2154 stale_objects AS (2155 SELECT o.key2156 FROM objects AS o, ct2157 WHERE2158 NOT EXISTS (2159 SELECT 12160 FROM reachable_objects ro2161 WHERE ro.key = o.key2162 )2163 AND NOT EXISTS (2164 SELECT 12165 FROM pending_objects AS po2166 WHERE po.key = o.key2167 )2168 AND o.deleted_at IS NULL -- Only mark fresh objects2169 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2170 FOR UPDATE2171 )2172 UPDATE objects2173 SET2174 deleted_at = ct.now,2175 first_deleted_at = COALESCE(first_deleted_at, ct.now)2176 FROM stale_objects, ct2177 WHERE objects.key = stale_objects.key2178 21792026/10/01 10:34:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21802026/10/01 10:34:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.903203ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21812026/10/01 10:34:27 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZjlkYjM5YjEtYzFhYy00NWFhLWI5MTUtYTY2MzFiOWYyNzY1LjM5MjQxMDg0LTIxOWQtNDdkYi1hZDFmLTdkZjJkOGIxYmMwZXgxNzkwODUwODY2NjYwNjE4MDAw parts=1021822026/10/01 10:34:27 INFO Received complete push request method=POST path=/api/pushes/2/complete2183--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (8.57s)21842026/10/01 10:34:28 INFO Aborted multipart uploads count=0 kept=021852026/10/01 10:34:28 WARN Force mode enabled - objects will be deleted immediately without grace period2186--- PASS: TestPendingClosureWriteTimeout (0.00s)2187 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2188 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2189 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2190 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.52s)21912026/10/01 10:34:28 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:63495/bucket94/?delete=\": context canceled"21922026/10/01 10:34:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=398.677385ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2193--- PASS: TestGCEndsOnShutdown (0.00s)2194 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.14s)2195 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.14s)2196 --- PASS: TestGCEndsOnShutdown/before_the_run (2.25s)21972026/10/01 10:34:28 INFO Received uploads request method=POST path=/api/pending_closures21982026/10/01 10:34:28 INFO Aborted multipart uploads count=0 kept=021992026/10/01 10:34:28 WARN Force mode enabled - objects will be deleted immediately without grace period22002026/10/01 10:34:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022012026/10/01 10:34:28 INFO Vacuumed table table=pending_closures22022026/10/01 10:34:28 INFO Vacuumed table table=pending_objects22032026/10/01 10:34:28 INFO Vacuumed table table=multipart_uploads22042026/10/01 10:34:28 INFO Vacuumed table table=closures22052026/10/01 10:34:28 INFO Vacuumed table table=objects22062026/10/01 10:34:28 INFO Received uploads request method=POST path=/api/pending_closures22072026/10/01 10:34:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=798.456112ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/10/01 10:34:28 INFO Aborted multipart uploads count=0 kept=022092026/10/01 10:34:28 WARN Force mode enabled - objects will be deleted immediately without grace period22102026/10/01 10:34:28 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=022112026/10/01 10:34:28 INFO Vacuumed table table=pending_closures22122026/10/01 10:34:28 INFO Vacuumed table table=pending_objects22132026/10/01 10:34:28 INFO Vacuumed table table=multipart_uploads22142026/10/01 10:34:28 INFO Vacuumed table table=closures22152026/10/01 10:34:28 INFO Vacuumed table table=objects2216--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2217 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.92s)2218 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.17s)22192026/10/01 10:34:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.688156873s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2220--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)2221 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.28s)2222 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.29s)2223 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.44s)22242026/10/01 10:34:31 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22252026/10/01 10:34:31 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22262026/10/01 10:34:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.576855ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/10/01 10:34:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=391.641131ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/10/01 10:34:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=840.458524ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/10/01 10:34:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.477277086s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/10/01 10:34:34 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_closures22312026/10/01 10:34:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.282894ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/10/01 10:34:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.353881ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22332026/10/01 10:34:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.673447ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22342026/10/01 10:34:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.52868374s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2235--- PASS: TestClientErrorHandling (0.00s)2236 --- PASS: TestClientErrorHandling/InvalidStorePath (3.89s)2237 --- PASS: TestClientErrorHandling/InvalidAuthToken (4.41s)2238 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.08s)2239PASS2240{"timestamp":"2026-10-01T10:34:37.279537Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63573","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(11)"}2241{"timestamp":"2026-10-01T10:34:37.279615Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63732","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(3)"}22422026-10-01 10:34:37.428 UTC [58914] LOG: received smart shutdown request22432026-10-01 10:34:37.428 UTC [58914] LOG: background worker "logical replication launcher" (PID 58924) exited with exit code 122442026-10-01 10:34:37.437 UTC [58919] LOG: shutting down22452026-10-01 10:34:37.437 UTC [58919] LOG: checkpoint starting: shutdown immediate22462026-10-01 10:34:38.738 UTC [58919] LOG: checkpoint complete: wrote 12394 buffers (75.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.693 s, sync=0.567 s, total=1.302 s; sync files=33360, longest=0.001 s, average=0.001 s; distance=475178 kB, estimate=475178 kB; lsn=0/1E797890, redo lsn=0/1E79789022472026-10-01 10:34:38.745 UTC [58914] LOG: database system is shut down2248Running OIDC tests...2249=== RUN TestAudienceForIssuer2250=== PAUSE TestAudienceForIssuer2251=== RUN TestHTTPClientForHasTimeouts2252=== PAUSE TestHTTPClientForHasTimeouts2253=== RUN TestGlobMatch2254=== PAUSE TestGlobMatch2255=== RUN TestValidateToken_ValidToken2256=== PAUSE TestValidateToken_ValidToken2257=== RUN TestValidateToken_WrongAudience2258=== PAUSE TestValidateToken_WrongAudience2259=== RUN TestValidateToken_Expired2260=== PAUSE TestValidateToken_Expired2261=== RUN TestValidateToken_BoundClaimsMismatch2262=== PAUSE TestValidateToken_BoundClaimsMismatch2263=== RUN TestValidateToken_BoundSubjectMismatch2264=== PAUSE TestValidateToken_BoundSubjectMismatch2265=== RUN TestValidateToken_MultipleProviders2266=== PAUSE TestValidateToken_MultipleProviders2267=== RUN TestValidateToken_NoMatchingProvider2268=== PAUSE TestValidateToken_NoMatchingProvider2269=== RUN TestValidateToken_KubernetesServiceAccount2270=== PAUSE TestValidateToken_KubernetesServiceAccount2271=== RUN TestNewValidator_KubernetesRequiresCA2272=== PAUSE TestNewValidator_KubernetesRequiresCA2273=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2275=== RUN TestPins_ReservedForMatchingRule2276=== PAUSE TestPins_ReservedForMatchingRule2277=== RUN TestPins_TopLevelShorthand2278=== PAUSE TestPins_TopLevelShorthand2279=== RUN TestPins_ConfigValidation2280=== PAUSE TestPins_ConfigValidation2281=== RUN TestScopes_LegacyProviderDefaultsToWrite2282=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2283=== RUN TestScopes_Rules2284=== PAUSE TestScopes_Rules2285=== RUN TestScopes_ConfigValidation2286=== PAUSE TestScopes_ConfigValidation2287=== CONT TestHTTPClientForHasTimeouts2288=== CONT TestValidateToken_KubernetesServiceAccount2289=== CONT TestScopes_ConfigValidation2290=== CONT TestPins_TopLevelShorthand2291=== CONT TestValidateToken_Expired2292=== CONT TestValidateToken_NoMatchingProvider2293=== CONT TestValidateToken_MultipleProviders2294=== CONT TestValidateToken_BoundClaimsMismatch2295=== CONT TestValidateToken_BoundSubjectMismatch2296=== CONT TestGlobMatch2297=== RUN TestGlobMatch/foo_foo2298=== PAUSE TestGlobMatch/foo_foo2299=== RUN TestGlobMatch/foo_bar2300=== PAUSE TestGlobMatch/foo_bar2301=== RUN TestGlobMatch/*_2302=== PAUSE TestGlobMatch/*_2303=== RUN TestGlobMatch/*_anything2304=== PAUSE TestGlobMatch/*_anything2305=== RUN TestGlobMatch/foo*_foo2306=== PAUSE TestGlobMatch/foo*_foo2307=== RUN TestGlobMatch/foo*_foobar2308=== PAUSE TestGlobMatch/foo*_foobar2309=== RUN TestGlobMatch/foo*_bar2310=== PAUSE TestGlobMatch/foo*_bar2311=== RUN TestGlobMatch/*bar_bar2312=== PAUSE TestGlobMatch/*bar_bar2313=== RUN TestGlobMatch/*bar_foobar2314=== PAUSE TestGlobMatch/*bar_foobar2315=== RUN TestGlobMatch/*bar_foo2316=== PAUSE TestGlobMatch/*bar_foo2317=== RUN TestGlobMatch/foo*bar_foobar2318=== PAUSE TestGlobMatch/foo*bar_foobar2319=== RUN TestGlobMatch/foo*bar_foo123bar2320=== PAUSE TestGlobMatch/foo*bar_foo123bar2321=== RUN TestGlobMatch/foo*bar_foobarbaz2322=== PAUSE TestGlobMatch/foo*bar_foobarbaz2323=== RUN TestGlobMatch/*/*_foo/bar2324=== PAUSE TestGlobMatch/*/*_foo/bar2325=== RUN TestGlobMatch/*/*_foo2326=== PAUSE TestGlobMatch/*/*_foo2327=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2328=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2329=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02330=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02331=== RUN TestGlobMatch/refs/*/main_refs/heads/main2332=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2333=== RUN TestGlobMatch/fo?_foo2334=== PAUSE TestGlobMatch/fo?_foo2335=== RUN TestGlobMatch/fo?_fo2336=== PAUSE TestGlobMatch/fo?_fo2337=== RUN TestGlobMatch/fo?_fooo2338=== PAUSE TestGlobMatch/fo?_fooo2339=== RUN TestGlobMatch/?oo_foo2340=== PAUSE TestGlobMatch/?oo_foo2341=== RUN TestGlobMatch/?oo_boo2342=== PAUSE TestGlobMatch/?oo_boo2343=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2344=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2345=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2346=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2347=== CONT TestValidateToken_WrongAudience2348--- PASS: TestScopes_ConfigValidation (0.00s)2349=== CONT TestPins_ReservedForMatchingRule23502026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64215/oidc2351--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)2352=== CONT TestNewValidator_KubernetesRequiresCA23532026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64219/oidc2354--- PASS: TestValidateToken_WrongAudience (0.07s)2355=== CONT TestValidateToken_ValidToken23562026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64221/oidc23572026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64223/oidc2358--- PASS: TestPins_ReservedForMatchingRule (0.08s)2359=== CONT TestScopes_Rules2360--- PASS: TestPins_TopLevelShorthand (0.09s)2361=== CONT TestScopes_LegacyProviderDefaultsToWrite23622026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64225/oidc2363=== CONT TestAudienceForIssuer2364--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)2365=== CONT TestPins_ConfigValidation2366--- PASS: TestAudienceForIssuer (0.00s)2367--- PASS: TestPins_ConfigValidation (0.00s)2368=== CONT TestValidateToken_KubernetesIssuerFromOwnToken23692026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64228/oidc23702026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64231/oidc2371--- PASS: TestValidateToken_Expired (0.12s)2372=== CONT TestGlobMatch/foo_foo2373=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2374=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/?oo_boo2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/?oo_foo2378=== CONT TestGlobMatch/fo?_fo2379=== CONT TestGlobMatch/fo?_fooo2380=== CONT TestGlobMatch/fo?_foo2381=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02382=== CONT TestGlobMatch/refs/*/main_refs/heads/main2383=== CONT TestGlobMatch/*/*_foo2384=== CONT TestGlobMatch/*/*_foo/bar2385=== CONT TestGlobMatch/*bar_bar2386=== CONT TestGlobMatch/foo*bar_foobarbaz2387=== CONT TestGlobMatch/foo*bar_foobar2388=== CONT TestGlobMatch/foo*bar_foo123bar2389=== CONT TestGlobMatch/*bar_foo2390=== CONT TestGlobMatch/*bar_foobar2391=== CONT TestGlobMatch/foo*_foo2392=== CONT TestGlobMatch/foo*_foobar2393=== CONT TestGlobMatch/foo*_bar2394=== CONT TestGlobMatch/*_2395=== CONT TestGlobMatch/*_anything2396=== CONT TestGlobMatch/foo_bar2397--- PASS: TestGlobMatch (0.00s)2398 --- PASS: TestGlobMatch/foo_foo (0.00s)2399 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/?oo_boo (0.00s)2402 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2403 --- PASS: TestGlobMatch/?oo_foo (0.00s)2404 --- PASS: TestGlobMatch/fo?_fo (0.00s)2405 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2406 --- PASS: TestGlobMatch/fo?_foo (0.00s)2407 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2408 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2409 --- PASS: TestGlobMatch/*/*_foo (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2411 --- PASS: TestGlobMatch/*bar_bar (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2413 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2415 --- PASS: TestGlobMatch/*bar_foo (0.00s)2416 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2417 --- PASS: TestGlobMatch/foo*_foo (0.00s)2418 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2419 --- PASS: TestGlobMatch/foo*_bar (0.00s)2420 --- PASS: TestGlobMatch/*_ (0.00s)2421 --- PASS: TestGlobMatch/*_anything (0.00s)2422 --- PASS: TestGlobMatch/foo_bar (0.00s)24232026/10/01 10:34:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64218/oidc24242026/10/01 10:34:41 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:642272425--- PASS: TestValidateToken_NoMatchingProvider (0.13s)2426--- PASS: TestScopes_Rules (0.04s)2427--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)24282026/10/01 10:34:41 http: TLS handshake error from 127.0.0.1:64234: remote error: tls: bad certificate2429--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)24302026/10/01 10:34:41 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232431--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)24322026/10/01 10:34:41 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64217/oidc24332026/10/01 10:34:41 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:64239/oidc24342026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64242/oidc2435--- PASS: TestValidateToken_MultipleProviders (0.15s)2436--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2437--- PASS: TestHTTPClientForHasTimeouts (0.20s)24382026/10/01 10:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64244/oidc2439--- PASS: TestValidateToken_ValidToken (0.19s)2440PASS2441Running signing tests...2442=== RUN TestGenerateFingerprint2443=== PAUSE TestGenerateFingerprint2444=== RUN TestParseSigningKey2445=== PAUSE TestParseSigningKey2446=== RUN TestSignMessage2447=== PAUSE TestSignMessage2448=== RUN TestSignNarinfo2449=== PAUSE TestSignNarinfo2450=== CONT TestParseSigningKey2451=== CONT TestSignNarinfo2452=== CONT TestGenerateFingerprint2453=== RUN TestParseSigningKey/valid_32-byte_key2454=== CONT TestSignMessage2455=== PAUSE TestParseSigningKey/valid_32-byte_key2456=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2457=== RUN TestGenerateFingerprint/basic_with_references2458=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2459=== RUN TestParseSigningKey/no_colon2460=== PAUSE TestParseSigningKey/no_colon2461=== PAUSE TestGenerateFingerprint/basic_with_references2462=== RUN TestParseSigningKey/empty_name2463=== RUN TestGenerateFingerprint/no_references2464=== PAUSE TestParseSigningKey/empty_name2465=== PAUSE TestGenerateFingerprint/no_references2466=== RUN TestParseSigningKey/invalid_base642467=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2468=== PAUSE TestParseSigningKey/invalid_base642469=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2470=== RUN TestParseSigningKey/wrong_length2471=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2472=== PAUSE TestParseSigningKey/wrong_length2473=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2474=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2475=== RUN TestGenerateFingerprint/invalid_nar_hash_length2476=== CONT TestParseSigningKey/no_colon2477=== CONT TestParseSigningKey/empty_name2478=== CONT TestParseSigningKey/wrong_length2479=== CONT TestParseSigningKey/invalid_base642480=== CONT TestParseSigningKey/valid_32-byte_key2481=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2482=== RUN TestGenerateFingerprint/invalid_store_path_prefix2483=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2484=== RUN TestGenerateFingerprint/invalid_reference_prefix2485=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2486=== CONT TestGenerateFingerprint/invalid_nar_hash_length2487=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2488=== CONT TestGenerateFingerprint/invalid_reference_prefix2489=== CONT TestGenerateFingerprint/basic_with_references2490=== CONT TestGenerateFingerprint/no_references2491=== CONT TestGenerateFingerprint/invalid_store_path_prefix2492=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2493--- PASS: TestGenerateFingerprint (0.00s)2494 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2495 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2496 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2497 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2498 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2499 --- PASS: TestGenerateFingerprint/no_references (0.00s)2500 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2501--- PASS: TestParseSigningKey (0.00s)2502 --- PASS: TestParseSigningKey/no_colon (0.00s)2503 --- PASS: TestParseSigningKey/empty_name (0.00s)2504 --- PASS: TestParseSigningKey/wrong_length (0.00s)2505 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2506 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2507 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2508--- PASS: TestSignMessage (0.01s)2509--- PASS: TestSignNarinfo (0.01s)2510PASS2511Running hook tests...2512=== RUN TestSendPathsEmpty2513=== PAUSE TestSendPathsEmpty2514=== RUN TestQueueEnqueueAndFetch2515=== PAUSE TestQueueEnqueueAndFetch2516=== RUN TestQueueDeduplication2517=== PAUSE TestQueueDeduplication2518=== RUN TestQueueRemove2519=== PAUSE TestQueueRemove2520=== RUN TestQueueFetchBatchLimit2521=== PAUSE TestQueueFetchBatchLimit2522=== RUN TestQueueRetryMovesToBack2523=== PAUSE TestQueueRetryMovesToBack2524=== RUN TestQueueFetchRemoveLifecycle2525=== PAUSE TestQueueFetchRemoveLifecycle2526=== RUN TestQueueConcurrentWriters2527=== PAUSE TestQueueConcurrentWriters2528=== RUN TestQueueEnqueueWaitsOutSlowWriter2529=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2530=== RUN TestQueueRemoveLargeClosure2531=== PAUSE TestQueueRemoveLargeClosure2532=== RUN TestServerClientIntegration2533=== PAUSE TestServerClientIntegration2534=== RUN TestServerQueueError2535=== PAUSE TestServerQueueError2536=== RUN TestServerRefusesOversizedAndNonStoreRequests2537=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2538=== RUN TestGetListenerSocketActivation2539 server_test.go:317: === RUN TestGetListenerSocketActivation2540 --- PASS: TestGetListenerSocketActivation (0.00s)2541 PASS2542 2543--- PASS: TestGetListenerSocketActivation (1.18s)2544=== RUN TestServerStalledClientDoesNotBlockShutdown2545=== PAUSE TestServerStalledClientDoesNotBlockShutdown2546=== RUN TestServerBacksOffOnAcceptErrors2547=== PAUSE TestServerBacksOffOnAcceptErrors2548=== RUN TestDrainIsolatesPoisonPath2549=== PAUSE TestDrainIsolatesPoisonPath2550=== RUN TestRunNotBlockedByPoisonHead2551=== PAUSE TestRunNotBlockedByPoisonHead2552=== RUN TestDrainGivesUpWhenServerDown2553=== PAUSE TestDrainGivesUpWhenServerDown2554=== RUN TestFailedPathPrunedByLaterClosure2555=== PAUSE TestFailedPathPrunedByLaterClosure2556=== RUN TestWorkerUploadsAndRemoves2557=== PAUSE TestWorkerUploadsAndRemoves2558=== RUN TestWorkerSkipsGCdPaths2559=== PAUSE TestWorkerSkipsGCdPaths2560=== RUN TestWorkerPrunesClosureDeps2561=== PAUSE TestWorkerPrunesClosureDeps2562=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2563=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2564=== RUN TestDrainTimeout2565=== PAUSE TestDrainTimeout2566=== RUN TestDrainTimeoutDuringIsolation2567=== PAUSE TestDrainTimeoutDuringIsolation2568=== RUN TestShutdownFinishesInFlightPush2569=== PAUSE TestShutdownFinishesInFlightPush2570=== RUN TestWorkerRemoveFailureIsNotProgress2571=== PAUSE TestWorkerRemoveFailureIsNotProgress2572=== RUN TestWorkerKeepsPathItCannotStat2573=== PAUSE TestWorkerKeepsPathItCannotStat2574=== CONT TestServerStalledClientDoesNotBlockShutdown2575=== CONT TestQueueRetryMovesToBack2576=== CONT TestServerBacksOffOnAcceptErrors2577=== CONT TestQueueEnqueueAndFetch2578=== CONT TestQueueRemove2579=== CONT TestQueueFetchRemoveLifecycle2580=== CONT TestQueueFetchBatchLimit25812026/10/01 10:34:45 ERROR Accept failed error="too many open files"2582=== CONT TestWorkerSkipsGCdPaths2583=== CONT TestWorkerKeepsPathItCannotStat2584=== CONT TestSendPathsEmpty2585--- PASS: TestSendPathsEmpty (0.00s)2586=== CONT TestShutdownFinishesInFlightPush2587=== RUN TestShutdownFinishesInFlightPush/completes2588=== PAUSE TestShutdownFinishesInFlightPush/completes2589=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2590=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2591=== CONT TestWorkerRemoveFailureIsNotProgress2592=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2593=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2594=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2595=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2596=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2597=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2598=== CONT TestDrainTimeoutDuringIsolation2599=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2600=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2601=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2602=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2603=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure26042026/10/01 10:34:45 ERROR Accept failed error="too many open files"26052026/10/01 10:34:45 ERROR Accept failed error="too many open files"26062026/10/01 10:34:45 INFO Upload queue status pending=226072026/10/01 10:34:45 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa error="lstat /nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa: permission denied"26082026/10/01 10:34:45 INFO Uploading batch count=226092026/10/01 10:34:45 INFO Upload queue status pending=32610--- PASS: TestQueueFetchBatchLimit (0.03s)26112026/10/01 10:34:45 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa error="lstat /nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa: permission denied"2612=== CONT TestWorkerPrunesClosureDeps2613--- PASS: TestQueueEnqueueAndFetch (0.03s)2614=== CONT TestQueueDeduplication26152026/10/01 10:34:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerSkipsGCdPaths2287000998/002/nonexistent2616--- PASS: TestQueueRemove (0.03s)2617=== CONT TestWorkerUploadsAndRemoves26182026/10/01 10:34:45 INFO Uploading batch count=226192026/10/01 10:34:45 WARN Cannot stat store path, will retry later path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa error="lstat /nix/var/nix/builds/nix-58869-1726934962/TestWorkerKeepsPathItCannotStat1030167952/002/locked/aaa: permission denied"2620--- PASS: TestQueueRetryMovesToBack (0.03s)2621=== CONT TestDrainTimeout26222026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=12623=== CONT TestFailedPathPrunedByLaterClosure2624--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2625--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)2626=== CONT TestDrainIsolatesPoisonPath26272026/10/01 10:34:45 ERROR Accept failed error="too many open files"26282026/10/01 10:34:45 INFO Upload queue status pending=226292026/10/01 10:34:45 INFO Upload queue status pending=226302026/10/01 10:34:45 INFO Uploading batch count=126312026/10/01 10:34:45 INFO Uploading batch count=226322026/10/01 10:34:45 INFO Uploading batch count=22633--- PASS: TestQueueDeduplication (0.01s)2634=== CONT TestDrainGivesUpWhenServerDown26352026/10/01 10:34:45 INFO Uploading batch count=126362026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=126372026/10/01 10:34:45 INFO Uploading batch count=426382026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=426392026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainIsolatesPoisonPath1881047950/002/bbb26402026/10/01 10:34:45 INFO Uploading batch count=126412026/10/01 10:34:45 INFO Uploading batch count=126422026/10/01 10:34:45 INFO Uploading batch count=126432026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=12644--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.04s)2645=== CONT TestServerClientIntegration2646--- PASS: TestServerClientIntegration (0.00s)2647=== CONT TestServerRefusesOversizedAndNonStoreRequests26482026/10/01 10:34:45 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26492026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store store=/nix/store26502026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26512026/10/01 10:34:45 INFO Uploading batch count=126522026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=126532026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2654=== CONT TestServerQueueError26552026/10/01 10:34:45 INFO Uploading batch count=226562026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=22657--- PASS: TestWorkerSkipsGCdPaths (0.05s)26582026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/a26592026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26602026/10/01 10:34:45 ERROR Failed to queue paths error="permission denied" count=12661=== CONT TestRunNotBlockedByPoisonHead26622026/10/01 10:34:45 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2663--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2664--- PASS: TestServerQueueError (0.00s)2665=== CONT TestQueueEnqueueWaitsOutSlowWriter26662026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26672026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26682026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/b26692026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26702026/10/01 10:34:45 INFO Uploading batch count=126712026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=126722026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26732026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26742026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26752026/10/01 10:34:45 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26762026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26772026/10/01 10:34:45 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26782026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=126792026/10/01 10:34:45 INFO Uploading batch count=226802026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=226812026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/c26822026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/d26832026/10/01 10:34:45 ERROR Failed to decode request error="unexpected EOF"2684--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2685=== CONT TestQueueRemoveLargeClosure2686--- PASS: TestDrainIsolatesPoisonPath (0.02s)2687=== CONT TestQueueConcurrentWriters26882026/10/01 10:34:45 INFO Uploading batch count=226892026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=226902026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/e26912026/10/01 10:34:45 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-58869-1726934962/TestDrainGivesUpWhenServerDown2141622166/002/f26922026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=1026932026/10/01 10:34:45 INFO Upload queue status pending=326942026/10/01 10:34:45 INFO Uploading batch count=126952026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=12696--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2697=== CONT TestShutdownFinishesInFlightPush/completes2698--- PASS: TestWorkerPrunesClosureDeps (0.03s)2699=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27002026/10/01 10:34:45 INFO Upload queue status pending=22701--- PASS: TestWorkerUploadsAndRemoves (0.03s)2702=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27032026/10/01 10:34:45 INFO Uploading batch count=227042026/10/01 10:34:45 INFO Upload queue status pending=227052026/10/01 10:34:45 INFO Uploading batch count=227062026/10/01 10:34:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerRemoveFailureIsNotProgresscollected_path883481937/001/nonexistent27072026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127082026/10/01 10:34:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerRemoveFailureIsNotProgresscollected_path883481937/001/nonexistent27092026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127102026/10/01 10:34:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-58869-1726934962/TestWorkerRemoveFailureIsNotProgresscollected_path883481937/001/nonexistent27112026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127122026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=12713=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27142026/10/01 10:34:45 ERROR Accept failed error="too many open files"27152026/10/01 10:34:45 INFO Uploading batch count=227162026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227172026/10/01 10:34:45 INFO Uploading batch count=227182026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227192026/10/01 10:34:45 INFO Uploading batch count=227202026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227212026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=22722=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27232026/10/01 10:34:45 INFO Uploading batch count=227242026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=227252026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127262026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127272026/10/01 10:34:45 INFO Uploading batch count=227282026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=227292026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127302026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127312026/10/01 10:34:45 INFO Uploading batch count=227322026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=227332026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127342026/10/01 10:34:45 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127352026/10/01 10:34:45 ERROR Drain finished with paths left in queue remaining=22736--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2737 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.01s)2738 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.01s)2739 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.01s)2740=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27412026/10/01 10:34:45 INFO Uploading batch count=427422026/10/01 10:34:45 ERROR Upload failed error="upload failed" count=427432026/10/01 10:34:46 ERROR Accept failed error="too many open files"2744=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27452026/10/01 10:34:46 INFO Uploading batch count=427462026/10/01 10:34:46 ERROR Upload failed error="upload failed" count=42747--- PASS: TestQueueConcurrentWriters (0.13s)27482026/10/01 10:34:46 ERROR Failed to decode request error="read unix /nix/var/nix/builds/nix-58869-1726934962/hook3447052259/test.sock->: i/o timeout"27492026/10/01 10:34:46 ERROR Failed to write response error="write unix /nix/var/nix/builds/nix-58869-1726934962/hook3447052259/test.sock->: i/o timeout"2750--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27512026/10/01 10:34:46 ERROR Upload failed error="context canceled" count=227522026/10/01 10:34:46 ERROR Drain finished with paths left in queue remaining=42753--- PASS: TestDrainTimeout (0.21s)27542026/10/01 10:34:46 ERROR Upload failed error="context canceled" count=227552026/10/01 10:34:46 ERROR Drain finished with paths left in queue remaining=22756--- PASS: TestShutdownFinishesInFlightPush (0.00s)2757 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2758 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.21s)27592026/10/01 10:34:46 ERROR Accept failed error="too many open files"27602026/10/01 10:34:46 ERROR Drain finished with paths left in queue remaining=427612026/10/01 10:34:46 ERROR Drain finished with paths left in queue remaining=32762--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2763 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.21s)2764 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.31s)27652026/10/01 10:34:46 ERROR Accept failed error="too many open files"2766--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27672026/10/01 10:34:46 INFO Uploading batch count=127682026/10/01 10:34:46 INFO Uploading batch count=127692026/10/01 10:34:46 INFO Uploading batch count=127702026/10/01 10:34:46 ERROR Upload failed error="upload failed" count=127712026/10/01 10:34:46 INFO Uploading batch count=127722026/10/01 10:34:46 ERROR Upload failed error="upload failed" count=127732026/10/01 10:34:46 INFO Uploading batch count=127742026/10/01 10:34:46 ERROR Upload failed error="upload failed" count=127752026/10/01 10:34:46 INFO Uploading batch count=127762026/10/01 10:34:46 ERROR Upload failed error="upload failed" count=127772026/10/01 10:34:46 ERROR Drain finished with paths left in queue remaining=12778--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2779--- PASS: TestQueueRemoveLargeClosure (1.13s)2780--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.01s)2781PASS2782Running niks3-hook command tests...2783=== RUN TestServeSecondSignalEndsDrain2784=== PAUSE TestServeSecondSignalEndsDrain2785=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2786=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2787=== CONT TestServeSecondSignalEndsDrain2788=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2789--- PASS: TestServeSecondSignalEndsDrain (0.07s)27902026/10/01 10:34:53 INFO Uploading batch count=12791--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)2792PASS2793Running rate limiter tests...2794=== RUN TestAdaptiveRateLimiter_ThreadSafety2795=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2796=== CONT TestAdaptiveRateLimiter_ThreadSafety27972026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=150.0512167000001427982026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=105.0358516900000927992026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=73.5250961830000628002026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=51.4675673281000428012026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=36.02729712967002528022026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=25.21910799076901528032026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=17.6533755935383128042026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=12.35736291547681628052026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=8.6501540408337728062026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=6.055107828583639528072026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528082026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528092026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528102026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528112026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528122026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528132026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528142026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528152026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528162026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528172026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528182026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528192026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528202026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528212026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528222026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528232026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528242026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528252026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528262026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528272026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528282026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528292026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528302026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528312026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528322026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528332026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528342026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=6.82050985000000228352026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528362026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528372026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528382026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528392026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528402026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528412026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528422026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528432026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=8.25281691850000428442026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=5.77697184295000328452026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528462026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528472026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528482026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528492026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528502026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528512026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528522026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528532026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528542026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528552026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528562026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528572026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528582026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528592026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528602026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528612026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528622026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528632026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528642026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528652026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528662026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528672026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528682026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528692026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528702026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528712026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528722026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528732026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528742026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528752026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528762026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528772026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528782026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528792026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528802026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528812026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=5.12435000000000128822026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528832026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528842026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528852026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528862026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528872026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528882026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528892026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528902026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528912026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528922026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528932026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528942026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528952026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=528962026/10/01 10:34:55 WARN Rate limiter backed off name=test rate=52897--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.13s)2898PASS