niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #431
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.08s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.78s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestSetClientTLS107=== PAUSE TestSetClientTLS108=== RUN TestSetClientTLSDoesNotMutateDefaultTransport109=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport110=== RUN TestSetClientTLSErrors111=== PAUSE TestSetClientTLSErrors112=== RUN TestStaticToken113=== PAUSE TestStaticToken114=== RUN TestFileTokenReadsAndCaches115=== PAUSE TestFileTokenReadsAndCaches116=== RUN TestFileTokenMissing117=== PAUSE TestFileTokenMissing118=== RUN TestFileTokenEmpty119=== PAUSE TestFileTokenEmpty120=== RUN TestScriptTokenNoExpiryRerunsEveryCall121=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall122=== RUN TestScriptTokenCachesUntilRefresh123=== PAUSE TestScriptTokenCachesUntilRefresh124=== RUN TestScriptTokenEmptyToken125=== PAUSE TestScriptTokenEmptyToken126=== RUN TestScriptTokenBadJSON127=== PAUSE TestScriptTokenBadJSON128=== RUN TestScriptTokenScriptFails129=== PAUSE TestScriptTokenScriptFails130=== RUN TestScriptTokenEmptyCommand131=== PAUSE TestScriptTokenEmptyCommand132=== RUN TestScriptTokenDoesNotWaitForItsChildren133=== PAUSE TestScriptTokenDoesNotWaitForItsChildren134=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer135=== CONT TestPartSizeForNAR136=== RUN TestPartSizeForNAR/zero_stays_at_minimum137=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum138=== CONT TestStreamPushStopsOnCancel139=== CONT TestDumpPathWriterError140=== CONT TestRateLimiterFeedback141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess143=== PAUSE TestRateLimiterFeedback/429_enables_limiter144=== RUN TestRateLimiterFeedback/503_enables_limiter145=== CONT TestRegisterUploadedObjectReusesConnections146=== PAUSE TestRateLimiterFeedback/503_enables_limiter147=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter148=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter149=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter150=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter151=== CONT TestScriptTokenDoesNotWaitForItsChildren152=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs153=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs154=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout155=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout156=== CONT TestScriptTokenEmptyCommand157--- PASS: TestScriptTokenEmptyCommand (0.00s)158=== CONT TestScriptTokenBadJSON159=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent160=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier161=== CONT TestDumpPathMatchesNix162=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier163=== CONT TestCompletePendingClosure_NotFoundWithoutKey164=== CONT TestTruncatedNARDumpIsNotCompleted165=== CONT TestPathInfoCACompatibility166=== CONT TestUploadMultipart_SupersededByPeer167=== CONT TestParsePathInfoJSON168=== CONT TestSupersededNARStillUploadsListing169=== CONT TestPathInfoHashCompatibility170=== CONT TestGetStorePathHash171=== CONT TestConvertHashToNix32172=== CONT TestParsePathInfoJSONMultiplePaths173=== CONT TestEncodeNixBase32WithRealHash174=== CONT TestUploadMultipart_ProducerErrorIsNotEOF175=== CONT TestEncodeNixBase32176=== CONT TestDumpPathSingleFile177=== RUN TestPartSizeForNAR/small_stays_at_minimum178=== RUN TestStreamPushStopsOnCancel/waiting_for_input179=== CONT TestResolveStorePath180=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up181=== RUN TestPathInfoCACompatibility/null_ca_field182--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)183=== CONT TestScriptTokenEmptyToken184=== RUN TestUploadMultipart_SupersededByPeer/exists185=== RUN TestParsePathInfoJSON/Nix_format186=== RUN TestSupersededNARStillUploadsListing/small_NAR187=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== RUN TestGetStorePathHash/valid_store_path189=== RUN TestConvertHashToNix32/SRI_format_to_Nix32190=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths191=== CONT TestScriptTokenCachesUntilRefresh192=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part193=== RUN TestEncodeNixBase32/test_string_hash194--- PASS: TestEncodeNixBase32WithRealHash (0.00s)195=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up196=== PAUSE TestPartSizeForNAR/small_stays_at_minimum197=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum198=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum199=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts200=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts201=== RUN TestPartSizeForNAR/1_TiB202=== PAUSE TestEncodeNixBase32/test_string_hash203=== RUN TestEncodeNixBase32/empty_input204=== PAUSE TestPartSizeForNAR/1_TiB205=== RUN TestPartSizeForNAR/5_TiB_S3_max_object206=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input207=== PAUSE TestSupersededNARStillUploadsListing/small_NAR208=== PAUSE TestUploadMultipart_SupersededByPeer/exists209=== RUN TestUploadMultipart_SupersededByPeer/missing210=== PAUSE TestEncodeNixBase32/empty_input211=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object212=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot213=== RUN TestSupersededNARStillUploadsListing/dump_cut_short214=== PAUSE TestParsePathInfoJSON/Nix_format215=== RUN TestParsePathInfoJSON/Lix_format216=== PAUSE TestParsePathInfoJSON/Lix_format217=== RUN TestParsePathInfoJSON/empty_input218=== PAUSE TestParsePathInfoJSON/empty_input219=== RUN TestParsePathInfoJSON/whitespace_only220=== PAUSE TestParsePathInfoJSON/whitespace_only221=== RUN TestParsePathInfoJSON/invalid_JSON222=== PAUSE TestParsePathInfoJSON/invalid_JSON223=== CONT TestScriptTokenScriptFails224--- PASS: TestResolveStorePath (0.01s)225=== CONT TestFileTokenEmpty226=== PAUSE TestGetStorePathHash/valid_store_path227=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)228=== RUN TestGetStorePathHash/basename_without_hyphen_should_error229=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error230=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error231=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32232=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths233=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234=== RUN TestConvertHashToNix32/already_Nix32_format235=== PAUSE TestPathInfoCACompatibility/null_ca_field236=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths237=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short238=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails239=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails240=== PAUSE TestConvertHashToNix32/already_Nix32_format241=== RUN TestConvertHashToNix32/invalid_format242=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part243=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary244=== PAUSE TestConvertHashToNix32/invalid_format245=== CONT TestSetClientTLSDoesNotMutateDefaultTransport246=== RUN TestPartSizeForNAR/capped_at_5_GiB247=== PAUSE TestPartSizeForNAR/capped_at_5_GiB248=== PAUSE TestUploadMultipart_SupersededByPeer/missing249=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot250=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot251=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot252=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot253=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot254=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot255=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot256=== CONT TestSetClientTLSErrors257=== CONT TestStreamPushBatchesUnderLoad258=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary259=== RUN TestStreamPushBatchesUnderLoad/together260=== CONT TestStreamPushStopsWhenCanceled261=== CONT TestSetClientTLS262=== PAUSE TestStreamPushBatchesUnderLoad/together263--- PASS: TestFileTokenEmpty (0.01s)264--- PASS: TestScriptTokenBadJSON (0.05s)265--- PASS: TestScriptTokenScriptFails (0.02s)266=== CONT TestClientSignaturesByStorePath267--- PASS: TestClientSignaturesByStorePath (0.00s)268=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time269=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken270=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time271=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken272=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error273=== CONT TestStreamPushReportsSkippedPaths274=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier275=== RUN TestPathInfoCACompatibility/old_string_format_-_text276=== CONT TestStaticToken277--- PASS: TestStaticToken (0.00s)278=== CONT TestStreamPushIsolatesFailures279=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error280--- PASS: TestStreamPushReportsSkippedPaths (0.00s)281=== CONT TestDoWithRetry_FinalResponseBodyReadable282=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon283=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier284=== CONT TestFileTokenMissing285--- PASS: TestStreamPushStopsWhenCanceled (0.00s)286=== CONT TestStreamPushGivesUpOnDeadServer287=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client288--- PASS: TestFileTokenMissing (0.00s)289=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client290=== CONT TestStreamPushReportsSignatures291=== CONT TestScriptTokenNoExpiryRerunsEveryCall292=== CONT TestStreamPushRequestLine293=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text294--- PASS: TestStreamPushIsolatesFailures (0.00s)295=== CONT TestShellSplit296--- PASS: TestShellSplit (0.00s)297=== CONT TestRetryTimeoutOutlastsMaxRetries298=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon299=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive300=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive301=== RUN TestPathInfoCACompatibility/new_structured_format_-_text302=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error303=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI304=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text305=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method306=== CONT TestStreamPushReportsEveryPath307=== CONT TestFileTokenReadsAndCaches308--- PASS: TestStreamPushReportsSignatures (0.00s)309=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun310--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)311=== CONT TestShellSplitErrors312--- PASS: TestShellSplitErrors (0.00s)313=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica314=== CONT TestUploadMultipart_PartsInParallel315=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure317=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client318=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client319=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry320=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512322=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512323--- PASS: TestStreamPushReportsEveryPath (0.01s)324--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.06s)325--- PASS: TestScriptTokenEmptyToken (0.08s)326=== CONT TestDoWithRetry_BodyReplayedViaGetBody327=== CONT TestCaseHackSuffix328=== CONT TestDoServerRequestAttachesToken329--- PASS: TestFileTokenReadsAndCaches (0.06s)330=== CONT TestUploadMultipart_FailedPartBufferNotReused331=== RUN TestSetClientTLS/rejects_connection_without_client_cert332=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert333=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA334=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA335=== RUN TestSetClientTLS/preserves_debug_logging_transport336=== PAUSE TestSetClientTLS/preserves_debug_logging_transport337=== CONT TestRateLimiterFeedback/429_enables_limiter338=== RUN TestSetClientTLSErrors/missing_cert_file339=== PAUSE TestSetClientTLSErrors/missing_cert_file340=== RUN TestSetClientTLSErrors/missing_key_file341=== PAUSE TestSetClientTLSErrors/missing_key_file342=== RUN TestSetClientTLSErrors/missing_ca_file343=== PAUSE TestSetClientTLSErrors/missing_ca_file344=== RUN TestSetClientTLSErrors/invalid_ca_file345=== PAUSE TestSetClientTLSErrors/invalid_ca_file346=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter347=== CONT TestFilterOversizedClosures348=== RUN TestFilterOversizedClosures/no_limit_keeps_everything349=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything350=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped351=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped352=== RUN TestFilterOversizedClosures/all_closures_skipped353=== PAUSE TestFilterOversizedClosures/all_closures_skipped354=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter355--- PASS: TestDoServerRequestAttachesToken (0.03s)356=== CONT TestRateLimiterFeedback/503_enables_limiter357--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.09s)358=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout359=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs360--- PASS: TestScriptTokenCachesUntilRefresh (0.12s)361=== CONT TestParsePathInfoJSON/Nix_format362--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.10s)363=== CONT TestParsePathInfoJSON/invalid_JSON364=== CONT TestParsePathInfoJSON/whitespace_only365=== CONT TestParsePathInfoJSON/empty_input366=== CONT TestParsePathInfoJSON/Lix_format367=== CONT TestEncodeNixBase32/test_string_hash368=== CONT TestEncodeNixBase32/empty_input369=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths370--- PASS: TestEncodeNixBase32 (0.02s)371 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)372 --- PASS: TestEncodeNixBase32/empty_input (0.00s)373=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths374=== CONT TestSupersededNARStillUploadsListing/small_NAR375=== CONT TestSupersededNARStillUploadsListing/dump_cut_short376=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails377--- PASS: TestParsePathInfoJSON (0.01s)378 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)379 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)380 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)381 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)382 --- PASS: TestParsePathInfoJSON/Nix_format (0.01s)383=== CONT TestUploadMultipart_SupersededByPeer/missing384=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary385--- PASS: TestRateLimiterFeedback (0.00s)386 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.03s)387 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.04s)388 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.05s)389 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.05s)390--- PASS: TestParsePathInfoJSONMultiplePaths (0.05s)391 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)392 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)393=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part394--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.15s)395=== CONT TestConvertHashToNix32/already_Nix32_format396=== CONT TestConvertHashToNix32/invalid_format397=== CONT TestConvertHashToNix32/SRI_format_to_Nix32398--- PASS: TestConvertHashToNix32 (0.03s)399 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)400 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)401 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)402=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot403--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.10s)404=== CONT TestUploadMultipart_SupersededByPeer/exists405=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken406--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.26s)407--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.26s)408=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot409=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot410=== CONT TestStreamPushStopsOnCancel/waiting_for_input411=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot412=== CONT TestPartSizeForNAR/zero_stays_at_minimum413=== CONT TestPartSizeForNAR/capped_at_5_GiB414=== CONT TestPartSizeForNAR/5_TiB_S3_max_object415=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts416=== CONT TestPartSizeForNAR/1_TiB417=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum418=== CONT TestPartSizeForNAR/small_stays_at_minimum419--- PASS: TestPartSizeForNAR (0.06s)420 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)421 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)422 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)423 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)424 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)425 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)426 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)427=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time428=== CONT TestStreamPushBatchesUnderLoad/together429=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error430=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error431=== CONT TestGetStorePathHash/basename_without_hyphen_should_error432--- PASS: TestStreamPushBatchesUnderLoad (0.00s)433 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)434 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)435=== CONT TestPathInfoCACompatibility/old_string_format_-_text436=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier437--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)438 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)439 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.18s)440=== CONT TestGetStorePathHash/valid_store_path441=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client442--- PASS: TestStreamPushRequestLine (0.33s)443=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier444--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.33s)445=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive446=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method447=== CONT TestPathInfoCACompatibility/null_ca_field448=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up449=== CONT TestPathInfoCACompatibility/new_structured_format_-_text450--- PASS: TestGetStorePathHash (0.03s)451 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)452 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)453 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)454 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)455--- PASS: TestPathInfoCACompatibility (0.06s)456 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)457 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)458 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)459 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)460 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)461=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client462=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon463=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512464=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)465=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI466--- PASS: TestDumpPathWriterError (0.45s)467=== CONT TestSetClientTLS/preserves_debug_logging_transport468=== CONT TestSetClientTLS/rejects_connection_without_client_cert469--- PASS: TestPathInfoHashCompatibility (0.04s)470 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)471 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)472 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)473 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)474=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA475--- PASS: TestCaseHackSuffix (0.36s)476=== CONT TestSetClientTLSErrors/missing_ca_file477=== CONT TestSetClientTLSErrors/missing_cert_file478--- PASS: TestDumpPathSingleFile (0.45s)479=== CONT TestSetClientTLSErrors/missing_key_file480=== CONT TestSetClientTLSErrors/invalid_ca_file481=== CONT TestFilterOversizedClosures/all_closures_skipped482--- PASS: TestSetClientTLSErrors (0.06s)483 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)484 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)485 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)486 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)487--- PASS: TestStreamPushStopsOnCancel (0.06s)488 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)489 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.07s)490 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)491 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.06s)492 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)493 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.11s)494=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped495=== CONT TestFilterOversizedClosures/no_limit_keeps_everything496--- PASS: TestFilterOversizedClosures (0.02s)497 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)498 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)499 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)500--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.06s)501 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.08s)502 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.10s)503 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.10s)504 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.11s)505 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.09s)506--- PASS: TestSetClientTLS (0.06s)507 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.07s)508 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.05s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)510--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.03s)511 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.31s)512 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.39s)513--- PASS: TestDumpPathMatchesNix (0.62s)514--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.58s)515--- PASS: TestRegisterUploadedObjectReusesConnections (0.89s)516--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)517--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)518--- PASS: TestUploadMultipart_PartsInParallel (1.01s)519--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.96s)520--- PASS: TestTruncatedNARDumpIsNotCompleted (1.22s)521--- PASS: TestSupersededNARStillUploadsListing (0.03s)522 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.24s)523 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.28s)524 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.11s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.08s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.22s)528PASS529Running server tests...530The files belonging to this database system will be owned by user "_tribuchetbld8".531This user must also own the server process.532533The database cluster will be initialized with locale "C".534The default database encoding has accordingly been set to "SQL_ASCII".535The default text search configuration will be set to "english".536537Data page checksums are enabled.538539creating directory /private/var/tb/8/scratch/b4969cc7c947cd0c/build/postgres1746027649/data ... ok540creating subdirectories ... ok541selecting dynamic shared memory implementation ... posix542selecting default "max_connections" ... 100543selecting default "shared_buffers" ... 128MB544selecting default time zone ... UTC545creating configuration files ... ok546running bootstrap script ... ok547performing post-bootstrap initialization ... ok548syncing data to disk ... ok549550initdb: warning: enabling "trust" authentication for local connections551initdb: 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.552553Success. You can now start the database server using:554555 pg_ctl -D /private/var/tb/8/scratch/b4969cc7c947cd0c/build/postgres1746027649/data -l logfile start556557/private/var/tb/8/scratch/b4969cc7c947cd0c/build/postgres1746027649:5432 - no response5582026-10-25 17:21:29.130 UTC [55743] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5592026-10-25 17:21:29.130 UTC [55743] LOG: listening on Unix socket "/private/var/tb/8/scratch/b4969cc7c947cd0c/build/postgres1746027649/.s.PGSQL.5432"5602026-10-25 17:21:29.136 UTC [55750] LOG: database system was shut down at 2026-10-25 17:21:29 UTC5612026-10-25 17:21:29.138 UTC [55743] LOG: database system is ready to accept connections562/private/var/tb/8/scratch/b4969cc7c947cd0c/build/postgres1746027649:5432 - accepting connections563{"timestamp":"2026-10-25T17:21:29.357782Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"45db8ceb-3663-4253-b6f9-fea2c4932529","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(6)"}564=== RUN TestService_AuthMiddleware565=== PAUSE TestService_AuthMiddleware566=== RUN TestService_AuthMiddleware_MTLSProxyHeader567=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader568=== RUN TestService_AuthMiddleware_MTLSBoundSubjects569=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects570=== RUN TestService_ReadAuthMiddleware571=== PAUSE TestService_ReadAuthMiddleware572=== RUN TestService_AuthMiddleware_OIDC573=== PAUSE TestService_AuthMiddleware_OIDC574=== RUN TestService_RequireScope_OIDC575=== PAUSE TestService_RequireScope_OIDC576=== RUN TestService_ReadScope_PublicByDefault577=== PAUSE TestService_ReadScope_PublicByDefault578=== RUN TestCacheConfigHandler579=== PAUSE TestCacheConfigHandler580=== RUN TestCacheStatsHandler581=== PAUSE TestCacheStatsHandler582=== RUN TestClientCADerivations583=== PAUSE TestClientCADerivations584=== RUN TestClientErrorHandling585=== PAUSE TestClientErrorHandling586=== RUN TestClientIntegration587=== PAUSE TestClientIntegration588=== RUN TestClientMultipleUploads589=== PAUSE TestClientMultipleUploads590=== RUN TestClientWithDependencies591=== PAUSE TestClientWithDependencies592=== RUN TestClientSharedPathCommittedMidPush593=== PAUSE TestClientSharedPathCommittedMidPush594=== RUN TestPinProtectsFromGC595=== PAUSE TestPinProtectsFromGC596=== RUN TestClientPushesUseOnePush597=== PAUSE TestClientPushesUseOnePush598=== RUN TestClientFallsBackToClosures599=== PAUSE TestClientFallsBackToClosures600=== RUN TestDeleteClosuresRacingPins601=== PAUSE TestDeleteClosuresRacingPins602=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock604=== RUN TestResolveDBConnectionString605=== PAUSE TestResolveDBConnectionString606=== RUN TestConnectWaitsForAPeerMigration607=== PAUSE TestConnectWaitsForAPeerMigration608=== RUN TestConnectSerialisesConcurrentMigrations609=== PAUSE TestConnectSerialisesConcurrentMigrations610=== RUN TestLeadElectsOneAndHandsOver611=== PAUSE TestLeadElectsOneAndHandsOver612=== RUN TestLeadIncumbentWinsAfterRestart6132026/10/25 17:21:29 INFO lead: acquired remote=192.0.2.1:12346142026/10/25 17:21:30 INFO lead: released remote=192.0.2.1:12346152026/10/25 17:21:30 INFO lead: acquired remote=192.0.2.1:12346162026/10/25 17:21:31 INFO lead: released remote=192.0.2.1:1234617--- PASS: TestLeadIncumbentWinsAfterRestart (1.96s)618=== RUN TestLeadIncumbentAnnouncesAtOnce619=== PAUSE TestLeadIncumbentAnnouncesAtOnce620=== RUN TestLeadEndsOnShutdown621=== PAUSE TestLeadEndsOnShutdown622=== RUN TestLeadEndsWhenItsConnectionHangs6232026/10/25 17:21:31 INFO lead: acquired remote=192.0.2.1:12346242026-10-25 17:21:33.008 UTC [55788] FATAL: terminating connection due to administrator command6252026/10/25 17:21:33 INFO lead: acquired remote=192.0.2.1:12346262026/10/25 17:21:34 WARN lead: lock connection lost error="timeout: context deadline exceeded"6272026/10/25 17:21:34 INFO lead: released remote=192.0.2.1:12346282026/10/25 17:21:34 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadEndsWhenItsConnectionHangs (3.19s)630=== RUN TestGCAdvisoryLockBlocksConcurrentRun631=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun632=== RUN TestGCBugBareHashReferences633=== PAUSE TestGCBugBareHashReferences634=== RUN TestGCMetrics635=== PAUSE TestGCMetrics636=== RUN TestPushDedupSurvivesConcurrentGC637=== PAUSE TestPushDedupSurvivesConcurrentGC638=== RUN TestDeduplicatedObjectsRecordedAsPending639=== PAUSE TestDeduplicatedObjectsRecordedAsPending640=== RUN TestGCSweepSkipsPendingObjects641=== PAUSE TestGCSweepSkipsPendingObjects642=== RUN TestTombstonedObjectOfferedWithoutWaiting643=== PAUSE TestTombstonedObjectOfferedWithoutWaiting644=== RUN TestGCSweepDeliversEachKeyOnce645=== PAUSE TestGCSweepDeliversEachKeyOnce646=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection648=== RUN TestForceGCDuringPushOffersSweptObject649=== PAUSE TestForceGCDuringPushOffersSweptObject650=== RUN TestFailedS3DeleteKeepsTombstone651=== PAUSE TestFailedS3DeleteKeepsTombstone652=== RUN TestSweepSkipsRowsLockedByPush653=== PAUSE TestSweepSkipsRowsLockedByPush654=== RUN TestRegisterCompletedObjectNeedsPendingRow655=== PAUSE TestRegisterCompletedObjectNeedsPendingRow656=== RUN TestGetExistingObjectsLocksRows657=== PAUSE TestGetExistingObjectsLocksRows658=== RUN TestSweepRechecksPendingAfterLocking659=== PAUSE TestSweepRechecksPendingAfterLocking660=== RUN TestPushWaitsForSweepHoldingRow661=== PAUSE TestPushWaitsForSweepHoldingRow662=== RUN TestCommitRacingPendingCleanupKeepsObjects663=== PAUSE TestCommitRacingPendingCleanupKeepsObjects664=== RUN TestGCEndsOnShutdown665=== PAUSE TestGCEndsOnShutdown666=== RUN TestGCTaskStore_StartNew667=== PAUSE TestGCTaskStore_StartNew668=== RUN TestGCTaskStore_DeduplicateSameParams669=== PAUSE TestGCTaskStore_DeduplicateSameParams670=== RUN TestGCTaskStore_ConflictDifferentParams671=== PAUSE TestGCTaskStore_ConflictDifferentParams672=== RUN TestGCTaskStore_GetEmpty673=== PAUSE TestGCTaskStore_GetEmpty674=== RUN TestGCTaskStore_GetReturnsLatest675=== PAUSE TestGCTaskStore_GetReturnsLatest676=== RUN TestGCTaskStore_CompletedAllowsNewTask677=== PAUSE TestGCTaskStore_CompletedAllowsNewTask678=== RUN TestGCTaskStore_PhaseUpdates679=== PAUSE TestGCTaskStore_PhaseUpdates680=== RUN TestGCTaskStore_Fail681=== PAUSE TestGCTaskStore_Fail682=== RUN TestGracefulShutdownDrainsInflight683=== PAUSE TestGracefulShutdownDrainsInflight684=== RUN TestService_healthCheckHandler685=== PAUSE TestService_healthCheckHandler686=== RUN TestService_readinessHandler687=== PAUSE TestService_readinessHandler688=== RUN TestGenerateLandingPage689=== PAUSE TestGenerateLandingPage690=== RUN TestChildrenInheritRaisedFileLimit691=== PAUSE TestChildrenInheritRaisedFileLimit692=== RUN TestCacheConfigHandlerMaxNarSize693=== PAUSE TestCacheConfigHandlerMaxNarSize694=== RUN TestCreatePendingClosureRejectsOversizedNAR695=== PAUSE TestCreatePendingClosureRejectsOversizedNAR696=== RUN TestNARDeduplicationMetadataUploadBug697=== PAUSE TestNARDeduplicationMetadataUploadBug698=== RUN TestMetricsInventory699=== PAUSE TestMetricsInventory700=== RUN TestMetricsCommit701=== PAUSE TestMetricsCommit702=== RUN TestService_NativeMTLS703=== PAUSE TestService_NativeMTLS704=== RUN TestServerTLSConfig705=== PAUSE TestServerTLSConfig706=== RUN TestMultipartCleanup707=== PAUSE TestMultipartCleanup708=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded710=== RUN TestPendingCleanupUsesOneCutoff711=== PAUSE TestPendingCleanupUsesOneCutoff712=== RUN TestPendingClosureFailureTracksEveryUpload713=== PAUSE TestPendingClosureFailureTracksEveryUpload714=== RUN TestPendingClosureFailureAbortsItsUploads715=== PAUSE TestPendingClosureFailureAbortsItsUploads716=== RUN TestObjectStatsTrigger717=== PAUSE TestObjectStatsTrigger718=== RUN TestObjectStatsUpdatedOncePerCommit719=== PAUSE TestObjectStatsUpdatedOncePerCommit720=== RUN TestReconnectLeavesObjectsUnlocked721=== PAUSE TestReconnectLeavesObjectsUnlocked722=== RUN TestOrphanedObjectsGC723=== PAUSE TestOrphanedObjectsGC724=== RUN TestOrphanedObjectsGCStressTest725=== PAUSE TestOrphanedObjectsGCStressTest726=== RUN TestCreatePin_ReservedPins727=== PAUSE TestCreatePin_ReservedPins728=== RUN TestConcurrentPinUpdatesAgree729=== PAUSE TestConcurrentPinUpdatesAgree730=== RUN TestCreatePinRejectsBadInput731=== PAUSE TestCreatePinRejectsBadInput732=== RUN TestDeletePinKeepsRowWhenS3Fails733=== PAUSE TestDeletePinKeepsRowWhenS3Fails734=== RUN TestPresentReportsOnlyClosureRoots735=== PAUSE TestPresentReportsOnlyClosureRoots736=== RUN TestPresentRefreshesOnlyStaleClosures737=== PAUSE TestPresentRefreshesOnlyStaleClosures738=== RUN TestPresentNotReportedWhileGCDeletesClosure739=== PAUSE TestPresentNotReportedWhileGCDeletesClosure740=== RUN TestParseSingleRange741=== PAUSE TestParseSingleRange742=== RUN TestProxyHeadersOnlyTrustedOnSocket7432026/10/25 17:21:34 INFO Starting HTTP server address=127.0.0.1:532607442026/10/25 17:21:34 INFO Starting HTTP server address=proxy.sock7452026/10/25 17:21:34 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7462026/10/25 17:21:34 INFO Shutdown signal received, draining in-flight requests timeout=10s747--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.20s)748=== RUN TestIsValidCachePath749=== PAUSE TestIsValidCachePath750=== RUN TestReadProxyNarinfo751=== PAUSE TestReadProxyNarinfo752=== RUN TestReadProxyNarinfoAlreadyDecompressed753=== PAUSE TestReadProxyNarinfoAlreadyDecompressed754=== RUN TestReadProxyContentNegotiation755=== PAUSE TestReadProxyContentNegotiation756=== RUN TestReadProxyNarStreaming757=== PAUSE TestReadProxyNarStreaming758=== RUN TestReadProxy404759=== PAUSE TestReadProxy404760=== RUN TestReadProxyInvalidPath761=== PAUSE TestReadProxyInvalidPath762=== RUN TestReadProxyHead763=== PAUSE TestReadProxyHead764=== RUN TestReadProxyOutlastsServerWriteTimeout765=== PAUSE TestReadProxyOutlastsServerWriteTimeout766=== RUN TestReadProxyConditionalGet767=== PAUSE TestReadProxyConditionalGet768=== RUN TestReadProxyRootRedirectsToIndexHTML769=== PAUSE TestReadProxyRootRedirectsToIndexHTML770=== RUN TestReadProxyDisabled771=== PAUSE TestReadProxyDisabled772=== RUN TestReadRedirectNar773=== PAUSE TestReadRedirectNar774=== RUN TestReadRedirectKeepsNarinfoProxied775=== PAUSE TestReadRedirectKeepsNarinfoProxied776=== RUN TestReadProxyRangeRequest777=== PAUSE TestReadProxyRangeRequest778=== RUN TestReadRedirectUsesPublicS3URL779=== PAUSE TestReadRedirectUsesPublicS3URL780=== RUN TestPush_OverlappingRootsStoreOneRowPerKey781=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey782=== RUN TestPush_CompleteCommitsEveryRoot783=== PAUSE TestPush_CompleteCommitsEveryRoot784=== RUN TestPush_RepeatedRootCommitsOnce785=== PAUSE TestPush_RepeatedRootCommitsOnce786=== RUN TestPush_CompleteWaitsForCleanupOfThePush787=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush788=== RUN TestPush_RootsAreLockedInByteOrder789=== PAUSE TestPush_RootsAreLockedInByteOrder790=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit791=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit792=== RUN TestPush_RejectsBadRequests793=== PAUSE TestPush_RejectsBadRequests794=== RUN TestPush_SignsNarinfosOfItsPendingObjects795=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects796=== RUN TestRedundantMultipartUpload797=== PAUSE TestRedundantMultipartUpload798=== RUN TestCompleteMultipartUpload_ErrorButObjectExists799=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists800=== RUN TestCompletedNarNotReofferedAcrossClosures801=== PAUSE TestCompletedNarNotReofferedAcrossClosures802=== RUN TestPresignedUploadRegisteredBeforeCommit803=== PAUSE TestPresignedUploadRegisteredBeforeCommit804=== RUN TestService_Rustfstest805=== PAUSE TestService_Rustfstest806=== RUN TestParseSize807=== PAUSE TestParseSize808=== RUN TestSkippedUploadsHandler809=== PAUSE TestSkippedUploadsHandler810=== RUN TestSystemdListenerNotActivated811--- PASS: TestSystemdListenerNotActivated (0.00s)812=== RUN TestWatchdogBeatsWhenHealthy813--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)814=== RUN TestWatchdogSkipsWhenUnhealthy8152026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 17:21:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 17:21:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 17:21:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 17:21:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/25 17:21:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"825--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)826=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle828=== RUN TestProxyWriteTimeout829=== PAUSE TestProxyWriteTimeout830=== RUN TestPendingClosureWriteTimeout831=== PAUSE TestPendingClosureWriteTimeout832=== RUN TestIsValidUploadKey833=== PAUSE TestIsValidUploadKey834=== RUN TestUploadHandlersRejectInvalidKeys835=== PAUSE TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectOversizedBody837=== PAUSE TestUploadHandlersRejectOversizedBody838=== RUN TestService_cleanupPendingClosuresHandler839=== PAUSE TestService_cleanupPendingClosuresHandler840=== RUN TestService_createPendingClosureHandler841=== PAUSE TestService_createPendingClosureHandler842=== RUN TestService_verifyS3Integrity843=== PAUSE TestService_verifyS3Integrity844=== RUN TestCompleteMultipartUnregistered845=== PAUSE TestCompleteMultipartUnregistered846=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT847=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT848=== CONT TestReadRedirectKeepsNarinfoProxied849=== CONT TestGCTaskStore_GetReturnsLatest850=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT851=== CONT TestReadProxyNarinfo852=== CONT TestService_AuthMiddleware853=== CONT TestReconnectLeavesObjectsUnlocked854--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)855=== CONT TestCreatePin_ReservedPins856=== CONT TestGCTaskStore_ConflictDifferentParams857=== CONT TestObjectStatsUpdatedOncePerCommit858=== CONT TestReadProxyDisabled859=== CONT TestPush_OverlappingRootsStoreOneRowPerKey860=== CONT TestReadProxyConditionalGet861=== CONT TestReadProxyOutlastsServerWriteTimeout862=== CONT TestPendingClosureFailureAbortsItsUploads863=== CONT TestReadProxyHead864=== CONT TestReadProxyRootRedirectsToIndexHTML865=== CONT TestReadProxyNarStreaming866=== CONT TestObjectStatsTrigger867=== CONT TestReadProxy404868=== CONT TestReadProxyContentNegotiation869=== CONT TestReadProxyNarinfoAlreadyDecompressed870=== CONT TestIsValidCachePath871=== CONT TestPendingClosureFailureTracksEveryUpload872=== CONT TestGCTaskStore_GetEmpty873=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false874=== CONT TestSkippedUploadsHandler875=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded876=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false877=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true878--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)879=== CONT TestPendingCleanupUsesOneCutoff880=== RUN TestIsValidCachePath/narinfo881--- PASS: TestGCTaskStore_GetEmpty (0.00s)882=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true883=== PAUSE TestIsValidCachePath/narinfo884=== CONT TestMultipartCleanup885=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars886=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars887=== RUN TestIsValidCachePath/nar_zst888=== PAUSE TestIsValidCachePath/nar_zst889=== RUN TestIsValidCachePath/nar_xz890=== PAUSE TestIsValidCachePath/nar_xz891=== RUN TestIsValidCachePath/nar_bz2892=== PAUSE TestIsValidCachePath/nar_bz2893=== RUN TestIsValidCachePath/nar_uncompressed894=== PAUSE TestIsValidCachePath/nar_uncompressed895=== RUN TestIsValidCachePath/ls896=== PAUSE TestIsValidCachePath/ls897=== RUN TestIsValidCachePath/log898=== PAUSE TestIsValidCachePath/log899=== RUN TestIsValidCachePath/realisation900=== PAUSE TestIsValidCachePath/realisation901=== RUN TestIsValidCachePath/nix-cache-info902=== PAUSE TestIsValidCachePath/nix-cache-info903=== RUN TestIsValidCachePath/index.html904=== PAUSE TestIsValidCachePath/index.html905=== RUN TestIsValidCachePath/traversal_parent906=== PAUSE TestIsValidCachePath/traversal_parent907=== RUN TestIsValidCachePath/traversal_in_middle908=== PAUSE TestIsValidCachePath/traversal_in_middle909=== RUN TestIsValidCachePath/invalid_char_e910=== PAUSE TestIsValidCachePath/invalid_char_e911=== RUN TestIsValidCachePath/invalid_char_u912=== PAUSE TestIsValidCachePath/invalid_char_u913=== RUN TestIsValidCachePath/random_path914=== PAUSE TestIsValidCachePath/random_path915=== RUN TestIsValidCachePath/empty9162026/10/25 17:21:35 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000917=== PAUSE TestIsValidCachePath/empty918=== RUN TestIsValidCachePath/leading_slash919=== PAUSE TestIsValidCachePath/leading_slash920=== RUN TestIsValidCachePath/wrong_extension921=== PAUSE TestIsValidCachePath/wrong_extension922=== RUN TestIsValidCachePath/short_hash923=== PAUSE TestIsValidCachePath/short_hash924=== CONT TestGCTaskStore_StartNew925--- PASS: TestGCTaskStore_StartNew (0.00s)926=== CONT TestService_NativeMTLS927--- PASS: TestSkippedUploadsHandler (0.04s)928=== CONT TestMetricsCommit9292026/10/25 17:21:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53264/oidc9302026/10/25 17:21:35 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9312026/10/25 17:21:35 WARN mTLS auth: subject not in bound subjects subject="CN=reader"932--- PASS: TestService_NativeMTLS (0.73s)933=== CONT TestGCTaskStore_DeduplicateSameParams934--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)935=== CONT TestGCEndsOnShutdown936=== RUN TestGCEndsOnShutdown/before_the_run937=== PAUSE TestGCEndsOnShutdown/before_the_run938=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete939=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete940=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark941=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark942=== CONT TestMetricsInventory943--- PASS: TestReadRedirectKeepsNarinfoProxied (1.01s)944=== CONT TestServerTLSConfig945=== RUN TestServerTLSConfig/no_client_CA946=== PAUSE TestServerTLSConfig/no_client_CA947=== RUN TestServerTLSConfig/missing_CA_file948=== PAUSE TestServerTLSConfig/missing_CA_file949=== RUN TestServerTLSConfig/not_a_PEM_file950=== PAUSE TestServerTLSConfig/not_a_PEM_file951=== CONT TestPushWaitsForSweepHoldingRow9522026/10/25 17:21:36 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>953--- PASS: TestReadProxyNarinfo (1.59s)954=== CONT TestSweepRechecksPendingAfterLocking955--- PASS: TestObjectStatsUpdatedOncePerCommit (1.67s)956=== CONT TestCreatePendingClosureRejectsOversizedNAR9572026/10/25 17:21:36 INFO Received uploads request method=POST path=/api/pending_closures958--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)959=== CONT TestGetExistingObjectsLocksRows9602026/10/25 17:21:36 INFO Received uploads request method=POST path=/api/pending_closures961--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.86s)962=== CONT TestGenerateLandingPage963--- PASS: TestGenerateLandingPage (0.01s)964=== CONT TestCommitRacingPendingCleanupKeepsObjects965--- PASS: TestReadProxyConditionalGet (2.19s)966=== CONT TestCacheConfigHandlerMaxNarSize967--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)968=== CONT TestRegisterCompletedObjectNeedsPendingRow9692026/10/25 17:21:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"970--- PASS: TestService_AuthMiddleware (2.37s)971=== CONT TestService_readinessHandler972--- PASS: TestReadProxyDisabled (2.58s)973=== CONT TestSweepSkipsRowsLockedByPush974--- PASS: TestReconnectLeavesObjectsUnlocked (3.05s)975=== CONT TestGracefulShutdownDrainsInflight9762026/10/25 17:21:38 INFO Starting HTTP server address=127.0.0.1:533189772026/10/25 17:21:38 INFO Shutdown signal received, draining in-flight requests timeout=10s978--- PASS: TestGracefulShutdownDrainsInflight (0.07s)979=== CONT TestForceGCDuringPushOffersSweptObject980=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows981=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows982=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check983=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check984=== CONT TestService_healthCheckHandler9852026/10/25 17:21:38 WARN Rate limiter enabled after throttle name=s3-test rate=59862026/10/25 17:21:38 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."9872026/10/25 17:21:38 WARN Rate limiter backed off name=s3-test rate=59882026/10/25 17:21:38 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."989--- PASS: TestReadProxy404 (3.33s)990=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9912026/10/25 17:21:38 INFO Received uploads request method=POST path=/api/pending_closures992--- PASS: TestReadProxyContentNegotiation (3.51s)993=== CONT TestGCTaskStore_PhaseUpdates994--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)995=== CONT TestGCSweepDeliversEachKeyOnce996--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (3.57s)997=== CONT TestGCTaskStore_Fail998--- PASS: TestGCTaskStore_Fail (0.00s)999=== CONT TestFailedS3DeleteKeepsTombstone10002026/10/25 17:21:38 INFO Received push request method=POST path=/api/pushes1001--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.03s)1002=== CONT TestGCTaskStore_CompletedAllowsNewTask1003--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1004=== CONT TestReadProxyInvalidPath1005--- PASS: TestReadProxyHead (4.19s)1006=== CONT TestTombstonedObjectOfferedWithoutWaiting1007--- PASS: TestReadProxyNarinfoAlreadyDecompressed (4.39s)1008=== CONT TestPresentReportsOnlyClosureRoots10092026/10/25 17:21:39 INFO Received uploads request method=POST path=/api/pending_closures10102026/10/25 17:21:39 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/25 17:21:39 INFO Received cleanup request method=DELETE path=/api/pending_closures10122026/10/25 17:21:39 INFO Received uploads request method=POST path=/api/pending_closures1013--- PASS: TestPendingClosureFailureAbortsItsUploads (4.88s)1014=== CONT TestParseSingleRange1015=== RUN TestParseSingleRange/none1016=== PAUSE TestParseSingleRange/none1017=== RUN TestParseSingleRange/unknown_unit1018=== PAUSE TestParseSingleRange/unknown_unit1019=== RUN TestParseSingleRange/multi-range_ignored1020=== PAUSE TestParseSingleRange/multi-range_ignored1021=== RUN TestParseSingleRange/malformed_no_dash1022=== PAUSE TestParseSingleRange/malformed_no_dash1023=== RUN TestParseSingleRange/malformed_both_empty1024=== PAUSE TestParseSingleRange/malformed_both_empty1025=== RUN TestParseSingleRange/malformed_end_before_start1026=== PAUSE TestParseSingleRange/malformed_end_before_start1027=== RUN TestParseSingleRange/closed1028=== PAUSE TestParseSingleRange/closed1029=== RUN TestParseSingleRange/open-ended1030=== PAUSE TestParseSingleRange/open-ended1031=== RUN TestParseSingleRange/end_clamped_to_size1032=== PAUSE TestParseSingleRange/end_clamped_to_size1033=== RUN TestParseSingleRange/suffix1034=== PAUSE TestParseSingleRange/suffix1035=== RUN TestParseSingleRange/suffix_exceeds_size1036=== PAUSE TestParseSingleRange/suffix_exceeds_size1037=== RUN TestParseSingleRange/single_byte1038=== PAUSE TestParseSingleRange/single_byte1039=== RUN TestParseSingleRange/start_past_EOF1040=== PAUSE TestParseSingleRange/start_past_EOF1041=== RUN TestParseSingleRange/start_far_past_EOF1042=== PAUSE TestParseSingleRange/start_far_past_EOF1043=== CONT TestGCSweepSkipsPendingObjects10442026/10/25 17:21:40 INFO Received push request method=POST path=/api/pushes1045--- PASS: TestObjectStatsTrigger (5.29s)1046=== CONT TestPresentRefreshesOnlyStaleClosures1047--- PASS: TestReadProxyNarStreaming (5.51s)1048=== CONT TestDeduplicatedObjectsRecordedAsPending1049--- PASS: TestReadProxyRootRedirectsToIndexHTML (5.73s)1050=== CONT TestPresentNotReportedWhileGCDeletesClosure1051=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1052=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1053=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1054=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1055=== CONT TestPushDedupSurvivesConcurrentGC10562026/10/25 17:21:40 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/25 17:21:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10582026/10/25 17:21:41 WARN Refused reserved pin name=worker-x86_64-linux10592026/10/25 17:21:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10602026/10/25 17:21:41 INFO Received create pin request method=POST path=/api/pins/my-app10612026/10/25 17:21:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10622026/10/25 17:21:41 INFO Received cleanup request method=DELETE path=/api/pending_closures10632026/10/25 17:21:41 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10642026/10/25 17:21:41 INFO Aborted multipart uploads count=0 kept=110652026/10/25 17:21:41 INFO Received cleanup request method=DELETE path=/api/pending_closures10662026/10/25 17:21:41 INFO Aborted multipart uploads count=1 kept=01067--- PASS: TestCreatePin_ReservedPins (6.19s)1068=== CONT TestDeletePinKeepsRowWhenS3Fails1069--- PASS: TestMultipartCleanup (6.23s)1070=== CONT TestPush_RootsAreLockedInByteOrder10712026/10/25 17:21:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10722026/10/25 17:21:41 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmRhNjAxOTE2LThiMmYtNGU3OS05ZmI4LTAwNmRkYjc0YTdjYXgxNzkyOTQ4OTAwMDUxNDQyMDAw parts=101073--- PASS: TestMetricsInventory (5.68s)1074=== CONT TestCompletedNarNotReofferedAcrossClosures10752026/10/25 17:21:41 INFO Received uploads request method=POST path=/api/pending_closures1076--- PASS: TestGetExistingObjectsLocksRows (5.28s)1077=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1078--- PASS: TestPushWaitsForSweepHoldingRow (6.13s)1079=== CONT TestGCMetrics10802026/10/25 17:21:42 INFO Aborted multipart uploads count=0 kept=010812026/10/25 17:21:42 WARN Force mode enabled - objects will be deleted immediately without grace period10822026/10/25 17:21:42 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=010832026/10/25 17:21:42 INFO Vacuumed table table=pending_closures10842026/10/25 17:21:42 INFO Vacuumed table table=pending_objects10852026/10/25 17:21:42 INFO Vacuumed table table=multipart_uploads10862026/10/25 17:21:42 INFO Vacuumed table table=closures10872026/10/25 17:21:42 INFO Vacuumed table table=objects1088--- PASS: TestSweepRechecksPendingAfterLocking (6.02s)1089=== CONT TestRedundantMultipartUpload10902026/10/25 17:21:42 INFO Aborted multipart uploads count=0 kept=010912026/10/25 17:21:42 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/25 17:21:42 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/25 17:21:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10942026/10/25 17:21:42 INFO Vacuumed table table=pending_closures10952026/10/25 17:21:43 INFO Vacuumed table table=pending_objects10962026/10/25 17:21:43 INFO Vacuumed table table=multipart_uploads10972026/10/25 17:21:43 INFO Vacuumed table table=closures10982026/10/25 17:21:43 INFO Vacuumed table table=objects10992026/10/25 17:21:43 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjNmYWVjMWUzLTY4M2MtNDNmNy05MmUxLTFjOWU5NjViN2IzYXgxNzkyOTQ4OTAwMDUwOTU1MDAw parts=1011002026/10/25 17:21:43 INFO Received complete push request method=POST path=/api/pushes/1/complete1101--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.84s)1102=== CONT TestPush_SignsNarinfosOfItsPendingObjects1103--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.17s)1104=== CONT TestPush_RejectsBadRequests11052026/10/25 17:21:43 INFO Completed push id=1 objects=4 duration=45.096833ms1106=== CONT TestGCBugBareHashReferences1107--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.06s)11082026/10/25 17:21:43 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11092026/10/25 17:21:43 INFO Completed upload id=2 objects=2 duration=1.888958ms1110--- PASS: TestMetricsCommit (8.07s)1111=== CONT TestPresignedUploadRegisteredBeforeCommit11122026/10/25 17:21:43 WARN readiness check failed error="closed pool"1113--- PASS: TestService_readinessHandler (5.95s)1114=== CONT TestGCAdvisoryLockBlocksConcurrentRun11152026/10/25 17:21:43 INFO Aborted multipart uploads count=0 kept=011162026/10/25 17:21:43 WARN Force mode enabled - objects will be deleted immediately without grace period11172026/10/25 17:21:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011182026/10/25 17:21:43 INFO Vacuumed table table=pending_closures11192026/10/25 17:21:43 INFO Vacuumed table table=pending_objects11202026/10/25 17:21:43 INFO Vacuumed table table=multipart_uploads11212026/10/25 17:21:43 INFO Vacuumed table table=closures11222026/10/25 17:21:44 INFO Vacuumed table table=objects11232026/10/25 17:21:44 INFO Aborted multipart uploads count=0 kept=011242026/10/25 17:21:44 WARN Force mode enabled - objects will be deleted immediately without grace period11252026/10/25 17:21:44 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=011262026/10/25 17:21:44 INFO Vacuumed table table=pending_closures11272026/10/25 17:21:44 INFO Vacuumed table table=pending_objects11282026/10/25 17:21:44 INFO Vacuumed table table=multipart_uploads11292026/10/25 17:21:44 INFO Vacuumed table table=closures11302026/10/25 17:21:44 INFO Vacuumed table table=objects1131--- PASS: TestSweepSkipsRowsLockedByPush (6.50s)1132=== CONT TestClientMultipleUploads1133=== CONT TestClientIntegration1134--- PASS: TestService_healthCheckHandler (6.06s)11352026/10/25 17:21:44 INFO Received uploads request method=POST path=/api/pending_closures1136--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.53s)1137=== CONT TestLeadIncumbentAnnouncesAtOnce11382026/10/25 17:21:45 INFO Aborted multipart uploads count=0 kept=011392026/10/25 17:21:45 WARN Force mode enabled - objects will be deleted immediately without grace period11402026/10/25 17:21:45 INFO Received uploads request method=POST path=/api/pending_closures11412026/10/25 17:21:45 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=011422026/10/25 17:21:45 INFO Vacuumed table table=pending_closures11432026/10/25 17:21:45 INFO Vacuumed table table=pending_objects11442026/10/25 17:21:45 INFO Vacuumed table table=multipart_uploads11452026/10/25 17:21:45 INFO Vacuumed table table=closures11462026/10/25 17:21:45 INFO Vacuumed table table=objects1147--- PASS: TestGCSweepDeliversEachKeyOnce (6.86s)1148=== CONT TestClientCADerivations11492026/10/25 17:21:45 INFO Aborted multipart uploads count=1 kept=011502026/10/25 17:21:45 INFO Aborted multipart uploads count=0 kept=011512026/10/25 17:21:45 WARN Force mode enabled - objects will be deleted immediately without grace period11522026/10/25 17:21:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11532026/10/25 17:21:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11542026/10/25 17:21:45 INFO Received cleanup request method=DELETE path=/api/pending_closures11552026/10/25 17:21:45 INFO Aborted multipart uploads count=1 kept=01156--- PASS: TestFailedS3DeleteKeepsTombstone (7.14s)1157=== CONT TestLeadElectsOneAndHandsOver1158--- PASS: TestReadProxyInvalidPath (6.70s)1159=== CONT TestClientErrorHandling1160=== RUN TestClientErrorHandling/InvalidStorePath1161=== PAUSE TestClientErrorHandling/InvalidStorePath1162=== RUN TestClientErrorHandling/InvalidAuthToken1163=== PAUSE TestClientErrorHandling/InvalidAuthToken1164=== RUN TestClientErrorHandling/ServerNotAvailable1165=== PAUSE TestClientErrorHandling/ServerNotAvailable1166=== CONT TestConnectSerialisesConcurrentMigrations1167=== CONT TestCacheStatsHandler1168--- PASS: TestPendingCleanupUsesOneCutoff (10.76s)11692026/10/25 17:21:46 INFO Received uploads request method=POST path=/api/pending_closures1170=== CONT TestConnectWaitsForAPeerMigration1171--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.84s)1172--- PASS: TestPresentReportsOnlyClosureRoots (6.87s)1173=== CONT TestService_ReadScope_PublicByDefault11742026/10/25 17:21:46 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/25 17:21:46 INFO Aborted multipart uploads count=0 kept=011762026/10/25 17:21:46 WARN Force mode enabled - objects will be deleted immediately without grace period11772026/10/25 17:21:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011782026/10/25 17:21:46 INFO Vacuumed table table=pending_closures11792026/10/25 17:21:46 INFO Vacuumed table table=pending_objects11802026/10/25 17:21:46 INFO Vacuumed table table=multipart_uploads11812026/10/25 17:21:46 INFO Vacuumed table table=closures11822026/10/25 17:21:46 INFO Vacuumed table table=objects1183--- PASS: TestGCSweepSkipsPendingObjects (6.79s)1184=== CONT TestResolveDBConnectionString1185=== RUN TestResolveDBConnectionString/flag_wins1186=== PAUSE TestResolveDBConnectionString/flag_wins1187=== RUN TestResolveDBConnectionString/file_when_flag_empty1188=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1189=== RUN TestResolveDBConnectionString/missing_file_is_an_error1190=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1191=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1192=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1193=== RUN TestResolveDBConnectionString/nothing_configured1194=== PAUSE TestResolveDBConnectionString/nothing_configured1195=== CONT TestCacheConfigHandler1196=== RUN TestCacheConfigHandler/full_config,_no_issuer1197=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1198=== RUN TestCacheConfigHandler/no_cache_url_configured1199=== PAUSE TestCacheConfigHandler/no_cache_url_configured1200=== RUN TestCacheConfigHandler/no_signing_keys1201=== PAUSE TestCacheConfigHandler/no_signing_keys1202=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1203=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1204=== CONT TestDeleteClosuresRacingPins1205--- PASS: TestPresentRefreshesOnlyStaleClosures (6.40s)1206=== CONT TestService_AuthMiddleware_OIDC12072026/10/25 17:21:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53491/oidc12082026/10/25 17:21:46 INFO Received uploads request method=POST path=/api/pending_closures1209--- PASS: TestDeduplicatedObjectsRecordedAsPending (6.43s)1210=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock12112026-10-25 17:21:47.034 UTC [56208] ERROR: relation "goose_db_version" already exists12122026-10-25 17:21:47.034 UTC [56208] STATEMENT: CREATE TABLE goose_db_version (1213 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1214 version_id bigint NOT NULL,1215 is_applied boolean NOT NULL,1216 tstamp timestamp NOT NULL DEFAULT now()1217 )12182026/10/25 17:21:47 INFO Received uploads request method=POST path=/api/pending_closures12192026/10/25 17:21:47 INFO Received create pin request method=POST path=/api/pins/app12202026/10/25 17:21:47 INFO Aborted multipart uploads count=0 kept=012212026/10/25 17:21:47 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=012222026/10/25 17:21:47 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo12232026/10/25 17:21:47 INFO Received delete pin request method=DELETE path=/api/pins/app12242026/10/25 17:21:47 INFO Vacuumed table table=pending_closures12252026/10/25 17:21:47 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12262026/10/25 17:21:47 INFO Vacuumed table table=pending_objects12272026/10/25 17:21:47 INFO Received delete pin request method=DELETE path=/api/pins/app12282026/10/25 17:21:47 INFO Vacuumed table table=multipart_uploads12292026/10/25 17:21:47 INFO Deleted pin name=app12302026/10/25 17:21:47 INFO Vacuumed table table=closures12312026/10/25 17:21:47 INFO Vacuumed table table=objects12322026/10/25 17:21:47 INFO Aborted multipart uploads count=0 kept=01233--- PASS: TestDeletePinKeepsRowWhenS3Fails (6.41s)12342026/10/25 17:21:47 WARN Force mode enabled - objects will be deleted immediately without grace period1235=== CONT TestService_ReadAuthMiddleware12362026/10/25 17:21:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012372026/10/25 17:21:47 INFO Vacuumed table table=pending_closures12382026/10/25 17:21:47 INFO Vacuumed table table=pending_objects12392026/10/25 17:21:47 INFO Vacuumed table table=multipart_uploads12402026/10/25 17:21:47 INFO Vacuumed table table=closures12412026/10/25 17:21:47 INFO Vacuumed table table=objects1242--- PASS: TestPushDedupSurvivesConcurrentGC (6.94s)1243=== CONT TestClientFallsBackToClosures12442026/10/25 17:21:47 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/25 17:21:47 INFO Received push request method=POST path=/api/pushes1246=== CONT TestService_RequireScope_OIDC1247--- PASS: TestConnectSerialisesConcurrentMigrations (2.25s)12482026/10/25 17:21:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53524/oidc12492026/10/25 17:21:48 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/25 17:21:48 INFO Aborted multipart uploads count=0 kept=012512026/10/25 17:21:48 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/25 17:21:48 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/25 17:21:48 INFO Vacuumed table table=pending_closures12542026/10/25 17:21:48 INFO Vacuumed table table=pending_objects12552026/10/25 17:21:48 INFO Vacuumed table table=multipart_uploads12562026/10/25 17:21:48 INFO Vacuumed table table=closures12572026/10/25 17:21:48 INFO Vacuumed table table=objects12582026/10/25 17:21:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12592026/10/25 17:21:48 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE0MmNmZTk4LWQ3MGUtNDU5Mi1hNmU2LTMxOGUzNDc2NGYzOXgxNzkyOTQ4OTA4MzMwOTc3MDAw1260--- PASS: TestGCMetrics (6.47s)1261=== CONT TestService_AuthMiddleware_MTLSProxyHeader12622026/10/25 17:21:48 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE0MmNmZTk4LWQ3MGUtNDU5Mi1hNmU2LTMxOGUzNDc2NGYzOXgxNzkyOTQ4OTA4MzMwOTc3MDAw error="Delete \"http://localhost:53233/bucket50/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE0MmNmZTk4LWQ3MGUtNDU5Mi1hNmU2LTMxOGUzNDc2NGYzOXgxNzkyOTQ4OTA4MzMwOTc3MDAw\": injected: abort refused"12632026/10/25 17:21:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12642026/10/25 17:21:48 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE0MmNmZTk4LWQ3MGUtNDU5Mi1hNmU2LTMxOGUzNDc2NGYzOXgxNzkyOTQ4OTA4MzMwOTc3MDAw12652026/10/25 17:21:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE0MmNmZTk4LWQ3MGUtNDU5Mi1hNmU2LTMxOGUzNDc2NGYzOXgxNzkyOTQ4OTA4MzMwOTc3MDAw parts=11266--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.84s)1267=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12682026/10/25 17:21:48 INFO Received uploads request method=POST path=/api/pending_closures12692026/10/25 17:21:49 INFO Received uploads request method=POST path=/api/pending_closures12702026/10/25 17:21:49 INFO Received push request method=POST path=/api/pushes1271--- PASS: TestGCBugBareHashReferences (6.46s)1272=== CONT TestClientSharedPathCommittedMidPush12732026/10/25 17:21:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12742026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12752026/10/25 17:21:49 INFO Signed narinfos id=1 count=112762026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12772026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12782026/10/25 17:21:49 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12792026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/10/25 17:21:49 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12812026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12822026/10/25 17:21:49 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112832026/10/25 17:21:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12842026/10/25 17:21:49 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo12852026/10/25 17:21:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1286--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (6.64s)1287=== CONT TestNARDeduplicationMetadataUploadBug12882026/10/25 17:21:49 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmM2MDUyYjU1LTcxNjctNDU2OS05ZDBjLTVkZDJlZTI4NjQwYngxNzkyOTQ4OTA3ODAzODgwMDAw parts=1212892026/10/25 17:21:49 INFO Received uploads request method=POST path=/api/pending_closures12902026/10/25 17:21:49 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmNmMzMzNDM4LTg3M2ItNDNkMy1hZjEzLTFmMzk3ODBhNzYxMXgxNzkyOTQ4OTA4MDEwODg1MDAw parts=101291--- PASS: TestCompletedNarNotReofferedAcrossClosures (8.36s)1292=== CONT TestClientWithDependencies12932026/10/25 17:21:49 INFO Received uploads request method=POST path=/api/pending_closures12942026/10/25 17:21:50 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12952026/10/25 17:21:50 INFO Received uploads request method=POST path=/api/pending_closures1296--- PASS: TestPresignedUploadRegisteredBeforeCommit (6.93s)1297=== CONT TestLeadEndsOnShutdown1298=== RUN TestPush_RejectsBadRequests/root_not_in_objects1299=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1300=== RUN TestPush_RejectsBadRequests/no_roots1301=== PAUSE TestPush_RejectsBadRequests/no_roots1302=== RUN TestPush_RejectsBadRequests/no_objects1303=== PAUSE TestPush_RejectsBadRequests/no_objects1304=== RUN TestPush_RejectsBadRequests/bad_root1305=== PAUSE TestPush_RejectsBadRequests/bad_root1306=== CONT TestPinProtectsFromGC13072026/10/25 17:21:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13082026/10/25 17:21:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjAyOGY2ZGJiLTQxNzktNDFiNS04MWU4LTE1NDlmYmViYjdjZXgxNzkyOTQ4OTA4OTk4OTQwMDAw parts=1213092026/10/25 17:21:51 INFO Received uploads request method=POST path=/api/pending_closures13102026/10/25 17:21:51 INFO Received uploads request method=POST path=/api/pending_closures1311=== NAME TestClientMultipleUploads1312 client_integration_test.go:480: Created store path 0: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientMultipleUploads1774106480/001/store/jvl769bncakyil83irhj9wg6n80bhb2r-test-file-0.txt13132026/10/25 17:21:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1314 client_integration_test.go:480: Created store path 1: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientMultipleUploads1774106480/001/store/23x6hdydgsn6c485qj2pqq08y793jjkp-test-file-1.txt13152026/10/25 17:21:51 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjk0OWEwOTVlLTgwNTUtNDBmZi1hZGIzLTU0MWI4MGU1YThkNXgxNzkyOTQ4OTA4MDA4NTE2MDAw parts=1013162026/10/25 17:21:51 INFO lead: acquired remote=192.0.2.1:123413172026/10/25 17:21:51 INFO lead: released remote=192.0.2.1:12341318 client_integration_test.go:480: Created store path 2: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientMultipleUploads1774106480/001/store/l7z4blxsrl8g8qc8zahlzb52yqwfj2wx-test-file-2.txt1319--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.80s)1320=== CONT TestPush_CompleteWaitsForCleanupOfThePush1321=== NAME TestClientIntegration1322 client_integration_test.go:334: Created store path: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientIntegration4178332991/002/store/2a7d5i0cd29igz6zy1rhvay60hrp2n2h-test-file.txt13232026/10/25 17:21:51 INFO Received push request method=POST path=/api/pushes13242026/10/25 17:21:51 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13252026/10/25 17:21:51 INFO Uploading jvl769bncakyil83irhj9wg6n80bhb2r-test-file-0.txt (160B)13262026/10/25 17:21:51 INFO Uploading 23x6hdydgsn6c485qj2pqq08y793jjkp-test-file-1.txt (160B)13272026/10/25 17:21:51 INFO Uploading l7z4blxsrl8g8qc8zahlzb52yqwfj2wx-test-file-2.txt (160B)13282026/10/25 17:21:51 INFO Received push request method=POST path=/api/pushes13292026/10/25 17:21:51 WARN Failed to register uploaded object key=jvl769bncakyil83irhj9wg6n80bhb2r.ls error="server returned 404: 404 page not found\n"13302026/10/25 17:21:51 WARN Failed to register uploaded object key=23x6hdydgsn6c485qj2pqq08y793jjkp.ls error="server returned 404: 404 page not found\n"13312026/10/25 17:21:51 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13322026/10/25 17:21:52 WARN Failed to register uploaded object key=l7z4blxsrl8g8qc8zahlzb52yqwfj2wx.ls error="server returned 404: 404 page not found\n"13332026/10/25 17:21:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13342026/10/25 17:21:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13352026/10/25 17:21:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13362026/10/25 17:21:52 INFO Signed narinfos id=1 count=313372026/10/25 17:21:52 INFO Uploading 3 narinfos13382026/10/25 17:21:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13392026/10/25 17:21:52 INFO Uploading 2a7d5i0cd29igz6zy1rhvay60hrp2n2h-test-file.txt (152B)13402026/10/25 17:21:52 WARN Failed to register uploaded object key=jvl769bncakyil83irhj9wg6n80bhb2r.narinfo error="server returned 404: 404 page not found\n"13412026/10/25 17:21:52 WARN Failed to register uploaded object key=23x6hdydgsn6c485qj2pqq08y793jjkp.narinfo error="server returned 404: 404 page not found\n"13422026/10/25 17:21:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13432026/10/25 17:21:52 WARN Failed to register uploaded object key=l7z4blxsrl8g8qc8zahlzb52yqwfj2wx.narinfo error="server returned 404: 404 page not found\n"13442026/10/25 17:21:52 WARN Failed to register uploaded object key=2a7d5i0cd29igz6zy1rhvay60hrp2n2h.ls error="server returned 404: 404 page not found\n"13452026/10/25 17:21:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13462026/10/25 17:21:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13472026/10/25 17:21:52 INFO Signed narinfos id=1 count=113482026/10/25 17:21:52 INFO Uploading 1 narinfos13492026/10/25 17:21:52 INFO Completed push id=1 objects=9 duration=42.920458ms13502026/10/25 17:21:52 INFO Upload complete. (441ms)1351=== NAME TestClientMultipleUploads1352 client_integration_test.go:491: Uploaded 3 paths in 505.391834ms13532026/10/25 17:21:52 INFO Received complete push request method=POST path=/api/pushes/1/complete13542026/10/25 17:21:52 WARN Failed to register uploaded object key=2a7d5i0cd29igz6zy1rhvay60hrp2n2h.narinfo error="server returned 404: 404 page not found\n"13552026/10/25 17:21:52 INFO Completed push id=1 objects=3 duration=37.537458ms13562026/10/25 17:21:52 INFO Upload complete. (458ms)13572026/10/25 17:21:52 INFO All 1 paths already cached1358=== NAME TestClientIntegration1359 client_integration_test.go:360: Retrieved narinfo from S3:1360 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientIntegration4178332991/002/store/2a7d5i0cd29igz6zy1rhvay60hrp2n2h-test-file.txt1361 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1362 Compression: zstd1363 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11364 NarSize: 1521365 References: 1366 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11367 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1368 client_integration_test.go:361: Decompressed .ls content (64 bytes):1369 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1370--- PASS: TestClientMultipleUploads (8.28s)1371=== CONT TestChildrenInheritRaisedFileLimit1372=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1373--- PASS: TestChildrenInheritRaisedFileLimit (0.01s)13742026/10/25 17:21:52 INFO Received push request method=POST path=/api/pushes13752026/10/25 17:21:52 INFO Object in database but missing from S3 key=2a7d5i0cd29igz6zy1rhvay60hrp2n2h.ls13762026/10/25 17:21:52 WARN Found objects in DB but missing from S3, will re-upload count=113772026/10/25 17:21:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13782026/10/25 17:21:52 WARN Failed to register uploaded object key=2a7d5i0cd29igz6zy1rhvay60hrp2n2h.ls error="server returned 404: 404 page not found\n"13792026/10/25 17:21:52 INFO Received complete push request method=POST path=/api/pushes/2/complete13802026/10/25 17:21:52 INFO Completed push id=2 objects=3 duration=907.333µs13812026/10/25 17:21:52 INFO Upload complete. (213ms)1382=== NAME TestClientIntegration1383 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1384 client_integration_test.go:389: Decompressed .ls content (49 bytes):1385 {"version":1,"root":{"type":"regular","size":39}}1386--- PASS: TestCacheStatsHandler (6.90s)1387=== CONT TestReadProxyRangeRequest1388=== NAME TestClientCADerivations1389 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientCADerivations3747959151/001/store/p2m5j0c82d3f33abv8d3izv87ypqvnk8-ca-test13902026/10/25 17:21:52 INFO Received push request method=POST path=/api/pushes13912026/10/25 17:21:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13922026/10/25 17:21:52 INFO lead: acquired remote=192.0.2.1:123413932026/10/25 17:21:52 INFO Received complete push request method=POST path=/api/pushes/3/complete13942026/10/25 17:21:52 WARN Failed to register uploaded object key=2a7d5i0cd29igz6zy1rhvay60hrp2n2h.ls error="server returned 404: 404 page not found\n"13952026/10/25 17:21:52 INFO Completed push id=3 objects=3 duration=1.465417ms13962026/10/25 17:21:52 INFO Upload complete. (161ms)1397=== NAME TestClientIntegration1398 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1399 client_integration_test.go:405: Decompressed .ls content (49 bytes):1400 {"version":1,"root":{"type":"regular","size":39}}1401=== NAME TestClientCADerivations1402 client_ca_test.go:139: Found 1 dependencies (including self)1403=== CONT TestPush_RepeatedRootCommitsOnce1404--- PASS: TestConnectWaitsForAPeerMigration (7.14s)14052026/10/25 17:21:53 INFO Received push request method=POST path=/api/pushes14062026/10/25 17:21:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14072026/10/25 17:21:53 INFO Uploading p2m5j0c82d3f33abv8d3izv87ypqvnk8-ca-test (144B)1408--- PASS: TestService_ReadScope_PublicByDefault (7.00s)1409=== CONT TestReadRedirectUsesPublicS3URL14102026/10/25 17:21:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14112026/10/25 17:21:53 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14122026/10/25 17:21:53 WARN Failed to register uploaded object key=p2m5j0c82d3f33abv8d3izv87ypqvnk8.ls error="server returned 404: 404 page not found\n"14132026/10/25 17:21:53 WARN Failed to register uploaded object key=log/77fs0vbjbqb1070ch0iz4l7j0f7rsm96-ca-test.drv error="server returned 404: 404 page not found\n"14142026/10/25 17:21:53 INFO Received push request method=POST path=/api/pushes14152026/10/25 17:21:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14162026/10/25 17:21:53 INFO Signed narinfos id=1 count=114172026/10/25 17:21:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14182026/10/25 17:21:53 INFO Uploading 1 narinfos14192026/10/25 17:21:53 INFO Uploading wss412d0py9mmlxk8b8w8vrflvj815yi-lost-commit.txt (152B)14202026/10/25 17:21:53 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjMzM2VkZGRhLWE4ODYtNDQ5YS1iZDJmLTFiNDhjM2QwNjFhY3gxNzkyOTQ4OTA4MDA5MTU1MDAw parts=1014212026/10/25 17:21:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14222026/10/25 17:21:53 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/25 17:21:53 WARN Failed to register uploaded object key=p2m5j0c82d3f33abv8d3izv87ypqvnk8.narinfo error="server returned 404: 404 page not found\n"14242026/10/25 17:21:53 WARN Failed to register uploaded object key=wss412d0py9mmlxk8b8w8vrflvj815yi.ls error="server returned 404: 404 page not found\n"14252026/10/25 17:21:53 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14262026/10/25 17:21:53 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14272026/10/25 17:21:53 INFO Signed narinfos id=4 count=114282026/10/25 17:21:53 INFO Uploading 1 narinfos14292026/10/25 17:21:53 INFO Completed push id=1 objects=4 duration=44.752208ms14302026/10/25 17:21:53 INFO Upload complete. (487ms)1431=== NAME TestClientCADerivations1432 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientCADerivations3747959151/001/store/p2m5j0c82d3f33abv8d3izv87ypqvnk8-ca-test1433 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1434 Compression: zstd1435 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1436 NarSize: 1441437 References: 1438 Deriver: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientCADerivations3747959151/001/store/77fs0vbjbqb1070ch0iz4l7j0f7rsm96-ca-test.drv1439 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1440 client_ca_test.go:185: Checking for realisation files in S3...14412026/10/25 17:21:53 INFO Received complete push request method=POST path=/api/pushes/4/complete1442 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations14432026/10/25 17:21:53 WARN Failed to register uploaded object key=wss412d0py9mmlxk8b8w8vrflvj815yi.narinfo error="server returned 404: 404 page not found\n"14442026/10/25 17:21:53 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjY0Y2UwMzdhLWU5YzEtNDhkMi05NTRmLWNjYTE2ZjQ5ZmRjZngxNzkyOTQ4OTExMjI0NjE1MDAw error="Get \"http://127.0.0.1:1/bucket52/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1445 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14462026/10/25 17:21:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjliM2ExYjVkLTVkZWUtNDA2Yi1hZjdjLTgwNjgwNDU3YTBjZXgxNzkyOTQ4OTExMTc2Mjk4MDAw parts=1214472026/10/25 17:21:53 INFO Completed push id=4 objects=3 duration=1.08125ms14482026/10/25 17:21:53 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:53565/api/pushes/4/complete\": EOF" url=http://127.0.0.1:53565/api/pushes/4/complete14492026/10/25 17:21:53 INFO Received cleanup request method=DELETE path=/api/pending_closures14502026/10/25 17:21:53 INFO Aborted multipart uploads count=1 kept=01451--- PASS: TestRedundantMultipartUpload (10.97s)1452=== CONT TestPush_CompleteCommitsEveryRoot14532026/10/25 17:21:53 INFO Received complete push request method=POST path=/api/pushes/4/complete14542026-10-25 17:21:53.696 UTC [56194] ERROR: Push does not exist: id=414552026-10-25 17:21:53.696 UTC [56194] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14562026-10-25 17:21:53.696 UTC [56194] STATEMENT: -- name: CommitPush :one1457 SELECT commit_push($1::bigint)::bigint1458 1459=== NAME TestClientCADerivations1460 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket61?endpoint=http://localhost:53233®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientCADerivations3747959151/001/store'1461 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114622026/10/25 17:21:53 WARN Push not found id=414632026/10/25 17:21:53 INFO Upload complete. (441ms)1464=== NAME TestClientIntegration1465 client_integration_test.go:435: Retrieved narinfo from S3:1466 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientIntegration4178332991/002/store/wss412d0py9mmlxk8b8w8vrflvj815yi-lost-commit.txt1467 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1468 Compression: zstd1469 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1470 NarSize: 1521471 References: 1472 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1473 client_integration_test.go:438: Testing garbage collection...14742026/10/25 17:21:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures14752026/10/25 17:21:53 INFO Garbage collection started14762026/10/25 17:21:53 INFO Aborted multipart uploads count=0 kept=014772026/10/25 17:21:53 WARN Force mode enabled - objects will be deleted immediately without grace period1478--- PASS: TestClientCADerivations (8.40s)1479=== CONT TestClientPushesUseOnePush14802026/10/25 17:21:53 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=014812026/10/25 17:21:53 INFO Vacuumed table table=pending_closures1482=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1483=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1484=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1485=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1486=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1487=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1488=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1489=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1490=== CONT TestCompleteMultipartUnregistered14912026/10/25 17:21:54 INFO Vacuumed table table=pending_objects14922026/10/25 17:21:54 INFO Vacuumed table table=multipart_uploads14932026/10/25 17:21:54 INFO Vacuumed table table=closures14942026/10/25 17:21:54 INFO Vacuumed table table=objects14952026/10/25 17:21:54 INFO lead: released remote=192.0.2.1:123414962026/10/25 17:21:54 INFO lead: acquired remote=192.0.2.1:12341497--- PASS: TestService_ReadAuthMiddleware (6.88s)1498=== CONT TestIsValidUploadKey1499=== RUN TestIsValidUploadKey/narinfo1500=== PAUSE TestIsValidUploadKey/narinfo1501=== RUN TestIsValidUploadKey/nar_zst1502=== PAUSE TestIsValidUploadKey/nar_zst1503=== RUN TestIsValidUploadKey/nar_xz1504=== PAUSE TestIsValidUploadKey/nar_xz1505=== RUN TestIsValidUploadKey/nar_plain1506=== PAUSE TestIsValidUploadKey/nar_plain1507=== RUN TestIsValidUploadKey/listing1508=== PAUSE TestIsValidUploadKey/listing1509=== RUN TestIsValidUploadKey/build_log1510=== PAUSE TestIsValidUploadKey/build_log1511=== RUN TestIsValidUploadKey/build_log_home-manager_file1512=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1513=== RUN TestIsValidUploadKey/build_log_plus_in_name1514=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1515=== RUN TestIsValidUploadKey/build_log_question_mark1516=== PAUSE TestIsValidUploadKey/build_log_question_mark1517=== RUN TestIsValidUploadKey/build_log_equals1518=== PAUSE TestIsValidUploadKey/build_log_equals1519=== RUN TestIsValidUploadKey/realisation1520=== PAUSE TestIsValidUploadKey/realisation1521=== RUN TestIsValidUploadKey/realisation_plus_in_output1522=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1523=== RUN TestIsValidUploadKey/nix-cache-info1524=== PAUSE TestIsValidUploadKey/nix-cache-info1525=== RUN TestIsValidUploadKey/index.html1526=== PAUSE TestIsValidUploadKey/index.html1527=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1528=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1529=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1530=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1531=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1532=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1533=== RUN TestIsValidUploadKey/traversal1534=== PAUSE TestIsValidUploadKey/traversal1535=== RUN TestIsValidUploadKey/traversal_nar1536=== PAUSE TestIsValidUploadKey/traversal_nar1537=== RUN TestIsValidUploadKey/absolute1538=== PAUSE TestIsValidUploadKey/absolute1539=== RUN TestIsValidUploadKey/empty_key1540=== PAUSE TestIsValidUploadKey/empty_key1541=== RUN TestIsValidUploadKey/unknown_type1542=== PAUSE TestIsValidUploadKey/unknown_type1543=== CONT TestService_verifyS3Integrity15442026/10/25 17:21:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15452026/10/25 17:21:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE1NGJkNmUyLWY5NmItNGZkYy04NDM4LTM3NWE0OWM2YzhiMngxNzkyOTQ4OTA4MDEwODcyMDAw parts=101546=== RUN TestService_RequireScope_OIDC/builder_may_write1547=== PAUSE TestService_RequireScope_OIDC/builder_may_write1548=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1549=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1550=== RUN TestService_RequireScope_OIDC/ops_may_admin1551=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1552=== RUN TestService_RequireScope_OIDC/ops_may_not_write1553=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1554=== RUN TestService_RequireScope_OIDC/reader_may_not_write1555=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1556=== RUN TestService_RequireScope_OIDC/static_token_may_admin1557=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1558=== RUN TestService_RequireScope_OIDC/static_token_may_write1559=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1560=== RUN TestService_RequireScope_OIDC/reader_may_read1561=== PAUSE TestService_RequireScope_OIDC/reader_may_read1562=== RUN TestService_RequireScope_OIDC/writer_implies_read1563=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1564=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1565=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1566=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1567=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1568=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1569=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1570=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1571=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1572=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1573=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1574=== CONT TestService_createPendingClosureHandler15752026/10/25 17:21:55 INFO lead: released remote=192.0.2.1:12341576--- PASS: TestLeadElectsOneAndHandsOver (9.50s)1577=== CONT TestService_cleanupPendingClosuresHandler1578--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.80s)1579=== CONT TestUploadHandlersRejectOversizedBody15802026/10/25 17:21:55 INFO Received uploads request method=POST path=/api/pending_closures1581=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1582=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1583=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1584=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1585=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1586=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1587=== CONT TestUploadHandlersRejectInvalidKeys1588=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1589=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1590=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1591=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1592=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1593=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1594=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1595=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1596=== CONT TestConcurrentPinUpdatesAgree15972026/10/25 17:21:55 INFO Received uploads request method=POST path=/api/pending_closures15982026/10/25 17:21:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15992026/10/25 17:21:55 INFO Uploading wxgnwa681sgnd3ca7rf5bg6nl3znqkrx-a (256B)16002026/10/25 17:21:55 INFO Uploading ga8c3pb5g38cvhja4aqhipy0pd76lkzs-shared-dep (136B)16012026/10/25 17:21:55 WARN Failed to register uploaded object key=swknqiw69v4ycywpkaqij0kymm8zqaf6.ls error="server returned 404: 404 page not found\n"16022026/10/25 17:21:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16032026/10/25 17:21:55 WARN Failed to register uploaded object key=nar/17a2hv0mv6ydsbh05vr1c6b0vwh5hniwb3ykly5inkg4b0frb7g2.nar.zst error="server returned 404: 404 page not found\n"16042026/10/25 17:21:55 WARN Failed to register uploaded object key=ga8c3pb5g38cvhja4aqhipy0pd76lkzs.ls error="server returned 404: 404 page not found\n"16052026/10/25 17:21:55 WARN Failed to register uploaded object key=wxgnwa681sgnd3ca7rf5bg6nl3znqkrx.ls error="server returned 404: 404 page not found\n"16062026/10/25 17:21:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16072026/10/25 17:21:55 INFO Signed narinfos id=1 count=216082026/10/25 17:21:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16092026/10/25 17:21:55 INFO Signed narinfos id=2 count=216102026/10/25 17:21:55 INFO Uploading 4 narinfos16112026/10/25 17:21:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01612=== NAME TestClientIntegration16132026/10/25 17:21:55 WARN Failed to register uploaded object key=ga8c3pb5g38cvhja4aqhipy0pd76lkzs.narinfo error="server returned 404: 404 page not found\n"1614 client_integration_test.go:445: Objects in database after GC:16152026/10/25 17:21:55 WARN Failed to register uploaded object key=wxgnwa681sgnd3ca7rf5bg6nl3znqkrx.narinfo error="server returned 404: 404 page not found\n"1616 client_integration_test.go:445: Successfully deleted all objects with GC --force16172026/10/25 17:21:55 WARN Failed to register uploaded object key=swknqiw69v4ycywpkaqij0kymm8zqaf6.narinfo error="server returned 404: 404 page not found\n"16182026/10/25 17:21:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16192026/10/25 17:21:55 WARN mTLS auth: bound subjects configured but subject DN unavailable16202026/10/25 17:21:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1621--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.02s)1622=== CONT TestCreatePinRejectsBadInput16232026/10/25 17:21:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16242026/10/25 17:21:55 WARN Failed to register uploaded object key=ga8c3pb5g38cvhja4aqhipy0pd76lkzs.narinfo error="server returned 404: 404 page not found\n"16252026/10/25 17:21:55 INFO Completed upload id=1 objects=6 duration=46.619416ms16262026/10/25 17:21:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16272026/10/25 17:21:55 INFO Completed upload id=2 objects=6 duration=909.25µs16282026/10/25 17:21:55 INFO Upload complete. (547ms)1629=== NAME TestClientFallsBackToClosures1630 client_pushes_test.go:112: Retrieved narinfo from S3:1631 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientFallsBackToClosures2932750277/001/store/ga8c3pb5g38cvhja4aqhipy0pd76lkzs-shared-dep1632 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1633 Compression: zstd1634 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821635 NarSize: 1361636 References: 1637 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1638--- PASS: TestClientIntegration (11.72s)1639=== CONT TestOrphanedObjectsGCStressTest1640=== NAME TestClientFallsBackToClosures1641 client_pushes_test.go:112: Retrieved narinfo from S3:1642 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientFallsBackToClosures2932750277/001/store/wxgnwa681sgnd3ca7rf5bg6nl3znqkrx-a1643 URL: nar/17a2hv0mv6ydsbh05vr1c6b0vwh5hniwb3ykly5inkg4b0frb7g2.nar.zst1644 Compression: zstd1645 NarHash: sha256:17a2hv0mv6ydsbh05vr1c6b0vwh5hniwb3ykly5inkg4b0frb7g21646 NarSize: 2561647 References: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientFallsBackToClosures2932750277/001/store/ga8c3pb5g38cvhja4aqhipy0pd76lkzs-shared-dep1648 CA: text:sha256:1fxpgs0hy8nlif76bvjaxa2dwadd4wh068kambrlnyxq5y2k9dig1649 client_pushes_test.go:112: Retrieved narinfo from S3:1650 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientFallsBackToClosures2932750277/001/store/swknqiw69v4ycywpkaqij0kymm8zqaf6-b1651 URL: nar/17a2hv0mv6ydsbh05vr1c6b0vwh5hniwb3ykly5inkg4b0frb7g2.nar.zst1652 Compression: zstd1653 NarHash: sha256:17a2hv0mv6ydsbh05vr1c6b0vwh5hniwb3ykly5inkg4b0frb7g21654 NarSize: 2561655 References: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientFallsBackToClosures2932750277/001/store/ga8c3pb5g38cvhja4aqhipy0pd76lkzs-shared-dep1656 CA: text:sha256:1fxpgs0hy8nlif76bvjaxa2dwadd4wh068kambrlnyxq5y2k9dig1657--- PASS: TestClientFallsBackToClosures (8.39s)1658=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16592026/10/25 17:21:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16602026/10/25 17:21:56 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjkxYTk4NTczLTBkZDktNDBkNC05ZjQ2LWQwM2QzNDgyMGEzY3gxNzkyOTQ4OTA4MDEwOTM5MDAw parts=101661=== NAME TestNARDeduplicationMetadataUploadBug1662 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestNARDeduplicationMetadataUploadBug1464090572/001/store/zrmg90nx0nw3pnks9a4wpsn507h6yd18-file1.txt16632026/10/25 17:21:56 INFO Received push request method=POST path=/api/pushes16642026/10/25 17:21:56 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16652026/10/25 17:21:56 INFO Uploading nrmdgwv8v0crwbv29v8lgk34xrgp32ci-top (264B)16662026/10/25 17:21:56 INFO Uploading 7pwlcvjbm5j02d3q7g8w8lbpij4kz1cp-shared-dep (136B)16672026/10/25 17:21:56 WARN Failed to register uploaded object key=nrmdgwv8v0crwbv29v8lgk34xrgp32ci.ls error="server returned 404: 404 page not found\n"16682026/10/25 17:21:56 INFO Received push request method=POST path=/api/pushes16692026/10/25 17:21:56 WARN Failed to register uploaded object key=7pwlcvjbm5j02d3q7g8w8lbpij4kz1cp.ls error="server returned 404: 404 page not found\n"16702026/10/25 17:21:57 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16712026/10/25 17:21:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16722026/10/25 17:21:57 WARN Failed to register uploaded object key=nar/1nrx5lzii7b2aqrbdaq6rl16jzrhfyrdl1xgr3ma7q048kndd7f0.nar.zst error="server returned 404: 404 page not found\n"16732026/10/25 17:21:57 INFO Signed narinfos id=1 count=216742026/10/25 17:21:57 INFO Uploading 2 narinfos16752026/10/25 17:21:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16762026/10/25 17:21:57 INFO Uploading zrmg90nx0nw3pnks9a4wpsn507h6yd18-file1.txt (160B)1677--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.05s)1678=== CONT TestOrphanedObjectsGC16792026/10/25 17:21:57 WARN Failed to register uploaded object key=nrmdgwv8v0crwbv29v8lgk34xrgp32ci.narinfo error="server returned 404: 404 page not found\n"16802026/10/25 17:21:57 INFO Received complete push request method=POST path=/api/pushes/1/complete16812026/10/25 17:21:57 WARN Failed to register uploaded object key=7pwlcvjbm5j02d3q7g8w8lbpij4kz1cp.narinfo error="server returned 404: 404 page not found\n"16822026/10/25 17:21:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16832026/10/25 17:21:57 WARN Failed to register uploaded object key=zrmg90nx0nw3pnks9a4wpsn507h6yd18.ls error="server returned 404: 404 page not found\n"16842026/10/25 17:21:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16852026/10/25 17:21:57 INFO Signed narinfos id=1 count=116862026/10/25 17:21:57 INFO Uploading 1 narinfos16872026/10/25 17:21:57 INFO Completed push id=1 objects=6 duration=75.505708ms16882026/10/25 17:21:57 INFO Upload complete. (466ms)1689=== NAME TestClientSharedPathCommittedMidPush1690 client_integration_test.go:816: Retrieved narinfo from S3:1691 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientSharedPathCommittedMidPush2341633282/001/store/7pwlcvjbm5j02d3q7g8w8lbpij4kz1cp-shared-dep1692 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1693 Compression: zstd1694 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821695 NarSize: 1361696 References: 1697 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16982026/10/25 17:21:57 INFO Received complete push request method=POST path=/api/pushes/1/complete1699 client_integration_test.go:816: Retrieved narinfo from S3:1700 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientSharedPathCommittedMidPush2341633282/001/store/nrmdgwv8v0crwbv29v8lgk34xrgp32ci-top1701 URL: nar/1nrx5lzii7b2aqrbdaq6rl16jzrhfyrdl1xgr3ma7q048kndd7f0.nar.zst1702 Compression: zstd17032026/10/25 17:21:57 WARN Failed to register uploaded object key=zrmg90nx0nw3pnks9a4wpsn507h6yd18.narinfo error="server returned 404: 404 page not found\n"1704 NarHash: sha256:1nrx5lzii7b2aqrbdaq6rl16jzrhfyrdl1xgr3ma7q048kndd7f01705 NarSize: 2641706 References: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientSharedPathCommittedMidPush2341633282/001/store/7pwlcvjbm5j02d3q7g8w8lbpij4kz1cp-shared-dep1707 CA: text:sha256:0sv0nr9zdsg6p66nw9rnqrd9aj1hm1fvpvl9cwgncsy585mz736017082026/10/25 17:21:57 INFO Completed push id=1 objects=3 duration=33.210958ms17092026/10/25 17:21:57 INFO Upload complete. (373ms)1710=== NAME TestNARDeduplicationMetadataUploadBug1711 metadata_upload_test.go:54: Retrieved narinfo from S3:1712 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestNARDeduplicationMetadataUploadBug1464090572/001/store/zrmg90nx0nw3pnks9a4wpsn507h6yd18-file1.txt1713 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1714 Compression: zstd1715 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1716 NarSize: 1601717 References: 1718 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1719 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1720 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1721 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17222026/10/25 17:21:57 INFO lead: acquired remote=192.0.2.1:12341723--- PASS: TestClientSharedPathCommittedMidPush (7.79s)1724=== CONT TestProxyWriteTimeout1725=== RUN TestProxyWriteTimeout/narinfo1726=== PAUSE TestProxyWriteTimeout/narinfo1727=== RUN TestProxyWriteTimeout/1_GiB_nar1728=== PAUSE TestProxyWriteTimeout/1_GiB_nar1729=== RUN TestProxyWriteTimeout/10_GiB_nar1730=== PAUSE TestProxyWriteTimeout/10_GiB_nar1731=== RUN TestProxyWriteTimeout/unknown_size1732=== PAUSE TestProxyWriteTimeout/unknown_size1733=== CONT TestPendingClosureWriteTimeout1734=== RUN TestPendingClosureWriteTimeout/empty1735=== PAUSE TestPendingClosureWriteTimeout/empty1736=== RUN TestPendingClosureWriteTimeout/400_objects1737=== PAUSE TestPendingClosureWriteTimeout/400_objects1738=== RUN TestPendingClosureWriteTimeout/670k_objects1739=== PAUSE TestPendingClosureWriteTimeout/670k_objects1740=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1741=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1742=== CONT TestService_Rustfstest1743=== NAME TestNARDeduplicationMetadataUploadBug1744 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestNARDeduplicationMetadataUploadBug1464090572/001/store/gi30isz34mrfd6rzil04pr1c7cfymvhy-file2.txt17452026/10/25 17:21:57 INFO Received push request method=POST path=/api/pushes17462026/10/25 17:21:57 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17472026/10/25 17:21:57 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"17482026/10/25 17:21:57 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17492026/10/25 17:21:57 WARN Failed to register uploaded object key=gi30isz34mrfd6rzil04pr1c7cfymvhy.ls error="server returned 404: 404 page not found\n"17502026/10/25 17:21:57 INFO Signed narinfos id=2 count=117512026/10/25 17:21:57 INFO Uploading 1 narinfos1752=== NAME TestClientWithDependencies1753 client_integration_test.go:735: Built derivation: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientWithDependencies2717802884/001/store/vn8iz145vwmbvns6n0457glj44p6v597-test-script1754--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (14.36s)1755=== CONT TestParseSize1756--- PASS: TestParseSize (0.00s)1757=== CONT TestReadRedirectNar17582026/10/25 17:21:57 INFO Received complete push request method=POST path=/api/pushes/2/complete17592026/10/25 17:21:57 WARN Failed to register uploaded object key=gi30isz34mrfd6rzil04pr1c7cfymvhy.narinfo error="server returned 404: 404 page not found\n"17602026/10/25 17:21:57 INFO Completed push id=2 objects=3 duration=3.066709ms17612026/10/25 17:21:57 INFO Upload complete. (284ms)1762=== NAME TestClientWithDependencies1763 client_integration_test.go:737: Found 1 dependencies (including self)1764=== NAME TestNARDeduplicationMetadataUploadBug1765 metadata_upload_test.go:76: Retrieved narinfo from S3:1766 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestNARDeduplicationMetadataUploadBug1464090572/001/store/gi30isz34mrfd6rzil04pr1c7cfymvhy-file2.txt1767 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1768 Compression: zstd1769 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1770 NarSize: 1601771 References: 1772 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1773 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1774 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1775 {"version":1,"root":{"type":"regular","size":44}}17762026/10/25 17:21:57 INFO Received push request method=POST path=/api/pushes1777--- PASS: TestNARDeduplicationMetadataUploadBug (8.20s)1778=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true17792026/10/25 17:21:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17802026/10/25 17:21:57 INFO Uploading vn8iz145vwmbvns6n0457glj44p6v597-test-script (136B)17812026/10/25 17:21:58 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17822026/10/25 17:21:58 WARN Failed to register uploaded object key=log/7znarwl3svfzl13kmwwddxa8pgfhz2rj-test-script.drv error="server returned 404: 404 page not found\n"17832026/10/25 17:21:58 WARN Failed to register uploaded object key=vn8iz145vwmbvns6n0457glj44p6v597.ls error="server returned 404: 404 page not found\n"17842026/10/25 17:21:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17852026/10/25 17:21:58 INFO Signed narinfos id=1 count=117862026/10/25 17:21:58 INFO Uploading 1 narinfos17872026/10/25 17:21:58 INFO Received complete push request method=POST path=/api/pushes/1/complete17882026/10/25 17:21:58 WARN Failed to register uploaded object key=vn8iz145vwmbvns6n0457glj44p6v597.narinfo error="server returned 404: 404 page not found\n"17892026/10/25 17:21:58 INFO Completed push id=1 objects=4 duration=42.857375ms17902026/10/25 17:21:58 INFO Upload complete. (370ms)17912026/10/25 17:21:58 INFO Aborted multipart uploads count=0 kept=017922026/10/25 17:21:58 WARN Force mode enabled - objects will be deleted immediately without grace period17932026/10/25 17:21:58 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=017942026/10/25 17:21:58 INFO Vacuumed table table=pending_closures17952026/10/25 17:21:58 INFO Vacuumed table table=pending_objects17962026/10/25 17:21:58 INFO Vacuumed table table=multipart_uploads17972026/10/25 17:21:58 INFO Vacuumed table table=closures17982026/10/25 17:21:58 INFO Vacuumed table table=objects17992026/10/25 17:21:58 INFO lead: released remote=192.0.2.1:12341800=== NAME TestClientWithDependencies1801 client_integration_test.go:753: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientWithDependencies2717802884/001/store) requires matching store prefix18022026/10/25 17:21:58 INFO Received push request method=POST path=/api/pushes1803--- PASS: TestLeadEndsOnShutdown (8.32s)1804=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1805--- PASS: TestClientWithDependencies (8.67s)1806=== CONT TestIsValidCachePath/narinfo1807=== CONT TestIsValidCachePath/nix-cache-info1808=== CONT TestIsValidCachePath/short_hash1809=== CONT TestIsValidCachePath/wrong_extension1810=== CONT TestIsValidCachePath/leading_slash1811=== CONT TestIsValidCachePath/empty1812=== CONT TestIsValidCachePath/invalid_char_u1813=== CONT TestIsValidCachePath/invalid_char_e1814=== CONT TestIsValidCachePath/traversal_in_middle1815=== CONT TestIsValidCachePath/random_path1816=== CONT TestIsValidCachePath/traversal_parent1817=== CONT TestIsValidCachePath/nar_bz21818=== CONT TestIsValidCachePath/realisation1819=== CONT TestIsValidCachePath/index.html1820=== CONT TestIsValidCachePath/log1821=== CONT TestIsValidCachePath/ls1822=== CONT TestIsValidCachePath/nar_xz1823=== CONT TestIsValidCachePath/nar_uncompressed1824=== CONT TestIsValidCachePath/nar_zst1825=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1826--- PASS: TestIsValidCachePath (0.01s)1827 --- PASS: TestIsValidCachePath/narinfo (0.00s)1828 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1829 --- PASS: TestIsValidCachePath/short_hash (0.00s)1830 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1831 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1832 --- PASS: TestIsValidCachePath/empty (0.00s)1833 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1834 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1835 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1836 --- PASS: TestIsValidCachePath/random_path (0.00s)1837 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1838 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1839 --- PASS: TestIsValidCachePath/realisation (0.00s)1840 --- PASS: TestIsValidCachePath/index.html (0.00s)1841 --- PASS: TestIsValidCachePath/log (0.00s)1842 --- PASS: TestIsValidCachePath/ls (0.00s)1843 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1844 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1845 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1846 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1847=== CONT TestGCEndsOnShutdown/before_the_run1848=== NAME TestPinProtectsFromGC18492026/10/25 17:21:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1850 client_integration_test.go:867: Pinned store path: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestPinProtectsFromGC1841678359/001/store/p3qc9r3c23dkva7d3mw2afc3kv4pxn5b-pinned-file.txt1851 client_integration_test.go:868: Unpinned store path: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestPinProtectsFromGC1841678359/001/store/0siqh2if05qpk5cnk5r6c0fww7nlx9p5-unpinned-file.txt18522026/10/25 17:21:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmU0NTdjN2JlLTI5MWUtNDJlYy1hNWU2LWE0ZWQ4Njg2ODZlMngxNzkyOTQ4OTA4MDA5MTU0MDAw parts=1018532026/10/25 17:21:58 INFO Received push request method=POST path=/api/pushes18542026/10/25 17:21:58 INFO Received push request method=POST path=/api/pushes18552026/10/25 17:21:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18562026/10/25 17:21:58 INFO Uploading p3qc9r3c23dkva7d3mw2afc3kv4pxn5b-pinned-file.txt (128B)18572026/10/25 17:21:58 WARN Failed to register uploaded object key=p3qc9r3c23dkva7d3mw2afc3kv4pxn5b.ls error="server returned 404: 404 page not found\n"18582026/10/25 17:21:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"18592026/10/25 17:21:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18602026/10/25 17:21:58 INFO Signed narinfos id=1 count=118612026/10/25 17:21:58 INFO Uploading 1 narinfos18622026/10/25 17:21:58 INFO Received complete push request method=POST path=/api/pushes/1/complete18632026/10/25 17:21:58 WARN Failed to register uploaded object key=p3qc9r3c23dkva7d3mw2afc3kv4pxn5b.narinfo error="server returned 404: 404 page not found\n"18642026-10-25 17:21:58.993 UTC [56226] ERROR: could not obtain lock on row in relation "closures"18652026-10-25 17:21:58.993 UTC [56226] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18662026-10-25 17:21:58.997 UTC [56226] ERROR: could not obtain lock on row in relation "closures"18672026-10-25 17:21:58.997 UTC [56226] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18682026-10-25 17:21:58.999 UTC [56226] ERROR: could not obtain lock on row in relation "closures"18692026-10-25 17:21:58.999 UTC [56226] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18702026-10-25 17:21:59.002 UTC [56226] ERROR: could not obtain lock on row in relation "closures"18712026-10-25 17:21:59.002 UTC [56226] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18722026-10-25 17:21:59.003 UTC [56226] ERROR: could not obtain lock on row in relation "closures"18732026-10-25 17:21:59.003 UTC [56226] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18742026/10/25 17:21:59 INFO Completed push id=1 objects=3 duration=25.519833ms18752026/10/25 17:21:59 INFO Upload complete. (364ms)1876--- PASS: TestDeleteClosuresRacingPins (12.32s)1877=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1878--- PASS: TestPush_RootsAreLockedInByteOrder (17.77s)1879=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18802026/10/25 17:21:59 INFO Received push request method=POST path=/api/pushes18812026/10/25 17:21:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18822026/10/25 17:21:59 INFO Uploading 0siqh2if05qpk5cnk5r6c0fww7nlx9p5-unpinned-file.txt (128B)18832026/10/25 17:21:59 WARN Failed to register uploaded object key=0siqh2if05qpk5cnk5r6c0fww7nlx9p5.ls error="server returned 404: 404 page not found\n"18842026/10/25 17:21:59 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18852026/10/25 17:21:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18862026/10/25 17:21:59 INFO Signed narinfos id=2 count=118872026/10/25 17:21:59 INFO Uploading 1 narinfos1888--- PASS: TestReadProxyRangeRequest (6.56s)1889=== CONT TestServerTLSConfig/not_a_PEM_file1890=== CONT TestServerTLSConfig/missing_CA_file18912026/10/25 17:21:59 INFO Received complete push request method=POST path=/api/pushes/2/complete1892=== CONT TestServerTLSConfig/no_client_CA18932026/10/25 17:21:59 WARN Failed to register uploaded object key=0siqh2if05qpk5cnk5r6c0fww7nlx9p5.narinfo error="server returned 404: 404 page not found\n"1894=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18952026/10/25 17:21:59 INFO Completed push id=2 objects=3 duration=1.178209ms1896--- PASS: TestServerTLSConfig (0.01s)1897 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1898 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1899 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)19002026/10/25 17:21:59 INFO Upload complete. (259ms)19012026/10/25 17:21:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures19022026/10/25 17:21:59 INFO Garbage collection started19032026/10/25 17:21:59 INFO Aborted multipart uploads count=0 kept=019042026/10/25 17:21:59 WARN Force mode enabled - objects will be deleted immediately without grace period19052026/10/25 17:21:59 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=019062026/10/25 17:21:59 INFO Received push request method=POST path=/api/pushes19072026/10/25 17:21:59 INFO Vacuumed table table=pending_closures19082026/10/25 17:21:59 INFO Vacuumed table table=pending_objects19092026/10/25 17:21:59 INFO Vacuumed table table=multipart_uploads19102026/10/25 17:21:59 INFO Vacuumed table table=closures19112026/10/25 17:21:59 INFO Vacuumed table table=objects1912--- PASS: TestReadRedirectUsesPublicS3URL (6.83s)1913=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19142026/10/25 17:22:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19152026/10/25 17:22:00 INFO Received push request method=POST path=/api/pushes19162026/10/25 17:22:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmY0YTlkNDU2LTczNjQtNDIxNi05NmRmLTczNGViNTRhMTBhY3gxNzkyOTQ4OTE4NDc2MjQzMDAw parts=1019172026/10/25 17:22:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19182026-10-25 17:22:01.006 UTC [56486] ERROR: Push does not exist: id=119192026-10-25 17:22:01.006 UTC [56486] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19202026-10-25 17:22:01.006 UTC [56486] STATEMENT: SELECT commit_push($1)1921--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.34s)1922=== CONT TestParseSingleRange/malformed_both_empty1923=== CONT TestParseSingleRange/start_far_past_EOF1924=== CONT TestParseSingleRange/start_past_EOF1925=== CONT TestParseSingleRange/single_byte1926=== CONT TestParseSingleRange/suffix_exceeds_size1927=== CONT TestParseSingleRange/suffix1928=== CONT TestParseSingleRange/malformed_end_before_start1929=== CONT TestParseSingleRange/end_clamped_to_size1930=== CONT TestParseSingleRange/open-ended1931=== CONT TestParseSingleRange/closed1932=== CONT TestParseSingleRange/multi-range_ignored1933=== CONT TestParseSingleRange/malformed_no_dash1934=== CONT TestParseSingleRange/unknown_unit1935=== CONT TestParseSingleRange/none1936=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1937--- PASS: TestParseSingleRange (0.00s)1938 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1939 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1940 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1941 --- PASS: TestParseSingleRange/single_byte (0.00s)1942 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1943 --- PASS: TestParseSingleRange/suffix (0.00s)1944 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1945 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1946 --- PASS: TestParseSingleRange/open-ended (0.00s)1947 --- PASS: TestParseSingleRange/closed (0.00s)1948 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1949 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1950 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1951 --- PASS: TestParseSingleRange/none (0.00s)19522026/10/25 17:22:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjc0NmRmYmI5LTFmOGEtNDAxZC04ZDc4LTlhMmYwODUzZDM4NngxNzkyOTQ4OTE4ODA4NDUxMDAw parts=1019532026/10/25 17:22:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019542026/10/25 17:22:01 INFO Received create pin request method=POST path=/api/pins/myapp19552026/10/25 17:22:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19562026/10/25 17:22:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1957--- PASS: TestCompleteMultipartUnregistered (7.66s)1958=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19592026/10/25 17:22:01 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestPinProtectsFromGC1841678359/001/store/p3qc9r3c23dkva7d3mw2afc3kv4pxn5b-pinned-file.txt narinfo_key=p3qc9r3c23dkva7d3mw2afc3kv4pxn5b.narinfo19602026/10/25 17:22:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures19612026/10/25 17:22:01 INFO Garbage collection started19622026/10/25 17:22:01 INFO Aborted multipart uploads count=0 kept=019632026/10/25 17:22:01 WARN Force mode enabled - objects will be deleted immediately without grace period19642026/10/25 17:22: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=019652026/10/25 17:22:01 INFO Vacuumed table table=pending_closures19662026/10/25 17:22:01 INFO Vacuumed table table=pending_objects19672026/10/25 17:22:01 INFO Vacuumed table table=multipart_uploads19682026/10/25 17:22:01 INFO Vacuumed table table=closures19692026/10/25 17:22:01 INFO Vacuumed table table=objects19702026/10/25 17:22:02 INFO Received uploads request method=POST path=/api/pending_closures19712026/10/25 17:22:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19722026/10/25 17:22:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjcxZmQzNWZlLTczMTItNDI0Yi05NGE3LTIzOTE4MGZhOGU4NngxNzkyOTQ4OTE5Njk3Nzc1MDAw parts=1019732026/10/25 17:22:02 INFO Received push request method=POST path=/api/pushes19742026/10/25 17:22:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19752026/10/25 17:22:02 INFO Uploading z612xy7ixkj50zjp1i88fcy7a05fqk1v-b (256B)19762026/10/25 17:22:02 INFO Uploading wbbngy1jh5nlzhq4ak6qdl8h8vnb6590-shared-dep (136B)19772026/10/25 17:22:02 WARN Failed to register uploaded object key=2p4hc15z3m41xirbgwdg0wf1bz0081ss.ls error="server returned 404: 404 page not found\n"19782026/10/25 17:22:02 WARN Failed to register uploaded object key=wbbngy1jh5nlzhq4ak6qdl8h8vnb6590.ls error="server returned 404: 404 page not found\n"19792026/10/25 17:22:02 WARN Failed to register uploaded object key=z612xy7ixkj50zjp1i88fcy7a05fqk1v.ls error="server returned 404: 404 page not found\n"19802026/10/25 17:22:02 WARN Failed to register uploaded object key=nar/0ysyp9grfrnfrbaz5ry183qbnqvslcn0vbpz90pk3g7s919fbhg5.nar.zst error="server returned 404: 404 page not found\n"19812026/10/25 17:22:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19822026/10/25 17:22:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19832026/10/25 17:22:02 INFO Received uploads request method=POST path=/api/pending_closures19842026/10/25 17:22:02 INFO Signed narinfos id=1 count=319852026/10/25 17:22:02 INFO Received uploads request method=POST path=/api/pending_closures19862026/10/25 17:22:02 INFO Received uploads request method=POST path=/api/pending_closures19872026/10/25 17:22:02 INFO Uploading 3 narinfos19882026/10/25 17:22:02 WARN Failed to register uploaded object key=2p4hc15z3m41xirbgwdg0wf1bz0081ss.narinfo error="server returned 404: 404 page not found\n"19892026/10/25 17:22:02 INFO Received complete push request method=POST path=/api/pushes/1/complete19902026/10/25 17:22:02 WARN Failed to register uploaded object key=wbbngy1jh5nlzhq4ak6qdl8h8vnb6590.narinfo error="server returned 404: 404 page not found\n"19912026/10/25 17:22:02 WARN Failed to register uploaded object key=z612xy7ixkj50zjp1i88fcy7a05fqk1v.narinfo error="server returned 404: 404 page not found\n"19922026/10/25 17:22:02 INFO Completed push id=1 objects=8 duration=100.873209ms19932026/10/25 17:22:02 INFO Upload complete. (638ms)1994=== NAME TestClientPushesUseOnePush1995 client_pushes_test.go:97: Retrieved narinfo from S3:1996 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientPushesUseOnePush3246570198/001/store/wbbngy1jh5nlzhq4ak6qdl8h8vnb6590-shared-dep1997 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1998 Compression: zstd1999 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822000 NarSize: 1362001 References: 2002 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2003 client_pushes_test.go:97: Retrieved narinfo from S3:2004 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientPushesUseOnePush3246570198/001/store/2p4hc15z3m41xirbgwdg0wf1bz0081ss-a2005 URL: nar/0ysyp9grfrnfrbaz5ry183qbnqvslcn0vbpz90pk3g7s919fbhg5.nar.zst2006 Compression: zstd2007 NarHash: sha256:0ysyp9grfrnfrbaz5ry183qbnqvslcn0vbpz90pk3g7s919fbhg52008 NarSize: 2562009 References: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientPushesUseOnePush3246570198/001/store/wbbngy1jh5nlzhq4ak6qdl8h8vnb6590-shared-dep2010 CA: text:sha256:1vgs3jicvdwf56q04qnmh1vwy7bxavyqbfg25fmwj18wyx3c2qjc2011 client_pushes_test.go:97: Retrieved narinfo from S3:2012 StorePath: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientPushesUseOnePush3246570198/001/store/z612xy7ixkj50zjp1i88fcy7a05fqk1v-b2013 URL: nar/0ysyp9grfrnfrbaz5ry183qbnqvslcn0vbpz90pk3g7s919fbhg5.nar.zst2014 Compression: zstd2015 NarHash: sha256:0ysyp9grfrnfrbaz5ry183qbnqvslcn0vbpz90pk3g7s919fbhg52016 NarSize: 2562017 References: /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestClientPushesUseOnePush3246570198/001/store/wbbngy1jh5nlzhq4ak6qdl8h8vnb6590-shared-dep2018 CA: text:sha256:1vgs3jicvdwf56q04qnmh1vwy7bxavyqbfg25fmwj18wyx3c2qjc2019--- PASS: TestClientPushesUseOnePush (9.34s)2020=== CONT TestClientErrorHandling/InvalidStorePath20212026/10/25 17:22:03 INFO Received cleanup request method=DELETE path=/api/pending_closures20222026/10/25 17:22:03 INFO Aborted multipart uploads count=0 kept=020232026/10/25 17:22:03 INFO Received uploads request method=POST path=/api/pending_closures20242026/10/25 17:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20252026/10/25 17:22:03 INFO Received cleanup request method=DELETE path=/api/pending_closures20262026/10/25 17:22:03 INFO Aborted multipart uploads count=1 kept=020272026/10/25 17:22:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20282026-10-25 17:22:03.486 UTC [56441] ERROR: Closure does not exist: id=120292026-10-25 17:22:03.486 UTC [56441] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE20302026-10-25 17:22:03.486 UTC [56441] STATEMENT: -- name: CommitPendingClosure :one2031 SELECT commit_pending_closure($1::bigint)::bigint2032 2033--- PASS: TestService_cleanupPendingClosuresHandler (8.27s)2034=== CONT TestClientErrorHandling/ServerNotAvailable20352026/10/25 17:22:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjFjZDMyMWQwLTc2ZTItNGYxMi1hZDM3LTQ5NTc5MTNiOTFiZHgxNzkyOTQ4OTIwNTU2MjM3MDAw parts=102036=== NAME TestPinProtectsFromGC2037 client_integration_test.go:976: Pin successfully protected closure from garbage collection20382026/10/25 17:22:03 INFO Received create pin request method=POST path=/api/pins/app20392026/10/25 17:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2040--- PASS: TestPinProtectsFromGC (13.34s)2041=== CONT TestClientErrorHandling/InvalidAuthToken20422026/10/25 17:22:04 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmM2NWU4NGI0LTg2ZTEtNDYwMi05MTY4LTU5Yjc5YTYwOGYyM3gxNzkyOTQ4OTE4ODA5NzI3MDAw parts=1020432026/10/25 17:22:04 INFO Received complete push request method=POST path=/api/pushes/1/complete20442026/10/25 17:22:04 INFO Received create pin request method=POST path=/api/pins/app20452026/10/25 17:22:04 INFO Completed push id=1 objects=4 duration=26.8745ms20462026/10/25 17:22:04 INFO Received push request method=POST path=/api/pushes20472026-10-25 17:22:04.292 UTC [55748] LOG: checkpoint starting: wal20482026/10/25 17:22:04 INFO Aborted multipart uploads count=0 kept=020492026/10/25 17:22:04 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20502026/10/25 17:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period20512026/10/25 17:22:04 WARN Request failed, retrying attempt=2 backoff=206.69858ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20522026/10/25 17:22:04 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo20532026/10/25 17:22:04 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=020542026/10/25 17:22:04 WARN Request failed, retrying attempt=3 backoff=436.619487ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20552026/10/25 17:22:04 INFO Vacuumed table table=pending_closures20562026/10/25 17:22:04 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo2057--- PASS: TestConcurrentPinUpdatesAgree (9.13s)2058=== CONT TestResolveDBConnectionString/file_when_flag_empty2059=== CONT TestResolveDBConnectionString/missing_file_is_an_error2060=== CONT TestResolveDBConnectionString/nothing_configured2061=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2062=== CONT TestResolveDBConnectionString/flag_wins2063=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2064=== CONT TestCacheConfigHandler/no_cache_url_configured2065=== CONT TestCacheConfigHandler/no_signing_keys20662026/10/25 17:22:04 INFO Vacuumed table table=pending_objects2067=== CONT TestCacheConfigHandler/full_config,_no_issuer2068--- PASS: TestResolveDBConnectionString (0.02s)2069 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2070 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2071 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2072 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2073 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2074=== CONT TestPush_RejectsBadRequests/root_not_in_objects2075--- PASS: TestCacheConfigHandler (0.00s)2076 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2077 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2078 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2079 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)20802026/10/25 17:22:04 INFO Received push request method=POST path=/api/pushes2081=== CONT TestPush_RejectsBadRequests/no_roots20822026/10/25 17:22:04 INFO Received push request method=POST path=/api/pushes2083=== CONT TestPush_RejectsBadRequests/no_objects20842026/10/25 17:22:04 INFO Received push request method=POST path=/api/pushes2085=== CONT TestPush_RejectsBadRequests/bad_root20862026/10/25 17:22:04 INFO Received push request method=POST path=/api/pushes20872026/10/25 17:22:04 INFO Vacuumed table table=multipart_uploads2088=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2089=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20902026/10/25 17:22:04 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2091=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20922026/10/25 17:22:04 WARN Authentication failed token_preview=eyJhbGciOi...J-U1EXcJPA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2093=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2094=== CONT TestIsValidUploadKey/narinfo2095=== CONT TestIsValidUploadKey/realisation_plus_in_output2096=== CONT TestIsValidUploadKey/realisation2097=== CONT TestIsValidUploadKey/build_log_question_mark2098=== CONT TestIsValidUploadKey/unknown_type2099=== CONT TestIsValidUploadKey/build_log_equals2100=== CONT TestIsValidUploadKey/absolute2101=== CONT TestIsValidUploadKey/build_log_home-manager_file2102=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2103=== CONT TestIsValidUploadKey/build_log_plus_in_name21042026/10/25 17:22:04 INFO Vacuumed table table=closures2105=== CONT TestIsValidUploadKey/index.html2106=== CONT TestIsValidUploadKey/build_log2107--- PASS: TestPush_RejectsBadRequests (7.62s)2108 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.01s)2109 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2110 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)2111 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)2112=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2113=== CONT TestIsValidUploadKey/traversal_nar2114=== CONT TestIsValidUploadKey/nix-cache-info2115=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2116=== CONT TestIsValidUploadKey/nar_zst2117=== CONT TestIsValidUploadKey/listing2118=== CONT TestIsValidUploadKey/nar_plain2119=== CONT TestIsValidUploadKey/traversal2120=== CONT TestIsValidUploadKey/nar_xz2121=== CONT TestIsValidUploadKey/empty_key2122--- PASS: TestIsValidUploadKey (0.03s)2123 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2124 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2125 --- PASS: TestIsValidUploadKey/realisation (0.00s)2126 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2127 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2128 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2129 --- PASS: TestIsValidUploadKey/absolute (0.00s)2130 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2131 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2132 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2133 --- PASS: TestIsValidUploadKey/index.html (0.00s)2134 --- PASS: TestIsValidUploadKey/build_log (0.00s)2135 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2136 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2137 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2138 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2139 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2140 --- PASS: TestIsValidUploadKey/listing (0.00s)2141 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2142 --- PASS: TestIsValidUploadKey/traversal (0.00s)2143 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2144 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2145--- PASS: TestService_AuthMiddleware_OIDC (7.37s)2146 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2147 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2148 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2149 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2150=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2151=== CONT TestService_RequireScope_OIDC/static_token_may_write21522026/10/25 17:22:05 INFO Vacuumed table table=objects2153=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2154=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2155=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2156=== CONT TestService_RequireScope_OIDC/writer_implies_read2157=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21582026/10/25 17:22:05 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2159=== CONT TestService_RequireScope_OIDC/reader_may_not_write2160=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read21612026/10/25 17:22:05 WARN Request failed, retrying attempt=4 backoff=803.389678ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2162=== CONT TestService_RequireScope_OIDC/reader_may_read2163=== CONT TestService_RequireScope_OIDC/ops_may_not_write2164=== CONT TestService_RequireScope_OIDC/static_token_may_admin21652026/10/25 17:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2166=== CONT TestService_RequireScope_OIDC/ops_may_admin2167=== CONT TestService_RequireScope_OIDC/builder_may_write2168=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21692026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21702026/10/25 17:22:05 INFO Received complete multipart upload request method=POST path=/21712026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21722026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21732026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21742026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21752026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21762026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21772026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21782026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy21792026/10/25 17:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2180--- PASS: TestService_RequireScope_OIDC (7.19s)2181 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2182 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2183 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2184 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2185 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2186 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2187 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.01s)2188 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2189 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2190 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2191 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2192 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2193 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2194 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)21952026/10/25 17:22:05 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjc5MWE5Y2YwLWQxNzgtNDZiMy05MTE3LTI0OWQyZGExNzNiM3gxNzkyOTQ4OTIyMTkwMDU1MDAw parts=1021962026/10/25 17:22:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21972026/10/25 17:22:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmQwN2Y2OGQ2LTA4NzQtNDY3ZS1hM2YyLTJhZjlhYTk2ZmM2NHgxNzkyOTQ4OTE5Njk4MjczMDAw parts=1021982026/10/25 17:22:05 INFO Received complete push request method=POST path=/api/pushes/1/complete21992026/10/25 17:22:05 INFO Completed upload id=1 objects=2 duration=45.173166ms22002026/10/25 17:22:05 INFO Completed push id=1 objects=4 duration=41.242125ms22012026/10/25 17:22:05 INFO Received uploads request method=POST path=/api/pending_closures22022026/10/25 17:22:05 INFO Received uploads request method=POST path=/api/pending_closures2203--- PASS: TestPush_RepeatedRootCommitsOnce (12.26s)22042026/10/25 17:22:05 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22052026/10/25 17:22:05 WARN Found objects in DB but missing from S3, will re-upload count=12206=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22072026/10/25 17:22:05 INFO Received request for more parts method=POST path=/22082026/10/25 17:22:05 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete22092026/10/25 17:22:05 INFO Completed upload id=3 objects=2 duration=1.149792ms2210=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22112026/10/25 17:22:05 INFO Received uploads request method=POST path=/2212--- PASS: TestService_verifyS3Integrity (11.03s)2213=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal22142026/10/25 17:22:05 INFO Received uploads request method=POST path=/2215=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22162026/10/25 17:22:05 INFO Received complete multipart upload request method=POST path=/2217=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22182026/10/25 17:22:05 INFO Received request for more parts method=POST path=/2219=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22202026/10/25 17:22:05 INFO Received uploads request method=POST path=/2221=== CONT TestProxyWriteTimeout/narinfo2222--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2223 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2224 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)2225 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.01s)2226 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)2227=== CONT TestProxyWriteTimeout/unknown_size2228=== CONT TestProxyWriteTimeout/10_GiB_nar2229=== CONT TestProxyWriteTimeout/1_GiB_nar2230--- PASS: TestProxyWriteTimeout (0.00s)2231 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2232 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2233 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2234 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2235=== CONT TestPendingClosureWriteTimeout/empty2236=== CONT TestPendingClosureWriteTimeout/400_objects2237=== CONT TestPendingClosureWriteTimeout/670k_objects2238=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline22392026/10/25 17:22:05 INFO Received create pin request method=POST path=/api/pins/deploy22402026/10/25 17:22:05 INFO Received uploads request method=POST path=/api/pending_closures22412026/10/25 17:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22422026/10/25 17:22:05 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo2243--- PASS: TestCreatePinRejectsBadInput (9.98s)22442026/10/25 17:22:05 WARN Request failed, retrying attempt=5 backoff=1.638695032s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22452026/10/25 17:22:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmE2MzNhYzM4LTBjNGItNDczNS1hY2JjLWU4NDY4ZjJmNWUyZHgxNzkyOTQ4OTIyNzYyMDgyMDAw parts=1022462026/10/25 17:22:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22472026/10/25 17:22:05 INFO Completed upload id=1 objects=2 duration=20.208625ms22482026/10/25 17:22:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000022492026/10/25 17:22:05 INFO Received uploads request method=POST path=/api/pending_closures22502026/10/25 17:22:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures22512026/10/25 17:22:06 INFO Aborted multipart uploads count=0 kept=022522026/10/25 17:22:06 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=022532026/10/25 17:22:06 INFO Vacuumed table table=pending_closures22542026/10/25 17:22:06 INFO Vacuumed table table=pending_objects22552026/10/25 17:22:06 INFO Vacuumed table table=multipart_uploads22562026/10/25 17:22:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22572026/10/25 17:22:06 INFO Vacuumed table table=closures22582026/10/25 17:22:06 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjRhNGFlMTcyLThlMDQtNGYyMS04MzgwLWI2YjkwNzQ3NDVjYngxNzkyOTQ4OTIwNTU2MjE0MDAw parts=1022592026/10/25 17:22:06 INFO Vacuumed table table=objects22602026/10/25 17:22:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22612026/10/25 17:22:06 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002262--- PASS: TestService_createPendingClosureHandler (11.35s)2263--- PASS: TestReadRedirectNar (9.13s)2264--- PASS: TestService_Rustfstest (10.07s)22652026/10/25 17:22:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22662026/10/25 17:22:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22672026/10/25 17:22:07 WARN Request failed, retrying attempt=2 backoff=219.307131ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/10/25 17:22:07 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjc1MWM3NWNlLThlNTAtNDA3NS05NGFkLTNhYmZhZjkwODAwYXgxNzkyOTQ4OTI0MTM1NDg0MDAw parts=1022692026/10/25 17:22:07 INFO Received complete push request method=POST path=/api/pushes/2/complete22702026/10/25 17:22:07 INFO Completed push id=2 objects=4 duration=2.547417ms2271--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (15.41s)22722026/10/25 17:22:07 INFO Received uploads request method=POST path=/api/pending_closures2273=== NAME TestOrphanedObjectsGC2274 orphaned_objects_gc_test.go:287: GC Test Summary:2275 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2276 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2277 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2278 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2279 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2280--- PASS: TestOrphanedObjectsGC (10.94s)22812026/10/25 17:22:08 WARN Request failed, retrying attempt=3 backoff=407.300584ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22822026/10/25 17:22:08 INFO Received uploads request method=POST path=/api/pending_closures22832026/10/25 17:22:08 WARN Request failed, retrying attempt=4 backoff=876.138488ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22842026/10/25 17:22:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22852026/10/25 17:22:08 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLmMwMzU3YTlhLWFmNjctNDA0NS1hMWZjLWFhMzM4YWMzM2FkOHgxNzkyOTQ4OTI3OTk2NTA2MDAw error="Access Denied"22862026/10/25 17:22:08 WARN keeping failed pending closure for cleanup to retry the abort id=122872026/10/25 17:22:08 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGJkMjUyMmQtYzRkYS00ODI4LWE5NzctM2ZkNWUxYTM1NmIwLjI1ZmRmMWMxLTlhOTItNGUxNC1iODNlLWQzNDBjZjUxOTY2ZXgxNzkyOTQ4OTIwNTU1Njk0MDAw parts=1022882026/10/25 17:22:08 INFO Received complete push request method=POST path=/api/pushes/1/complete22892026/10/25 17:22:08 INFO Completed push id=1 objects=6 duration=6.036917ms2290--- PASS: TestPush_CompleteCommitsEveryRoot (14.98s)2291--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2292 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (10.62s)2293 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (10.54s)22942026/10/25 17:22:09 INFO Aborted multipart uploads count=0 kept=022952026/10/25 17:22:09 WARN Force mode enabled - objects will be deleted immediately without grace period22962026/10/25 17:22:09 WARN Request failed, retrying attempt=5 backoff=1.658968565s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22972026/10/25 17:22:09 INFO Aborted multipart uploads count=0 kept=022982026/10/25 17:22:09 WARN Force mode enabled - objects will be deleted immediately without grace period22992026/10/25 17:22:09 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53233/bucket101/?delete=\": context canceled"2300--- PASS: TestGCEndsOnShutdown (0.01s)2301 --- PASS: TestGCEndsOnShutdown/before_the_run (10.27s)2302 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (10.17s)2303 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (10.53s)23042026/10/25 17:22:09 INFO Received uploads request method=POST path=/api/pending_closures23052026/10/25 17:22:09 INFO Aborted multipart uploads count=0 kept=023062026/10/25 17:22:09 WARN Force mode enabled - objects will be deleted immediately without grace period23072026/10/25 17:22:09 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=023082026/10/25 17:22:09 INFO Vacuumed table table=pending_closures23092026/10/25 17:22:09 INFO Vacuumed table table=pending_objects23102026/10/25 17:22:09 INFO Vacuumed table table=multipart_uploads23112026/10/25 17:22:09 INFO Vacuumed table table=closures23122026/10/25 17:22:09 INFO Vacuumed table table=objects23132026/10/25 17:22:09 WARN Rate limiter enabled after throttle name=s3-test rate=523142026/10/25 17:22:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2315=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2316 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102317 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002318--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.88s)23192026/10/25 17:22:10 INFO Received uploads request method=POST path=/api/pending_closures23202026/10/25 17:22:10 INFO Aborted multipart uploads count=0 kept=023212026/10/25 17:22:10 WARN Force mode enabled - objects will be deleted immediately without grace period23222026/10/25 17:22:10 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=023232026/10/25 17:22:10 INFO Vacuumed table table=pending_closures23242026/10/25 17:22:10 INFO Vacuumed table table=pending_objects23252026/10/25 17:22:10 INFO Vacuumed table table=multipart_uploads23262026/10/25 17:22:10 INFO Vacuumed table table=closures23272026/10/25 17:22:10 INFO Vacuumed table table=objects2328--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2329 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (10.80s)2330 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (10.26s)23312026/10/25 17:22:10 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"23322026/10/25 17:22:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23332026/10/25 17:22:11 WARN Request failed, retrying attempt=2 backoff=217.420867ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23342026/10/25 17:22:11 WARN Request failed, retrying attempt=3 backoff=437.993086ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2335--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2336 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (9.32s)2337 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (10.14s)23382026/10/25 17:22:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23392026/10/25 17:22:11 WARN Request failed, retrying attempt=4 backoff=822.224138ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23402026/10/25 17:22:11 INFO Received uploads request method=POST path=/api/pending_closures23412026/10/25 17:22:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23422026/10/25 17:22:12 WARN Request failed, retrying attempt=5 backoff=1.677974966s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2343--- PASS: TestPendingClosureWriteTimeout (0.00s)2344 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2345 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2346 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2347 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.92s)2348--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)2349 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.42s)2350 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.39s)2351 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.62s)23522026/10/25 17:22:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23532026/10/25 17:22:14 WARN Request failed, retrying attempt=2 backoff=217.980525ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23542026/10/25 17:22:14 WARN Request failed, retrying attempt=3 backoff=368.131366ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23552026/10/25 17:22:14 WARN Request failed, retrying attempt=4 backoff=790.865743ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2356=== NAME TestOrphanedObjectsGCStressTest2357 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2358 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23592026/10/25 17:22:15 WARN Request failed, retrying attempt=5 backoff=1.526642944s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2360 orphaned_objects_gc_test.go:503: Stress test completed successfully:2361 orphaned_objects_gc_test.go:504: - Active objects preserved: 202362 orphaned_objects_gc_test.go:505: - Objects deleted: 2102363 orphaned_objects_gc_test.go:506: - Total GC'd: 2102364--- PASS: TestOrphanedObjectsGCStressTest (20.03s)2365--- PASS: TestClientErrorHandling (0.01s)2366 --- PASS: TestClientErrorHandling/InvalidStorePath (8.03s)2367 --- PASS: TestClientErrorHandling/InvalidAuthToken (7.95s)2368 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.73s)2369PASS2370{"timestamp":"2026-10-25T17:22:17.299506Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53604","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}23712026-10-25 17:22:17.530 UTC [55743] LOG: received smart shutdown request23722026-10-25 17:22:17.533 UTC [55743] LOG: background worker "logical replication launcher" (PID 55753) exited with exit code 123732026-10-25 17:22:19.289 UTC [55748] LOG: checkpoint complete: wrote 7478 buffers (45.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.429 s, sync=1.391 s, total=14.997 s; sync files=37077, longest=0.011 s, average=0.001 s; distance=533105 kB, estimate=533105 kB; lsn=0/233C7EB0, redo lsn=0/220294E023742026-10-25 17:22:19.290 UTC [55748] LOG: shutting down23752026-10-25 17:22:19.291 UTC [55748] LOG: checkpoint starting: shutdown immediate23762026-10-25 17:22:19.488 UTC [55748] LOG: checkpoint complete: wrote 3644 buffers (22.2%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.156 s, sync=0.039 s, total=0.198 s; sync files=1201, longest=0.001 s, average=0.001 s; distance=20090 kB, estimate=481803 kB; lsn=0/233C7F28, redo lsn=0/233C7F2823772026-10-25 17:22:19.503 UTC [55743] LOG: database system is shut down2378Running OIDC tests...2379=== RUN TestAudienceForIssuer2380=== PAUSE TestAudienceForIssuer2381=== RUN TestHTTPClientForHasTimeouts2382=== PAUSE TestHTTPClientForHasTimeouts2383=== RUN TestGlobMatch2384=== PAUSE TestGlobMatch2385=== RUN TestValidateToken_ValidToken2386=== PAUSE TestValidateToken_ValidToken2387=== RUN TestValidateToken_WrongAudience2388=== PAUSE TestValidateToken_WrongAudience2389=== RUN TestValidateToken_Expired2390=== PAUSE TestValidateToken_Expired2391=== RUN TestValidateToken_BoundClaimsMismatch2392=== PAUSE TestValidateToken_BoundClaimsMismatch2393=== RUN TestValidateToken_BoundSubjectMismatch2394=== PAUSE TestValidateToken_BoundSubjectMismatch2395=== RUN TestValidateToken_MultipleProviders2396=== PAUSE TestValidateToken_MultipleProviders2397=== RUN TestValidateToken_NoMatchingProvider2398=== PAUSE TestValidateToken_NoMatchingProvider2399=== RUN TestValidateToken_KubernetesServiceAccount2400=== PAUSE TestValidateToken_KubernetesServiceAccount2401=== RUN TestNewValidator_KubernetesRequiresCA2402=== PAUSE TestNewValidator_KubernetesRequiresCA2403=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2404=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2405=== RUN TestPins_ReservedForMatchingRule2406=== PAUSE TestPins_ReservedForMatchingRule2407=== RUN TestPins_TopLevelShorthand2408=== PAUSE TestPins_TopLevelShorthand2409=== RUN TestPins_ConfigValidation2410=== PAUSE TestPins_ConfigValidation2411=== RUN TestScopes_LegacyProviderDefaultsToWrite2412=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2413=== RUN TestScopes_Rules2414=== PAUSE TestScopes_Rules2415=== RUN TestScopes_ConfigValidation2416=== PAUSE TestScopes_ConfigValidation2417=== CONT TestValidateToken_ValidToken2418=== CONT TestValidateToken_NoMatchingProvider2419=== CONT TestScopes_ConfigValidation2420=== CONT TestScopes_LegacyProviderDefaultsToWrite2421=== CONT TestPins_ConfigValidation2422=== CONT TestScopes_Rules2423=== CONT TestPins_ReservedForMatchingRule2424--- PASS: TestScopes_ConfigValidation (0.00s)2425=== CONT TestPins_TopLevelShorthand2426=== CONT TestNewValidator_KubernetesRequiresCA2427=== CONT TestValidateToken_KubernetesServiceAccount2428=== CONT TestValidateToken_Expired2429=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2430=== CONT TestValidateToken_MultipleProviders2431=== CONT TestValidateToken_BoundSubjectMismatch2432=== CONT TestValidateToken_BoundClaimsMismatch2433=== CONT TestGlobMatch2434=== RUN TestGlobMatch/foo_foo2435=== PAUSE TestGlobMatch/foo_foo2436=== CONT TestValidateToken_WrongAudience2437=== RUN TestGlobMatch/foo_bar2438=== PAUSE TestGlobMatch/foo_bar2439=== RUN TestGlobMatch/*_2440=== PAUSE TestGlobMatch/*_2441=== RUN TestGlobMatch/*_anything2442=== PAUSE TestGlobMatch/*_anything2443=== RUN TestGlobMatch/foo*_foo2444=== PAUSE TestGlobMatch/foo*_foo2445=== RUN TestGlobMatch/foo*_foobar2446=== PAUSE TestGlobMatch/foo*_foobar2447=== RUN TestGlobMatch/foo*_bar2448=== PAUSE TestGlobMatch/foo*_bar2449=== RUN TestGlobMatch/*bar_bar2450=== PAUSE TestGlobMatch/*bar_bar2451=== RUN TestGlobMatch/*bar_foobar2452=== PAUSE TestGlobMatch/*bar_foobar2453=== RUN TestGlobMatch/*bar_foo2454=== PAUSE TestGlobMatch/*bar_foo2455=== RUN TestGlobMatch/foo*bar_foobar2456=== PAUSE TestGlobMatch/foo*bar_foobar2457=== RUN TestGlobMatch/foo*bar_foo123bar2458=== PAUSE TestGlobMatch/foo*bar_foo123bar2459=== RUN TestGlobMatch/foo*bar_foobarbaz2460=== PAUSE TestGlobMatch/foo*bar_foobarbaz2461=== RUN TestGlobMatch/*/*_foo/bar2462=== PAUSE TestGlobMatch/*/*_foo/bar2463=== RUN TestGlobMatch/*/*_foo2464=== PAUSE TestGlobMatch/*/*_foo2465=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2466=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2467=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02468=== CONT TestHTTPClientForHasTimeouts2469=== CONT TestAudienceForIssuer2470--- PASS: TestPins_ConfigValidation (0.01s)2471=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02472--- PASS: TestAudienceForIssuer (0.00s)2473=== RUN TestGlobMatch/refs/*/main_refs/heads/main2474=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2475=== RUN TestGlobMatch/fo?_foo2476=== PAUSE TestGlobMatch/fo?_foo2477=== RUN TestGlobMatch/fo?_fo2478=== PAUSE TestGlobMatch/fo?_fo2479=== RUN TestGlobMatch/fo?_fooo2480=== PAUSE TestGlobMatch/fo?_fooo2481=== RUN TestGlobMatch/?oo_foo2482=== PAUSE TestGlobMatch/?oo_foo2483=== RUN TestGlobMatch/?oo_boo2484=== PAUSE TestGlobMatch/?oo_boo2485=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2486=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2487=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2488=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2489=== CONT TestGlobMatch/foo_bar2490=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2491=== CONT TestGlobMatch/?oo_boo2492=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2493=== CONT TestGlobMatch/?oo_foo2494=== CONT TestGlobMatch/fo?_fooo2495=== CONT TestGlobMatch/fo?_foo2496=== CONT TestGlobMatch/fo?_fo2497=== CONT TestGlobMatch/refs/*/main_refs/heads/main2498=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2499=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02500=== CONT TestGlobMatch/*/*_foo2501=== CONT TestGlobMatch/*/*_foo/bar2502=== CONT TestGlobMatch/foo*bar_foo123bar2503=== CONT TestGlobMatch/foo*bar_foobarbaz2504=== CONT TestGlobMatch/*bar_foo2505=== CONT TestGlobMatch/*bar_foobar2506=== CONT TestGlobMatch/*bar_bar2507=== CONT TestGlobMatch/foo*bar_foobar2508=== CONT TestGlobMatch/foo*_foobar2509=== CONT TestGlobMatch/foo*_foo2510=== CONT TestGlobMatch/*_anything2511=== CONT TestGlobMatch/foo*_bar2512=== CONT TestGlobMatch/*_2513=== CONT TestGlobMatch/foo_foo2514--- PASS: TestGlobMatch (0.01s)2515 --- PASS: TestGlobMatch/foo_bar (0.00s)2516 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2517 --- PASS: TestGlobMatch/?oo_boo (0.00s)2518 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2519 --- PASS: TestGlobMatch/?oo_foo (0.00s)2520 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2521 --- PASS: TestGlobMatch/fo?_foo (0.00s)2522 --- PASS: TestGlobMatch/fo?_fo (0.00s)2523 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2524 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2525 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2526 --- PASS: TestGlobMatch/*/*_foo (0.00s)2527 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2528 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2529 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2530 --- PASS: TestGlobMatch/*bar_foo (0.00s)2531 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2532 --- PASS: TestGlobMatch/*bar_bar (0.00s)2533 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2534 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2535 --- PASS: TestGlobMatch/foo*_foo (0.00s)2536 --- PASS: TestGlobMatch/*_anything (0.00s)2537 --- PASS: TestGlobMatch/foo*_bar (0.00s)2538 --- PASS: TestGlobMatch/*_ (0.00s)2539 --- PASS: TestGlobMatch/foo_foo (0.00s)25402026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54036/oidc25412026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54039/oidc2542--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.13s)25432026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54042/oidc25442026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54041/oidc25452026/10/25 17:22:23 http: TLS handshake error from 127.0.0.1:54038: remote error: tls: bad certificate2546--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2547--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)2548--- PASS: TestValidateToken_WrongAudience (0.16s)2549--- PASS: TestPins_TopLevelShorthand (0.18s)2550--- PASS: TestHTTPClientForHasTimeouts (0.22s)25512026/10/25 17:22:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54034/oidc2552--- PASS: TestValidateToken_NoMatchingProvider (0.29s)25532026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54049/oidc2554--- PASS: TestPins_ReservedForMatchingRule (0.35s)25552026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54051/oidc25562026/10/25 17:22:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5404825572026/10/25 17:22:23 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232558--- PASS: TestScopes_Rules (0.39s)2559--- PASS: TestValidateToken_KubernetesServiceAccount (0.40s)2560--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.40s)25612026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54056/oidc2562--- PASS: TestValidateToken_ValidToken (0.47s)25632026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54058/oidc25642026/10/25 17:22:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54047/oidc25652026/10/25 17:22:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54059/oidc2566--- PASS: TestValidateToken_Expired (0.47s)2567--- PASS: TestValidateToken_MultipleProviders (0.47s)25682026/10/25 17:22:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54063/oidc2569--- PASS: TestValidateToken_BoundClaimsMismatch (0.56s)2570PASS2571Running hook tests...2572=== RUN TestSendPathsEmpty2573=== PAUSE TestSendPathsEmpty2574=== RUN TestQueueEnqueueAndFetch2575=== PAUSE TestQueueEnqueueAndFetch2576=== RUN TestQueueDeduplication2577=== PAUSE TestQueueDeduplication2578=== RUN TestQueueRemove2579=== PAUSE TestQueueRemove2580=== RUN TestQueueFetchBatchLimit2581=== PAUSE TestQueueFetchBatchLimit2582=== RUN TestQueueRetryMovesToBack2583=== PAUSE TestQueueRetryMovesToBack2584=== RUN TestQueueFetchRemoveLifecycle2585=== PAUSE TestQueueFetchRemoveLifecycle2586=== RUN TestQueueConcurrentWriters2587=== PAUSE TestQueueConcurrentWriters2588=== RUN TestQueueEnqueueWaitsOutSlowWriter2589=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2590=== RUN TestQueueRemoveLargeClosure2591=== PAUSE TestQueueRemoveLargeClosure2592=== RUN TestServerClientIntegration2593--- PASS: TestServerClientIntegration (0.00s)2594=== RUN TestServerQueueError25952026/10/25 17:22:25 ERROR Failed to queue paths error="permission denied" count=12596--- PASS: TestServerQueueError (0.00s)2597=== RUN TestServerRefusesOversizedAndNonStoreRequests2598=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2599=== RUN TestGetListenerSocketActivation2600 server_test.go:256: systemd socket activation does not exist on darwin2601--- SKIP: TestGetListenerSocketActivation (0.00s)2602=== RUN TestServerStalledClientDoesNotBlockShutdown2603=== PAUSE TestServerStalledClientDoesNotBlockShutdown2604=== RUN TestServerBacksOffOnAcceptErrors2605=== PAUSE TestServerBacksOffOnAcceptErrors2606=== RUN TestDrainIsolatesPoisonPath2607=== PAUSE TestDrainIsolatesPoisonPath2608=== RUN TestRunNotBlockedByPoisonHead2609=== PAUSE TestRunNotBlockedByPoisonHead2610=== RUN TestDrainGivesUpWhenServerDown2611=== PAUSE TestDrainGivesUpWhenServerDown2612=== RUN TestFailedPathPrunedByLaterClosure2613=== PAUSE TestFailedPathPrunedByLaterClosure2614=== RUN TestWorkerUploadsAndRemoves2615=== PAUSE TestWorkerUploadsAndRemoves2616=== RUN TestWorkerSkipsGCdPaths2617=== PAUSE TestWorkerSkipsGCdPaths2618=== RUN TestWorkerPrunesClosureDeps2619=== PAUSE TestWorkerPrunesClosureDeps2620=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2621=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2622=== RUN TestDrainTimeout2623=== PAUSE TestDrainTimeout2624=== RUN TestDrainTimeoutDuringIsolation2625=== PAUSE TestDrainTimeoutDuringIsolation2626=== RUN TestShutdownFinishesInFlightPush2627=== PAUSE TestShutdownFinishesInFlightPush2628=== RUN TestWorkerRemoveFailureIsNotProgress2629=== PAUSE TestWorkerRemoveFailureIsNotProgress2630=== RUN TestWorkerKeepsPathItCannotStat2631=== PAUSE TestWorkerKeepsPathItCannotStat2632=== CONT TestSendPathsEmpty2633=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2634=== CONT TestQueueDeduplication2635--- PASS: TestSendPathsEmpty (0.00s)2636=== CONT TestDrainGivesUpWhenServerDown2637=== CONT TestQueueEnqueueWaitsOutSlowWriter2638=== CONT TestWorkerKeepsPathItCannotStat2639=== CONT TestWorkerRemoveFailureIsNotProgress2640=== CONT TestDrainTimeoutDuringIsolation2641=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2642=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2643=== CONT TestShutdownFinishesInFlightPush2644=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2645=== RUN TestShutdownFinishesInFlightPush/completes2646=== PAUSE TestShutdownFinishesInFlightPush/completes2647=== CONT TestServerBacksOffOnAcceptErrors2648=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2649=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2650=== CONT TestQueueRemoveLargeClosure2651=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26522026/10/25 17:22:25 ERROR Accept failed error="too many open files"2653=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2654=== CONT TestServerRefusesOversizedAndNonStoreRequests2655=== CONT TestServerStalledClientDoesNotBlockShutdown26562026/10/25 17:22:25 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2657=== CONT TestQueueFetchRemoveLifecycle2658=== CONT TestQueueConcurrentWriters26592026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store store=/nix/store2660=== CONT TestQueueRetryMovesToBack2661=== CONT TestQueueEnqueueAndFetch26622026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2663=== CONT TestRunNotBlockedByPoisonHead2664=== CONT TestWorkerPrunesClosureDeps2665=== CONT TestQueueFetchBatchLimit2666=== CONT TestFailedPathPrunedByLaterClosure2667=== CONT TestQueueRemove2668=== CONT TestWorkerUploadsAndRemoves2669=== CONT TestWorkerSkipsGCdPaths2670=== CONT TestDrainIsolatesPoisonPath26712026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2672=== CONT TestDrainTimeout2673=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2674=== CONT TestShutdownFinishesInFlightPush/completes2675=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2676=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2677=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2678=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2679=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26802026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26812026/10/25 17:22:25 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26822026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26832026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26842026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26852026/10/25 17:22:25 ERROR Accept failed error="too many open files"26862026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26872026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26882026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26892026/10/25 17:22:25 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26902026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26912026/10/25 17:22:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26922026/10/25 17:22:25 ERROR Failed to decode request error="unexpected EOF"2693--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2694=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26952026/10/25 17:22:25 ERROR Accept failed error="too many open files"26962026/10/25 17:22:25 INFO Upload queue status pending=226972026/10/25 17:22:25 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa error="lstat /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa: permission denied"26982026/10/25 17:22:25 INFO Uploading batch count=226992026/10/25 17:22:25 INFO Upload queue status pending=227002026/10/25 17:22:25 INFO Uploading batch count=427012026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=427022026/10/25 17:22:25 INFO Uploading batch count=127032026/10/25 17:22:25 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa error="lstat /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa: permission denied"27042026/10/25 17:22:25 INFO Upload queue status pending=227052026/10/25 17:22:25 INFO Upload queue status pending=327062026/10/25 17:22:25 INFO Uploading batch count=227072026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainIsolatesPoisonPath3073264044/002/bbb27082026/10/25 17:22:25 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa error="lstat /private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerKeepsPathItCannotStat2423485532/002/locked/aaa: permission denied"27092026/10/25 17:22:25 INFO Uploading batch count=127102026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=127112026/10/25 17:22:25 INFO Upload queue status pending=227122026/10/25 17:22:25 ERROR Accept failed error="too many open files"2713--- PASS: TestQueueRemove (0.03s)2714=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27152026/10/25 17:22:25 INFO Uploading batch count=227162026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=227172026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/a27182026/10/25 17:22:25 INFO Uploading batch count=227192026/10/25 17:22:25 INFO Uploading batch count=227202026/10/25 17:22:25 INFO Upload queue status pending=327212026/10/25 17:22:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerSkipsGCdPaths161745291/002/nonexistent27222026/10/25 17:22:25 INFO Upload queue status pending=227232026/10/25 17:22:25 INFO Uploading batch count=227242026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/b27252026/10/25 17:22:25 INFO Uploading batch count=227262026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=127272026/10/25 17:22:25 INFO Uploading batch count=127282026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=127292026/10/25 17:22:25 INFO Uploading batch count=427302026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=427312026/10/25 17:22:25 INFO Uploading batch count=127322026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=127332026/10/25 17:22:25 INFO Uploading batch count=227342026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=22735=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2736=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27372026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/c2738--- PASS: TestQueueEnqueueAndFetch (0.04s)2739--- PASS: TestQueueDeduplication (0.04s)27402026/10/25 17:22:25 INFO Uploading batch count=127412026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=127422026/10/25 17:22:25 INFO Uploading batch count=12743--- PASS: TestQueueFetchBatchLimit (0.04s)2744=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2745--- PASS: TestQueueFetchRemoveLifecycle (0.04s)27462026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/d2747--- PASS: TestQueueRetryMovesToBack (0.04s)2748--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)27492026/10/25 17:22:25 INFO Uploading batch count=227502026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=227512026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/e27522026/10/25 17:22:25 INFO Uploading batch count=127532026/10/25 17:22:25 INFO Uploading batch count=127542026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=127552026/10/25 17:22:25 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestDrainGivesUpWhenServerDown3990530653/002/f27562026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=127572026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=102758--- PASS: TestWorkerUploadsAndRemoves (0.05s)2759--- PASS: TestFailedPathPrunedByLaterClosure (0.05s)2760--- PASS: TestDrainIsolatesPoisonPath (0.05s)27612026/10/25 17:22:25 INFO Uploading batch count=427622026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=42763--- PASS: TestDrainGivesUpWhenServerDown (0.05s)2764--- PASS: TestWorkerPrunesClosureDeps (0.06s)2765--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.06s)27662026/10/25 17:22:25 INFO Uploading batch count=227672026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=227682026/10/25 17:22:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerRemoveFailureIsNotProgresscollected_path3798280819/001/nonexistent27692026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12770--- PASS: TestWorkerSkipsGCdPaths (0.06s)27712026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127722026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127732026/10/25 17:22:25 INFO Uploading batch count=227742026/10/25 17:22:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerRemoveFailureIsNotProgresscollected_path3798280819/001/nonexistent27752026/10/25 17:22:25 INFO Uploading batch count=227762026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227772026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=227782026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127792026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127802026/10/25 17:22:25 INFO Uploading batch count=227812026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127822026/10/25 17:22:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/b4969cc7c947cd0c/build/TestWorkerRemoveFailureIsNotProgresscollected_path3798280819/001/nonexistent27832026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227842026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127852026/10/25 17:22:25 INFO Uploading batch count=227862026/10/25 17:22:25 ERROR Upload failed error="upload failed" count=227872026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=127882026/10/25 17:22:25 INFO Uploading batch count=227892026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227902026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127912026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=227922026/10/25 17:22:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127932026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=22794--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2795 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.02s)2796 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.03s)2797 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.03s)27982026/10/25 17:22:25 ERROR Accept failed error="too many open files"27992026/10/25 17:22:25 ERROR Accept failed error="too many open files"28002026/10/25 17:22:25 ERROR Failed to decode request error="read unix /private/var/tb/8/scratch/b4969cc7c947cd0c/build/hook2803823674/test.sock->: i/o timeout"28012026/10/25 17:22:25 ERROR Failed to write response error="write unix /private/var/tb/8/scratch/b4969cc7c947cd0c/build/hook2803823674/test.sock->: i/o timeout"2802--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28032026/10/25 17:22:25 ERROR Upload failed error="context canceled" count=228042026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=228052026/10/25 17:22:25 ERROR Upload failed error="context canceled" count=228062026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=42807--- PASS: TestShutdownFinishesInFlightPush (0.00s)2808 --- PASS: TestShutdownFinishesInFlightPush/completes (0.14s)2809 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28102026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=42811--- PASS: TestDrainTimeout (0.24s)2812--- PASS: TestQueueConcurrentWriters (0.29s)28132026/10/25 17:22:25 ERROR Accept failed error="too many open files"28142026/10/25 17:22:25 ERROR Drain finished with paths left in queue remaining=32815--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2816 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.24s)2817 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.32s)28182026/10/25 17:22:25 ERROR Accept failed error="too many open files"2819--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28202026/10/25 17:22:26 INFO Uploading batch count=128212026/10/25 17:22:26 INFO Uploading batch count=128222026/10/25 17:22:26 INFO Uploading batch count=128232026/10/25 17:22:26 ERROR Upload failed error="upload failed" count=128242026/10/25 17:22:26 INFO Uploading batch count=128252026/10/25 17:22:26 ERROR Upload failed error="upload failed" count=128262026/10/25 17:22:26 INFO Uploading batch count=128272026/10/25 17:22:26 ERROR Upload failed error="upload failed" count=128282026/10/25 17:22:26 INFO Uploading batch count=128292026/10/25 17:22:26 ERROR Upload failed error="upload failed" count=128302026/10/25 17:22:26 ERROR Drain finished with paths left in queue remaining=12831--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2832--- PASS: TestQueueRemoveLargeClosure (1.39s)2833--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.04s)2834PASS2835Running signing tests...2836=== RUN TestExternalSigner2837=== PAUSE TestExternalSigner2838=== RUN TestExternalSignerWrongPublicKey2839=== PAUSE TestExternalSignerWrongPublicKey2840=== RUN TestExternalSignerErrors2841=== PAUSE TestExternalSignerErrors2842=== RUN TestExternalSignerRestartsAfterCrash2843=== PAUSE TestExternalSignerRestartsAfterCrash2844=== RUN TestExternalSignerProgramErrorKeepsProcess2845=== PAUSE TestExternalSignerProgramErrorKeepsProcess2846=== RUN TestExternalSignerClose2847=== PAUSE TestExternalSignerClose2848=== RUN TestExternalSignerRejectsInvalidPublicKey2849=== PAUSE TestExternalSignerRejectsInvalidPublicKey2850=== RUN TestExternalSignerCancellation2851=== PAUSE TestExternalSignerCancellation2852=== RUN TestGenerateFingerprint2853=== PAUSE TestGenerateFingerprint2854=== RUN TestParseSigningKey2855=== PAUSE TestParseSigningKey2856=== RUN TestSign2857=== PAUSE TestSign2858=== RUN TestSignBatch2859=== PAUSE TestSignBatch2860=== RUN TestNilKeyPublicKey2861=== PAUSE TestNilKeyPublicKey2862=== RUN TestSignErrors2863=== PAUSE TestSignErrors2864=== CONT TestExternalSignerWrongPublicKey2865=== CONT TestExternalSignerRejectsInvalidPublicKey2866=== RUN TestExternalSignerRejectsInvalidPublicKey/#002867=== CONT TestNilKeyPublicKey2868=== CONT TestSignErrors2869=== CONT TestExternalSignerClose2870=== CONT TestExternalSignerCancellation2871=== CONT TestExternalSignerProgramErrorKeepsProcess2872=== CONT TestExternalSignerErrors2873=== CONT TestExternalSignerRestartsAfterCrash2874=== RUN TestExternalSignerErrors/null_signatures2875=== PAUSE TestExternalSignerErrors/null_signatures2876=== CONT TestSign2877=== CONT TestParseSigningKey2878=== CONT TestExternalSigner2879=== CONT TestGenerateFingerprint2880=== CONT TestSignBatch2881=== RUN TestGenerateFingerprint/basic_with_references2882=== PAUSE TestGenerateFingerprint/basic_with_references2883--- PASS: TestNilKeyPublicKey (0.00s)2884=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002885=== RUN TestExternalSignerErrors/unrequested_key2886=== RUN TestParseSigningKey/valid_32-byte_key2887=== PAUSE TestParseSigningKey/valid_32-byte_key2888=== RUN TestGenerateFingerprint/no_references2889=== PAUSE TestExternalSignerErrors/unrequested_key2890=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2891=== PAUSE TestGenerateFingerprint/no_references2892=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2893=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2894=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2895=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2896=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2897=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2898=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2899=== RUN TestExternalSignerErrors/invalid_signature_base642900=== RUN TestParseSigningKey/no_colon2901=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2902=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2903=== PAUSE TestExternalSignerErrors/invalid_signature_base642904=== RUN TestGenerateFingerprint/invalid_nar_hash_length2905=== PAUSE TestParseSigningKey/no_colon2906=== RUN TestExternalSignerErrors/invalid_JSON2907=== PAUSE TestExternalSignerErrors/invalid_JSON2908=== RUN TestExternalSignerErrors/null2909=== RUN TestParseSigningKey/empty_name2910=== PAUSE TestParseSigningKey/empty_name2911=== RUN TestParseSigningKey/invalid_base642912=== PAUSE TestParseSigningKey/invalid_base642913=== RUN TestParseSigningKey/wrong_length2914=== PAUSE TestParseSigningKey/wrong_length2915=== PAUSE TestExternalSignerErrors/null2916=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2917=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2918=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2919=== CONT TestParseSigningKey/wrong_length2920=== CONT TestParseSigningKey/no_colon2921=== CONT TestParseSigningKey/invalid_base642922=== CONT TestParseSigningKey/valid_32-byte_key2923=== CONT TestParseSigningKey/empty_name2924=== RUN TestExternalSignerErrors/missing_signatures2925=== PAUSE TestExternalSignerErrors/missing_signatures2926=== RUN TestGenerateFingerprint/invalid_store_path_prefix2927=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2928=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2929=== RUN TestExternalSignerErrors/wrong_signatures_shape2930=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2931=== RUN TestGenerateFingerprint/invalid_reference_prefix2932=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2933=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2934=== CONT TestGenerateFingerprint/basic_with_references2935=== RUN TestExternalSignerErrors/too_few_signatures2936=== CONT TestGenerateFingerprint/invalid_nar_hash_length2937=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2938=== PAUSE TestExternalSignerErrors/too_few_signatures2939=== CONT TestGenerateFingerprint/invalid_reference_prefix2940=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2941=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2942=== CONT TestExternalSignerRejectsInvalidPublicKey/#002943=== CONT TestGenerateFingerprint/invalid_store_path_prefix2944=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2945=== CONT TestGenerateFingerprint/no_references2946=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2947=== RUN TestExternalSignerErrors/missing_signature_name2948=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2949--- PASS: TestGenerateFingerprint (0.00s)2950 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2951 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2952 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2953 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2954 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2955 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2956 --- PASS: TestGenerateFingerprint/no_references (0.00s)2957=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2958=== PAUSE TestExternalSignerErrors/missing_signature_name2959=== RUN TestExternalSignerErrors/wrong_signature_length2960=== PAUSE TestExternalSignerErrors/wrong_signature_length2961--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2962 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2963 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2964 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2965 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2966 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2967=== RUN TestExternalSignerErrors/program_error2968=== PAUSE TestExternalSignerErrors/program_error2969=== RUN TestExternalSignerErrors/wrong_shape2970=== PAUSE TestExternalSignerErrors/wrong_shape2971=== RUN TestExternalSignerErrors/wrong_id2972=== PAUSE TestExternalSignerErrors/wrong_id2973=== RUN TestExternalSignerErrors/exit_at_startup2974=== PAUSE TestExternalSignerErrors/exit_at_startup2975=== RUN TestExternalSignerErrors/exit_on_request2976=== PAUSE TestExternalSignerErrors/exit_on_request2977=== RUN TestExternalSignerErrors/wrong_signature_name2978=== PAUSE TestExternalSignerErrors/wrong_signature_name2979=== CONT TestExternalSignerErrors/null_signatures2980=== RUN TestSignErrors/nil_key2981=== PAUSE TestSignErrors/nil_key2982=== RUN TestSignErrors/nil_narinfo2983=== PAUSE TestSignErrors/nil_narinfo2984=== RUN TestSignErrors/invalid_narinfo2985=== PAUSE TestSignErrors/invalid_narinfo2986=== RUN TestSignErrors/canceled2987=== PAUSE TestSignErrors/canceled2988=== CONT TestSignErrors/nil_key2989=== CONT TestSignErrors/invalid_narinfo2990=== CONT TestExternalSignerErrors/exit_on_request2991=== CONT TestSignErrors/nil_narinfo2992=== CONT TestExternalSignerErrors/too_few_signatures2993=== CONT TestExternalSignerErrors/missing_signature_name2994=== CONT TestExternalSignerErrors/wrong_signature_name2995=== CONT TestExternalSignerErrors/wrong_signatures_shape2996--- PASS: TestSign (0.01s)2997=== CONT TestExternalSignerErrors/invalid_signature_base642998=== CONT TestExternalSignerErrors/missing_signatures2999=== CONT TestSignErrors/canceled3000=== CONT TestExternalSignerErrors/exit_at_startup3001=== CONT TestExternalSignerErrors/program_error3002=== CONT TestExternalSignerErrors/unrequested_key3003=== CONT TestExternalSignerErrors/wrong_id3004--- PASS: TestParseSigningKey (0.00s)3005 --- PASS: TestParseSigningKey/wrong_length (0.00s)3006 --- PASS: TestParseSigningKey/no_colon (0.00s)3007 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3008 --- PASS: TestParseSigningKey/empty_name (0.00s)3009 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3010 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3011--- PASS: TestSignErrors (0.01s)3012 --- PASS: TestSignErrors/nil_key (0.00s)3013 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3014 --- PASS: TestSignErrors/nil_narinfo (0.00s)3015 --- PASS: TestSignErrors/canceled (0.00s)3016=== CONT TestExternalSignerErrors/invalid_JSON3017=== CONT TestExternalSignerErrors/null3018=== CONT TestExternalSignerErrors/wrong_shape3019=== CONT TestExternalSignerErrors/wrong_signature_length3020--- PASS: TestSignBatch (0.02s)3021--- PASS: TestExternalSignerWrongPublicKey (0.21s)3022--- PASS: TestExternalSignerCancellation (0.45s)3023--- PASS: TestExternalSignerRestartsAfterCrash (0.64s)3024--- PASS: TestExternalSigner (0.84s)3025--- PASS: TestExternalSignerProgramErrorKeepsProcess (1.01s)3026--- PASS: TestExternalSignerClose (1.21s)3027--- PASS: TestExternalSignerErrors (0.01s)3028 --- PASS: TestExternalSignerErrors/null_signatures (1.39s)3029 --- PASS: TestExternalSignerErrors/missing_signatures (1.58s)3030 --- PASS: TestExternalSignerErrors/invalid_JSON (1.78s)3031 --- PASS: TestExternalSignerErrors/wrong_shape (1.97s)3032 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.17s)3033 --- PASS: TestExternalSignerErrors/unrequested_key (2.36s)3034 --- PASS: TestExternalSignerErrors/program_error (2.55s)3035 --- PASS: TestExternalSignerErrors/exit_on_request (2.75s)3036 --- PASS: TestExternalSignerErrors/null (2.94s)3037 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (3.13s)3038 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.33s)3039 --- PASS: TestExternalSignerErrors/too_few_signatures (3.55s)3040 --- PASS: TestExternalSignerErrors/exit_at_startup (3.74s)3041 --- PASS: TestExternalSignerErrors/wrong_id (3.93s)3042 --- PASS: TestExternalSignerErrors/wrong_signature_name (4.13s)3043 --- PASS: TestExternalSignerErrors/missing_signature_name (4.33s)3044PASS3045Running OpenBao signer tests...3046=== RUN TestSign3047=== PAUSE TestSign3048=== RUN TestSignErrors3049=== PAUSE TestSignErrors3050=== RUN TestServe3051=== PAUSE TestServe3052=== RUN TestServeRejectsGarbage3053=== PAUSE TestServeRejectsGarbage3054=== CONT TestSignErrors3055=== CONT TestServe3056=== CONT TestSign3057=== RUN TestSignErrors/http_error3058=== CONT TestServeRejectsGarbage3059=== PAUSE TestSignErrors/http_error3060--- PASS: TestServeRejectsGarbage (0.00s)3061=== RUN TestSignErrors/invalid_json3062=== PAUSE TestSignErrors/invalid_json3063=== RUN TestSignErrors/no_prefix3064=== PAUSE TestSignErrors/no_prefix3065=== RUN TestSignErrors/invalid_base643066=== PAUSE TestSignErrors/invalid_base643067=== CONT TestSignErrors/http_error3068=== CONT TestSignErrors/invalid_json3069=== CONT TestSignErrors/invalid_base643070=== CONT TestSignErrors/no_prefix3071--- PASS: TestServe (0.00s)3072--- PASS: TestSign (0.00s)3073--- PASS: TestSignErrors (0.00s)3074 --- PASS: TestSignErrors/http_error (0.00s)3075 --- PASS: TestSignErrors/invalid_base64 (0.00s)3076 --- PASS: TestSignErrors/invalid_json (0.00s)3077 --- PASS: TestSignErrors/no_prefix (0.00s)3078PASS3079Running niks3-hook command tests...3080=== RUN TestServeSecondSignalEndsDrain3081=== PAUSE TestServeSecondSignalEndsDrain3082=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3083=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3084=== CONT TestServeSecondSignalEndsDrain3085=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3086--- PASS: TestServeSecondSignalEndsDrain (0.05s)30872026/10/25 17:22:40 INFO Upload queue status pending=130882026/10/25 17:22:40 INFO Uploading batch count=13089--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3090PASS3091Running rate limiter tests...3092=== RUN TestAdaptiveRateLimiter_ThreadSafety3093=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3094=== CONT TestAdaptiveRateLimiter_ThreadSafety30952026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=124.0092700000000730962026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=86.8064890000000430972026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=60.7645423000000230982026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=42.53517961000001430992026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=29.77462572700000731002026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=20.84223800890000431012026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=14.58956660623000331022026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=10.21269662436100131032026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=7.14888763705270131042026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=5.0042213459368931052026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531062026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531072026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531082026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531092026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531102026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531112026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531122026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531132026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531142026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531152026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531162026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531172026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531182026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531192026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531202026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531212026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531222026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531232026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531242026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531252026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531262026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531272026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531282026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531292026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531302026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531312026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531322026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=5.12435000000000131332026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531342026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531352026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531362026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531372026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531382026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531392026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531402026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531412026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531422026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531432026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531442026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531452026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531462026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531472026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531482026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531492026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531502026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531512026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=5.12435000000000131522026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531532026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531542026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531552026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531562026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531572026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531582026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531592026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531602026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531612026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531622026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531632026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531642026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531652026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=21.40568165694512431662026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=14.98397715986158531672026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=10.48878401190310931682026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=7.34214880833217531692026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=5.139504165832522531702026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531712026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531722026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531732026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531742026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531752026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531762026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531772026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531782026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531792026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531802026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=8.25281691850000431812026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=5.77697184295000331822026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531832026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531842026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531852026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531862026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531872026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531882026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531892026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531902026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531912026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531922026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531932026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=531942026/10/25 17:22:41 WARN Rate limiter backed off name=test rate=53195--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.04s)3196PASS