niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #470
· raw
1tribuchet: building on jamie2Running 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_ReturnsAfterDroppedBody22=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestDumpPathCaseHackMatchesNix28--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)29=== RUN TestDumpPathCaseHackCollision30--- PASS: TestDumpPathCaseHackCollision (0.00s)31=== RUN TestTruncatedNARDumpIsNotCompleted32=== PAUSE TestTruncatedNARDumpIsNotCompleted33=== RUN TestDumpPathMatchesNix34=== PAUSE TestDumpPathMatchesNix35=== RUN TestDumpPathSingleFile36=== PAUSE TestDumpPathSingleFile37=== RUN TestDumpPathWriterError38=== PAUSE TestDumpPathWriterError39=== RUN TestDumpPathWriterErrorStopsReading40 nar_test.go:289: read 114 of 32768000 bytes41--- PASS: TestDumpPathWriterErrorStopsReading (0.59s)42=== RUN TestEncodeNixBase3243=== PAUSE TestEncodeNixBase3244=== RUN TestEncodeNixBase32WithRealHash45=== PAUSE TestEncodeNixBase32WithRealHash46=== RUN TestConvertHashToNix3247=== PAUSE TestConvertHashToNix3248=== RUN TestGetStorePathHash49=== PAUSE TestGetStorePathHash50=== RUN TestPathInfoHashCompatibility51=== PAUSE TestPathInfoHashCompatibility52=== RUN TestParsePathInfoJSON53=== PAUSE TestParsePathInfoJSON54=== RUN TestParsePathInfoJSONMultiplePaths55=== PAUSE TestParsePathInfoJSONMultiplePaths56=== RUN TestPathInfoCACompatibility57=== PAUSE TestPathInfoCACompatibility58=== RUN TestUploadPendingObjectsStopsStartingAfterFailure59--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)60=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent61=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent62=== RUN TestCompletePendingClosure_NotFoundWithoutKey63=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey64=== RUN TestRateLimiterFeedback65=== PAUSE TestRateLimiterFeedback66=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess67=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess68=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer69=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer70=== RUN TestRegisterUploadedObject_OutlivesPush71=== PAUSE TestRegisterUploadedObject_OutlivesPush72=== RUN TestResolveStorePath73=== PAUSE TestResolveStorePath74=== RUN TestDoWithRetry_BodyReplayedViaGetBody75=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody76=== RUN TestRetryTimeoutOutlastsMaxRetries77=== PAUSE TestRetryTimeoutOutlastsMaxRetries78=== RUN TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestStreamPushReportsSkippedPaths97=== PAUSE TestStreamPushReportsSkippedPaths98=== RUN TestClientSignaturesByStorePath99=== PAUSE TestClientSignaturesByStorePath100=== RUN TestStreamPushStopsWhenCanceled101=== PAUSE TestStreamPushStopsWhenCanceled102=== RUN TestStreamPushStopsOnCancel103=== PAUSE TestStreamPushStopsOnCancel104=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel105=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel106=== 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 TestDoServerRequestAttachesToken135=== CONT TestResolveStorePath136=== CONT TestDumpPathWriterError137=== CONT TestStreamPushStopsOnCancel138=== CONT TestScriptTokenEmptyCommand139=== CONT TestScriptTokenDoesNotWaitForItsChildren140--- PASS: TestScriptTokenEmptyCommand (0.00s)141=== CONT TestScriptTokenScriptFails142=== CONT TestScriptTokenCachesUntilRefresh143=== CONT TestStreamPushIsolatesFailures144=== CONT TestScriptTokenBadJSON145=== CONT TestFileTokenEmpty146=== CONT TestScriptTokenEmptyToken147=== CONT TestFileTokenReadsAndCaches148=== CONT TestStreamPushStopsWhenCanceled149=== CONT TestScriptTokenNoExpiryRerunsEveryCall150=== CONT TestClientSignaturesByStorePath151=== CONT TestSetClientTLSDoesNotMutateDefaultTransport152=== CONT TestStreamPushReportsEveryPath153=== CONT TestStreamPushReportsSkippedPaths154=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel155=== CONT TestSetClientTLS156=== CONT TestPathInfoCACompatibility157=== CONT TestStreamPushRequestLine158=== CONT TestRegisterUploadedObject_OutlivesPush159=== CONT TestFileTokenMissing160=== RUN TestStreamPushStopsOnCancel/waiting_for_input161=== CONT TestGetStorePathHash162=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input163=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot164=== RUN TestGetStorePathHash/valid_store_path165=== CONT TestStaticToken166=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer168--- PASS: TestResolveStorePath (0.00s)169=== CONT TestUploadMultipart_PartsInParallel170=== CONT TestDumpPathSingleFile171=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure172=== CONT TestRegisterUploadedObjectReusesConnections173=== RUN TestPathInfoCACompatibility/null_ca_field174=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot175=== PAUSE TestGetStorePathHash/valid_store_path176=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun177=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs178=== CONT TestStreamPushGivesUpOnDeadServer179--- PASS: TestFileTokenReadsAndCaches (0.00s)180=== CONT TestPathInfoHashCompatibility181=== CONT TestStreamPushReportsSignatures182=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== CONT TestDoWithRetry_FinalResponseBodyReadable184=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot185=== CONT TestConvertHashToNix32186=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot187=== RUN TestConvertHashToNix32/SRI_format_to_Nix32188=== PAUSE TestPathInfoCACompatibility/null_ca_field189=== RUN TestGetStorePathHash/basename_without_hyphen_should_error190=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32191=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout192--- PASS: TestClientSignaturesByStorePath (0.00s)193=== CONT TestShellSplitErrors194=== CONT TestParsePathInfoJSON195=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot196--- PASS: TestShellSplitErrors (0.00s)197=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout198--- PASS: TestStreamPushStopsWhenCanceled (0.00s)199--- PASS: TestDoServerRequestAttachesToken (0.01s)200=== RUN TestParsePathInfoJSON/Nix_format201--- PASS: TestRegisterUploadedObject_OutlivesPush (0.01s)202=== RUN TestPathInfoCACompatibility/old_string_format_-_text203=== RUN TestConvertHashToNix32/already_Nix32_format204=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text206--- PASS: TestFileTokenEmpty (0.00s)207=== PAUSE TestConvertHashToNix32/already_Nix32_format208=== RUN TestConvertHashToNix32/invalid_format209=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot210=== CONT TestDoWithRetry_BodyReplayedViaGetBody211=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)212=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error213=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon214=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive215=== PAUSE TestConvertHashToNix32/invalid_format216--- PASS: TestStreamPushReportsSkippedPaths (0.00s)217--- PASS: TestStaticToken (0.00s)218=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot219=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica220=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot221=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error222=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== PAUSE TestParsePathInfoJSON/Nix_format224=== RUN TestParsePathInfoJSON/Lix_format225=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error226=== CONT TestDumpPathMatchesNix227=== PAUSE TestParsePathInfoJSON/Lix_format228=== RUN TestParsePathInfoJSON/empty_input229=== PAUSE TestParsePathInfoJSON/empty_input230=== CONT TestTruncatedNARDumpIsNotCompleted231=== RUN TestParsePathInfoJSON/whitespace_only232=== CONT TestRateLimiterFeedback233=== CONT TestFilterOversizedClosures234=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon235=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken236=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess237--- PASS: TestFileTokenMissing (0.00s)238=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error239=== RUN TestPathInfoCACompatibility/new_structured_format_-_text240=== CONT TestSetClientTLSErrors241=== PAUSE TestParsePathInfoJSON/whitespace_only242=== RUN TestRateLimiterFeedback/429_enables_limiter243=== RUN TestFilterOversizedClosures/no_limit_keeps_everything244=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken245--- PASS: TestStreamPushReportsEveryPath (0.00s)246=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI247=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestPartSizeForNAR249=== CONT TestUploadMultipart_ProducerErrorIsNotEOF250=== RUN TestParsePathInfoJSON/invalid_JSON251=== PAUSE TestRateLimiterFeedback/429_enables_limiter252=== RUN TestSetClientTLS/rejects_connection_without_client_cert253=== RUN TestRateLimiterFeedback/503_enables_limiter254=== PAUSE TestRateLimiterFeedback/503_enables_limiter255=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything256=== CONT TestEncodeNixBase32257--- PASS: TestStreamPushIsolatesFailures (0.01s)258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter260=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped261=== RUN TestSetClientTLSErrors/missing_cert_file262=== RUN TestEncodeNixBase32/test_string_hash263=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part265=== RUN TestPartSizeForNAR/zero_stays_at_minimum266=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert267=== PAUSE TestParsePathInfoJSON/invalid_JSON268=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512269=== CONT TestUploadMultipart_ReturnsAfterDroppedBody270=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512271--- PASS: TestScriptTokenBadJSON (0.01s)272=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part273=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA274=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary275=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped276=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter277=== CONT TestCompletePendingClosure_NotFoundWithoutKey278=== CONT TestCaseHackSuffix279=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent280=== PAUSE TestEncodeNixBase32/test_string_hash281=== PAUSE TestSetClientTLSErrors/missing_cert_file282=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method283=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum284=== RUN TestSetClientTLSErrors/missing_key_file285=== RUN TestPartSizeForNAR/small_stays_at_minimum286=== PAUSE TestSetClientTLSErrors/missing_key_file287=== RUN TestSetClientTLSErrors/missing_ca_file288=== CONT TestStreamPushBatchesUnderLoad289=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false290=== CONT TestParsePathInfoJSONMultiplePaths291=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths292=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false293--- PASS: TestScriptTokenEmptyToken (0.01s)294=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths295--- PASS: TestScriptTokenScriptFails (0.01s)296=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary297--- PASS: TestStreamPushReportsSignatures (0.00s)298=== RUN TestFilterOversizedClosures/all_closures_skipped299=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter300=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier301=== RUN TestEncodeNixBase32/empty_input302=== PAUSE TestPartSizeForNAR/small_stays_at_minimum303=== PAUSE TestSetClientTLSErrors/missing_ca_file304=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true305=== PAUSE TestEncodeNixBase32/empty_input306=== CONT TestRetryTimeoutOutlastsMaxRetries307=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum308=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA309=== RUN TestSetClientTLS/preserves_debug_logging_transport310=== PAUSE TestSetClientTLS/preserves_debug_logging_transport311=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum312=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true313=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths314=== RUN TestSetClientTLSErrors/invalid_ca_file315=== CONT TestEncodeNixBase32WithRealHash316=== CONT TestShellSplit317--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)318=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs319=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths320=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts321=== CONT TestConvertHashToNix32/invalid_format322=== PAUSE TestFilterOversizedClosures/all_closures_skipped323=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter324=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier325=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry326=== PAUSE TestSetClientTLSErrors/invalid_ca_file327=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout328--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)329=== CONT TestConvertHashToNix32/already_Nix32_format330--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)331--- PASS: TestDumpPathSingleFile (0.17s)332=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts333=== CONT TestGetStorePathHash/valid_store_path334=== CONT TestConvertHashToNix32/SRI_format_to_Nix32335=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error336=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error337=== CONT TestGetStorePathHash/basename_without_hyphen_should_error338=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up339=== CONT TestStreamPushStopsOnCancel/waiting_for_input340=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken341--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)342=== RUN TestPartSizeForNAR/1_TiB343=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot344=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot345=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot346=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot347=== CONT TestParsePathInfoJSON/Lix_format348=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up349--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)350--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)351=== PAUSE TestPartSizeForNAR/1_TiB352=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier353--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.15s)354=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier355=== CONT TestParsePathInfoJSON/empty_input356=== RUN TestPartSizeForNAR/5_TiB_S3_max_object357=== CONT TestParsePathInfoJSON/whitespace_only358--- PASS: TestEncodeNixBase32WithRealHash (0.00s)359=== CONT TestParsePathInfoJSON/invalid_JSON360=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI362=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon363=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512364=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object365=== RUN TestPartSizeForNAR/capped_at_5_GiB366=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client367=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client368=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)369=== CONT TestPathInfoCACompatibility/new_structured_format_-_text370=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method371=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive372=== CONT TestPathInfoCACompatibility/old_string_format_-_text373--- PASS: TestShellSplit (0.00s)374=== PAUSE TestPartSizeForNAR/capped_at_5_GiB375=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client376=== CONT TestPathInfoCACompatibility/null_ca_field377=== CONT TestParsePathInfoJSON/Nix_format378=== CONT TestEncodeNixBase32/empty_input379=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part380--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.14s)381=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary382=== CONT TestEncodeNixBase32/test_string_hash383=== CONT TestSetClientTLS/rejects_connection_without_client_cert384--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)385=== CONT TestSetClientTLS/preserves_debug_logging_transport386--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)387--- PASS: TestConvertHashToNix32 (0.00s)388 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)389 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)390 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)391--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.17s)392--- PASS: TestGetStorePathHash (0.02s)393 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)394 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)395 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)396 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)397--- PASS: TestParsePathInfoJSON (0.01s)398 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)399 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)400 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)403--- PASS: TestPathInfoHashCompatibility (0.02s)404 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)405 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)406 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)407 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)408--- PASS: TestPathInfoCACompatibility (0.16s)409 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)410 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)411 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)412 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)413 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)414--- PASS: TestEncodeNixBase32 (0.14s)415 --- PASS: TestEncodeNixBase32/empty_input (0.00s)416 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)417=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA418--- PASS: TestCaseHackSuffix (0.03s)419=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true420=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false421=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths422=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths423--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)424=== CONT TestFilterOversizedClosures/all_closures_skipped425=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped426--- PASS: TestStreamPushBatchesUnderLoad (0.00s)427 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)428 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)429=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter430--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)431 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)432 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)433=== CONT TestFilterOversizedClosures/no_limit_keeps_everything434=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter435--- PASS: TestFilterOversizedClosures (0.15s)436 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)437 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)438 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)439=== CONT TestRateLimiterFeedback/503_enables_limiter440=== CONT TestRateLimiterFeedback/429_enables_limiter441--- PASS: TestDumpPathWriterError (0.33s)442=== CONT TestSetClientTLSErrors/missing_cert_file443=== CONT TestSetClientTLSErrors/missing_key_file444=== CONT TestPartSizeForNAR/5_TiB_S3_max_object445=== CONT TestSetClientTLSErrors/missing_ca_file446=== CONT TestPartSizeForNAR/small_stays_at_minimum447=== CONT TestSetClientTLSErrors/invalid_ca_file448=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier449--- PASS: TestRateLimiterFeedback (0.15s)450 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)451 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)452 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.12s)453 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.12s)454=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum455=== CONT TestPartSizeForNAR/1_TiB456=== CONT TestPartSizeForNAR/capped_at_5_GiB457=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts458=== CONT TestPartSizeForNAR/zero_stays_at_minimum459=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client460=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up461=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client462=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier463--- PASS: TestStreamPushStopsOnCancel (0.03s)464 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.16s)465 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.16s)466 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.16s)467 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.16s)468 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.17s)469 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.17s)470--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.17s)471--- PASS: TestSetClientTLSErrors (0.15s)472 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)473 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)474 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)475 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)476--- PASS: TestPartSizeForNAR (0.16s)477 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)478 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)479 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)480 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)481 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)482 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)483 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)484--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.34s)485--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)486 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)487 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)488 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)489 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)490 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)491--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.39s)492--- PASS: TestSetClientTLS (0.17s)493 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)494 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.14s)495 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.24s)496--- PASS: TestRegisterUploadedObjectReusesConnections (0.46s)497--- PASS: TestStreamPushRequestLine (0.52s)498--- PASS: TestDumpPathMatchesNix (0.54s)499--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.14s)500 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.38s)501 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.38s)502--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)503--- PASS: TestTruncatedNARDumpIsNotCompleted (1.20s)504--- PASS: TestUploadMultipart_PartsInParallel (1.25s)505--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)506 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)507 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)508PASS509Running server tests...510The files belonging to this database system will be owned by user "nixbld".511This user must also own the server process.512513The database cluster will be initialized with locale "C".514The default database encoding has accordingly been set to "SQL_ASCII".515The default text search configuration will be set to "english".516517Data page checksums are enabled.518519creating directory /build/postgres1927963245/data ... ok520creating subdirectories ... ok521selecting dynamic shared memory implementation ... posix522selecting default "max_connections" ... 100523selecting default "shared_buffers" ... 128MB524selecting default time zone ... UTC525creating configuration files ... ok526running bootstrap script ... ok527performing post-bootstrap initialization ... ok528syncing data to disk ... ok529530initdb: warning: enabling "trust" authentication for local connections531initdb: 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.532533Success. You can now start the database server using:534535 pg_ctl -D /build/postgres1927963245/data -l logfile start536537/build/postgres1927963245:5432 - no response5382026-11-07 23:33:09.330 UTC [171] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5392026-11-07 23:33:09.331 UTC [171] LOG: listening on Unix socket "/build/postgres1927963245/.s.PGSQL.5432"5402026-11-07 23:33:09.336 UTC [178] LOG: database system was shut down at 2026-11-07 23:33:09 UTC5412026-11-07 23:33:09.340 UTC [171] LOG: database system is ready to accept connections542/build/postgres1927963245:5432 - accepting connections543=== RUN TestAbortSucceeded544=== PAUSE TestAbortSucceeded545=== RUN TestService_AuthMiddleware546=== PAUSE TestService_AuthMiddleware547=== RUN TestService_AuthMiddleware_MTLSProxyHeader548=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader549=== RUN TestService_AuthMiddleware_MTLSBoundSubjects550=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects551=== RUN TestService_ReadAuthMiddleware552=== PAUSE TestService_ReadAuthMiddleware553=== RUN TestService_AuthMiddleware_OIDC554=== PAUSE TestService_AuthMiddleware_OIDC555=== RUN TestService_RequireScope_OIDC556=== PAUSE TestService_RequireScope_OIDC557=== RUN TestService_ReadScope_PublicByDefault558=== PAUSE TestService_ReadScope_PublicByDefault559=== RUN TestCacheConfigHandler560=== PAUSE TestCacheConfigHandler561=== RUN TestCacheStatsHandler562=== PAUSE TestCacheStatsHandler563=== RUN TestClientCADerivations564=== PAUSE TestClientCADerivations565=== RUN TestClientErrorHandling566=== PAUSE TestClientErrorHandling567=== RUN TestClientIntegration568=== PAUSE TestClientIntegration569=== RUN TestClientMultipleUploads570=== PAUSE TestClientMultipleUploads571=== RUN TestClientWithDependencies572=== PAUSE TestClientWithDependencies573=== RUN TestClientSharedPathCommittedMidPush574=== PAUSE TestClientSharedPathCommittedMidPush575=== RUN TestPinProtectsFromGC576=== PAUSE TestPinProtectsFromGC577=== RUN TestClientPushesUseOnePush578=== PAUSE TestClientPushesUseOnePush579=== RUN TestClientFallsBackToClosures580=== PAUSE TestClientFallsBackToClosures581=== RUN TestDeleteClosuresRacingPins582=== PAUSE TestDeleteClosuresRacingPins583=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock584=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock585=== RUN TestResolveDBConnectionString586=== PAUSE TestResolveDBConnectionString587=== RUN TestConnectWaitsForAPeerMigration588=== PAUSE TestConnectWaitsForAPeerMigration589=== RUN TestConnectSerialisesConcurrentMigrations590=== PAUSE TestConnectSerialisesConcurrentMigrations591=== RUN TestLeadElectsOneAndHandsOver592=== PAUSE TestLeadElectsOneAndHandsOver593=== RUN TestLeadIncumbentWinsAfterRestart5942026/11/07 23:33:10 INFO lead: acquired remote=192.0.2.1:12345952026/11/07 23:33:10 INFO lead: released remote=192.0.2.1:12345962026/11/07 23:33:10 INFO lead: acquired remote=192.0.2.1:12345972026/11/07 23:33:11 INFO lead: released remote=192.0.2.1:1234598--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)599=== RUN TestLeadIncumbentAnnouncesAtOnce600=== PAUSE TestLeadIncumbentAnnouncesAtOnce601=== RUN TestLeadEndsOnShutdown602=== PAUSE TestLeadEndsOnShutdown603=== RUN TestLeadEndsWhenItsConnectionHangs6042026/11/07 23:33:11 INFO lead: acquired remote=192.0.2.1:12346052026-11-07 23:33:13.304 UTC [624] FATAL: terminating connection due to administrator command6062026/11/07 23:33:13 INFO lead: acquired remote=192.0.2.1:12346072026/11/07 23:33:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"6082026/11/07 23:33:14 INFO lead: released remote=192.0.2.1:12346092026/11/07 23:33:14 INFO lead: released remote=192.0.2.1:1234610--- PASS: TestLeadEndsWhenItsConnectionHangs (3.17s)611=== RUN TestGCAdvisoryLockBlocksConcurrentRun612=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun613=== RUN TestGCBugBareHashReferences614=== PAUSE TestGCBugBareHashReferences615=== RUN TestGCMetrics616=== PAUSE TestGCMetrics617=== RUN TestPushDedupSurvivesConcurrentGC618=== PAUSE TestPushDedupSurvivesConcurrentGC619=== RUN TestDeduplicatedObjectsRecordedAsPending620=== PAUSE TestDeduplicatedObjectsRecordedAsPending621=== RUN TestGCSweepSkipsPendingObjects622=== PAUSE TestGCSweepSkipsPendingObjects623=== RUN TestTombstonedObjectOfferedWithoutWaiting624=== PAUSE TestTombstonedObjectOfferedWithoutWaiting625=== RUN TestGCSweepDeliversEachKeyOnce626=== PAUSE TestGCSweepDeliversEachKeyOnce627=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection628=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection629=== RUN TestForceGCDuringPushOffersSweptObject630=== PAUSE TestForceGCDuringPushOffersSweptObject631=== RUN TestFailedS3DeleteKeepsTombstone632=== PAUSE TestFailedS3DeleteKeepsTombstone633=== RUN TestSweepSkipsRowsLockedByPush634=== PAUSE TestSweepSkipsRowsLockedByPush635=== RUN TestRegisterCompletedObjectNeedsPendingRow636=== PAUSE TestRegisterCompletedObjectNeedsPendingRow637=== RUN TestGetExistingObjectsLocksRows638=== PAUSE TestGetExistingObjectsLocksRows639=== RUN TestSweepRechecksPendingAfterLocking640=== PAUSE TestSweepRechecksPendingAfterLocking641=== RUN TestPushWaitsForSweepHoldingRow642=== PAUSE TestPushWaitsForSweepHoldingRow643=== RUN TestCommitRacingPendingCleanupKeepsObjects644=== PAUSE TestCommitRacingPendingCleanupKeepsObjects645=== RUN TestGCEndsOnShutdown646=== PAUSE TestGCEndsOnShutdown647=== RUN TestGCTaskStore_StartNew648=== PAUSE TestGCTaskStore_StartNew649=== RUN TestGCTaskStore_DeduplicateSameParams650=== PAUSE TestGCTaskStore_DeduplicateSameParams651=== RUN TestGCTaskStore_ConflictDifferentParams652=== PAUSE TestGCTaskStore_ConflictDifferentParams653=== RUN TestGCTaskStore_GetEmpty654=== PAUSE TestGCTaskStore_GetEmpty655=== RUN TestGCTaskStore_GetReturnsLatest656=== PAUSE TestGCTaskStore_GetReturnsLatest657=== RUN TestGCTaskStore_CompletedAllowsNewTask658=== PAUSE TestGCTaskStore_CompletedAllowsNewTask659=== RUN TestGCTaskStore_PhaseUpdates660=== PAUSE TestGCTaskStore_PhaseUpdates661=== RUN TestGCTaskStore_Fail662=== PAUSE TestGCTaskStore_Fail663=== RUN TestGracefulShutdownDrainsInflight664=== PAUSE TestGracefulShutdownDrainsInflight665=== RUN TestService_healthCheckHandler666=== PAUSE TestService_healthCheckHandler667=== RUN TestService_readinessHandler668=== PAUSE TestService_readinessHandler669=== RUN TestGenerateLandingPage670=== PAUSE TestGenerateLandingPage671=== RUN TestEnsureAbortUploadsRule672=== PAUSE TestEnsureAbortUploadsRule673=== RUN TestChildrenInheritRaisedFileLimit674=== PAUSE TestChildrenInheritRaisedFileLimit675=== RUN TestCacheConfigHandlerMaxNarSize676=== PAUSE TestCacheConfigHandlerMaxNarSize677=== RUN TestCreatePendingClosureRejectsOversizedNAR678=== PAUSE TestCreatePendingClosureRejectsOversizedNAR679=== RUN TestNARDeduplicationMetadataUploadBug680=== PAUSE TestNARDeduplicationMetadataUploadBug681=== RUN TestMetricsInventory682=== PAUSE TestMetricsInventory683=== RUN TestMetricsCommit684=== PAUSE TestMetricsCommit685=== RUN TestService_NativeMTLS686=== PAUSE TestService_NativeMTLS687=== RUN TestServerTLSConfig688=== PAUSE TestServerTLSConfig689=== RUN TestMultipartCleanup690=== PAUSE TestMultipartCleanup691=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded692=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded693=== RUN TestPendingCleanupUsesOneCutoff694=== PAUSE TestPendingCleanupUsesOneCutoff695=== RUN TestObjectStatsTrigger696=== PAUSE TestObjectStatsTrigger697=== RUN TestObjectStatsUpdatedOncePerCommit698=== PAUSE TestObjectStatsUpdatedOncePerCommit699=== RUN TestReconnectLeavesObjectsUnlocked700=== PAUSE TestReconnectLeavesObjectsUnlocked701=== RUN TestOrphanedObjectsGC702=== PAUSE TestOrphanedObjectsGC703=== RUN TestOrphanedObjectsGCStressTest704=== PAUSE TestOrphanedObjectsGCStressTest705=== RUN TestCreatePin_ReservedPins706=== PAUSE TestCreatePin_ReservedPins707=== RUN TestConcurrentPinUpdatesAgree708=== PAUSE TestConcurrentPinUpdatesAgree709=== RUN TestCreatePinRejectsBadInput710=== PAUSE TestCreatePinRejectsBadInput711=== RUN TestDeletePinKeepsRowWhenS3Fails712=== PAUSE TestDeletePinKeepsRowWhenS3Fails713=== RUN TestPresentReportsOnlyClosureRoots714=== PAUSE TestPresentReportsOnlyClosureRoots715=== RUN TestPresentRefreshesOnlyStaleClosures716=== PAUSE TestPresentRefreshesOnlyStaleClosures717=== RUN TestPresentNotReportedWhileGCDeletesClosure718=== PAUSE TestPresentNotReportedWhileGCDeletesClosure719=== RUN TestParseSingleRange720=== PAUSE TestParseSingleRange721=== RUN TestProxyHeadersOnlyTrustedOnSocket7222026/11/07 23:33:15 INFO Starting HTTP server address=127.0.0.1:349657232026/11/07 23:33:15 INFO Starting HTTP server address=proxy.sock7242026/11/07 23:33:15 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7252026/11/07 23:33:15 INFO Shutdown signal received, draining in-flight requests timeout=10s726--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.14s)727=== RUN TestIsValidCachePath728=== PAUSE TestIsValidCachePath729=== RUN TestReadProxyNarinfo730=== PAUSE TestReadProxyNarinfo731=== RUN TestReadProxyNarinfoAlreadyDecompressed732=== PAUSE TestReadProxyNarinfoAlreadyDecompressed733=== RUN TestReadProxyContentNegotiation734=== PAUSE TestReadProxyContentNegotiation735=== RUN TestReadProxyNarStreaming736=== PAUSE TestReadProxyNarStreaming737=== RUN TestReadProxy404And429738=== PAUSE TestReadProxy404And429739=== RUN TestReadProxyInvalidPath740=== PAUSE TestReadProxyInvalidPath741=== RUN TestReadProxyHead742=== PAUSE TestReadProxyHead743=== RUN TestReadProxyOutlastsServerWriteTimeout744=== PAUSE TestReadProxyOutlastsServerWriteTimeout745=== RUN TestReadProxyConditionalGet746=== PAUSE TestReadProxyConditionalGet747=== RUN TestReadProxyRootRedirectsToIndexHTML748=== PAUSE TestReadProxyRootRedirectsToIndexHTML749=== RUN TestReadProxyDisabled750=== PAUSE TestReadProxyDisabled751=== RUN TestReadRedirectNar752=== PAUSE TestReadRedirectNar753=== RUN TestReadRedirectKeepsNarinfoProxied754=== PAUSE TestReadRedirectKeepsNarinfoProxied755=== RUN TestReadProxyRangeRequest756=== PAUSE TestReadProxyRangeRequest757=== RUN TestReadRedirectUsesPublicS3URL758=== PAUSE TestReadRedirectUsesPublicS3URL759=== RUN TestPush_OverlappingRootsStoreOneRowPerKey760=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey761=== RUN TestPush_CompleteCommitsEveryRoot762=== PAUSE TestPush_CompleteCommitsEveryRoot763=== RUN TestPush_RepeatedRootCommitsOnce764=== PAUSE TestPush_RepeatedRootCommitsOnce765=== RUN TestPush_CompleteWaitsForCleanupOfThePush766=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush767=== RUN TestPush_RootsAreLockedInByteOrder768=== PAUSE TestPush_RootsAreLockedInByteOrder769=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit770=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit771=== RUN TestPush_RejectsBadRequests772=== PAUSE TestPush_RejectsBadRequests773=== RUN TestPush_SignsNarinfosOfItsPendingObjects774=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects775=== RUN TestSharedNarBothUploadsComplete776=== PAUSE TestSharedNarBothUploadsComplete777=== RUN TestCompleteMultipartUpload_ErrorButObjectExists778=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists779=== RUN TestCompletedNarNotReofferedAcrossClosures780=== PAUSE TestCompletedNarNotReofferedAcrossClosures781=== RUN TestPresignedUploadRegisteredBeforeCommit782=== PAUSE TestPresignedUploadRegisteredBeforeCommit783=== RUN TestService_Rustfstest784=== PAUSE TestService_Rustfstest785=== RUN TestParseSize786=== PAUSE TestParseSize787=== RUN TestSkippedUploadsHandler788=== PAUSE TestSkippedUploadsHandler789=== RUN TestSystemdListenerNotActivated790--- PASS: TestSystemdListenerNotActivated (0.00s)791=== RUN TestWatchdogBeatsWhenHealthy792--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)793=== RUN TestWatchdogSkipsWhenUnhealthy7942026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7952026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7962026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7972026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7982026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7992026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8002026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8012026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8022026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8032026/11/07 23:33:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"804--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)805=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle806=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle807=== RUN TestProxyWriteTimeout808=== PAUSE TestProxyWriteTimeout809=== RUN TestPendingClosureWriteTimeout810=== PAUSE TestPendingClosureWriteTimeout811=== RUN TestIsValidUploadKey812=== PAUSE TestIsValidUploadKey813=== RUN TestUploadHandlersRejectInvalidKeys814=== PAUSE TestUploadHandlersRejectInvalidKeys815=== RUN TestUploadHandlersRejectOversizedBody816=== PAUSE TestUploadHandlersRejectOversizedBody817=== RUN TestService_cleanupPendingClosuresHandler818=== PAUSE TestService_cleanupPendingClosuresHandler819=== RUN TestService_createPendingClosureHandler820=== PAUSE TestService_createPendingClosureHandler821=== RUN TestService_verifyS3Integrity822=== PAUSE TestService_verifyS3Integrity823=== RUN TestService_verifyS3ReuploadsStaleNarinfo824=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo825=== RUN TestCompleteMultipartUnregistered826=== PAUSE TestCompleteMultipartUnregistered827=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT828=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT829=== CONT TestClientCADerivations830=== CONT TestService_createPendingClosureHandler831=== CONT TestGCTaskStore_DeduplicateSameParams832=== CONT TestPush_RootsAreLockedInByteOrder833--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)834=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT835=== CONT TestCompleteMultipartUnregistered836=== CONT TestService_verifyS3ReuploadsStaleNarinfo837=== CONT TestGCTaskStore_CompletedAllowsNewTask838=== CONT TestService_readinessHandler839=== CONT TestGracefulShutdownDrainsInflight840=== CONT TestGCTaskStore_PhaseUpdates841=== CONT TestGCEndsOnShutdown842=== CONT TestGCTaskStore_Fail8432026/11/07 23:33:15 INFO Starting HTTP server address=127.0.0.1:46057844=== CONT TestGCTaskStore_GetReturnsLatest845=== CONT TestReadRedirectUsesPublicS3URL846=== CONT TestServerTLSConfig847=== CONT TestPush_CompleteWaitsForCleanupOfThePush848=== CONT TestPush_RejectsBadRequests849=== CONT TestReadProxyNarStreaming8502026/11/07 23:33:15 INFO Shutdown signal received, draining in-flight requests timeout=10s851=== CONT TestService_healthCheckHandler852=== CONT TestConnectSerialisesConcurrentMigrations853=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit854=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded855=== CONT TestReadProxy404And429856=== CONT TestPush_CompleteCommitsEveryRoot857--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)858=== CONT TestPush_RepeatedRootCommitsOnce859--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)860=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed861=== CONT TestPush_OverlappingRootsStoreOneRowPerKey862=== RUN TestGCEndsOnShutdown/before_the_run863=== CONT TestReadProxyNarinfoAlreadyDecompressed864=== RUN TestServerTLSConfig/no_client_CA865=== CONT TestChildrenInheritRaisedFileLimit866--- PASS: TestGCTaskStore_Fail (0.00s)867--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)868=== PAUSE TestServerTLSConfig/no_client_CA869=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed870=== PAUSE TestGCEndsOnShutdown/before_the_run871=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete872=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete873=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark874=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark875=== RUN TestServerTLSConfig/missing_CA_file876=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed877=== CONT TestLeadEndsOnShutdown878=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed879=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost880=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost881=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed882=== PAUSE TestServerTLSConfig/missing_CA_file883=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed884=== RUN TestServerTLSConfig/not_a_PEM_file885=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed886=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed887=== PAUSE TestServerTLSConfig/not_a_PEM_file888=== CONT TestGCSweepDeliversEachKeyOnce889=== CONT TestUploadHandlersRejectOversizedBody890--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)891=== CONT TestReadProxyContentNegotiation892--- PASS: TestGracefulShutdownDrainsInflight (0.07s)893=== CONT TestReadProxyNarinfo894=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure895=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure896=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart897=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart898=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts899=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts900=== CONT TestService_verifyS3Integrity9012026-11-07 23:33:15.953 UTC [711] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"9022026-11-07 23:33:15.953 UTC [711] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.9032026-11-07 23:33:15.953 UTC [711] STATEMENT: CREATE TABLE goose_db_version (904 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,905 version_id bigint NOT NULL,906 is_applied boolean NOT NULL,907 tstamp timestamp NOT NULL DEFAULT now()908 )9092026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures9102026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures9112026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures9122026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes913=== CONT TestReadProxyRangeRequest914--- PASS: TestReadProxyNarStreaming (1.08s)915=== NAME TestClientCADerivations916 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1958520349/001/store/yzy5jxq2yn73057cjlbqbb4n46ffs1a5-ca-test9172026/11/07 23:33:16 WARN readiness check failed error="closed pool"918--- PASS: TestService_readinessHandler (1.12s)919=== CONT TestCreatePendingClosureRejectsOversizedNAR9202026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures921--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)922=== CONT TestCommitRacingPendingCleanupKeepsObjects923=== NAME TestClientCADerivations924 client_ca_test.go:139: Found 1 dependencies (including self)9252026/11/07 23:33:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9262026/11/07 23:33:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst927--- PASS: TestCompleteMultipartUnregistered (1.19s)9282026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures929=== CONT TestPushWaitsForSweepHoldingRow9302026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes931--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.23s)932=== CONT TestGetExistingObjectsLocksRows9332026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes9342026/11/07 23:33:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9352026/11/07 23:33:16 INFO Uploading yzy5jxq2yn73057cjlbqbb4n46ffs1a5-ca-test (144B)936=== RUN TestPush_RejectsBadRequests/no_roots937=== PAUSE TestPush_RejectsBadRequests/no_roots938=== RUN TestPush_RejectsBadRequests/no_objects939=== PAUSE TestPush_RejectsBadRequests/no_objects940=== RUN TestPush_RejectsBadRequests/bad_root941=== PAUSE TestPush_RejectsBadRequests/bad_root942=== RUN TestPush_RejectsBadRequests/root_not_in_objects943=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects944=== CONT TestGCTaskStore_StartNew945=== CONT TestSweepRechecksPendingAfterLocking946--- PASS: TestGCTaskStore_StartNew (0.00s)9472026/11/07 23:33:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9482026/11/07 23:33:16 WARN Failed to register uploaded object key=log/95hfpy4cfrb0imiks3yya58wsxkryv3f-ca-test.drv error="server returned 404: 404 page not found\n"9492026/11/07 23:33:16 WARN Failed to register uploaded object key=yzy5jxq2yn73057cjlbqbb4n46ffs1a5.ls error="server returned 404: 404 page not found\n"9502026/11/07 23:33:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9512026/11/07 23:33:16 INFO Signed narinfos id=1 count=19522026/11/07 23:33:16 INFO Uploading 1 narinfos9532026/11/07 23:33:16 INFO Received complete push request method=POST path=/api/pushes/1/complete9542026/11/07 23:33:16 WARN Failed to register uploaded object key=yzy5jxq2yn73057cjlbqbb4n46ffs1a5.narinfo error="server returned 404: 404 page not found\n"955--- PASS: TestService_healthCheckHandler (1.34s)956=== CONT TestSharedNarBothUploadsComplete9572026/11/07 23:33:16 INFO Completed push id=1 objects=4 duration=10.319844ms9582026/11/07 23:33:16 INFO Upload complete. (175ms)959=== NAME TestClientCADerivations960 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1958520349/001/store/yzy5jxq2yn73057cjlbqbb4n46ffs1a5-ca-test961 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst962 Compression: zstd963 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n964 NarSize: 144965 References: 966 Deriver: /build/TestClientCADerivations1958520349/001/store/95hfpy4cfrb0imiks3yya58wsxkryv3f-ca-test.drv967 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n968 client_ca_test.go:185: Checking for realisation files in S3...969 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations970 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache9712026/11/07 23:33:16 INFO Aborted multipart uploads count=0 kept=09722026/11/07 23:33:16 WARN Force mode enabled - objects will be deleted immediately without grace period973--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.39s)974=== CONT TestCacheConfigHandlerMaxNarSize975--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)976=== CONT TestPushDedupSurvivesConcurrentGC9772026/11/07 23:33:16 INFO lead: acquired remote=192.0.2.1:12349782026/11/07 23:33:16 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=09792026/11/07 23:33:16 INFO Vacuumed table table=pending_closures9802026/11/07 23:33:16 INFO Vacuumed table table=pending_objects9812026/11/07 23:33:16 INFO Vacuumed table table=multipart_uploads9822026/11/07 23:33:16 INFO Vacuumed table table=closures9832026/11/07 23:33:16 INFO Vacuumed table table=objects9842026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures985=== CONT TestDeduplicatedObjectsRecordedAsPending986--- PASS: TestGCSweepDeliversEachKeyOnce (1.46s)9872026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes988--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.49s)989=== CONT TestEnsureAbortUploadsRule9902026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes9912026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes9922026/11/07 23:33:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9932026/11/07 23:33:16 INFO Received push request method=POST path=/api/pushes994--- PASS: TestReadRedirectUsesPublicS3URL (1.56s)995=== CONT TestGCBugBareHashReferences9962026/11/07 23:33:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmFlODY4MDliLTBjNWQtNGFlYy04ZTkxLTk3YmI5NzZhY2YxM3gxNzk0MDk0Mzk2MzExNTc5MDcy parts=109972026/11/07 23:33:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9982026/11/07 23:33:16 INFO Completed upload id=1 objects=2 duration=3.913138ms9992026/11/07 23:33:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010002026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures10012026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures10022026/11/07 23:33:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures10032026/11/07 23:33:16 INFO Aborted multipart uploads count=0 kept=01004--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.59s)1005=== CONT TestRegisterCompletedObjectNeedsPendingRow10062026/11/07 23:33:16 WARN Rate limiter enabled after throttle name=s3-test rate=510072026/11/07 23:33:16 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."10082026/11/07 23:33:16 WARN Rate limiter backed off name=s3-test rate=510092026/11/07 23:33:16 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=010102026/11/07 23:33:16 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."10112026/11/07 23:33:16 INFO Vacuumed table table=pending_closures10122026/11/07 23:33:16 INFO Vacuumed table table=pending_objects10132026/11/07 23:33:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026/11/07 23:33:16 INFO Vacuumed table table=multipart_uploads10152026/11/07 23:33:16 INFO Vacuumed table table=closures10162026/11/07 23:33:16 INFO Vacuumed table table=objects1017--- PASS: TestReadProxy404And429 (1.63s)1018=== CONT TestGenerateLandingPage10192026/11/07 23:33:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001020--- PASS: TestGenerateLandingPage (0.01s)1021=== CONT TestSweepSkipsRowsLockedByPush10222026/11/07 23:33:16 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjcxZjE1MjQ4LTRhMDgtNGE4ZS1iMzZkLTJhOWRhMWI3YTk4MHgxNzk0MDk0Mzk2Mzg0OTEyNTM3 parts=101023=== CONT TestGCMetrics1024--- PASS: TestReadProxyRangeRequest (0.59s)1025=== NAME TestClientCADerivations1026 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1027 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1028 error: binary cache 's3://bucket4?endpoint=http://localhost:34955®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1958520349/001/store'1029 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 110302026/11/07 23:33:16 INFO Received uploads request method=POST path=/api/pending_closures1031=== CONT TestFailedS3DeleteKeepsTombstone1032--- PASS: TestConnectSerialisesConcurrentMigrations (1.69s)1033=== CONT TestForceGCDuringPushOffersSweptObject1034--- PASS: TestService_createPendingClosureHandler (1.69s)1035=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1036=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1037=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1038=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1039=== CONT TestLeadIncumbentAnnouncesAtOnce10402026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=010412026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period10422026/11/07 23:33:17 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=010432026/11/07 23:33:17 INFO Vacuumed table table=pending_closures1044--- PASS: TestClientCADerivations (1.72s)10452026/11/07 23:33:17 INFO Vacuumed table table=pending_objects10462026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads10472026/11/07 23:33:17 INFO Vacuumed table table=closures1048=== CONT TestLeadElectsOneAndHandsOver10492026/11/07 23:33:17 INFO Vacuumed table table=objects1050=== CONT TestClientErrorHandling1051--- PASS: TestGetExistingObjectsLocksRows (0.50s)1052=== RUN TestClientErrorHandling/InvalidStorePath1053=== PAUSE TestClientErrorHandling/InvalidStorePath1054=== RUN TestClientErrorHandling/InvalidAuthToken1055=== PAUSE TestClientErrorHandling/InvalidAuthToken1056=== RUN TestClientErrorHandling/ServerNotAvailable1057=== PAUSE TestClientErrorHandling/ServerNotAvailable1058=== CONT TestGCAdvisoryLockBlocksConcurrentRun10592026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=010602026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period1061--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.63s)1062=== CONT TestConnectWaitsForAPeerMigration10632026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures10642026/11/07 23:33:17 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=010652026/11/07 23:33:17 INFO Vacuumed table table=pending_closures10662026/11/07 23:33:17 INFO Vacuumed table table=pending_objects10672026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures10682026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads10692026/11/07 23:33:17 INFO Vacuumed table table=closures10702026/11/07 23:33:17 INFO Vacuumed table table=objects10712026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10722026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures10732026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures10742026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjcwNjg0YTg2LTcyOWMtNDUxYS1hY2E0LTdlOWUzMGU4MTIzZXgxNzk0MDk0Mzk2NTQ4MzQxOTI5 parts=101075--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)1076=== CONT TestTombstonedObjectOfferedWithoutWaiting1077--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.38s)1078=== CONT TestClientSharedPathCommittedMidPush10792026/11/07 23:33:17 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket35 days=21080--- PASS: TestEnsureAbortUploadsRule (0.39s)1081=== CONT TestClientPushesUseOnePush10822026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=010832026/11/07 23:33:17 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=010842026/11/07 23:33:17 INFO Vacuumed table table=pending_closures10852026/11/07 23:33:17 INFO Vacuumed table table=pending_objects10862026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads10872026/11/07 23:33:17 INFO Vacuumed table table=closures10882026/11/07 23:33:17 INFO Vacuumed table table=objects10892026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=010902026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period1091=== CONT TestParseSize1092--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.33s)1093=== CONT TestPinProtectsFromGC1094--- PASS: TestParseSize (0.00s)10952026/11/07 23:33:17 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=010962026/11/07 23:33:17 INFO Vacuumed table table=pending_closures10972026/11/07 23:33:17 INFO Vacuumed table table=pending_objects10982026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads10992026/11/07 23:33:17 INFO Vacuumed table table=closures11002026/11/07 23:33:17 INFO Vacuumed table table=objects11012026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=01102--- PASS: TestPushDedupSurvivesConcurrentGC (0.56s)1103=== CONT TestResolveDBConnectionString11042026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period1105=== RUN TestResolveDBConnectionString/flag_wins1106=== PAUSE TestResolveDBConnectionString/flag_wins1107=== RUN TestResolveDBConnectionString/file_when_flag_empty1108=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1109=== RUN TestResolveDBConnectionString/missing_file_is_an_error1110=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1111=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1112=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1113=== RUN TestResolveDBConnectionString/nothing_configured1114=== PAUSE TestResolveDBConnectionString/nothing_configured1115=== CONT TestIsValidCachePath1116=== RUN TestIsValidCachePath/narinfo1117=== PAUSE TestIsValidCachePath/narinfo1118=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1119=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1120=== RUN TestIsValidCachePath/nar_zst1121=== PAUSE TestIsValidCachePath/nar_zst1122=== RUN TestIsValidCachePath/nar_xz1123=== PAUSE TestIsValidCachePath/nar_xz1124=== RUN TestIsValidCachePath/nar_bz21125=== PAUSE TestIsValidCachePath/nar_bz21126=== RUN TestIsValidCachePath/nar_uncompressed1127=== PAUSE TestIsValidCachePath/nar_uncompressed1128=== RUN TestIsValidCachePath/ls1129=== PAUSE TestIsValidCachePath/ls1130=== RUN TestIsValidCachePath/log1131=== PAUSE TestIsValidCachePath/log1132=== RUN TestIsValidCachePath/realisation1133=== PAUSE TestIsValidCachePath/realisation1134=== RUN TestIsValidCachePath/nix-cache-info1135=== PAUSE TestIsValidCachePath/nix-cache-info11362026/11/07 23:33:17 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=01137=== RUN TestIsValidCachePath/index.html1138=== PAUSE TestIsValidCachePath/index.html1139=== RUN TestIsValidCachePath/traversal_parent1140=== PAUSE TestIsValidCachePath/traversal_parent1141=== RUN TestIsValidCachePath/traversal_in_middle1142=== PAUSE TestIsValidCachePath/traversal_in_middle1143=== RUN TestIsValidCachePath/invalid_char_e1144=== PAUSE TestIsValidCachePath/invalid_char_e1145=== RUN TestIsValidCachePath/invalid_char_u1146=== PAUSE TestIsValidCachePath/invalid_char_u1147=== RUN TestIsValidCachePath/random_path1148=== PAUSE TestIsValidCachePath/random_path1149=== RUN TestIsValidCachePath/empty1150=== PAUSE TestIsValidCachePath/empty1151=== RUN TestIsValidCachePath/leading_slash11522026/11/07 23:33:17 INFO Vacuumed table table=pending_closures1153=== PAUSE TestIsValidCachePath/leading_slash1154=== RUN TestIsValidCachePath/wrong_extension1155=== PAUSE TestIsValidCachePath/wrong_extension11562026/11/07 23:33:17 INFO Vacuumed table table=pending_objects1157=== RUN TestIsValidCachePath/short_hash11582026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads1159=== PAUSE TestIsValidCachePath/short_hash1160=== CONT TestUploadHandlersRejectInvalidKeys11612026/11/07 23:33:17 INFO Vacuumed table table=closures11622026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=01163=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1164=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1165=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1166=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1167=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1168=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1169=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key11702026/11/07 23:33:17 INFO Vacuumed table table=objects1171=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1172=== CONT TestService_NativeMTLS11732026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period11742026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=011752026/11/07 23:33:17 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=011762026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period11772026/11/07 23:33:17 INFO Vacuumed table table=pending_closures11782026/11/07 23:33:17 INFO Vacuumed table table=pending_objects11792026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads11802026/11/07 23:33:17 INFO Vacuumed table table=closures11812026/11/07 23:33:17 INFO Vacuumed table table=objects11822026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures11832026/11/07 23:33:17 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=011842026/11/07 23:33:17 INFO Vacuumed table table=pending_closures11852026/11/07 23:33:17 INFO Vacuumed table table=pending_objects11862026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads11872026/11/07 23:33:17 INFO Vacuumed table table=closures1188--- PASS: TestReadProxyContentNegotiation (2.01s)1189=== CONT TestGCSweepSkipsPendingObjects11902026/11/07 23:33:17 INFO Vacuumed table table=objects11912026/11/07 23:33:17 INFO lead: acquired remote=192.0.2.1:123411922026/11/07 23:33:17 INFO lead: released remote=192.0.2.1:12341193=== CONT TestClientMultipleUploads1194--- PASS: TestSweepSkipsRowsLockedByPush (0.39s)1195--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.34s)1196=== CONT TestPresentNotReportedWhileGCDeletesClosure1197=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1198=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1199=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1200=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1201=== CONT TestMetricsCommit1202--- PASS: TestGCMetrics (0.38s)1203=== CONT TestIsValidUploadKey1204=== RUN TestIsValidUploadKey/narinfo1205=== PAUSE TestIsValidUploadKey/narinfo1206=== RUN TestIsValidUploadKey/nar_zst1207=== PAUSE TestIsValidUploadKey/nar_zst1208=== RUN TestIsValidUploadKey/nar_xz1209=== PAUSE TestIsValidUploadKey/nar_xz1210=== RUN TestIsValidUploadKey/nar_plain1211=== PAUSE TestIsValidUploadKey/nar_plain1212=== RUN TestIsValidUploadKey/listing1213=== PAUSE TestIsValidUploadKey/listing1214=== RUN TestIsValidUploadKey/build_log1215=== PAUSE TestIsValidUploadKey/build_log1216=== RUN TestIsValidUploadKey/build_log_home-manager_file1217=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1218=== RUN TestIsValidUploadKey/build_log_plus_in_name1219=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1220=== RUN TestIsValidUploadKey/build_log_question_mark1221=== PAUSE TestIsValidUploadKey/build_log_question_mark1222=== RUN TestIsValidUploadKey/build_log_equals1223=== PAUSE TestIsValidUploadKey/build_log_equals1224=== RUN TestIsValidUploadKey/realisation1225=== PAUSE TestIsValidUploadKey/realisation1226=== RUN TestIsValidUploadKey/realisation_plus_in_output1227=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1228=== RUN TestIsValidUploadKey/nix-cache-info1229=== PAUSE TestIsValidUploadKey/nix-cache-info1230=== RUN TestIsValidUploadKey/index.html1231=== PAUSE TestIsValidUploadKey/index.html12322026/11/07 23:33:17 INFO lead: acquired remote=192.0.2.1:12341233=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1234=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1235=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1236=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1237=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1238=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1239=== RUN TestIsValidUploadKey/traversal1240=== PAUSE TestIsValidUploadKey/traversal1241=== RUN TestIsValidUploadKey/traversal_nar1242=== PAUSE TestIsValidUploadKey/traversal_nar1243=== RUN TestIsValidUploadKey/absolute1244=== PAUSE TestIsValidUploadKey/absolute1245=== RUN TestIsValidUploadKey/empty_key1246=== PAUSE TestIsValidUploadKey/empty_key1247=== RUN TestIsValidUploadKey/unknown_type1248=== PAUSE TestIsValidUploadKey/unknown_type1249=== CONT TestParseSingleRange1250=== RUN TestParseSingleRange/none1251=== PAUSE TestParseSingleRange/none1252=== RUN TestParseSingleRange/unknown_unit1253=== PAUSE TestParseSingleRange/unknown_unit1254=== RUN TestParseSingleRange/multi-range_ignored1255=== PAUSE TestParseSingleRange/multi-range_ignored1256=== RUN TestParseSingleRange/malformed_no_dash1257=== PAUSE TestParseSingleRange/malformed_no_dash1258=== RUN TestParseSingleRange/malformed_both_empty1259=== PAUSE TestParseSingleRange/malformed_both_empty1260=== RUN TestParseSingleRange/malformed_end_before_start1261=== PAUSE TestParseSingleRange/malformed_end_before_start1262=== RUN TestParseSingleRange/closed1263=== PAUSE TestParseSingleRange/closed1264=== RUN TestParseSingleRange/open-ended1265=== PAUSE TestParseSingleRange/open-ended1266=== RUN TestParseSingleRange/end_clamped_to_size1267=== PAUSE TestParseSingleRange/end_clamped_to_size1268=== RUN TestParseSingleRange/suffix1269=== PAUSE TestParseSingleRange/suffix1270=== RUN TestParseSingleRange/suffix_exceeds_size1271=== PAUSE TestParseSingleRange/suffix_exceeds_size1272=== RUN TestParseSingleRange/single_byte1273=== PAUSE TestParseSingleRange/single_byte1274=== RUN TestParseSingleRange/start_past_EOF1275=== PAUSE TestParseSingleRange/start_past_EOF1276=== RUN TestParseSingleRange/start_far_past_EOF1277=== PAUSE TestParseSingleRange/start_far_past_EOF1278=== CONT TestMetricsInventory12792026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12802026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=012812026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period12822026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12832026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmFiYjZkOWY1LWYwNWMtNDZlYy1iMDdjLWYyNzMxNGRjZDhiMHgxNzk0MDk0Mzk2NzkzNDA4MTkw parts=1012842026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures12852026/11/07 23:33:17 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12862026/11/07 23:33:17 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."12872026-11-07 23:33:17.434 UTC [1153] ERROR: Push does not exist: id=112882026-11-07 23:33:17.434 UTC [1153] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12892026-11-07 23:33:17.434 UTC [1153] STATEMENT: SELECT commit_push($1)12902026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjBmYTIwZGNhLTMwZDAtNDQ1Zi1hYzIzLWM5ZmFkNGYxYzQwZHgxNzk0MDk0Mzk2ODE5OTY4MjE0 parts=101291--- PASS: TestGCBugBareHashReferences (0.58s)1292=== CONT TestService_cleanupPendingClosuresHandler1293--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.31s)1294=== CONT TestReconnectLeavesObjectsUnlocked1295--- PASS: TestFailedS3DeleteKeepsTombstone (0.46s)1296=== CONT TestProxyWriteTimeout1297=== RUN TestProxyWriteTimeout/narinfo1298=== PAUSE TestProxyWriteTimeout/narinfo1299=== RUN TestProxyWriteTimeout/1_GiB_nar1300=== PAUSE TestProxyWriteTimeout/1_GiB_nar1301=== RUN TestProxyWriteTimeout/10_GiB_nar1302=== PAUSE TestProxyWriteTimeout/10_GiB_nar1303=== RUN TestProxyWriteTimeout/unknown_size1304=== PAUSE TestProxyWriteTimeout/unknown_size1305=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1306--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.15s)1307=== CONT TestCreatePin_ReservedPins13082026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13092026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmRkMTU1MzBhLTgzOWQtNGVkMC05ODZlLWE1NTI3OTMyMjY4OXgxNzk0MDk0Mzk2ODc3MTM2MjY5 parts=101310--- PASS: TestPushWaitsForSweepHoldingRow (1.04s)1311=== CONT TestObjectStatsUpdatedOncePerCommit13122026/11/07 23:33:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42323/oidc13132026/11/07 23:33:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13142026/11/07 23:33:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13152026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1316--- PASS: TestService_NativeMTLS (0.28s)1317=== CONT TestPendingClosureWriteTimeout1318=== RUN TestPendingClosureWriteTimeout/empty1319=== PAUSE TestPendingClosureWriteTimeout/empty1320=== RUN TestPendingClosureWriteTimeout/400_objects1321=== PAUSE TestPendingClosureWriteTimeout/400_objects1322=== RUN TestPendingClosureWriteTimeout/670k_objects1323=== PAUSE TestPendingClosureWriteTimeout/670k_objects1324=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1325=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1326=== CONT TestObjectStatsTrigger13272026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjViYzNiZTRhLTQyMzctNDcyYy1hOGU0LWVmZWE3NDQ2NDU0Y3gxNzk0MDk0Mzk2Mzg1NzQ4MDQ3 parts=1013292026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures13302026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjQ5Yjk0YTYxLWQzNGQtNDlhYi04NzkxLTZmZmI2NzFkM2IxZHgxNzk0MDk0Mzk2OTAyNzcyNDQ0 parts=1013312026/11/07 23:33:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13322026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=013332026/11/07 23:33:17 INFO Completed upload id=1 objects=2 duration=3.929538ms13342026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period13352026/11/07 23:33:17 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=013362026/11/07 23:33:17 INFO Vacuumed table table=pending_closures13372026/11/07 23:33:17 INFO Vacuumed table table=pending_objects13382026/11/07 23:33:17 INFO Vacuumed table table=multipart_uploads1339=== NAME TestPinProtectsFromGC13402026/11/07 23:33:17 INFO Vacuumed table table=closures1341 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC1198448043/001/store/vlmkkamg96zr4k6fafi07x140fx394rq-pinned-file.txt1342 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC1198448043/001/store/8gjmzcb3f1iav646a50d6g59cj4a21j8-unpinned-file.txt13432026/11/07 23:33:17 INFO Vacuumed table table=objects13442026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes13452026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes13462026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures13472026/11/07 23:33:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13482026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures13492026/11/07 23:33:17 INFO Uploading bdq2sf38gp0dn7miz5zvgqhkk3m95cqh-top (224B)13502026/11/07 23:33:17 INFO Uploading d3ympkhfw7ny1ihsmp8dki5p38yzr9sl-shared-dep (136B)13512026/11/07 23:33:17 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13522026/11/07 23:33:17 WARN Found objects in DB but missing from S3, will re-upload count=11353=== NAME TestClientMultipleUploads1354 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads3893071914/001/store/7ly3csc5009mly4z6hb8r547hdn4rs2g-test-file-0.txt13552026/11/07 23:33:17 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1356--- PASS: TestGCSweepSkipsPendingObjects (0.33s)1357=== CONT TestPresentReportsOnlyClosureRoots13582026/11/07 23:33:17 INFO Completed upload id=3 objects=2 duration=1.018129ms13592026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13602026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/1vmhb1siirqbvjhs9i19cbjckl3a17ihm6jr2zrj734m80ycqnma.nar.zst error="server returned 404: 404 page not found\n"13612026/11/07 23:33:17 WARN Failed to register uploaded object key=d3ympkhfw7ny1ihsmp8dki5p38yzr9sl.ls error="server returned 404: 404 page not found\n"13622026/11/07 23:33:17 WARN Failed to register uploaded object key=bdq2sf38gp0dn7miz5zvgqhkk3m95cqh.ls error="server returned 404: 404 page not found\n"13632026/11/07 23:33:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13642026/11/07 23:33:17 INFO Signed narinfos id=1 count=213652026/11/07 23:33:17 INFO Uploading 2 narinfos1366=== CONT TestPendingCleanupUsesOneCutoff1367--- PASS: TestService_verifyS3Integrity (1.76s)13682026/11/07 23:33:17 WARN Failed to register uploaded object key=bdq2sf38gp0dn7miz5zvgqhkk3m95cqh.narinfo error="server returned 404: 404 page not found\n"13692026/11/07 23:33:17 INFO Received complete push request method=POST path=/api/pushes/1/complete13702026/11/07 23:33:17 WARN Failed to register uploaded object key=d3ympkhfw7ny1ihsmp8dki5p38yzr9sl.narinfo error="server returned 404: 404 page not found\n"13712026/11/07 23:33:17 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"13722026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes13732026/11/07 23:33:17 INFO Completed push id=1 objects=6 duration=5.653167ms13742026/11/07 23:33:17 INFO Upload complete. (104ms)1375=== NAME TestClientSharedPathCommittedMidPush1376 client_integration_test.go:803: Retrieved narinfo from S3:1377 StorePath: /build/TestClientSharedPathCommittedMidPush3726415740/001/store/d3ympkhfw7ny1ihsmp8dki5p38yzr9sl-shared-dep1378 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1379 Compression: zstd1380 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821381 NarSize: 1361382 References: 1383 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1384=== NAME TestClientMultipleUploads1385 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads3893071914/001/store/ncwzs46pd30rs4jgyx6hi7vp51d74mcg-test-file-1.txt1386=== NAME TestClientSharedPathCommittedMidPush1387 client_integration_test.go:803: Retrieved narinfo from S3:1388 StorePath: /build/TestClientSharedPathCommittedMidPush3726415740/001/store/bdq2sf38gp0dn7miz5zvgqhkk3m95cqh-top1389 URL: nar/1vmhb1siirqbvjhs9i19cbjckl3a17ihm6jr2zrj734m80ycqnma.nar.zst1390 Compression: zstd1391 NarHash: sha256:1vmhb1siirqbvjhs9i19cbjckl3a17ihm6jr2zrj734m80ycqnma1392 NarSize: 2241393 References: /build/TestClientSharedPathCommittedMidPush3726415740/001/store/d3ympkhfw7ny1ihsmp8dki5p38yzr9sl-shared-dep1394 CA: text:sha256:1953q8nzm5lfzvhr84vrs07z6npykn20qyl177qy7zxsj2mjmhk413952026/11/07 23:33:17 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13962026/11/07 23:33:17 INFO Uploading 7zgspzacjd0zvdrmjv54gnasj7gsk042-shared-dep (136B)13972026/11/07 23:33:17 INFO Uploading wl46djicc2gb1299zcpp5m6az9gvg81i-a (216B)13982026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes13992026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1400=== NAME TestClientMultipleUploads1401 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads3893071914/001/store/8mdhyqdcsp3zra2khjdn05y9g4bjvixa-test-file-2.txt14022026/11/07 23:33:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14032026/11/07 23:33:17 INFO Uploading vlmkkamg96zr4k6fafi07x140fx394rq-pinned-file.txt (128B)14042026/11/07 23:33:17 WARN Failed to register uploaded object key=j0kjja3i3s569h3n1rgk8yrs5c4r2jcv.ls error="server returned 404: 404 page not found\n"14052026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14062026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/1d3xisinirqpg4bwj05d06hga23pigaqp0bwr1bwnszz0sdsjyjc.nar.zst error="server returned 404: 404 page not found\n"1407=== CONT TestPresentRefreshesOnlyStaleClosures1408--- PASS: TestMetricsInventory (0.38s)1409--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.71s)1410=== CONT TestNARDeduplicationMetadataUploadBug1411--- PASS: TestClientSharedPathCommittedMidPush (0.60s)1412=== CONT TestDeletePinKeepsRowWhenS3Fails14132026/11/07 23:33:17 WARN Failed to register uploaded object key=7zgspzacjd0zvdrmjv54gnasj7gsk042.ls error="server returned 404: 404 page not found\n"14142026/11/07 23:33:17 WARN Failed to register uploaded object key=wl46djicc2gb1299zcpp5m6az9gvg81i.ls error="server returned 404: 404 page not found\n"14152026/11/07 23:33:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14162026/11/07 23:33:17 INFO Signed narinfos id=1 count=314172026/11/07 23:33:17 INFO Uploading 3 narinfos14182026/11/07 23:33:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjFmOTllODZmLTlkMjgtNDA2ZC05NWVjLThmOTQyMzYzYzM3YngxNzk0MDk0Mzk3MDgwMjI4NzI2 parts=1214192026/11/07 23:33:17 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>14202026/11/07 23:33:17 WARN Failed to register uploaded object key=7zgspzacjd0zvdrmjv54gnasj7gsk042.narinfo error="server returned 404: 404 page not found\n"14212026/11/07 23:33:17 INFO Received cleanup request method=DELETE path=/api/pending_closures14222026/11/07 23:33:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14232026/11/07 23:33:17 WARN Failed to register uploaded object key=vlmkkamg96zr4k6fafi07x140fx394rq.ls error="server returned 404: 404 page not found\n"14242026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14252026/11/07 23:33:17 INFO Signed narinfos id=1 count=114262026/11/07 23:33:17 INFO Uploading 1 narinfos14272026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=014282026/11/07 23:33:17 WARN Failed to register uploaded object key=wl46djicc2gb1299zcpp5m6az9gvg81i.narinfo error="server returned 404: 404 page not found\n"14292026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures14302026/11/07 23:33:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14312026/11/07 23:33:17 WARN Failed to register uploaded object key=vlmkkamg96zr4k6fafi07x140fx394rq.narinfo error="server returned 404: 404 page not found\n"14322026/11/07 23:33:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14332026/11/07 23:33:17 WARN Failed to register uploaded object key=j0kjja3i3s569h3n1rgk8yrs5c4r2jcv.narinfo error="server returned 404: 404 page not found\n"1434--- PASS: TestReconnectLeavesObjectsUnlocked (0.33s)1435=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14362026/11/07 23:33:17 INFO Completed push id=1 objects=3 duration=7.834896ms14372026/11/07 23:33:17 INFO Upload complete. (127ms)14382026/11/07 23:33:17 INFO Completed push id=1 objects=8 duration=11.542093ms14392026/11/07 23:33:17 INFO Upload complete. (147ms)1440=== NAME TestClientPushesUseOnePush1441 client_pushes_test.go:97: Retrieved narinfo from S3:1442 StorePath: /build/TestClientPushesUseOnePush4159589532/001/store/7zgspzacjd0zvdrmjv54gnasj7gsk042-shared-dep1443 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1444 Compression: zstd1445 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821446 NarSize: 1361447 References: 1448 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14492026/11/07 23:33:17 INFO Received cleanup request method=DELETE path=/api/pending_closures1450--- PASS: TestReadProxyNarinfo (2.42s)1451=== CONT TestConcurrentPinUpdatesAgree14522026/11/07 23:33:17 INFO Aborted multipart uploads count=1 kept=01453=== NAME TestClientPushesUseOnePush1454 client_pushes_test.go:97: Retrieved narinfo from S3:1455 StorePath: /build/TestClientPushesUseOnePush4159589532/001/store/wl46djicc2gb1299zcpp5m6az9gvg81i-a1456 URL: nar/1d3xisinirqpg4bwj05d06hga23pigaqp0bwr1bwnszz0sdsjyjc.nar.zst1457 Compression: zstd1458 NarHash: sha256:1d3xisinirqpg4bwj05d06hga23pigaqp0bwr1bwnszz0sdsjyjc1459 NarSize: 2161460 References: /build/TestClientPushesUseOnePush4159589532/001/store/7zgspzacjd0zvdrmjv54gnasj7gsk042-shared-dep1461 CA: text:sha256:10rrxdcinnllirds5hpp68igxynffz4kws060m2n53xzp5jy4m2014622026/11/07 23:33:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14632026-11-07 23:33:17.809 UTC [1277] ERROR: Closure does not exist: id=114642026-11-07 23:33:17.809 UTC [1277] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE14652026-11-07 23:33:17.809 UTC [1277] STATEMENT: -- name: CommitPendingClosure :one1466 SELECT commit_pending_closure($1::bigint)::bigint1467 1468 client_pushes_test.go:97: Retrieved narinfo from S3:1469 StorePath: /build/TestClientPushesUseOnePush4159589532/001/store/j0kjja3i3s569h3n1rgk8yrs5c4r2jcv-b1470 URL: nar/1d3xisinirqpg4bwj05d06hga23pigaqp0bwr1bwnszz0sdsjyjc.nar.zst1471 Compression: zstd1472 NarHash: sha256:1d3xisinirqpg4bwj05d06hga23pigaqp0bwr1bwnszz0sdsjyjc1473 NarSize: 2161474 References: /build/TestClientPushesUseOnePush4159589532/001/store/7zgspzacjd0zvdrmjv54gnasj7gsk042-shared-dep1475 CA: text:sha256:10rrxdcinnllirds5hpp68igxynffz4kws060m2n53xzp5jy4m2014762026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures14772026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes1478--- PASS: TestService_cleanupPendingClosuresHandler (0.37s)1479=== CONT TestMultipartCleanup14802026/11/07 23:33:17 INFO lead: released remote=192.0.2.1:123414812026/11/07 23:33:17 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14822026/11/07 23:33:17 INFO Uploading 7ly3csc5009mly4z6hb8r547hdn4rs2g-test-file-0.txt (160B)14832026/11/07 23:33:17 INFO Uploading ncwzs46pd30rs4jgyx6hi7vp51d74mcg-test-file-1.txt (160B)14842026/11/07 23:33:17 INFO Uploading 8mdhyqdcsp3zra2khjdn05y9g4bjvixa-test-file-2.txt (160B)1485--- PASS: TestClientPushesUseOnePush (0.65s)1486=== CONT TestReadRedirectNar14872026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14882026/11/07 23:33:17 WARN Failed to register uploaded object key=8mdhyqdcsp3zra2khjdn05y9g4bjvixa.ls error="server returned 404: 404 page not found\n"14892026/11/07 23:33:17 WARN Failed to register uploaded object key=7ly3csc5009mly4z6hb8r547hdn4rs2g.ls error="server returned 404: 404 page not found\n"14902026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14912026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1492--- PASS: TestLeadEndsOnShutdown (2.54s)1493=== CONT TestOrphanedObjectsGC14942026/11/07 23:33:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14952026/11/07 23:33:17 WARN Refused reserved pin name=worker-x86_64-linux14962026/11/07 23:33:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14972026/11/07 23:33:17 INFO Received create pin request method=POST path=/api/pins/my-app14982026/11/07 23:33:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14992026/11/07 23:33:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15002026/11/07 23:33:17 WARN Failed to register uploaded object key=ncwzs46pd30rs4jgyx6hi7vp51d74mcg.ls error="server returned 404: 404 page not found\n"15012026/11/07 23:33:17 INFO Signed narinfos id=1 count=315022026/11/07 23:33:17 INFO Uploading 3 narinfos15032026/11/07 23:33:17 WARN Failed to register uploaded object key=7ly3csc5009mly4z6hb8r547hdn4rs2g.narinfo error="server returned 404: 404 page not found\n"15042026/11/07 23:33:17 WARN Failed to register uploaded object key=8mdhyqdcsp3zra2khjdn05y9g4bjvixa.narinfo error="server returned 404: 404 page not found\n"15052026/11/07 23:33:17 INFO Received push request method=POST path=/api/pushes1506=== CONT TestSkippedUploadsHandler1507--- PASS: TestCreatePin_ReservedPins (0.41s)15082026/11/07 23:33:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15092026/11/07 23:33:17 INFO Uploading 8gjmzcb3f1iav646a50d6g59cj4a21j8-unpinned-file.txt (128B)15102026/11/07 23:33:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15112026/11/07 23:33:17 WARN Failed to register uploaded object key=ncwzs46pd30rs4jgyx6hi7vp51d74mcg.narinfo error="server returned 404: 404 page not found\n"15122026/11/07 23:33:17 INFO Client skipped oversized paths paths=3 nar_bytes=500000000015132026/11/07 23:33:17 INFO Completed push id=1 objects=9 duration=11.401143ms15142026/11/07 23:33:17 INFO Upload complete. (115ms)1515=== NAME TestClientMultipleUploads1516 client_integration_test.go:478: Uploaded 3 paths in 149.53577ms15172026/11/07 23:33:17 WARN Failed to register uploaded object key=8gjmzcb3f1iav646a50d6g59cj4a21j8.ls error="server returned 404: 404 page not found\n"15182026/11/07 23:33:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15192026/11/07 23:33:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15202026/11/07 23:33:17 INFO Signed narinfos id=2 count=115212026/11/07 23:33:17 INFO Uploading 1 narinfos15222026/11/07 23:33:17 INFO Received complete push request method=POST path=/api/pushes/2/complete15232026/11/07 23:33:17 WARN Failed to register uploaded object key=8gjmzcb3f1iav646a50d6g59cj4a21j8.narinfo error="server returned 404: 404 page not found\n"1524--- PASS: TestSkippedUploadsHandler (0.03s)1525=== CONT TestCreatePinRejectsBadInput15262026/11/07 23:33:17 INFO Completed push id=2 objects=3 duration=2.525938ms15272026/11/07 23:33:17 INFO Upload complete. (71ms)1528--- PASS: TestClientMultipleUploads (0.58s)1529=== CONT TestReadRedirectKeepsNarinfoProxied1530--- PASS: TestObjectStatsTrigger (0.38s)1531=== CONT TestGCTaskStore_ConflictDifferentParams1532--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1533=== CONT TestReadProxyInvalidPath15342026/11/07 23:33:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures15352026/11/07 23:33:17 INFO Garbage collection started1536--- PASS: TestObjectStatsUpdatedOncePerCommit (0.41s)1537=== CONT TestReadProxyHead15382026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures15392026/11/07 23:33:17 INFO Aborted multipart uploads count=0 kept=01540--- PASS: TestPresentReportsOnlyClosureRoots (0.32s)1541=== CONT TestOrphanedObjectsGCStressTest15422026/11/07 23:33:17 WARN Force mode enabled - objects will be deleted immediately without grace period15432026/11/07 23:33:17 INFO Received uploads request method=POST path=/api/pending_closures15442026/11/07 23:33:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15452026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15462026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmI3ZTQ0ODY1LWVmNDItNGFiMi05NGQxLTg2ZWI3ZTVlMWYyZXgxNzk0MDk0Mzk2NzkxMzU0MjYx parts=1015472026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15482026/11/07 23:33:18 INFO Received cleanup request method=DELETE path=/api/pending_closures15492026/11/07 23:33:18 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=015502026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmY1YjI1NjdiLTE3YTgtNGZiZi1iZDU1LTNkMmUzYWQzMzdlMHgxNzk0MDk0Mzk2ODIxNzY4MTUz parts=1015512026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15522026/11/07 23:33:18 INFO Vacuumed table table=pending_closures15532026/11/07 23:33:18 INFO Completed push id=1 objects=4 duration=17.34476ms15542026/11/07 23:33:18 INFO Received push request method=POST path=/api/pushes15552026/11/07 23:33:18 INFO Vacuumed table table=pending_objects15562026/11/07 23:33:18 INFO Vacuumed table table=multipart_uploads15572026/11/07 23:33:18 INFO Vacuumed table table=closures15582026/11/07 23:33:18 INFO Vacuumed table table=objects15592026/11/07 23:33:18 INFO Completed push id=1 objects=4 duration=14.877431ms1560--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.59s)1561=== CONT TestReadProxyDisabled1562=== NAME TestNARDeduplicationMetadataUploadBug1563 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3916990902/001/store/5bsm4vqz99s1mk8rqfmc94y43paxhrxi-file1.txt1564--- PASS: TestPresentRefreshesOnlyStaleClosures (0.31s)1565=== CONT TestCompletedNarNotReofferedAcrossClosures15662026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures1567--- PASS: TestPush_RepeatedRootCommitsOnce (2.76s)1568=== CONT TestReadProxyOutlastsServerWriteTimeout15692026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15702026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/app15712026/11/07 23:33:18 INFO Aborted multipart uploads count=0 kept=015722026/11/07 23:33:18 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15732026/11/07 23:33:18 INFO Received delete pin request method=DELETE path=/api/pins/app15742026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmI5ZjM3ODhlLTRjNzQtNGM5Ni05YWEyLTBmMTMzZmE0ZmIwOXgxNzk0MDk0Mzk2ODc1NzMzODYw parts=1015752026/11/07 23:33:18 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket65/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15762026/11/07 23:33:18 WARN Force mode enabled - objects will be deleted immediately without grace period15772026/11/07 23:33:18 INFO Received delete pin request method=DELETE path=/api/pins/app15782026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/app15792026/11/07 23:33:18 INFO Received push request method=POST path=/api/pushes15802026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/app15812026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15822026/11/07 23:33:18 INFO Deleted pin name=app15832026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures15842026/11/07 23:33:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15852026/11/07 23:33:18 INFO Uploading 5bsm4vqz99s1mk8rqfmc94y43paxhrxi-file1.txt (160B)15862026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjAyODBmZWIyLTQzOWEtNDUxZS1iNzI3LTgyMWQyMDBlNWU1MHgxNzk0MDk0Mzk2Mzg0MjcwMDE4 parts=1015872026/11/07 23:33:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1588--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.42s)1589=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock15902026/11/07 23:33:18 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=015912026/11/07 23:33:18 INFO Vacuumed table table=pending_closures15922026/11/07 23:33:18 INFO Vacuumed table table=pending_objects15932026/11/07 23:33:18 INFO Vacuumed table table=multipart_uploads15942026/11/07 23:33:18 INFO Vacuumed table table=closures15952026/11/07 23:33:18 WARN Failed to register uploaded object key=5bsm4vqz99s1mk8rqfmc94y43paxhrxi.ls error="server returned 404: 404 page not found\n"15962026/11/07 23:33:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15972026/11/07 23:33:18 INFO Vacuumed table table=objects15982026/11/07 23:33:18 INFO Signed narinfos id=1 count=115992026/11/07 23:33:18 INFO Uploading 1 narinfos16002026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16012026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/1/complete16022026/11/07 23:33:18 WARN Failed to register uploaded object key=5bsm4vqz99s1mk8rqfmc94y43paxhrxi.narinfo error="server returned 404: 404 page not found\n"16032026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16042026/11/07 23:33:18 INFO Completed push id=1 objects=3 duration=10.546623ms16052026/11/07 23:33:18 INFO Upload complete. (130ms)1606=== NAME TestNARDeduplicationMetadataUploadBug1607 metadata_upload_test.go:54: Retrieved narinfo from S3:1608 StorePath: /build/TestNARDeduplicationMetadataUploadBug3916990902/001/store/5bsm4vqz99s1mk8rqfmc94y43paxhrxi-file1.txt1609 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1610 Compression: zstd1611 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1612 NarSize: 1601613 References: 1614 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1615 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1616 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1617 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1618--- PASS: TestReadRedirectNar (0.42s)1619=== CONT TestService_AuthMiddleware_OIDC16202026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjFjZmE5NmE2LTVjNmEtNDJkNi05MGM2LWFjMDg0NjYyZjgzMHgxNzk0MDk0Mzk3NjQ0MzI2MDQ2 parts=1016212026/11/07 23:33:18 INFO Received cleanup request method=DELETE path=/api/pending_closures16222026/11/07 23:33:18 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket67/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16232026/11/07 23:33:18 INFO Aborted multipart uploads count=0 kept=116242026/11/07 23:33:18 INFO Received cleanup request method=DELETE path=/api/pending_closures1625=== NAME TestNARDeduplicationMetadataUploadBug1626 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3916990902/001/store/023iy2154wh8m3gfslf0fa0478zizf6l-file2.txt16272026/11/07 23:33:18 INFO Aborted multipart uploads count=1 kept=016282026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16292026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16302026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16312026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16322026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16332026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16342026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16352026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy16362026/11/07 23:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46011/oidc1637--- PASS: TestMultipartCleanup (0.50s)1638=== CONT TestCacheConfigHandler1639=== RUN TestCacheConfigHandler/full_config,_no_issuer1640=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1641=== RUN TestCacheConfigHandler/no_cache_url_configured1642=== PAUSE TestCacheConfigHandler/no_cache_url_configured1643=== RUN TestCacheConfigHandler/no_signing_keys1644=== PAUSE TestCacheConfigHandler/no_signing_keys1645=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1646=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1647=== CONT TestService_ReadScope_PublicByDefault16482026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy1649--- PASS: TestReadProxyInvalidPath (0.40s)1650=== CONT TestPresignedUploadRegisteredBeforeCommit16512026/11/07 23:33:18 INFO Received push request method=POST path=/api/pushes16522026/11/07 23:33:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16532026/11/07 23:33:18 WARN Failed to register uploaded object key=023iy2154wh8m3gfslf0fa0478zizf6l.ls error="server returned 404: 404 page not found\n"16542026/11/07 23:33:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16552026/11/07 23:33:18 INFO Signed narinfos id=2 count=116562026/11/07 23:33:18 INFO Uploading 1 narinfos16572026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16582026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/2/complete16592026/11/07 23:33:18 WARN Failed to register uploaded object key=023iy2154wh8m3gfslf0fa0478zizf6l.narinfo error="server returned 404: 404 page not found\n"16602026/11/07 23:33:18 INFO Completed push id=2 objects=3 duration=2.848028ms16612026/11/07 23:33:18 INFO Upload complete. (112ms)1662=== NAME TestNARDeduplicationMetadataUploadBug1663 metadata_upload_test.go:76: Retrieved narinfo from S3:1664 StorePath: /build/TestNARDeduplicationMetadataUploadBug3916990902/001/store/023iy2154wh8m3gfslf0fa0478zizf6l-file2.txt1665 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1666 Compression: zstd1667 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1668 NarSize: 1601669 References: 1670 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1671 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1672 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1673 {"version":1,"root":{"type":"regular","size":44}}1674--- PASS: TestReadProxyDisabled (0.40s)1675=== CONT TestGCTaskStore_GetEmpty1676=== CONT TestCacheStatsHandler1677--- PASS: TestGCTaskStore_GetEmpty (0.00s)16782026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjU5ZTQxZDcxLWI4MTYtNGU4YS1hODE2LWQwYzE2MjkwZWYzZXgxNzk0MDk0Mzk3MDk5NDQ2NTc1 parts=1216792026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures1680--- PASS: TestNARDeduplicationMetadataUploadBug (0.74s)1681=== CONT TestReadProxyRootRedirectsToIndexHTML1682--- PASS: TestSharedNarBothUploadsComplete (1.84s)1683=== CONT TestService_RequireScope_OIDC1684--- PASS: TestReadRedirectKeepsNarinfoProxied (0.57s)1685=== CONT TestClientFallsBackToClosures1686=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1687=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1688=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1689=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1690=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1691=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1692=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1693=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1694=== CONT TestReadProxyConditionalGet16952026/11/07 23:33:18 INFO lead: released remote=192.0.2.1:123416962026/11/07 23:33:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42373/oidc1697--- PASS: TestReadProxyHead (0.65s)1698=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1699--- PASS: TestService_ReadScope_PublicByDefault (0.28s)1700=== CONT TestService_AuthMiddleware_MTLSProxyHeader17012026/11/07 23:33:18 INFO lead: acquired remote=192.0.2.1:123417022026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures17032026/11/07 23:33:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst17042026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures17052026/11/07 23:33:18 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1706=== NAME TestOrphanedObjectsGC1707 orphaned_objects_gc_test.go:287: GC Test Summary:1708 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1709 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1710 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1711 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1712 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects17132026/11/07 23:33:18 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1714--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.38s)1715=== CONT TestPush_SignsNarinfosOfItsPendingObjects1716--- PASS: TestConcurrentPinUpdatesAgree (0.93s)1717=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1718--- PASS: TestOrphanedObjectsGC (0.88s)1719=== CONT TestClientWithDependencies17202026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17212026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmVmOGI1ZWQ1LTM2M2YtNDcwYi05Y2U1LWU1ZGUxZjE1ZGQyM3gxNzk0MDk0Mzk2ODc2OTk4Mjg5 parts=1017222026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/1/complete17232026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17242026/11/07 23:33:18 INFO Completed push id=1 objects=6 duration=11.879373ms1725--- PASS: TestCacheStatsHandler (0.33s)1726=== CONT TestService_AuthMiddleware1727--- PASS: TestPush_CompleteCommitsEveryRoot (3.48s)1728=== CONT TestClientIntegration17292026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjc0Y2E0ZTZiLTJlMTEtNGNhZS05YWMxLTE0M2YwZjliNWNkMXgxNzk0MDk0Mzk2MzgzNjk2MDQ4 parts=101730--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.34s)1731=== CONT TestService_ReadAuthMiddleware17322026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17332026/11/07 23:33:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17342026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjYxYmExZDA1LWM0ZTctNDAzNS1iM2I3LWY3MjViNWYyMTRhZXgxNzk0MDk0Mzk4MDUyMTgzNjE5 parts=1017352026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/2/complete17362026/11/07 23:33:18 INFO Completed push id=2 objects=4 duration=12.012283ms17372026/11/07 23:33:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjlhYzAyODZmLWYzZjMtNGRlOC04NmVhLWI4Mjg0ZDdjZWMwMngxNzk0MDk0Mzk3NjQ0NDA2NTI2 parts=1017382026/11/07 23:33:18 INFO Received complete push request method=POST path=/api/pushes/1/complete1739=== RUN TestService_RequireScope_OIDC/builder_may_write1740=== PAUSE TestService_RequireScope_OIDC/builder_may_write1741=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1742=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1743=== RUN TestService_RequireScope_OIDC/ops_may_admin1744=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1745=== RUN TestService_RequireScope_OIDC/ops_may_not_write1746=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1747=== RUN TestService_RequireScope_OIDC/reader_may_not_write1748=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1749=== RUN TestService_RequireScope_OIDC/static_token_may_admin1750=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1751=== RUN TestService_RequireScope_OIDC/static_token_may_write1752=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1753=== RUN TestService_RequireScope_OIDC/reader_may_read17542026/11/07 23:33:18 INFO Completed push id=1 objects=4 duration=12.192103ms1755=== PAUSE TestService_RequireScope_OIDC/reader_may_read1756=== RUN TestService_RequireScope_OIDC/writer_implies_read1757=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1758=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1759=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1760=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1761=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1762=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1763=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1764=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1765=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1766=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1767=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1768=== CONT TestAbortSucceeded1769--- PASS: TestAbortSucceeded (0.00s)1770=== CONT TestService_Rustfstest17712026/11/07 23:33:18 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17722026/11/07 23:33:18 INFO Completed upload id=2 objects=2 duration=2.872718ms1773--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.62s)1774=== CONT TestDeleteClosuresRacingPins17752026/11/07 23:33:18 INFO Received uploads request method=POST path=/api/pending_closures1776=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17772026/11/07 23:33:18 INFO Received create pin request method=POST path=/api/pins/deploy1778--- PASS: TestMetricsCommit (1.64s)17792026/11/07 23:33:19 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1780--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.43s)1781=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1782--- PASS: TestCreatePinRejectsBadInput (1.13s)1783=== CONT TestGCEndsOnShutdown/before_the_run17842026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures17852026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures17862026/11/07 23:33:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17872026/11/07 23:33:19 INFO Uploading pvwr5zhvnrg4v3z1k0893w1c0h3liipc-b (216B)17882026/11/07 23:33:19 INFO Uploading m5sspb5vmvs0k9hw7siqrlszw9qcxdq0-shared-dep (136B)17892026/11/07 23:33:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17902026/11/07 23:33:19 WARN mTLS auth: bound subjects configured but subject DN unavailable17912026/11/07 23:33:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"17922026/11/07 23:33:19 WARN Failed to register uploaded object key=6rms8x2q8gn9xw3i2dj1d79x4bhj44a9.ls error="server returned 404: 404 page not found\n"17932026/11/07 23:33:19 WARN Failed to register uploaded object key=nar/1m8pma46jp65g4jchaqdq4k2j9wcwm255gd0x7y7qlas9f920wzr.nar.zst error="server returned 404: 404 page not found\n"1794--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)17952026/11/07 23:33:19 WARN Failed to register uploaded object key=pvwr5zhvnrg4v3z1k0893w1c0h3liipc.ls error="server returned 404: 404 page not found\n"1796=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed17972026/11/07 23:33:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17982026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes17992026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18002026/11/07 23:33:19 WARN Failed to register uploaded object key=m5sspb5vmvs0k9hw7siqrlszw9qcxdq0.ls error="server returned 404: 404 page not found\n"18012026/11/07 23:33:19 INFO Signed narinfos id=1 count=218022026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18032026/11/07 23:33:19 INFO Signed narinfos id=2 count=218042026/11/07 23:33:19 INFO Uploading 4 narinfos1805=== NAME TestClientWithDependencies1806 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies4130535445/001/store/dk65avmckygri3x6dq95zbqn76pmdivw-test-script18072026/11/07 23:33:19 WARN Failed to register uploaded object key=6rms8x2q8gn9xw3i2dj1d79x4bhj44a9.narinfo error="server returned 404: 404 page not found\n"18082026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18092026/11/07 23:33:19 INFO Signed narinfos id=1 count=118102026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18112026/11/07 23:33:19 WARN Failed to register uploaded object key=m5sspb5vmvs0k9hw7siqrlszw9qcxdq0.narinfo error="server returned 404: 404 page not found\n"18122026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18132026/11/07 23:33:19 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"18142026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18152026/11/07 23:33:19 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"18162026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18172026/11/07 23:33:19 WARN Failed to register uploaded object key=pvwr5zhvnrg4v3z1k0893w1c0h3liipc.narinfo error="server returned 404: 404 page not found\n"18182026/11/07 23:33:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18192026/11/07 23:33:19 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=118202026/11/07 23:33:19 WARN Failed to register uploaded object key=m5sspb5vmvs0k9hw7siqrlszw9qcxdq0.narinfo error="server returned 404: 404 page not found\n"18212026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18222026/11/07 23:33:19 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo18232026/11/07 23:33:19 INFO Completed upload id=1 objects=6 duration=10.170033ms18242026/11/07 23:33:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18252026/11/07 23:33:19 INFO Completed upload id=2 objects=6 duration=2.175298ms18262026/11/07 23:33:19 INFO Upload complete. (169ms)1827=== NAME TestClientFallsBackToClosures1828 client_pushes_test.go:112: Retrieved narinfo from S3:1829 StorePath: /build/TestClientFallsBackToClosures3472510199/001/store/m5sspb5vmvs0k9hw7siqrlszw9qcxdq0-shared-dep1830 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1831 Compression: zstd1832 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821833 NarSize: 1361834 References: 1835 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1836=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1837--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.44s)1838=== NAME TestClientWithDependencies1839 client_integration_test.go:724: Found 1 dependencies (including self)1840=== NAME TestClientFallsBackToClosures1841 client_pushes_test.go:112: Retrieved narinfo from S3:1842 StorePath: /build/TestClientFallsBackToClosures3472510199/001/store/6rms8x2q8gn9xw3i2dj1d79x4bhj44a9-a1843 URL: nar/1m8pma46jp65g4jchaqdq4k2j9wcwm255gd0x7y7qlas9f920wzr.nar.zst1844 Compression: zstd1845 NarHash: sha256:1m8pma46jp65g4jchaqdq4k2j9wcwm255gd0x7y7qlas9f920wzr1846 NarSize: 2161847 References: /build/TestClientFallsBackToClosures3472510199/001/store/m5sspb5vmvs0k9hw7siqrlszw9qcxdq0-shared-dep1848 CA: text:sha256:1xwhns4dnmi9df9fvc8llfy90s1zk9n198992b9n2315px2zdvyy1849 client_pushes_test.go:112: Retrieved narinfo from S3:18502026/11/07 23:33:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1851 StorePath: /build/TestClientFallsBackToClosures3472510199/001/store/pvwr5zhvnrg4v3z1k0893w1c0h3liipc-b1852 URL: nar/1m8pma46jp65g4jchaqdq4k2j9wcwm255gd0x7y7qlas9f920wzr.nar.zst1853 Compression: zstd1854 NarHash: sha256:1m8pma46jp65g4jchaqdq4k2j9wcwm255gd0x7y7qlas9f920wzr1855 NarSize: 2161856 References: /build/TestClientFallsBackToClosures3472510199/001/store/m5sspb5vmvs0k9hw7siqrlszw9qcxdq0-shared-dep1857 CA: text:sha256:1xwhns4dnmi9df9fvc8llfy90s1zk9n198992b9n2315px2zdvyy18582026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1859=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed1860--- PASS: TestService_AuthMiddleware (0.41s)1861=== NAME TestClientIntegration1862 client_integration_test.go:331: Created store path: /build/TestClientIntegration1143247764/002/store/1w7ya7ahz2z092zb02034c2aap796xk9-test-file.txt18632026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjFkZDQzM2VhLWMyMGEtNDBmMC1iNGJhLTBjODhlZjQ2MzgyYngxNzk0MDk0Mzk4NDgyMTM0NjMw parts=1218642026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures1865--- PASS: TestReadProxyConditionalGet (0.65s)1866=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1867--- PASS: TestClientFallsBackToClosures (0.71s)1868=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1869--- PASS: TestService_ReadAuthMiddleware (0.40s)1870=== CONT TestServerTLSConfig/no_client_CA1871=== CONT TestServerTLSConfig/not_a_PEM_file1872=== CONT TestServerTLSConfig/missing_CA_file1873=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1874--- PASS: TestServerTLSConfig (0.01s)1875 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1876 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1877 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)18782026/11/07 23:33:19 INFO Received uploads request method=POST path=/1879=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1880--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.06s)18812026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/1882--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.17s)1883=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18842026/11/07 23:33:19 INFO Received request for more parts method=POST path=/18852026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes18862026/11/07 23:33:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18872026/11/07 23:33:19 INFO Uploading dk65avmckygri3x6dq95zbqn76pmdivw-test-script (136B)18882026/11/07 23:33:19 WARN Failed to register uploaded object key=log/igakpvwbr2rbq8iijl3bim02ckwh5agl-test-script.drv error="server returned 404: 404 page not found\n"18892026/11/07 23:33:19 WARN Failed to register uploaded object key=dk65avmckygri3x6dq95zbqn76pmdivw.ls error="server returned 404: 404 page not found\n"18902026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18912026/11/07 23:33:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18922026/11/07 23:33:19 INFO Signed narinfos id=1 count=118932026/11/07 23:33:19 INFO Uploading 1 narinfos18942026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/1/complete18952026/11/07 23:33:19 WARN Failed to register uploaded object key=dk65avmckygri3x6dq95zbqn76pmdivw.narinfo error="server returned 404: 404 page not found\n"18962026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes18972026/11/07 23:33:19 INFO Completed push id=1 objects=4 duration=6.668616ms18982026/11/07 23:33:19 INFO Upload complete. (96ms)18992026/11/07 23:33:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19002026/11/07 23:33:19 INFO Uploading 1w7ya7ahz2z092zb02034c2aap796xk9-test-file.txt (152B)1901--- PASS: TestService_Rustfstest (0.38s)1902=== CONT TestPush_RejectsBadRequests/no_roots19032026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes1904=== CONT TestPush_RejectsBadRequests/root_not_in_objects19052026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes1906=== CONT TestPush_RejectsBadRequests/bad_root19072026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes1908=== CONT TestPush_RejectsBadRequests/no_objects19092026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes1910=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19112026/11/07 23:33:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19122026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=019132026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period19142026/11/07 23:33:19 WARN Failed to register uploaded object key=1w7ya7ahz2z092zb02034c2aap796xk9.ls error="server returned 404: 404 page not found\n"19152026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19162026/11/07 23:33:19 INFO Signed narinfos id=1 count=119172026/11/07 23:33:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019182026/11/07 23:33:19 INFO Uploading 1 narinfos1919--- PASS: TestPush_RejectsBadRequests (1.32s)1920 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1921 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1922 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1923 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19242026/11/07 23:33:19 INFO Vacuumed table table=pending_closures19252026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/1/complete19262026/11/07 23:33:19 WARN Failed to register uploaded object key=1w7ya7ahz2z092zb02034c2aap796xk9.narinfo error="server returned 404: 404 page not found\n"19272026/11/07 23:33:19 INFO Vacuumed table table=pending_objects19282026/11/07 23:33:19 INFO Vacuumed table table=multipart_uploads19292026/11/07 23:33:19 INFO Vacuumed table table=closures19302026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=019312026/11/07 23:33:19 INFO Vacuumed table table=objects1932=== NAME TestClientWithDependencies1933 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4130535445/001/store) requires matching store prefix19342026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period19352026/11/07 23:33:19 INFO Completed push id=1 objects=3 duration=11.222523ms19362026/11/07 23:33:19 INFO Upload complete. (98ms)19372026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=01938--- PASS: TestClientWithDependencies (0.63s)1939=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19402026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period19412026/11/07 23:33:19 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34955/bucket98/?delete=\": context canceled"1942=== CONT TestClientErrorHandling/InvalidStorePath19432026/11/07 23:33:19 INFO All 1 paths already cached1944=== NAME TestClientIntegration1945 client_integration_test.go:357: Retrieved narinfo from S3:1946 StorePath: /build/TestClientIntegration1143247764/002/store/1w7ya7ahz2z092zb02034c2aap796xk9-test-file.txt1947 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1948 Compression: zstd1949 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11950 NarSize: 1521951 References: 1952 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119532026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1954=== CONT TestClientErrorHandling/ServerNotAvailable1955=== NAME TestClientIntegration1956 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1957 client_integration_test.go:358: Decompressed .ls content (64 bytes):1958 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1959=== CONT TestClientErrorHandling/InvalidAuthToken1960--- PASS: TestGCEndsOnShutdown (0.01s)1961 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.40s)1962 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.36s)1963 --- PASS: TestGCEndsOnShutdown/before_the_run (0.37s)19642026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures19652026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjM5NTJlYzdkLTgzYTUtNDljOS1hMTZiLTVjM2ZhYmNkY2Q1NHgxNzk0MDk0Mzk2Mzg2NDc0OTI3 parts=1019662026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures19672026/11/07 23:33:19 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/present19682026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures19692026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19702026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes19712026/11/07 23:33:19 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjQxYThjYTI3LTc3ZDQtNDc2Zi04M2U5LWEyYzE2NGRmNzQ5MngxNzk0MDk0Mzk4OTg2ODk4NzA219722026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures19732026/11/07 23:33:19 INFO Object in database but missing from S3 key=1w7ya7ahz2z092zb02034c2aap796xk9.ls19742026/11/07 23:33:19 WARN Found objects in DB but missing from S3, will re-upload count=119752026/11/07 23:33:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19762026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjQxYThjYTI3LTc3ZDQtNDc2Zi04M2U5LWEyYzE2NGRmNzQ5MngxNzk0MDk0Mzk4OTg2ODk4NzA2 parts=119772026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/2/complete19782026/11/07 23:33:19 WARN Failed to register uploaded object key=1w7ya7ahz2z092zb02034c2aap796xk9.ls error="server returned 404: 404 page not found\n"19792026/11/07 23:33:19 INFO Completed push id=2 objects=3 duration=2.593299ms19802026/11/07 23:33:19 INFO Upload complete. (69ms)1981=== NAME TestClientIntegration1982 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1983 client_integration_test.go:375: Decompressed .ls content (49 bytes):1984 {"version":1,"root":{"type":"regular","size":39}}1985=== CONT TestResolveDBConnectionString/flag_wins1986--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.95s)19872026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures1988=== CONT TestResolveDBConnectionString/nothing_configured1989=== CONT TestResolveDBConnectionString/missing_file_is_an_error1990=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1991=== CONT TestResolveDBConnectionString/file_when_flag_empty1992=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1993=== CONT TestIsValidCachePath/traversal_parent1994=== CONT TestIsValidCachePath/wrong_extension1995=== CONT TestIsValidCachePath/nar_uncompressed1996=== CONT TestIsValidCachePath/short_hash1997=== CONT TestIsValidCachePath/nix-cache-info1998=== CONT TestIsValidCachePath/empty1999=== CONT TestIsValidCachePath/ls2000=== CONT TestIsValidCachePath/leading_slash2001--- PASS: TestResolveDBConnectionString (0.00s)2002 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2003 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2004 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2005 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2006 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2007=== CONT TestIsValidCachePath/nar_xz2008=== CONT TestIsValidCachePath/invalid_char_e2009=== CONT TestIsValidCachePath/invalid_char_u2010=== CONT TestIsValidCachePath/random_path2011=== CONT TestIsValidCachePath/index.html2012=== CONT TestIsValidCachePath/narinfo2013=== CONT TestIsValidCachePath/nar_zst2014=== CONT TestIsValidCachePath/nar_bz22015=== CONT TestIsValidCachePath/log2016=== CONT TestIsValidCachePath/traversal_in_middle2017=== CONT TestIsValidCachePath/realisation2018=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2019--- PASS: TestIsValidCachePath (0.01s)2020 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2021 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2022 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2023 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2024 --- PASS: TestIsValidCachePath/short_hash (0.00s)2025 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2026 --- PASS: TestIsValidCachePath/empty (0.00s)2027 --- PASS: TestIsValidCachePath/ls (0.00s)2028 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2029 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2030 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2031 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2032 --- PASS: TestIsValidCachePath/random_path (0.00s)2033 --- PASS: TestIsValidCachePath/index.html (0.00s)2034 --- PASS: TestIsValidCachePath/narinfo (0.00s)2035 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2036 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2037 --- PASS: TestIsValidCachePath/log (0.00s)2038 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2039 --- PASS: TestIsValidCachePath/realisation (0.00s)20402026/11/07 23:33:19 INFO Received request for more parts method=POST path=/2041=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20422026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/2043=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20442026/11/07 23:33:19 INFO Received uploads request method=POST path=/2045=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20462026/11/07 23:33:19 INFO Received uploads request method=POST path=/2047=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2048--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2049 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2050 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2051 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2052 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)20532026/11/07 23:33:19 WARN Request failed, retrying attempt=2 backoff=184.473446ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20542026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures20552026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=020562026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period20572026/11/07 23:33:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020582026/11/07 23:33:19 INFO Vacuumed table table=pending_closures20592026/11/07 23:33:19 INFO Vacuumed table table=pending_objects20602026/11/07 23:33:19 INFO Vacuumed table table=multipart_uploads20612026/11/07 23:33:19 INFO Vacuumed table table=closures20622026/11/07 23:33:19 INFO Vacuumed table table=objects20632026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes20642026/11/07 23:33:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20652026/11/07 23:33:19 WARN Failed to register uploaded object key=1w7ya7ahz2z092zb02034c2aap796xk9.ls error="server returned 404: 404 page not found\n"20662026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/3/complete20672026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures20682026/11/07 23:33:19 INFO Completed push id=3 objects=3 duration=3.571718ms20692026/11/07 23:33:19 INFO Upload complete. (59ms)2070=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2071=== NAME TestClientIntegration2072 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)2073 client_integration_test.go:392: Decompressed .ls content (49 bytes):2074 {"version":1,"root":{"type":"regular","size":39}}20752026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=02076=== CONT TestIsValidUploadKey/narinfo2077=== CONT TestIsValidUploadKey/build_log_equals2078=== CONT TestIsValidUploadKey/unknown_type2079=== CONT TestIsValidUploadKey/build_log_question_mark20802026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period2081=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2082=== CONT TestIsValidUploadKey/build_log_plus_in_name2083=== CONT TestIsValidUploadKey/build_log2084=== CONT TestIsValidUploadKey/nar_plain2085=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2086=== CONT TestIsValidUploadKey/traversal2087=== CONT TestIsValidUploadKey/build_log_home-manager_file2088=== CONT TestIsValidUploadKey/listing2089=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2090=== CONT TestIsValidUploadKey/absolute2091=== CONT TestIsValidUploadKey/nix-cache-info2092=== CONT TestIsValidUploadKey/empty_key2093=== CONT TestIsValidUploadKey/realisation_plus_in_output2094=== CONT TestIsValidUploadKey/traversal_nar2095=== CONT TestIsValidUploadKey/realisation2096=== CONT TestIsValidUploadKey/index.html2097=== CONT TestIsValidUploadKey/nar_xz2098=== CONT TestIsValidUploadKey/nar_zst2099=== CONT TestParseSingleRange/none2100=== CONT TestParseSingleRange/open-ended2101=== CONT TestParseSingleRange/start_past_EOF2102--- PASS: TestIsValidUploadKey (0.01s)2103 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2104 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2105 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2106 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2107 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2108 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2109 --- PASS: TestIsValidUploadKey/build_log (0.00s)2110 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2111 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2112 --- PASS: TestIsValidUploadKey/traversal (0.00s)2113 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2114 --- PASS: TestIsValidUploadKey/listing (0.00s)2115 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2116 --- PASS: TestIsValidUploadKey/absolute (0.00s)2117 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2118 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2119 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2120 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2121 --- PASS: TestIsValidUploadKey/realisation (0.00s)2122 --- PASS: TestIsValidUploadKey/index.html (0.00s)2123 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2124 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2125=== CONT TestParseSingleRange/suffix_exceeds_size2126=== CONT TestParseSingleRange/start_far_past_EOF2127=== CONT TestParseSingleRange/single_byte2128=== CONT TestParseSingleRange/suffix2129=== CONT TestParseSingleRange/closed2130=== CONT TestParseSingleRange/malformed_both_empty2131=== CONT TestParseSingleRange/unknown_unit2132=== CONT TestParseSingleRange/multi-range_ignored2133=== CONT TestParseSingleRange/end_clamped_to_size2134=== CONT TestParseSingleRange/malformed_end_before_start2135=== CONT TestParseSingleRange/malformed_no_dash2136=== CONT TestProxyWriteTimeout/narinfo2137--- PASS: TestParseSingleRange (0.00s)2138 --- PASS: TestParseSingleRange/none (0.00s)2139 --- PASS: TestParseSingleRange/open-ended (0.00s)2140 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2141 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2142 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2143 --- PASS: TestParseSingleRange/single_byte (0.00s)2144 --- PASS: TestParseSingleRange/suffix (0.00s)2145 --- PASS: TestParseSingleRange/closed (0.00s)2146 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2147 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2148 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2149 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2150 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2151 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2152=== CONT TestProxyWriteTimeout/10_GiB_nar2153=== CONT TestProxyWriteTimeout/unknown_size2154=== CONT TestProxyWriteTimeout/1_GiB_nar2155=== CONT TestPendingClosureWriteTimeout/empty2156--- PASS: TestProxyWriteTimeout (0.00s)2157 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2158 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2159 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2160 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2161=== CONT TestPendingClosureWriteTimeout/400_objects2162=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline21632026-11-07 23:33:19.692 UTC [176] LOG: checkpoints are occurring too frequently (10 seconds apart)21642026-11-07 23:33:19.692 UTC [176] HINT: Consider increasing the configuration parameter "max_wal_size".21652026-11-07 23:33:19.692 UTC [176] LOG: checkpoint starting: wal21662026/11/07 23:33:19 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=021672026/11/07 23:33:19 INFO Vacuumed table table=pending_closures21682026/11/07 23:33:19 INFO Vacuumed table table=pending_objects21692026/11/07 23:33:19 INFO Vacuumed table table=multipart_uploads21702026/11/07 23:33:19 INFO Vacuumed table table=closures21712026/11/07 23:33:19 INFO Vacuumed table table=objects21722026/11/07 23:33:19 INFO lead: released remote=192.0.2.1:12342173--- PASS: TestLeadElectsOneAndHandsOver (2.72s)2174=== CONT TestPendingClosureWriteTimeout/670k_objects2175=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2176=== CONT TestCacheConfigHandler/no_signing_keys2177=== CONT TestCacheConfigHandler/no_cache_url_configured21782026/11/07 23:33:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2179=== CONT TestCacheConfigHandler/full_config,_no_issuer2180=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2181--- PASS: TestCacheConfigHandler (0.00s)2182 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2183 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2184 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2185 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2186=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2187=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21882026/11/07 23:33:19 WARN Authentication failed token_preview=eyJhbGciOi...dQgTA2h9lA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2189=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21902026/11/07 23:33:19 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]2191=== CONT TestService_RequireScope_OIDC/ops_may_admin2192=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2193=== CONT TestService_RequireScope_OIDC/static_token_may_admin2194=== CONT TestService_RequireScope_OIDC/ops_may_not_write2195=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2196=== CONT TestService_RequireScope_OIDC/static_token_may_write2197=== CONT TestService_RequireScope_OIDC/writer_implies_read2198--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2199 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.35s)2200 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.40s)2201=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2202=== CONT TestService_RequireScope_OIDC/builder_may_write2203=== CONT TestService_RequireScope_OIDC/reader_may_read2204=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2205=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2206=== CONT TestService_RequireScope_OIDC/reader_may_not_write2207=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22082026/11/07 23:33:19 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]22092026/11/07 23:33:19 WARN Request failed, retrying attempt=3 backoff=431.035995ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22102026/11/07 23:33:19 INFO Received push request method=POST path=/api/pushes2211--- PASS: TestService_AuthMiddleware_OIDC (0.32s)2212 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2213 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2214 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2215 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)22162026/11/07 23:33:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22172026/11/07 23:33:19 INFO Uploading kb93m8akr3a0rr800mxrh7dbld4hz03f-lost-commit.txt (152B)2218--- PASS: TestService_RequireScope_OIDC (0.45s)2219 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2220 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2221 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2222 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2223 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2224 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2225 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2226 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2227 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2228 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2229 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2230 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2231 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2232 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)22332026/11/07 23:33:19 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22342026/11/07 23:33:19 WARN Failed to register uploaded object key=kb93m8akr3a0rr800mxrh7dbld4hz03f.ls error="server returned 404: 404 page not found\n"22352026/11/07 23:33:19 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign22362026/11/07 23:33:19 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"22372026/11/07 23:33:19 INFO Signed narinfos id=4 count=122382026/11/07 23:33:19 INFO Uploading 1 narinfos22392026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/4/complete22402026/11/07 23:33:19 WARN Failed to register uploaded object key=kb93m8akr3a0rr800mxrh7dbld4hz03f.narinfo error="server returned 404: 404 page not found\n"22412026/11/07 23:33:19 INFO Completed push id=4 objects=3 duration=2.093479ms22422026/11/07 23:33:19 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33383/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33383/api/pushes/4/complete22432026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures22442026/11/07 23:33:19 INFO Received complete push request method=POST path=/api/pushes/4/complete22452026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22462026-11-07 23:33:19.940 UTC [1890] ERROR: Push does not exist: id=422472026-11-07 23:33:19.940 UTC [1890] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE22482026-11-07 23:33:19.940 UTC [1890] STATEMENT: -- name: CommitPush :one2249 SELECT commit_push($1::bigint)::bigint2250 22512026/11/07 23:33:19 WARN Push not found id=422522026/11/07 23:33:19 INFO Upload complete. (213ms)2253=== NAME TestClientIntegration2254 client_integration_test.go:422: Retrieved narinfo from S3:2255 StorePath: /build/TestClientIntegration1143247764/002/store/kb93m8akr3a0rr800mxrh7dbld4hz03f-lost-commit.txt2256 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2257 Compression: zstd2258 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2259 NarSize: 1522260 References: 2261 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl22622026/11/07 23:33:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02263 client_integration_test.go:425: Testing garbage collection...22642026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22652026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjRlMWI1YmQ0LTM4MGMtNDA3MS1hMzlkLWVmYjc0YTc0MDlhNHgxNzk0MDk0Mzk2Mzg0MzUwODM4 parts=1022662026/11/07 23:33:19 INFO Received create pin request method=POST path=/api/pins/myapp22672026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22682026/11/07 23:33:19 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1198448043/001/store/vlmkkamg96zr4k6fafi07x140fx394rq-pinned-file.txt narinfo_key=vlmkkamg96zr4k6fafi07x140fx394rq.narinfo22692026/11/07 23:33:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures22702026/11/07 23:33:19 INFO Garbage collection started22712026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmZiNGEwOTVlLTc2MmEtNGYwZS1iYTRlLTM1YTY4M2E3NjUyY3gxNzk0MDk0Mzk5NDE5MTU5NjA1 parts=1022722026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=022732026/11/07 23:33:19 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjVjYzVlZWYyLTE0YmUtNDBkNi05OTNhLThiZmRkMmYzZjlmNHgxNzk0MDk0Mzk5NDQ5NjU1ODc3 parts=1022742026/11/07 23:33:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22752026/11/07 23:33:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22762026/11/07 23:33:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures22772026/11/07 23:33:19 INFO Garbage collection started22782026/11/07 23:33:19 INFO Completed upload id=1 objects=3 duration=4.604197ms22792026/11/07 23:33:19 INFO Completed upload id=1 objects=3 duration=5.314727ms22802026/11/07 23:33:19 INFO Received uploads request method=POST path=/api/pending_closures22812026/11/07 23:33:19 WARN Force mode enabled - objects will be deleted immediately without grace period22822026/11/07 23:33:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22832026-11-07 23:33:19.995 UTC [771] ERROR: could not obtain lock on row in relation "closures"22842026-11-07 23:33:19.995 UTC [771] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22852026-11-07 23:33:19.996 UTC [771] ERROR: could not obtain lock on row in relation "closures"22862026-11-07 23:33:19.996 UTC [771] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22872026/11/07 23:33:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022882026/11/07 23:33:19 INFO Aborted multipart uploads count=0 kept=022892026-11-07 23:33:19.997 UTC [771] ERROR: could not obtain lock on row in relation "closures"22902026-11-07 23:33:19.997 UTC [771] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22912026-11-07 23:33:19.997 UTC [771] ERROR: could not obtain lock on row in relation "closures"22922026-11-07 23:33:19.997 UTC [771] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22932026-11-07 23:33:19.998 UTC [771] ERROR: could not obtain lock on row in relation "closures"22942026-11-07 23:33:19.998 UTC [771] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22952026/11/07 23:33:19 INFO Vacuumed table table=pending_closures22962026/11/07 23:33:20 INFO Vacuumed table table=pending_objects22972026/11/07 23:33:20 INFO Vacuumed table table=multipart_uploads22982026/11/07 23:33:20 WARN Force mode enabled - objects will be deleted immediately without grace period22992026/11/07 23:33:20 INFO Vacuumed table table=closures23002026/11/07 23:33:20 INFO Vacuumed table table=objects23012026/11/07 23:33:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjk4ODNmMGU1LWRjZWUtNGRkOS04YTc0LTkzYThmODM1MWJiNXgxNzk0MDk0Mzk5NDg4NjIxNDAz parts=1023022026/11/07 23:33:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23032026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23042026/11/07 23:33:20 INFO Completed upload id=1 objects=3 duration=4.129987ms23052026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23062026/11/07 23:33:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst23072026/11/07 23:33:20 WARN Found objects in DB but missing from S3, will re-upload count=123082026/11/07 23:33:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2309--- PASS: TestPush_RootsAreLockedInByteOrder (4.72s)23102026/11/07 23:33:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjk1ZGQ4ZTA1LTcxY2UtNGU1ZS1iYzNkLTg2MTMwMTQ1YWJjOXgxNzk0MDk0Mzk5NTE3MTc3OTU2 parts=1023112026/11/07 23:33:20 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=023122026/11/07 23:33:20 INFO Vacuumed table table=pending_closures23132026/11/07 23:33:20 INFO Vacuumed table table=pending_objects23142026/11/07 23:33:20 INFO Vacuumed table table=multipart_uploads23152026/11/07 23:33:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23162026/11/07 23:33:20 INFO Vacuumed table table=closures23172026/11/07 23:33:20 INFO Completed upload id=1 objects=3 duration=4.378587ms23182026/11/07 23:33:20 INFO Vacuumed table table=objects23192026/11/07 23:33:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23202026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23212026/11/07 23:33:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst23222026/11/07 23:33:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo23232026/11/07 23:33:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLmM4ODk1NWExLWI3OTAtNGE0Mi05MDUxLTAwZjMwNGUzYjlhMXgxNzk0MDk0Mzk5NTYxNzU4MDU5 parts=1023242026/11/07 23:33:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23252026/11/07 23:33:20 INFO Completed upload id=1 objects=3 duration=3.909568ms23262026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23272026/11/07 23:33:20 WARN Request failed, retrying attempt=4 backoff=755.20937ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2328--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2329 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.70s)2330 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.71s)2331--- PASS: TestDeleteClosuresRacingPins (1.45s)23322026/11/07 23:33:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23332026/11/07 23:33:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjVlZTBlNTBhLTg5ZWEtNDk4Ni05NDQ2LTQzODUzODc3YjMxY3gxNzk0MDk0Mzk5OTkyNjU4Nzcw parts=1023342026/11/07 23:33:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23352026/11/07 23:33:20 INFO Completed upload id=2 objects=3 duration=2.413308ms23362026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23372026/11/07 23:33:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst23382026/11/07 23:33:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2339--- PASS: TestPendingClosureWriteTimeout (0.00s)2340 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2341 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2342 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2343 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)2344=== NAME TestOrphanedObjectsGCStressTest2345 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains23462026/11/07 23:33:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2347 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23482026/11/07 23:33:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NmJmN2YwOTgtZmQ1OC00MjhmLTljOGYtZDRmNDQ1YWIxODYwLjMzNzk5ODA0LWM5MDQtNDgwYi05YmExLWYyZjY1NDM1Mjc5Y3gxNzk0MDk0NDAwMTUxMjY0ODQ1 parts=1023492026/11/07 23:33:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23502026/11/07 23:33:20 INFO Completed upload id=2 objects=3 duration=1.574629ms23512026/11/07 23:33:20 INFO Received uploads request method=POST path=/api/pending_closures23522026/11/07 23:33:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst23532026/11/07 23:33:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2354--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.01s)2355 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.88s)2356 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.84s)2357 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.95s)2358 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (1.59s)2359 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (1.69s)23602026/11/07 23:33:20 WARN Request failed, retrying attempt=5 backoff=1.580862656s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23612026/11/07 23:33:21 WARN Rate limiter enabled after throttle name=s3-test rate=523622026/11/07 23:33:21 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2363=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2364 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102365 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002366--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.31s)2367=== NAME TestPinProtectsFromGC2368 client_integration_test.go:963: Pin successfully protected closure from garbage collection23692026/11/07 23:33:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02370=== NAME TestClientIntegration2371 client_integration_test.go:432: Objects in database after GC:2372 client_integration_test.go:432: Successfully deleted all objects with GC --force2373--- PASS: TestPinProtectsFromGC (4.78s)2374--- PASS: TestClientIntegration (3.23s)2375=== NAME TestOrphanedObjectsGCStressTest2376 orphaned_objects_gc_test.go:503: Stress test completed successfully:2377 orphaned_objects_gc_test.go:504: - Active objects preserved: 202378 orphaned_objects_gc_test.go:505: - Objects deleted: 2102379 orphaned_objects_gc_test.go:506: - Total GC'd: 2102380--- PASS: TestConnectWaitsForAPeerMigration (5.19s)2381--- PASS: TestOrphanedObjectsGCStressTest (4.28s)23822026/11/07 23:33:22 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-config23832026/11/07 23:33:22 WARN Request failed, retrying attempt=2 backoff=182.156735ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23842026/11/07 23:33:22 WARN Request failed, retrying attempt=3 backoff=418.860868ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2385--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.87s)23862026/11/07 23:33:23 WARN Request failed, retrying attempt=4 backoff=744.782865ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23872026/11/07 23:33:24 WARN Request failed, retrying attempt=5 backoff=1.544742086s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23882026/11/07 23:33:24 INFO Aborted multipart uploads count=1 kept=023892026/11/07 23:33:24 INFO Received cleanup request method=DELETE path=/api/pending_closures23902026/11/07 23:33:24 INFO Aborted multipart uploads count=1 kept=02391--- PASS: TestPendingCleanupUsesOneCutoff (6.40s)23922026/11/07 23:33:25 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"23932026/11/07 23:33:25 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-config23942026/11/07 23:33:25 WARN Request failed, retrying attempt=2 backoff=193.736417ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23952026/11/07 23:33:25 WARN Request failed, retrying attempt=3 backoff=391.782641ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2396--- PASS: TestUploadHandlersRejectOversizedBody (0.60s)2397 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.57s)2398 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.60s)2399 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (6.95s)24002026/11/07 23:33:26 WARN Request failed, retrying attempt=4 backoff=851.345918ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24012026/11/07 23:33:27 WARN Request failed, retrying attempt=5 backoff=1.709696287s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24022026/11/07 23:33:28 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_closures24032026/11/07 23:33:28 WARN Request failed, retrying attempt=2 backoff=191.78413ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24042026/11/07 23:33:29 WARN Request failed, retrying attempt=3 backoff=401.225425ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24052026/11/07 23:33:29 WARN Request failed, retrying attempt=4 backoff=813.377598ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24062026/11/07 23:33:30 WARN Request failed, retrying attempt=5 backoff=1.493612429s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2407--- PASS: TestClientErrorHandling (0.00s)2408 --- PASS: TestClientErrorHandling/InvalidStorePath (0.28s)2409 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.41s)2410 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.47s)2411PASS2412{"timestamp":"2026-11-07T23:33:31.878769166Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49840","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(390)"}2413{"timestamp":"2026-11-07T23:33:31.877818157Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49942","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(395)"}2414{"timestamp":"2026-11-07T23:33:31.877823397Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49542","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(399)"}2415{"timestamp":"2026-11-07T23:33:31.878261737Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49832","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}2416{"timestamp":"2026-11-07T23:33:31.878906766Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49874","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(401)"}24172026-11-07 23:33:32.264 UTC [171] LOG: received smart shutdown request24182026-11-07 23:33:32.270 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 124192026-11-07 23:33:33.873 UTC [176] LOG: checkpoint complete: wrote 9359 buffers (57.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.767 s, sync=1.331 s, total=14.181 s; sync files=38087, longest=0.005 s, average=0.001 s; distance=533944 kB, estimate=533944 kB; lsn=0/23796B80, redo lsn=0/220D3F4824202026-11-07 23:33:33.876 UTC [176] LOG: shutting down24212026-11-07 23:33:33.876 UTC [176] LOG: checkpoint starting: shutdown immediate24222026-11-07 23:33:33.999 UTC [176] LOG: checkpoint complete: wrote 922 buffers (5.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.018 s, sync=0.099 s, total=0.124 s; sync files=374, longest=0.001 s, average=0.001 s; distance=23307 kB, estimate=482880 kB; lsn=0/23796BF8, redo lsn=0/23796BF824232026-11-07 23:33:34.063 UTC [171] LOG: database system is shut down2424Running OIDC tests...2425=== RUN TestAudienceForIssuer2426=== PAUSE TestAudienceForIssuer2427=== RUN TestHTTPClientForHasTimeouts2428=== PAUSE TestHTTPClientForHasTimeouts2429=== RUN TestGlobMatch2430=== PAUSE TestGlobMatch2431=== RUN TestValidateToken_ValidToken2432=== PAUSE TestValidateToken_ValidToken2433=== RUN TestValidateToken_WrongAudience2434=== PAUSE TestValidateToken_WrongAudience2435=== RUN TestValidateToken_Expired2436=== PAUSE TestValidateToken_Expired2437=== RUN TestValidateToken_BoundClaimsMismatch2438=== PAUSE TestValidateToken_BoundClaimsMismatch2439=== RUN TestValidateToken_BoundSubjectMismatch2440=== PAUSE TestValidateToken_BoundSubjectMismatch2441=== RUN TestValidateToken_MultipleProviders2442=== PAUSE TestValidateToken_MultipleProviders2443=== RUN TestValidateToken_NoMatchingProvider2444=== PAUSE TestValidateToken_NoMatchingProvider2445=== RUN TestValidateToken_KubernetesServiceAccount2446=== PAUSE TestValidateToken_KubernetesServiceAccount2447=== RUN TestNewValidator_KubernetesRequiresCA2448=== PAUSE TestNewValidator_KubernetesRequiresCA2449=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2450=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2451=== RUN TestPins_ReservedForMatchingRule2452=== PAUSE TestPins_ReservedForMatchingRule2453=== RUN TestPins_TopLevelShorthand2454=== PAUSE TestPins_TopLevelShorthand2455=== RUN TestPins_ConfigValidation2456=== PAUSE TestPins_ConfigValidation2457=== RUN TestScopes_LegacyProviderDefaultsToWrite2458=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2459=== RUN TestScopes_Rules2460=== PAUSE TestScopes_Rules2461=== RUN TestScopes_ConfigValidation2462=== PAUSE TestScopes_ConfigValidation2463=== CONT TestAudienceForIssuer2464=== CONT TestValidateToken_NoMatchingProvider2465=== CONT TestPins_ConfigValidation2466=== CONT TestScopes_LegacyProviderDefaultsToWrite2467--- PASS: TestAudienceForIssuer (0.00s)2468=== CONT TestPins_ReservedForMatchingRule2469--- PASS: TestPins_ConfigValidation (0.00s)2470=== CONT TestNewValidator_KubernetesRequiresCA2471=== CONT TestValidateToken_MultipleProviders2472=== CONT TestPins_TopLevelShorthand2473=== CONT TestValidateToken_BoundSubjectMismatch2474=== CONT TestValidateToken_Expired2475=== CONT TestValidateToken_ValidToken2476=== CONT TestValidateToken_BoundClaimsMismatch2477=== CONT TestValidateToken_WrongAudience2478=== CONT TestGlobMatch2479=== RUN TestGlobMatch/foo_foo2480=== PAUSE TestGlobMatch/foo_foo2481=== RUN TestGlobMatch/foo_bar2482=== PAUSE TestGlobMatch/foo_bar2483=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2484=== CONT TestHTTPClientForHasTimeouts2485=== CONT TestValidateToken_KubernetesServiceAccount2486=== CONT TestScopes_ConfigValidation2487=== CONT TestScopes_Rules2488=== RUN TestGlobMatch/*_2489=== PAUSE TestGlobMatch/*_2490=== RUN TestGlobMatch/*_anything2491=== PAUSE TestGlobMatch/*_anything2492=== RUN TestGlobMatch/foo*_foo2493=== PAUSE TestGlobMatch/foo*_foo2494=== RUN TestGlobMatch/foo*_foobar2495=== PAUSE TestGlobMatch/foo*_foobar2496=== RUN TestGlobMatch/foo*_bar2497=== PAUSE TestGlobMatch/foo*_bar2498=== RUN TestGlobMatch/*bar_bar2499=== PAUSE TestGlobMatch/*bar_bar2500=== RUN TestGlobMatch/*bar_foobar2501=== PAUSE TestGlobMatch/*bar_foobar2502=== RUN TestGlobMatch/*bar_foo2503=== PAUSE TestGlobMatch/*bar_foo2504=== RUN TestGlobMatch/foo*bar_foobar2505=== PAUSE TestGlobMatch/foo*bar_foobar2506=== RUN TestGlobMatch/foo*bar_foo123bar2507=== PAUSE TestGlobMatch/foo*bar_foo123bar2508=== RUN TestGlobMatch/foo*bar_foobarbaz2509=== PAUSE TestGlobMatch/foo*bar_foobarbaz2510=== RUN TestGlobMatch/*/*_foo/bar2511=== PAUSE TestGlobMatch/*/*_foo/bar2512=== RUN TestGlobMatch/*/*_foo2513=== PAUSE TestGlobMatch/*/*_foo2514=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2515=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2516=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02517=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02518=== RUN TestGlobMatch/refs/*/main_refs/heads/main2519=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2520--- PASS: TestScopes_ConfigValidation (0.01s)2521=== RUN TestGlobMatch/fo?_foo2522=== PAUSE TestGlobMatch/fo?_foo2523=== RUN TestGlobMatch/fo?_fo2524=== PAUSE TestGlobMatch/fo?_fo2525=== RUN TestGlobMatch/fo?_fooo2526=== PAUSE TestGlobMatch/fo?_fooo2527=== RUN TestGlobMatch/?oo_foo2528=== PAUSE TestGlobMatch/?oo_foo2529=== RUN TestGlobMatch/?oo_boo2530=== PAUSE TestGlobMatch/?oo_boo2531=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2532=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2533=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2534=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2535=== CONT TestGlobMatch/foo_foo2536=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2537=== CONT TestGlobMatch/foo*bar_foobarbaz2538=== CONT TestGlobMatch/foo_bar2539=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2540=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2541=== CONT TestGlobMatch/foo*_bar2542=== CONT TestGlobMatch/*_anything2543=== CONT TestGlobMatch/?oo_boo2544=== CONT TestGlobMatch/*bar_foo2545=== CONT TestGlobMatch/fo?_fooo2546=== CONT TestGlobMatch/foo*_foo2547=== CONT TestGlobMatch/*_2548=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02549=== CONT TestGlobMatch/foo*bar_foobar2550=== CONT TestGlobMatch/*bar_foobar2551=== CONT TestGlobMatch/fo?_fo2552=== CONT TestGlobMatch/foo*bar_foo123bar2553=== CONT TestGlobMatch/fo?_foo2554=== CONT TestGlobMatch/*bar_bar2555=== CONT TestGlobMatch/?oo_foo2556=== CONT TestGlobMatch/*/*_foo/bar2557=== CONT TestGlobMatch/refs/*/main_refs/heads/main2558=== CONT TestGlobMatch/*/*_foo2559=== CONT TestGlobMatch/foo*_foobar2560--- PASS: TestGlobMatch (0.01s)2561 --- PASS: TestGlobMatch/foo_foo (0.00s)2562 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2563 --- PASS: TestGlobMatch/foo_bar (0.00s)2564 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2565 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2566 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2567 --- PASS: TestGlobMatch/foo*_bar (0.00s)2568 --- PASS: TestGlobMatch/*_anything (0.00s)2569 --- PASS: TestGlobMatch/?oo_boo (0.00s)2570 --- PASS: TestGlobMatch/*bar_foo (0.00s)2571 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2572 --- PASS: TestGlobMatch/foo*_foo (0.00s)2573 --- PASS: TestGlobMatch/*_ (0.00s)2574 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2575 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2576 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2577 --- PASS: TestGlobMatch/fo?_fo (0.00s)2578 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2579 --- PASS: TestGlobMatch/fo?_foo (0.00s)2580 --- PASS: TestGlobMatch/*bar_bar (0.00s)2581 --- PASS: TestGlobMatch/?oo_foo (0.00s)2582 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2583 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2584 --- PASS: TestGlobMatch/*/*_foo (0.00s)2585 --- PASS: TestGlobMatch/foo*_foobar (0.00s)25862026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42687/oidc2587--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)25882026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38727/oidc2589--- PASS: TestValidateToken_Expired (0.04s)25902026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46275/oidc25912026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45911/oidc2592--- PASS: TestPins_TopLevelShorthand (0.05s)2593--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)25942026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43161/oidc2595--- PASS: TestPins_ReservedForMatchingRule (0.07s)25962026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38111/oidc25972026/11/07 23:33:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36791/oidc25982026/11/07 23:33:37 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:34095/oidc2599--- PASS: TestValidateToken_ValidToken (0.09s)2600--- PASS: TestValidateToken_MultipleProviders (0.09s)26012026/11/07 23:33:37 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232602--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)26032026/11/07 23:33:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39849/oidc2604--- PASS: TestValidateToken_NoMatchingProvider (0.17s)26052026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34755/oidc2606--- PASS: TestValidateToken_WrongAudience (0.17s)26072026/11/07 23:33:37 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3793126082026/11/07 23:33:37 http: TLS handshake error from 127.0.0.1:40870: remote error: tls: bad certificate2609--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)2610--- PASS: TestValidateToken_KubernetesServiceAccount (0.18s)26112026/11/07 23:33:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38827/oidc26122026/11/07 23:33:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40253/oidc2613--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.21s)2614--- PASS: TestScopes_Rules (0.21s)2615--- PASS: TestHTTPClientForHasTimeouts (0.41s)2616PASS2617Running hook tests...2618=== RUN TestSendPathsEmpty2619=== PAUSE TestSendPathsEmpty2620=== RUN TestQueueEnqueueAndFetch2621=== PAUSE TestQueueEnqueueAndFetch2622=== RUN TestQueueDeduplication2623=== PAUSE TestQueueDeduplication2624=== RUN TestQueueRemove2625=== PAUSE TestQueueRemove2626=== RUN TestQueueFetchBatchLimit2627=== PAUSE TestQueueFetchBatchLimit2628=== RUN TestQueueRetryMovesToBack2629=== PAUSE TestQueueRetryMovesToBack2630=== RUN TestQueueFetchRemoveLifecycle2631=== PAUSE TestQueueFetchRemoveLifecycle2632=== RUN TestQueueConcurrentWriters2633=== PAUSE TestQueueConcurrentWriters2634=== RUN TestQueueRemoveLargeClosure2635=== PAUSE TestQueueRemoveLargeClosure2636=== RUN TestServerClientIntegration2637--- PASS: TestServerClientIntegration (0.00s)2638=== RUN TestServerQueueError26392026/11/07 23:33:39 ERROR Failed to queue paths error="permission denied" count=12640--- PASS: TestServerQueueError (0.00s)2641=== RUN TestServerRefusesOversizedAndNonStoreRequests2642=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2643=== RUN TestGetListenerSocketActivation2644 server_test.go:309: === RUN TestGetListenerSocketActivation2645 --- PASS: TestGetListenerSocketActivation (0.00s)2646 PASS2647 2648--- PASS: TestGetListenerSocketActivation (1.02s)2649=== RUN TestServerStalledClientDoesNotBlockShutdown2650=== PAUSE TestServerStalledClientDoesNotBlockShutdown2651=== RUN TestServerBacksOffOnAcceptErrors2652=== PAUSE TestServerBacksOffOnAcceptErrors2653=== RUN TestDrainIsolatesPoisonPath2654=== PAUSE TestDrainIsolatesPoisonPath2655=== RUN TestRunNotBlockedByPoisonHead2656=== PAUSE TestRunNotBlockedByPoisonHead2657=== RUN TestDrainGivesUpWhenServerDown2658=== PAUSE TestDrainGivesUpWhenServerDown2659=== RUN TestFailedPathPrunedByLaterClosure2660=== PAUSE TestFailedPathPrunedByLaterClosure2661=== RUN TestWorkerUploadsAndRemoves2662=== PAUSE TestWorkerUploadsAndRemoves2663=== RUN TestWorkerSkipsGCdPaths2664=== PAUSE TestWorkerSkipsGCdPaths2665=== RUN TestWorkerPrunesClosureDeps2666=== PAUSE TestWorkerPrunesClosureDeps2667=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2668=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2669=== RUN TestDrainTimeout2670=== PAUSE TestDrainTimeout2671=== RUN TestDrainTimeoutDuringIsolation2672=== PAUSE TestDrainTimeoutDuringIsolation2673=== RUN TestShutdownFinishesInFlightPush2674=== PAUSE TestShutdownFinishesInFlightPush2675=== RUN TestWorkerRemoveFailureIsNotProgress2676=== PAUSE TestWorkerRemoveFailureIsNotProgress2677=== RUN TestWorkerKeepsPathItCannotStat2678=== PAUSE TestWorkerKeepsPathItCannotStat2679=== CONT TestQueueEnqueueAndFetch2680=== CONT TestDrainGivesUpWhenServerDown2681=== CONT TestDrainTimeoutDuringIsolation2682=== CONT TestWorkerKeepsPathItCannotStat2683=== CONT TestWorkerRemoveFailureIsNotProgress2684=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2685=== CONT TestShutdownFinishesInFlightPush2686=== CONT TestDrainTimeout2687=== CONT TestWorkerPrunesClosureDeps2688=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2689=== CONT TestWorkerUploadsAndRemoves2690=== CONT TestWorkerSkipsGCdPaths2691=== CONT TestFailedPathPrunedByLaterClosure2692=== CONT TestRunNotBlockedByPoisonHead2693=== CONT TestQueueFetchRemoveLifecycle2694=== CONT TestQueueRemove2695=== CONT TestQueueConcurrentWriters2696=== CONT TestServerBacksOffOnAcceptErrors2697=== CONT TestQueueRetryMovesToBack2698=== CONT TestDrainIsolatesPoisonPath2699=== CONT TestServerRefusesOversizedAndNonStoreRequests2700=== CONT TestQueueRemoveLargeClosure2701=== CONT TestServerStalledClientDoesNotBlockShutdown2702=== CONT TestQueueDeduplication2703=== CONT TestSendPathsEmpty2704=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short27052026/11/07 23:33:40 ERROR Accept failed error="too many open files"2706=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2707=== RUN TestShutdownFinishesInFlightPush/completes2708--- PASS: TestSendPathsEmpty (0.00s)2709=== CONT TestQueueFetchBatchLimit2710=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2711=== PAUSE TestShutdownFinishesInFlightPush/completes27122026/11/07 23:33:40 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2713=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2714=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27152026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store store=/nix/store2716=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2717=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2718=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2719=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2720=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths27212026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2722=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2723=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2724=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2725=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27262026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27272026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27282026/11/07 23:33:40 ERROR Accept failed error="too many open files"27292026/11/07 23:33:40 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27302026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27312026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27322026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27332026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27342026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27352026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27362026/11/07 23:33:40 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27372026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27382026/11/07 23:33:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27392026/11/07 23:33:40 ERROR Failed to decode request error="unexpected EOF"2740--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2741=== CONT TestShutdownFinishesInFlightPush/completes27422026/11/07 23:33:40 ERROR Accept failed error="too many open files"27432026/11/07 23:33:40 ERROR Accept failed error="too many open files"27442026/11/07 23:33:40 INFO Uploading batch count=427452026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=427462026/11/07 23:33:40 INFO Upload queue status pending=327472026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4126298188/002/bbb27482026/11/07 23:33:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths471002994/002/nonexistent27492026/11/07 23:33:40 INFO Uploading batch count=227502026/11/07 23:33:40 INFO Upload queue status pending=227512026/11/07 23:33:40 INFO Upload queue status pending=227522026/11/07 23:33:40 INFO Uploading batch count=127532026/11/07 23:33:40 INFO Uploading batch count=227542026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=227552026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/a27562026/11/07 23:33:40 INFO Uploading batch count=227572026/11/07 23:33:40 INFO Uploading batch count=227582026/11/07 23:33:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa: permission denied"27592026/11/07 23:33:40 INFO Uploading batch count=127602026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=127612026/11/07 23:33:40 INFO Upload queue status pending=227622026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/b27632026/11/07 23:33:40 INFO Uploading batch count=127642026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=127652026/11/07 23:33:40 INFO Uploading batch count=227662026/11/07 23:33:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa: permission denied"27672026/11/07 23:33:40 INFO Uploading batch count=127682026/11/07 23:33:40 INFO Upload queue status pending=227692026/11/07 23:33:40 INFO Uploading batch count=227702026/11/07 23:33:40 INFO Uploading batch count=227712026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=227722026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/c2773--- PASS: TestQueueRemove (0.07s)2774=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27752026/11/07 23:33:40 INFO Upload queue status pending=327762026/11/07 23:33:40 INFO Uploading batch count=127772026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=127782026/11/07 23:33:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3805111950/002/locked/aaa: permission denied"2779=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2780--- PASS: TestQueueEnqueueAndFetch (0.07s)27812026/11/07 23:33:40 INFO Uploading batch count=127822026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=12783--- PASS: TestQueueFetchBatchLimit (0.07s)2784=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27852026/11/07 23:33:40 INFO Uploading batch count=427862026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=42787--- PASS: TestQueueRetryMovesToBack (0.07s)2788--- PASS: TestQueueDeduplication (0.07s)27892026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/d27902026/11/07 23:33:40 INFO Uploading batch count=12791--- PASS: TestQueueFetchRemoveLifecycle (0.08s)27922026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=127932026/11/07 23:33:40 INFO Upload queue status pending=227942026/11/07 23:33:40 INFO Uploading batch count=127952026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=127962026/11/07 23:33:40 INFO Uploading batch count=227972026/11/07 23:33:40 INFO Uploading batch count=427982026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=427992026/11/07 23:33:40 INFO Uploading batch count=228002026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=228012026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/e28022026/11/07 23:33:40 ERROR Accept failed error="too many open files"2803--- PASS: TestWorkerKeepsPathItCannotStat (0.08s)28042026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=128052026/11/07 23:33:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3707963547/002/f2806--- PASS: TestFailedPathPrunedByLaterClosure (0.08s)2807--- PASS: TestWorkerSkipsGCdPaths (0.09s)28082026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=102809--- PASS: TestDrainIsolatesPoisonPath (0.09s)2810--- PASS: TestWorkerUploadsAndRemoves (0.09s)2811--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)2812--- PASS: TestWorkerPrunesClosureDeps (0.09s)2813--- PASS: TestDrainGivesUpWhenServerDown (0.09s)28142026/11/07 23:33:40 INFO Uploading batch count=228152026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=228162026/11/07 23:33:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4170226772/001/nonexistent28172026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128182026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128192026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128202026/11/07 23:33:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4170226772/001/nonexistent28212026/11/07 23:33:40 INFO Uploading batch count=228222026/11/07 23:33:40 INFO Uploading batch count=228232026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128242026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=228252026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128262026/11/07 23:33:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4170226772/001/nonexistent28272026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228282026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128292026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128302026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=128312026/11/07 23:33:40 INFO Uploading batch count=228322026/11/07 23:33:40 ERROR Upload failed error="upload failed" count=228332026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128342026/11/07 23:33:40 INFO Uploading batch count=228352026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128362026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228372026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=228382026/11/07 23:33:40 INFO Uploading batch count=228392026/11/07 23:33:40 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228402026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=22841--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2842 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2843 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)2844 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)28452026/11/07 23:33:40 ERROR Accept failed error="too many open files"28462026/11/07 23:33:40 ERROR Failed to decode request error="read unix /build/hook1658494409/test.sock->@: i/o timeout"28472026/11/07 23:33:40 ERROR Failed to write response error="write unix /build/hook1658494409/test.sock->@: i/o timeout"2848--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28492026/11/07 23:33:40 ERROR Upload failed error="context canceled" count=228502026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=42851--- PASS: TestDrainTimeout (0.26s)28522026/11/07 23:33:40 ERROR Upload failed error="context canceled" count=228532026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=228542026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=42855--- PASS: TestShutdownFinishesInFlightPush (0.00s)2856 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2857 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.27s)28582026/11/07 23:33:40 ERROR Accept failed error="too many open files"28592026/11/07 23:33:40 ERROR Drain finished with paths left in queue remaining=32860--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2861 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2862 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)2863--- PASS: TestQueueConcurrentWriters (0.61s)28642026/11/07 23:33:40 ERROR Accept failed error="too many open files"2865--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28662026/11/07 23:33:41 INFO Uploading batch count=128672026/11/07 23:33:41 INFO Uploading batch count=128682026/11/07 23:33:41 INFO Uploading batch count=128692026/11/07 23:33:41 ERROR Upload failed error="upload failed" count=128702026/11/07 23:33:41 INFO Uploading batch count=128712026/11/07 23:33:41 ERROR Upload failed error="upload failed" count=128722026/11/07 23:33:41 INFO Uploading batch count=128732026/11/07 23:33:41 ERROR Upload failed error="upload failed" count=128742026/11/07 23:33:41 INFO Uploading batch count=128752026/11/07 23:33:41 ERROR Upload failed error="upload failed" count=128762026/11/07 23:33:41 ERROR Drain finished with paths left in queue remaining=12877--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2878--- PASS: TestQueueRemoveLargeClosure (1.48s)2879PASS2880Running signing tests...2881=== RUN TestExternalSigner2882=== PAUSE TestExternalSigner2883=== RUN TestExternalSignerWrongPublicKey2884=== PAUSE TestExternalSignerWrongPublicKey2885=== RUN TestExternalSignerErrors2886=== PAUSE TestExternalSignerErrors2887=== RUN TestExternalSignerRestartsAfterCrash2888=== PAUSE TestExternalSignerRestartsAfterCrash2889=== RUN TestExternalSignerProgramErrorKeepsProcess2890=== PAUSE TestExternalSignerProgramErrorKeepsProcess2891=== RUN TestExternalSignerClose2892=== PAUSE TestExternalSignerClose2893=== RUN TestExternalSignerRejectsInvalidPublicKey2894=== PAUSE TestExternalSignerRejectsInvalidPublicKey2895=== RUN TestExternalSignerCancellation2896=== PAUSE TestExternalSignerCancellation2897=== RUN TestGenerateFingerprint2898=== PAUSE TestGenerateFingerprint2899=== RUN TestParseSigningKey2900=== PAUSE TestParseSigningKey2901=== RUN TestSign2902=== PAUSE TestSign2903=== RUN TestSignBatch2904=== PAUSE TestSignBatch2905=== RUN TestNilKeyPublicKey2906=== PAUSE TestNilKeyPublicKey2907=== RUN TestSignErrors2908=== PAUSE TestSignErrors2909=== CONT TestExternalSigner2910=== CONT TestExternalSignerCancellation2911=== CONT TestSign2912=== CONT TestSignBatch2913=== CONT TestGenerateFingerprint2914=== RUN TestGenerateFingerprint/basic_with_references2915=== PAUSE TestGenerateFingerprint/basic_with_references2916=== RUN TestGenerateFingerprint/no_references2917=== PAUSE TestGenerateFingerprint/no_references2918=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2919=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2920=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2921=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2922=== RUN TestGenerateFingerprint/invalid_nar_hash_length2923=== CONT TestNilKeyPublicKey2924=== CONT TestExternalSignerProgramErrorKeepsProcess2925=== CONT TestExternalSignerRejectsInvalidPublicKey2926=== RUN TestExternalSignerRejectsInvalidPublicKey/#002927=== CONT TestExternalSignerClose2928=== CONT TestExternalSignerErrors2929=== RUN TestExternalSignerErrors/null2930=== CONT TestExternalSignerRestartsAfterCrash2931=== PAUSE TestExternalSignerErrors/null2932=== CONT TestExternalSignerWrongPublicKey2933=== CONT TestParseSigningKey2934=== RUN TestParseSigningKey/valid_32-byte_key2935=== CONT TestSignErrors2936=== PAUSE TestParseSigningKey/valid_32-byte_key2937--- PASS: TestNilKeyPublicKey (0.00s)2938=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002939=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2940=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2941=== RUN TestExternalSignerErrors/missing_signature_name2942=== RUN TestSignErrors/nil_key2943=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2944=== PAUSE TestExternalSignerErrors/missing_signature_name2945=== PAUSE TestSignErrors/nil_key2946=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2947=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2948=== RUN TestExternalSignerErrors/invalid_JSON2949--- PASS: TestSign (0.00s)2950=== RUN TestParseSigningKey/no_colon2951=== RUN TestGenerateFingerprint/invalid_store_path_prefix2952=== PAUSE TestParseSigningKey/no_colon2953=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2954=== RUN TestSignErrors/nil_narinfo2955=== PAUSE TestExternalSignerErrors/invalid_JSON2956=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2957=== RUN TestParseSigningKey/empty_name2958=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2959=== PAUSE TestParseSigningKey/empty_name2960=== PAUSE TestSignErrors/nil_narinfo2961=== RUN TestExternalSignerErrors/wrong_shape2962=== RUN TestGenerateFingerprint/invalid_reference_prefix2963=== PAUSE TestExternalSignerErrors/wrong_shape2964=== RUN TestExternalSignerErrors/null_signatures2965=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2966=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2967=== RUN TestParseSigningKey/invalid_base642968=== PAUSE TestParseSigningKey/invalid_base642969=== RUN TestSignErrors/invalid_narinfo2970=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2971=== PAUSE TestExternalSignerErrors/null_signatures2972=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2973=== CONT TestGenerateFingerprint/invalid_reference_prefix2974=== RUN TestParseSigningKey/wrong_length2975=== PAUSE TestSignErrors/invalid_narinfo2976=== PAUSE TestParseSigningKey/wrong_length2977=== RUN TestSignErrors/canceled2978=== CONT TestParseSigningKey/invalid_base642979=== PAUSE TestSignErrors/canceled2980=== CONT TestSignErrors/nil_key2981=== CONT TestGenerateFingerprint/basic_with_references2982=== CONT TestSignErrors/nil_narinfo2983=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2984=== CONT TestParseSigningKey/no_colon2985=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2986=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2987=== CONT TestGenerateFingerprint/no_references2988=== CONT TestGenerateFingerprint/invalid_nar_hash_length2989=== CONT TestGenerateFingerprint/invalid_store_path_prefix2990=== RUN TestExternalSignerErrors/too_few_signatures2991=== PAUSE TestExternalSignerErrors/too_few_signatures2992--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2993=== CONT TestParseSigningKey/valid_32-byte_key2994--- PASS: TestSignBatch (0.01s)2995=== CONT TestParseSigningKey/wrong_length2996--- PASS: TestExternalSignerWrongPublicKey (0.00s)2997=== CONT TestSignErrors/canceled2998--- PASS: TestExternalSignerClose (0.01s)2999=== CONT TestSignErrors/invalid_narinfo3000--- PASS: TestGenerateFingerprint (0.01s)3001 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3002 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3003 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3004 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3005 --- PASS: TestGenerateFingerprint/no_references (0.00s)3006 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3007 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3008--- PASS: TestSignErrors (0.00s)3009 --- PASS: TestSignErrors/nil_key (0.00s)3010 --- PASS: TestSignErrors/nil_narinfo (0.00s)3011 --- PASS: TestSignErrors/canceled (0.00s)3012 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3013=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3014=== RUN TestExternalSignerErrors/unrequested_key3015=== CONT TestParseSigningKey/empty_name3016=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon3017--- PASS: TestParseSigningKey (0.00s)3018 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3019 --- PASS: TestParseSigningKey/no_colon (0.00s)3020 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3021 --- PASS: TestParseSigningKey/wrong_length (0.00s)3022 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3023 --- PASS: TestParseSigningKey/empty_name (0.00s)3024=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=3025=== PAUSE TestExternalSignerErrors/unrequested_key3026=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!3027--- PASS: TestExternalSigner (0.01s)3028=== RUN TestExternalSignerErrors/wrong_signature_length3029=== PAUSE TestExternalSignerErrors/wrong_signature_length3030=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3031=== CONT TestExternalSignerRejectsInvalidPublicKey/#003032=== RUN TestExternalSignerErrors/program_error3033=== PAUSE TestExternalSignerErrors/program_error3034--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)3035 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)3036 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3037 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3038 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3039 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)3040=== RUN TestExternalSignerErrors/wrong_id3041=== PAUSE TestExternalSignerErrors/wrong_id3042=== RUN TestExternalSignerErrors/missing_signatures3043=== PAUSE TestExternalSignerErrors/missing_signatures3044=== RUN TestExternalSignerErrors/wrong_signature_name3045=== PAUSE TestExternalSignerErrors/wrong_signature_name3046=== RUN TestExternalSignerErrors/exit_on_request3047=== PAUSE TestExternalSignerErrors/exit_on_request3048=== RUN TestExternalSignerErrors/wrong_signatures_shape3049=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3050=== RUN TestExternalSignerErrors/invalid_signature_base643051=== PAUSE TestExternalSignerErrors/invalid_signature_base643052=== RUN TestExternalSignerErrors/exit_at_startup3053=== PAUSE TestExternalSignerErrors/exit_at_startup3054=== CONT TestExternalSignerErrors/null3055=== CONT TestExternalSignerErrors/too_few_signatures3056=== CONT TestExternalSignerErrors/missing_signatures3057=== CONT TestExternalSignerErrors/exit_at_startup3058=== CONT TestExternalSignerErrors/null_signatures3059=== CONT TestExternalSignerErrors/invalid_signature_base643060=== CONT TestExternalSignerErrors/wrong_signature_length3061=== CONT TestExternalSignerErrors/exit_on_request3062=== CONT TestExternalSignerErrors/unrequested_key3063=== CONT TestExternalSignerErrors/wrong_id3064=== CONT TestExternalSignerErrors/wrong_signatures_shape3065=== CONT TestExternalSignerErrors/wrong_signature_name3066=== CONT TestExternalSignerErrors/program_error3067=== CONT TestExternalSignerErrors/missing_signature_name3068=== CONT TestExternalSignerErrors/invalid_JSON3069=== CONT TestExternalSignerErrors/wrong_shape3070--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3071--- PASS: TestExternalSignerErrors (0.01s)3072 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)3073 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3074 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3075 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3076 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3077 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3078 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3079 --- PASS: TestExternalSignerErrors/null (0.01s)3080 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3081 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3082 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3083 --- PASS: TestExternalSignerErrors/program_error (0.01s)3084 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3085 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3086 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3087 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3088--- PASS: TestExternalSignerCancellation (0.02s)3089PASS3090Running OpenBao signer tests...3091=== RUN TestSign3092=== PAUSE TestSign3093=== RUN TestSignErrors3094=== PAUSE TestSignErrors3095=== RUN TestServe3096=== PAUSE TestServe3097=== RUN TestServeRejectsGarbage3098=== PAUSE TestServeRejectsGarbage3099=== CONT TestSignErrors3100=== CONT TestServe3101=== CONT TestServeRejectsGarbage3102=== RUN TestSignErrors/http_error3103=== CONT TestSign3104=== PAUSE TestSignErrors/http_error3105--- PASS: TestServeRejectsGarbage (0.00s)3106=== RUN TestSignErrors/invalid_json3107=== PAUSE TestSignErrors/invalid_json3108=== RUN TestSignErrors/no_prefix3109--- PASS: TestServe (0.00s)3110=== PAUSE TestSignErrors/no_prefix3111=== RUN TestSignErrors/invalid_base643112=== PAUSE TestSignErrors/invalid_base643113=== CONT TestSignErrors/http_error3114=== CONT TestSignErrors/no_prefix3115=== CONT TestSignErrors/invalid_json3116=== CONT TestSignErrors/invalid_base643117--- PASS: TestSign (0.01s)3118--- PASS: TestSignErrors (0.00s)3119 --- PASS: TestSignErrors/invalid_json (0.01s)3120 --- PASS: TestSignErrors/http_error (0.01s)3121 --- PASS: TestSignErrors/invalid_base64 (0.01s)3122 --- PASS: TestSignErrors/no_prefix (0.01s)3123PASS3124Running niks3-hook command tests...3125=== RUN TestServeSecondSignalEndsDrain3126=== PAUSE TestServeSecondSignalEndsDrain3127=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3128=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3129=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3130=== CONT TestServeSecondSignalEndsDrain3131--- PASS: TestServeSecondSignalEndsDrain (0.08s)31322026/11/07 23:33:45 INFO Upload queue status pending=131332026/11/07 23:33:45 INFO Uploading batch count=13134--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3135PASS3136Running rate limiter tests...3137=== RUN TestAdaptiveRateLimiter_ThreadSafety3138=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3139=== CONT TestAdaptiveRateLimiter_ThreadSafety31402026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=112.7357000000000731412026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=78.9149900000000531422026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=55.2404930000000331432026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=38.6683451000000231442026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=27.0678415700000131452026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=18.94748909900000631462026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=13.26324236930000431472026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=9.28426965851000231482026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=6.49898876095700131492026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531502026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=14.62036859295479231512026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=10.23425801506835431522026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=7.16398061054784731532026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=5.01478642738349331542026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531552026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531562026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531572026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531582026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531592026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531602026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=5.12435000000000131612026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531622026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531632026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531642026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531652026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531662026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531672026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531682026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531692026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531702026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531712026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531722026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531732026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531742026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531752026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531762026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531772026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531782026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531792026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531802026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531812026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531822026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531832026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531842026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531852026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531862026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531872026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531882026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531892026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531902026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=8.25281691850000431912026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=5.77697184295000331922026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531932026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531942026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531952026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531962026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531972026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531982026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=531992026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532002026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532012026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532022026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532032026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532042026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532052026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532062026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532072026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532082026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532092026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532102026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532112026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532122026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=5.63678500000000132132026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532142026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532152026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532162026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532172026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532182026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532192026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532202026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532212026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532222026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532232026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532242026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532252026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=5.12435000000000132262026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532272026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532282026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532292026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532302026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532312026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532322026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532332026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532342026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532352026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532362026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532372026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532382026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=532392026/11/07 23:33:46 WARN Rate limiter backed off name=test rate=53240--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.10s)3241PASS