niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #470
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ReturnsAfterDroppedBody22=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestDumpPathCaseHackMatchesNix28--- PASS: TestDumpPathCaseHackMatchesNix (0.10s)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:280: no /proc/self/io: open /proc/self/io: no such file or directory41--- SKIP: TestDumpPathWriterErrorStopsReading (0.39s)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.01s)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 TestScriptTokenCachesUntilRefresh136=== CONT TestEncodeNixBase32137=== RUN TestEncodeNixBase32/test_string_hash138=== PAUSE TestEncodeNixBase32/test_string_hash139=== CONT TestScriptTokenDoesNotWaitForItsChildren140=== CONT TestScriptTokenEmptyCommand141=== CONT TestScriptTokenScriptFails142=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs143=== CONT TestScriptTokenBadJSON144--- PASS: TestScriptTokenEmptyCommand (0.00s)145=== CONT TestScriptTokenEmptyToken146=== CONT TestRegisterUploadedObject_OutlivesPush147=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs148=== CONT TestParsePathInfoJSON149=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout150=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout151=== CONT TestFileTokenEmpty152=== RUN TestParsePathInfoJSON/Nix_format153=== CONT TestParsePathInfoJSONMultiplePaths154=== CONT TestGetStorePathHash155=== PAUSE TestParsePathInfoJSON/Nix_format156=== RUN TestGetStorePathHash/valid_store_path157=== RUN TestParsePathInfoJSON/Lix_format158=== CONT TestPathInfoHashCompatibility159=== CONT TestEncodeNixBase32WithRealHash160=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161=== CONT TestCompletePendingClosure_NotFoundWithoutKey162=== CONT TestDoWithRetry_FinalResponseBodyReadable163--- PASS: TestEncodeNixBase32WithRealHash (0.00s)164=== CONT TestRateLimiterFeedback165=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer166=== RUN TestRateLimiterFeedback/429_enables_limiter167=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== CONT TestPathInfoCACompatibility170=== CONT TestStreamPushStopsWhenCanceled171=== CONT TestScriptTokenNoExpiryRerunsEveryCall172=== CONT TestResolveStorePath173=== RUN TestEncodeNixBase32/empty_input174=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== CONT TestConvertHashToNix32176=== PAUSE TestGetStorePathHash/valid_store_path177=== PAUSE TestParsePathInfoJSON/Lix_format178=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)179=== CONT TestFileTokenReadsAndCaches180=== PAUSE TestRateLimiterFeedback/429_enables_limiter181=== RUN TestRateLimiterFeedback/503_enables_limiter182=== PAUSE TestEncodeNixBase32/empty_input183=== CONT TestFileTokenMissing184--- PASS: TestFileTokenEmpty (0.01s)185=== CONT TestSetClientTLSDoesNotMutateDefaultTransport186--- PASS: TestResolveStorePath (0.00s)187=== CONT TestSetClientTLSErrors188=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier189=== RUN TestParsePathInfoJSON/empty_input190=== RUN TestPathInfoCACompatibility/null_ca_field191=== RUN TestConvertHashToNix32/SRI_format_to_Nix32192=== RUN TestGetStorePathHash/basename_without_hyphen_should_error193=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon194=== CONT TestStaticToken195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestParsePathInfoJSON/empty_input197=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths198--- PASS: TestScriptTokenScriptFails (0.01s)199=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier200=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel201=== CONT TestSetClientTLS202=== PAUSE TestRateLimiterFeedback/503_enables_limiter203=== PAUSE TestPathInfoCACompatibility/null_ca_field204=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error205=== CONT TestStreamPushStopsOnCancel206=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI207=== RUN TestParsePathInfoJSON/whitespace_only208=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure209=== CONT TestPartSizeForNAR210=== CONT TestDumpPathWriterError211=== CONT TestUploadMultipart_ProducerErrorIsNotEOF212=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32213=== CONT TestDumpPathMatchesNix214--- PASS: TestDoServerRequestAttachesToken (0.02s)215=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths216=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up217=== RUN TestSetClientTLSErrors/missing_cert_file218=== CONT TestUploadMultipart_ReturnsAfterDroppedBody219=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestStreamPushStopsOnCancel/waiting_for_input221=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error223=== PAUSE TestParsePathInfoJSON/whitespace_only224=== RUN TestPathInfoCACompatibility/old_string_format_-_text225=== RUN TestPartSizeForNAR/zero_stays_at_minimum226=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part227--- PASS: TestFileTokenMissing (0.00s)228=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths229=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up230=== RUN TestConvertHashToNix32/already_Nix32_format231=== PAUSE TestSetClientTLSErrors/missing_cert_file232=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512233=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error234=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter235=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input236--- PASS: TestStreamPushStopsWhenCanceled (0.00s)237=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum238=== RUN TestParsePathInfoJSON/invalid_JSON239=== CONT TestStreamPushReportsSkippedPaths240=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part241=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary242=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary243=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text244=== CONT TestStreamPushReportsSignatures245=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive246=== CONT TestDumpPathSingleFile247=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive248=== RUN TestPathInfoCACompatibility/new_structured_format_-_text249=== CONT TestStreamPushReportsEveryPath250=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text251=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier252=== RUN TestSetClientTLSErrors/missing_key_file253=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier254=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method255=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client256=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512257=== CONT TestStreamPushRequestLine258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== PAUSE TestConvertHashToNix32/already_Nix32_format260=== CONT TestStreamPushBatchesUnderLoad261=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error262--- PASS: TestStaticToken (0.00s)263=== PAUSE TestParsePathInfoJSON/invalid_JSON264=== RUN TestPartSizeForNAR/small_stays_at_minimum265=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot266=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter267=== CONT TestClientSignaturesByStorePath268=== RUN TestSetClientTLSErrors/missing_ca_file269=== CONT TestStreamPushGivesUpOnDeadServer270=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client271=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method272=== RUN TestConvertHashToNix32/invalid_format273=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false274--- PASS: TestFileTokenReadsAndCaches (0.01s)275=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error276=== CONT TestShellSplitErrors277=== PAUSE TestPartSizeForNAR/small_stays_at_minimum278=== CONT TestStreamPushIsolatesFailures279=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot280=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter281=== PAUSE TestSetClientTLSErrors/missing_ca_file282--- PASS: TestClientSignaturesByStorePath (0.00s)283=== CONT TestUploadMultipart_PartsInParallel284=== CONT TestShellSplit285=== CONT TestRetryTimeoutOutlastsMaxRetries286=== PAUSE TestConvertHashToNix32/invalid_format287=== CONT TestCaseHackSuffix288=== CONT TestDoWithRetry_BodyReplayedViaGetBody289=== CONT TestRegisterUploadedObjectReusesConnections290=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false291--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)292--- PASS: TestRegisterUploadedObject_OutlivesPush (0.01s)293=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica294=== CONT TestTruncatedNARDumpIsNotCompleted295=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum296=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum297=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client298--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)299=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client300=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun301--- PASS: TestScriptTokenEmptyToken (0.02s)302--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)303--- PASS: TestStreamPushReportsSkippedPaths (0.00s)304--- PASS: TestStreamPushReportsSignatures (0.00s)305--- PASS: TestStreamPushReportsEveryPath (0.00s)306=== RUN TestSetClientTLS/rejects_connection_without_client_cert307--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.01s)308--- PASS: TestShellSplitErrors (0.00s)309=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert310--- PASS: TestShellSplit (0.00s)311--- PASS: TestScriptTokenBadJSON (0.01s)312--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)313--- PASS: TestStreamPushIsolatesFailures (0.00s)314=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry315--- PASS: TestStreamPushGivesUpOnDeadServer (0.04s)316=== CONT TestFilterOversizedClosures317=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot318=== RUN TestSetClientTLSErrors/invalid_ca_file319=== PAUSE TestSetClientTLSErrors/invalid_ca_file320=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot321=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot322=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true323=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs324=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot325=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts326=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts327=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true328=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot329=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA330=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA331=== RUN TestSetClientTLS/preserves_debug_logging_transport332=== PAUSE TestSetClientTLS/preserves_debug_logging_transport333=== RUN TestPartSizeForNAR/1_TiB334=== PAUSE TestPartSizeForNAR/1_TiB335=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout336=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot337=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken338=== RUN TestFilterOversizedClosures/no_limit_keeps_everything339=== RUN TestPartSizeForNAR/5_TiB_S3_max_object340=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken341=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything342=== CONT TestEncodeNixBase32/test_string_hash343=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object344=== RUN TestPartSizeForNAR/capped_at_5_GiB345=== PAUSE TestPartSizeForNAR/capped_at_5_GiB346=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped347=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped348=== RUN TestFilterOversizedClosures/all_closures_skipped349=== PAUSE TestFilterOversizedClosures/all_closures_skipped350=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths351=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary352=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part353=== CONT TestEncodeNixBase32/empty_input354=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths355--- PASS: TestEncodeNixBase32 (0.01s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)359--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)360=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI362=== CONT TestParsePathInfoJSON/Lix_format363=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512364=== CONT TestParsePathInfoJSON/empty_input365=== CONT TestParsePathInfoJSON/whitespace_only366=== CONT TestParsePathInfoJSON/invalid_JSON367=== CONT TestParsePathInfoJSON/Nix_format368=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter369=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter370--- PASS: TestPathInfoHashCompatibility (0.02s)371 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)372 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)373 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)374 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)375--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.06s)376=== CONT TestRateLimiterFeedback/503_enables_limiter377--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)378 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)379 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.01s)380--- PASS: TestParsePathInfoJSON (0.03s)381 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)382 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)383 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)384 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)385 --- PASS: TestParsePathInfoJSON/Nix_format (0.01s)386=== CONT TestRateLimiterFeedback/429_enables_limiter387--- PASS: TestScriptTokenCachesUntilRefresh (0.11s)388=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive389=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method390=== CONT TestConvertHashToNix32/already_Nix32_format391=== CONT TestPathInfoCACompatibility/new_structured_format_-_text392=== CONT TestConvertHashToNix32/SRI_format_to_Nix32393=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error394=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error395=== CONT TestGetStorePathHash/basename_without_hyphen_should_error396=== CONT TestPathInfoCACompatibility/old_string_format_-_text397=== CONT TestGetStorePathHash/valid_store_path398--- PASS: TestGetStorePathHash (0.03s)399 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)400 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)401 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)402 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)403=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier404--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.09s)405=== CONT TestPathInfoCACompatibility/null_ca_field406=== CONT TestConvertHashToNix32/invalid_format407--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.12s)408=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client409--- PASS: TestConvertHashToNix32 (0.04s)410 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)411 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)412 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)413=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier414=== CONT TestSetClientTLSErrors/invalid_ca_file415--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.15s)416=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client417=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up418=== CONT TestSetClientTLSErrors/missing_ca_file419=== CONT TestSetClientTLSErrors/missing_key_file420=== CONT TestSetClientTLSErrors/missing_cert_file421=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false422--- PASS: TestRateLimiterFeedback (0.03s)423 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.09s)424 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.10s)425 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.11s)426 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.10s)427=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true428=== CONT TestSetClientTLS/rejects_connection_without_client_cert429=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA430--- PASS: TestSetClientTLSErrors (0.06s)431 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)433 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)434 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)435=== CONT TestSetClientTLS/preserves_debug_logging_transport436--- PASS: TestPathInfoCACompatibility (0.07s)437 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)438 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.02s)439 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)440 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)441 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.02s)442--- PASS: TestStreamPushBatchesUnderLoad (0.04s)443 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)444 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)445--- PASS: TestCaseHackSuffix (0.21s)446=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken447--- PASS: TestDumpPathSingleFile (0.23s)448=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot449=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot450=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot451=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot452=== CONT TestStreamPushStopsOnCancel/waiting_for_input453--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.05s)454 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.10s)455 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.06s)456 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.07s)457 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.06s)458 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.07s)459=== CONT TestFilterOversizedClosures/no_limit_keeps_everything460=== CONT TestFilterOversizedClosures/all_closures_skipped461=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped462=== CONT TestPartSizeForNAR/zero_stays_at_minimum463--- PASS: TestFilterOversizedClosures (0.00s)464 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)465 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)466 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)467=== CONT TestPartSizeForNAR/5_TiB_S3_max_object468=== CONT TestPartSizeForNAR/capped_at_5_GiB469=== CONT TestPartSizeForNAR/1_TiB470=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum471=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts472=== CONT TestPartSizeForNAR/small_stays_at_minimum473--- PASS: TestPartSizeForNAR (0.05s)474 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)475 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)476 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)477 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)478 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.01s)479 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)480 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)481--- PASS: TestStreamPushStopsOnCancel (0.05s)482 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.06s)483 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.07s)484 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.07s)485 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.07s)486 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.07s)487 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.07s)488--- PASS: TestDumpPathWriterError (0.34s)489--- PASS: TestSetClientTLS (0.05s)490 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.10s)491 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.15s)492 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.16s)493--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)494 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.19s)495 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.30s)496--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.35s)497--- PASS: TestStreamPushRequestLine (0.38s)498--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.40s)499--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.41s)500--- PASS: TestDumpPathMatchesNix (0.44s)501--- PASS: TestRegisterUploadedObjectReusesConnections (0.49s)502--- PASS: TestTruncatedNARDumpIsNotCompleted (0.72s)503--- PASS: TestUploadMultipart_PartsInParallel (0.92s)504--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)505--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)506 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.17s)507 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.21s)508PASS509Running server tests...510The files belonging to this database system will be owned by user "_tribuchetbld4".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 /private/var/tb/4/scratch/89da011d463ecd02/build/postgres3764635269/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 /private/var/tb/4/scratch/89da011d463ecd02/build/postgres3764635269/data -l logfile start5365372026-11-07 23:33:23.150 UTC [81800] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5382026-11-07 23:33:23.150 UTC [81800] LOG: listening on Unix socket "/private/var/tb/4/scratch/89da011d463ecd02/build/postgres3764635269/.s.PGSQL.5432"5392026-11-07 23:33:23.153 UTC [81807] LOG: database system was shut down at 2026-11-07 23:33:23 UTC5402026-11-07 23:33:23.154 UTC [81800] LOG: database system is ready to accept connections541/private/var/tb/4/scratch/89da011d463ecd02/build/postgres3764635269:5432 - accepting connections542{"timestamp":"2026-11-07T23:33:25.711834Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"22421612-dc32-425e-81b9-01ec8da88ee9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}543{"timestamp":"2026-11-07T23:33:25.817766Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"558f0da8-796c-48d9-917e-d9a1f95b0621","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}544=== RUN TestAbortSucceeded545=== PAUSE TestAbortSucceeded546=== RUN TestService_AuthMiddleware547=== PAUSE TestService_AuthMiddleware548=== RUN TestService_AuthMiddleware_MTLSProxyHeader549=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader550=== RUN TestService_AuthMiddleware_MTLSBoundSubjects551=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects552=== RUN TestService_ReadAuthMiddleware553=== PAUSE TestService_ReadAuthMiddleware554=== RUN TestService_AuthMiddleware_OIDC555=== PAUSE TestService_AuthMiddleware_OIDC556=== RUN TestService_RequireScope_OIDC557=== PAUSE TestService_RequireScope_OIDC558=== RUN TestService_ReadScope_PublicByDefault559=== PAUSE TestService_ReadScope_PublicByDefault560=== RUN TestCacheConfigHandler561=== PAUSE TestCacheConfigHandler562=== RUN TestCacheStatsHandler563=== PAUSE TestCacheStatsHandler564=== RUN TestClientCADerivations565=== PAUSE TestClientCADerivations566=== RUN TestClientErrorHandling567=== PAUSE TestClientErrorHandling568=== RUN TestClientIntegration569=== PAUSE TestClientIntegration570=== RUN TestClientMultipleUploads571=== PAUSE TestClientMultipleUploads572=== RUN TestClientWithDependencies573=== PAUSE TestClientWithDependencies574=== RUN TestClientSharedPathCommittedMidPush575=== PAUSE TestClientSharedPathCommittedMidPush576=== RUN TestPinProtectsFromGC577=== PAUSE TestPinProtectsFromGC578=== RUN TestClientPushesUseOnePush579=== PAUSE TestClientPushesUseOnePush580=== RUN TestClientFallsBackToClosures581=== PAUSE TestClientFallsBackToClosures582=== RUN TestDeleteClosuresRacingPins583=== PAUSE TestDeleteClosuresRacingPins584=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock585=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock586=== RUN TestResolveDBConnectionString587=== PAUSE TestResolveDBConnectionString588=== RUN TestConnectWaitsForAPeerMigration589=== PAUSE TestConnectWaitsForAPeerMigration590=== RUN TestConnectSerialisesConcurrentMigrations591=== PAUSE TestConnectSerialisesConcurrentMigrations592=== RUN TestLeadElectsOneAndHandsOver593=== PAUSE TestLeadElectsOneAndHandsOver594=== RUN TestLeadIncumbentWinsAfterRestart5952026/11/07 23:33:26 INFO lead: acquired remote=192.0.2.1:12345962026/11/07 23:33:26 INFO lead: released remote=192.0.2.1:12345972026/11/07 23:33:27 INFO lead: acquired remote=192.0.2.1:12345982026/11/07 23:33:28 INFO lead: released remote=192.0.2.1:1234599--- PASS: TestLeadIncumbentWinsAfterRestart (2.20s)600=== RUN TestLeadIncumbentAnnouncesAtOnce601=== PAUSE TestLeadIncumbentAnnouncesAtOnce602=== RUN TestLeadEndsOnShutdown603=== PAUSE TestLeadEndsOnShutdown604=== RUN TestLeadEndsWhenItsConnectionHangs6052026/11/07 23:33:28 INFO lead: acquired remote=192.0.2.1:12346062026-11-07 23:33:29.695 UTC [81842] FATAL: terminating connection due to administrator command6072026/11/07 23:33:29 INFO lead: acquired remote=192.0.2.1:12346082026/11/07 23:33:30 WARN lead: lock connection lost error="timeout: context deadline exceeded"6092026/11/07 23:33:30 INFO lead: released remote=192.0.2.1:12346102026/11/07 23:33:31 INFO lead: released remote=192.0.2.1:1234611--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)612=== RUN TestGCAdvisoryLockBlocksConcurrentRun613=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun614=== RUN TestGCBugBareHashReferences615=== PAUSE TestGCBugBareHashReferences616=== RUN TestGCMetrics617=== PAUSE TestGCMetrics618=== RUN TestPushDedupSurvivesConcurrentGC619=== PAUSE TestPushDedupSurvivesConcurrentGC620=== RUN TestDeduplicatedObjectsRecordedAsPending621=== PAUSE TestDeduplicatedObjectsRecordedAsPending622=== RUN TestGCSweepSkipsPendingObjects623=== PAUSE TestGCSweepSkipsPendingObjects624=== RUN TestTombstonedObjectOfferedWithoutWaiting625=== PAUSE TestTombstonedObjectOfferedWithoutWaiting626=== RUN TestGCSweepDeliversEachKeyOnce627=== PAUSE TestGCSweepDeliversEachKeyOnce628=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection629=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection630=== RUN TestForceGCDuringPushOffersSweptObject631=== PAUSE TestForceGCDuringPushOffersSweptObject632=== RUN TestFailedS3DeleteKeepsTombstone633=== PAUSE TestFailedS3DeleteKeepsTombstone634=== RUN TestSweepSkipsRowsLockedByPush635=== PAUSE TestSweepSkipsRowsLockedByPush636=== RUN TestRegisterCompletedObjectNeedsPendingRow637=== PAUSE TestRegisterCompletedObjectNeedsPendingRow638=== RUN TestGetExistingObjectsLocksRows639=== PAUSE TestGetExistingObjectsLocksRows640=== RUN TestSweepRechecksPendingAfterLocking641=== PAUSE TestSweepRechecksPendingAfterLocking642=== RUN TestPushWaitsForSweepHoldingRow643=== PAUSE TestPushWaitsForSweepHoldingRow644=== RUN TestCommitRacingPendingCleanupKeepsObjects645=== PAUSE TestCommitRacingPendingCleanupKeepsObjects646=== RUN TestGCEndsOnShutdown647=== PAUSE TestGCEndsOnShutdown648=== RUN TestGCTaskStore_StartNew649=== PAUSE TestGCTaskStore_StartNew650=== RUN TestGCTaskStore_DeduplicateSameParams651=== PAUSE TestGCTaskStore_DeduplicateSameParams652=== RUN TestGCTaskStore_ConflictDifferentParams653=== PAUSE TestGCTaskStore_ConflictDifferentParams654=== RUN TestGCTaskStore_GetEmpty655=== PAUSE TestGCTaskStore_GetEmpty656=== RUN TestGCTaskStore_GetReturnsLatest657=== PAUSE TestGCTaskStore_GetReturnsLatest658=== RUN TestGCTaskStore_CompletedAllowsNewTask659=== PAUSE TestGCTaskStore_CompletedAllowsNewTask660=== RUN TestGCTaskStore_PhaseUpdates661=== PAUSE TestGCTaskStore_PhaseUpdates662=== RUN TestGCTaskStore_Fail663=== PAUSE TestGCTaskStore_Fail664=== RUN TestGracefulShutdownDrainsInflight665=== PAUSE TestGracefulShutdownDrainsInflight666=== RUN TestService_healthCheckHandler667=== PAUSE TestService_healthCheckHandler668=== RUN TestService_readinessHandler669=== PAUSE TestService_readinessHandler670=== RUN TestGenerateLandingPage671=== PAUSE TestGenerateLandingPage672=== RUN TestEnsureAbortUploadsRule673=== PAUSE TestEnsureAbortUploadsRule674=== RUN TestChildrenInheritRaisedFileLimit675=== PAUSE TestChildrenInheritRaisedFileLimit676=== RUN TestCacheConfigHandlerMaxNarSize677=== PAUSE TestCacheConfigHandlerMaxNarSize678=== RUN TestCreatePendingClosureRejectsOversizedNAR679=== PAUSE TestCreatePendingClosureRejectsOversizedNAR680=== RUN TestNARDeduplicationMetadataUploadBug681=== PAUSE TestNARDeduplicationMetadataUploadBug682=== RUN TestMetricsInventory683=== PAUSE TestMetricsInventory684=== RUN TestMetricsCommit685=== PAUSE TestMetricsCommit686=== RUN TestService_NativeMTLS687=== PAUSE TestService_NativeMTLS688=== RUN TestServerTLSConfig689=== PAUSE TestServerTLSConfig690=== RUN TestMultipartCleanup691=== PAUSE TestMultipartCleanup692=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded693=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded694=== RUN TestPendingCleanupUsesOneCutoff695=== PAUSE TestPendingCleanupUsesOneCutoff696=== RUN TestObjectStatsTrigger697=== PAUSE TestObjectStatsTrigger698=== RUN TestObjectStatsUpdatedOncePerCommit699=== PAUSE TestObjectStatsUpdatedOncePerCommit700=== RUN TestReconnectLeavesObjectsUnlocked701=== PAUSE TestReconnectLeavesObjectsUnlocked702=== RUN TestOrphanedObjectsGC703=== PAUSE TestOrphanedObjectsGC704=== RUN TestOrphanedObjectsGCStressTest705=== PAUSE TestOrphanedObjectsGCStressTest706=== RUN TestCreatePin_ReservedPins707=== PAUSE TestCreatePin_ReservedPins708=== RUN TestConcurrentPinUpdatesAgree709=== PAUSE TestConcurrentPinUpdatesAgree710=== RUN TestCreatePinRejectsBadInput711=== PAUSE TestCreatePinRejectsBadInput712=== RUN TestDeletePinKeepsRowWhenS3Fails713=== PAUSE TestDeletePinKeepsRowWhenS3Fails714=== RUN TestPresentReportsOnlyClosureRoots715=== PAUSE TestPresentReportsOnlyClosureRoots716=== RUN TestPresentRefreshesOnlyStaleClosures717=== PAUSE TestPresentRefreshesOnlyStaleClosures718=== RUN TestPresentNotReportedWhileGCDeletesClosure719=== PAUSE TestPresentNotReportedWhileGCDeletesClosure720=== RUN TestParseSingleRange721=== PAUSE TestParseSingleRange722=== RUN TestProxyHeadersOnlyTrustedOnSocket7232026/11/07 23:33:31 INFO Starting HTTP server address=127.0.0.1:547327242026/11/07 23:33:31 INFO Starting HTTP server address=proxy.sock7252026/11/07 23:33:31 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7262026/11/07 23:33:31 INFO Shutdown signal received, draining in-flight requests timeout=10s727--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.25s)728=== RUN TestIsValidCachePath729=== PAUSE TestIsValidCachePath730=== RUN TestReadProxyNarinfo731=== PAUSE TestReadProxyNarinfo732=== RUN TestReadProxyNarinfoAlreadyDecompressed733=== PAUSE TestReadProxyNarinfoAlreadyDecompressed734=== RUN TestReadProxyContentNegotiation735=== PAUSE TestReadProxyContentNegotiation736=== RUN TestReadProxyNarStreaming737=== PAUSE TestReadProxyNarStreaming738=== RUN TestReadProxy404And429739=== PAUSE TestReadProxy404And429740=== RUN TestReadProxyInvalidPath741=== PAUSE TestReadProxyInvalidPath742=== RUN TestReadProxyHead743=== PAUSE TestReadProxyHead744=== RUN TestReadProxyOutlastsServerWriteTimeout745=== PAUSE TestReadProxyOutlastsServerWriteTimeout746=== RUN TestReadProxyConditionalGet747=== PAUSE TestReadProxyConditionalGet748=== RUN TestReadProxyRootRedirectsToIndexHTML749=== PAUSE TestReadProxyRootRedirectsToIndexHTML750=== RUN TestReadProxyDisabled751=== PAUSE TestReadProxyDisabled752=== RUN TestReadRedirectNar753=== PAUSE TestReadRedirectNar754=== RUN TestReadRedirectKeepsNarinfoProxied755=== PAUSE TestReadRedirectKeepsNarinfoProxied756=== RUN TestReadProxyRangeRequest757=== PAUSE TestReadProxyRangeRequest758=== RUN TestReadRedirectUsesPublicS3URL759=== PAUSE TestReadRedirectUsesPublicS3URL760=== RUN TestPush_OverlappingRootsStoreOneRowPerKey761=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey762=== RUN TestPush_CompleteCommitsEveryRoot763=== PAUSE TestPush_CompleteCommitsEveryRoot764=== RUN TestPush_RepeatedRootCommitsOnce765=== PAUSE TestPush_RepeatedRootCommitsOnce766=== RUN TestPush_CompleteWaitsForCleanupOfThePush767=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush768=== RUN TestPush_RootsAreLockedInByteOrder769=== PAUSE TestPush_RootsAreLockedInByteOrder770=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit771=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit772=== RUN TestPush_RejectsBadRequests773=== PAUSE TestPush_RejectsBadRequests774=== RUN TestPush_SignsNarinfosOfItsPendingObjects775=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects776=== RUN TestSharedNarBothUploadsComplete777=== PAUSE TestSharedNarBothUploadsComplete778=== RUN TestCompleteMultipartUpload_ErrorButObjectExists779=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists780=== RUN TestCompletedNarNotReofferedAcrossClosures781=== PAUSE TestCompletedNarNotReofferedAcrossClosures782=== RUN TestPresignedUploadRegisteredBeforeCommit783=== PAUSE TestPresignedUploadRegisteredBeforeCommit784=== RUN TestService_Rustfstest785=== PAUSE TestService_Rustfstest786=== RUN TestParseSize787=== PAUSE TestParseSize788=== RUN TestSkippedUploadsHandler789=== PAUSE TestSkippedUploadsHandler790=== RUN TestSystemdListenerNotActivated791--- PASS: TestSystemdListenerNotActivated (0.00s)792=== RUN TestWatchdogBeatsWhenHealthy793--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)794=== RUN TestWatchdogSkipsWhenUnhealthy7952026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7962026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7972026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7982026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7992026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8002026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8012026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8022026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8032026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8042026/11/07 23:33:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"805--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)806=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle807=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle808=== RUN TestProxyWriteTimeout809=== PAUSE TestProxyWriteTimeout810=== RUN TestPendingClosureWriteTimeout811=== PAUSE TestPendingClosureWriteTimeout812=== RUN TestIsValidUploadKey813=== PAUSE TestIsValidUploadKey814=== RUN TestUploadHandlersRejectInvalidKeys815=== PAUSE TestUploadHandlersRejectInvalidKeys816=== RUN TestUploadHandlersRejectOversizedBody817=== PAUSE TestUploadHandlersRejectOversizedBody818=== RUN TestService_cleanupPendingClosuresHandler819=== PAUSE TestService_cleanupPendingClosuresHandler820=== RUN TestService_createPendingClosureHandler821=== PAUSE TestService_createPendingClosureHandler822=== RUN TestService_verifyS3Integrity823=== PAUSE TestService_verifyS3Integrity824=== RUN TestService_verifyS3ReuploadsStaleNarinfo825=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo826=== RUN TestCompleteMultipartUnregistered827=== PAUSE TestCompleteMultipartUnregistered828=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT829=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT830=== CONT TestService_AuthMiddleware831=== CONT TestUploadHandlersRejectOversizedBody832=== CONT TestObjectStatsUpdatedOncePerCommit833=== CONT TestChildrenInheritRaisedFileLimit834=== CONT TestCreatePin_ReservedPins835=== CONT TestOrphanedObjectsGCStressTest836=== CONT TestCacheConfigHandlerMaxNarSize837=== CONT TestParseSingleRange838=== CONT TestOrphanedObjectsGC839=== CONT TestNARDeduplicationMetadataUploadBug840=== CONT TestCreatePinRejectsBadInput841=== CONT TestService_verifyS3ReuploadsStaleNarinfo842=== CONT TestService_verifyS3Integrity843=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed844=== CONT TestCompleteMultipartUnregistered845=== CONT TestService_createPendingClosureHandler846=== CONT TestSweepRechecksPendingAfterLocking847=== CONT TestMetricsCommit848=== CONT TestPresentNotReportedWhileGCDeletesClosure849=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale850=== CONT TestReadProxyNarinfoAlreadyDecompressed851=== CONT TestCreatePendingClosureRejectsOversizedNAR852=== CONT TestPresentRefreshesOnlyStaleClosures853=== CONT TestDeletePinKeepsRowWhenS3Fails854=== CONT TestConcurrentPinUpdatesAgree855=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8562026/11/07 23:33:31 INFO Received uploads request method=POST path=/api/pending_closures857=== RUN TestParseSingleRange/none858--- PASS: TestCacheConfigHandlerMaxNarSize (0.01s)859=== PAUSE TestParseSingleRange/none860=== RUN TestParseSingleRange/unknown_unit861=== PAUSE TestParseSingleRange/unknown_unit862=== RUN TestParseSingleRange/multi-range_ignored863=== PAUSE TestParseSingleRange/multi-range_ignored864=== CONT TestRegisterCompletedObjectNeedsPendingRow865=== CONT TestGetExistingObjectsLocksRows866--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.02s)867=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale868=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed869=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed870=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed871=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost872=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost873=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed874=== RUN TestParseSingleRange/malformed_no_dash875=== PAUSE TestParseSingleRange/malformed_no_dash876=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed877=== RUN TestParseSingleRange/malformed_both_empty878=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh879=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh880=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed881=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed882=== PAUSE TestParseSingleRange/malformed_both_empty883=== CONT TestFailedS3DeleteKeepsTombstone884=== RUN TestParseSingleRange/malformed_end_before_start885=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection886=== PAUSE TestParseSingleRange/malformed_end_before_start887=== RUN TestParseSingleRange/closed888=== PAUSE TestParseSingleRange/closed889=== RUN TestParseSingleRange/open-ended890=== PAUSE TestParseSingleRange/open-ended891=== RUN TestParseSingleRange/end_clamped_to_size892=== PAUSE TestParseSingleRange/end_clamped_to_size893=== RUN TestParseSingleRange/suffix894=== PAUSE TestParseSingleRange/suffix895=== RUN TestParseSingleRange/suffix_exceeds_size896=== PAUSE TestParseSingleRange/suffix_exceeds_size897=== RUN TestParseSingleRange/single_byte898=== PAUSE TestParseSingleRange/single_byte899=== RUN TestParseSingleRange/start_past_EOF900=== PAUSE TestParseSingleRange/start_past_EOF901=== RUN TestParseSingleRange/start_far_past_EOF902=== PAUSE TestParseSingleRange/start_far_past_EOF903=== CONT TestForceGCDuringPushOffersSweptObject904=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows905=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows906=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check907=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check908=== CONT TestGCSweepDeliversEachKeyOnce909--- PASS: TestChildrenInheritRaisedFileLimit (0.11s)910=== CONT TestTombstonedObjectOfferedWithoutWaiting9112026/11/07 23:33:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54736/oidc912=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure913=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure914=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart915=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart916=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts917=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts918=== CONT TestGCSweepSkipsPendingObjects9192026/11/07 23:33:32 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"920--- PASS: TestService_AuthMiddleware (0.74s)921=== CONT TestPushDedupSurvivesConcurrentGC922--- PASS: TestObjectStatsUpdatedOncePerCommit (1.33s)923=== CONT TestDeduplicatedObjectsRecordedAsPending9242026/11/07 23:33:32 INFO Aborted multipart uploads count=0 kept=09252026/11/07 23:33:33 WARN Force mode enabled - objects will be deleted immediately without grace period9262026/11/07 23:33:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09272026/11/07 23:33:33 INFO Vacuumed table table=pending_closures9282026/11/07 23:33:33 INFO Vacuumed table table=pending_objects9292026/11/07 23:33:33 INFO Vacuumed table table=multipart_uploads9302026/11/07 23:33:33 INFO Vacuumed table table=closures9312026/11/07 23:33:33 INFO Vacuumed table table=objects932--- PASS: TestSweepRechecksPendingAfterLocking (1.60s)933=== CONT TestGCMetrics9342026/11/07 23:33:34 INFO Received uploads request method=POST path=/api/pending_closures9352026/11/07 23:33:34 INFO Received uploads request method=POST path=/api/pending_closures9362026/11/07 23:33:34 INFO Received uploads request method=POST path=/api/pending_closures937=== NAME TestNARDeduplicationMetadataUploadBug938 metadata_upload_test.go:48: First store path: /private/var/tb/4/scratch/89da011d463ecd02/build/TestNARDeduplicationMetadataUploadBug4094268856/001/store/ch04yrfiap5731p96dvvwkrxhxxfdch9-file1.txt9392026/11/07 23:33:34 INFO Received push request method=POST path=/api/pushes9402026/11/07 23:33:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9412026/11/07 23:33:34 INFO Uploading ch04yrfiap5731p96dvvwkrxhxxfdch9-file1.txt (160B)9422026/11/07 23:33:34 WARN Failed to register uploaded object key=ch04yrfiap5731p96dvvwkrxhxxfdch9.ls error="server returned 404: 404 page not found\n"9432026/11/07 23:33:34 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9442026/11/07 23:33:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9452026/11/07 23:33:34 INFO Signed narinfos id=1 count=19462026/11/07 23:33:34 INFO Uploading 1 narinfos9472026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9482026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9492026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9502026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9512026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9522026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9532026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9542026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9552026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9562026/11/07 23:33:34 INFO Received complete push request method=POST path=/api/pushes/1/complete9572026/11/07 23:33:34 WARN Failed to register uploaded object key=ch04yrfiap5731p96dvvwkrxhxxfdch9.narinfo error="server returned 404: 404 page not found\n"9582026/11/07 23:33:34 INFO Completed push id=1 objects=3 duration=15.499917ms9592026/11/07 23:33:34 INFO Upload complete. (279ms)960 metadata_upload_test.go:54: Retrieved narinfo from S3:961 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestNARDeduplicationMetadataUploadBug4094268856/001/store/ch04yrfiap5731p96dvvwkrxhxxfdch9-file1.txt962 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst963 Compression: zstd964 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf965 NarSize: 160966 References: 967 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf968 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)969 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):970 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}971 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/4/scratch/89da011d463ecd02/build/TestNARDeduplicationMetadataUploadBug4094268856/001/store/aw771p1x7cgym9wil3v3jbmbc5020swb-file2.txt9722026/11/07 23:33:34 INFO Received push request method=POST path=/api/pushes9732026/11/07 23:33:34 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9742026/11/07 23:33:34 INFO Received create pin request method=POST path=/api/pins/deploy9752026/11/07 23:33:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9762026/11/07 23:33:34 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst977--- PASS: TestCompleteMultipartUnregistered (3.31s)978=== CONT TestGCAdvisoryLockBlocksConcurrentRun9792026/11/07 23:33:34 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9802026/11/07 23:33:34 WARN Failed to register uploaded object key=aw771p1x7cgym9wil3v3jbmbc5020swb.ls error="server returned 404: 404 page not found\n"9812026/11/07 23:33:34 INFO Signed narinfos id=2 count=19822026/11/07 23:33:35 INFO Uploading 1 narinfos9832026/11/07 23:33:35 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo984--- PASS: TestCreatePinRejectsBadInput (3.45s)985=== CONT TestGCBugBareHashReferences9862026/11/07 23:33:35 INFO Received complete push request method=POST path=/api/pushes/2/complete9872026/11/07 23:33:35 WARN Failed to register uploaded object key=aw771p1x7cgym9wil3v3jbmbc5020swb.narinfo error="server returned 404: 404 page not found\n"9882026/11/07 23:33:35 INFO Completed push id=2 objects=3 duration=151.075875ms9892026/11/07 23:33:35 INFO Upload complete. (395ms)990=== NAME TestNARDeduplicationMetadataUploadBug991 metadata_upload_test.go:76: Retrieved narinfo from S3:992 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestNARDeduplicationMetadataUploadBug4094268856/001/store/aw771p1x7cgym9wil3v3jbmbc5020swb-file2.txt993 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst994 Compression: zstd995 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf996 NarSize: 160997 References: 998 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf999 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1000 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1001 {"version":1,"root":{"type":"regular","size":44}}1002=== NAME TestOrphanedObjectsGC1003 orphaned_objects_gc_test.go:287: GC Test Summary:1004 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1005 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1006 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1007 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1008 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1009--- PASS: TestOrphanedObjectsGC (3.72s)1010=== CONT TestLeadEndsOnShutdown1011--- PASS: TestNARDeduplicationMetadataUploadBug (3.75s)1012=== CONT TestLeadIncumbentAnnouncesAtOnce1013--- PASS: TestPresentRefreshesOnlyStaleClosures (3.87s)1014=== CONT TestConnectSerialisesConcurrentMigrations1015=== CONT TestLeadElectsOneAndHandsOver1016--- PASS: TestGetExistingObjectsLocksRows (4.11s)10172026/11/07 23:33:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10182026/11/07 23:33:35 INFO Received uploads request method=POST path=/api/pending_closures10192026/11/07 23:33:36 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjIwZTViZDc3LTFhOTItNDYyNy1iMDlmLWY5ZmE3NDEyMzIzY3gxNzk0MDk0NDE0Mjk0MTQ5MDAw parts=1010202026/11/07 23:33:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10212026/11/07 23:33:36 INFO Completed upload id=1 objects=2 duration=18.42225ms10222026/11/07 23:33:36 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010232026/11/07 23:33:36 INFO Received uploads request method=POST path=/api/pending_closures10242026/11/07 23:33:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures10252026/11/07 23:33:36 INFO Aborted multipart uploads count=0 kept=010262026/11/07 23:33:36 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=010272026/11/07 23:33:36 INFO Vacuumed table table=pending_closures10282026/11/07 23:33:36 INFO Aborted multipart uploads count=0 kept=010292026/11/07 23:33:36 WARN Force mode enabled - objects will be deleted immediately without grace period10302026/11/07 23:33:36 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10312026/11/07 23:33:36 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10322026/11/07 23:33:36 INFO Vacuumed table table=pending_objects10332026/11/07 23:33:36 INFO Vacuumed table table=multipart_uploads10342026/11/07 23:33:36 INFO Vacuumed table table=closures10352026/11/07 23:33:36 INFO Vacuumed table table=objects10362026/11/07 23:33:36 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010372026/11/07 23:33:36 INFO Received push request method=POST path=/api/pushes1038--- PASS: TestService_createPendingClosureHandler (4.69s)1039--- PASS: TestFailedS3DeleteKeepsTombstone (4.63s)1040=== CONT TestPresentReportsOnlyClosureRoots1041=== CONT TestResolveDBConnectionString1042=== RUN TestResolveDBConnectionString/flag_wins1043=== PAUSE TestResolveDBConnectionString/flag_wins1044=== RUN TestResolveDBConnectionString/file_when_flag_empty1045=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1046=== RUN TestResolveDBConnectionString/missing_file_is_an_error1047=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1048=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1049=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1050=== RUN TestResolveDBConnectionString/nothing_configured1051=== PAUSE TestResolveDBConnectionString/nothing_configured1052=== CONT TestConnectWaitsForAPeerMigration10532026/11/07 23:33:36 INFO Aborted multipart uploads count=0 kept=010542026/11/07 23:33:36 WARN Force mode enabled - objects will be deleted immediately without grace period10552026/11/07 23:33:37 INFO Received uploads request method=POST path=/api/pending_closures10562026/11/07 23:33:37 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=010572026/11/07 23:33:37 INFO Vacuumed table table=pending_closures10582026/11/07 23:33:37 INFO Vacuumed table table=pending_objects10592026/11/07 23:33:37 INFO Vacuumed table table=multipart_uploads10602026/11/07 23:33:37 INFO Vacuumed table table=closures10612026/11/07 23:33:37 INFO Vacuumed table table=objects1062--- PASS: TestGCSweepDeliversEachKeyOnce (5.77s)1063=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1064--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.87s)1065=== CONT TestPush_RepeatedRootCommitsOnce1066--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.39s)1067=== CONT TestEnsureAbortUploadsRule10682026-11-07 23:33:38.178 UTC [81983] ERROR: relation "goose_db_version" already exists10692026-11-07 23:33:38.178 UTC [81983] STATEMENT: CREATE TABLE goose_db_version (1070 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1071 version_id bigint NOT NULL,1072 is_applied boolean NOT NULL,1073 tstamp timestamp NOT NULL DEFAULT now()1074 )10752026/11/07 23:33:38 INFO Received uploads request method=POST path=/api/pending_closures10762026/11/07 23:33:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10772026/11/07 23:33:38 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjFiYzA1OWM1LWE2NGItNDBiYi1hNWI5LTk5MmQ1M2I0M2RjY3gxNzk0MDk0NDE2NDAyODU5MDAw parts=101078--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.91s)1079=== CONT TestObjectStatsTrigger10802026/11/07 23:33:38 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestTombstonedObjectOfferedWithoutWaiting (7.16s)1082=== CONT TestService_readinessHandler10832026/11/07 23:33:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/app1085=== CONT TestReconnectLeavesObjectsUnlocked1086--- PASS: TestConnectSerialisesConcurrentMigrations (3.68s)10872026/11/07 23:33:39 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjdlMGE1Yjg5LWE4ZGUtNGIyNy1hMTU2LWJjMDUwNTA1OTI4YngxNzk0MDk0NDE3MDY4NDE5MDAw parts=1010882026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/app10892026/11/07 23:33:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10902026/11/07 23:33:39 INFO Completed upload id=1 objects=2 duration=30.032208ms10912026/11/07 23:33:39 INFO Received uploads request method=POST path=/api/pending_closures10922026/11/07 23:33:39 INFO Received uploads request method=POST path=/api/pending_closures10932026/11/07 23:33:39 INFO Received uploads request method=POST path=/api/pending_closures10942026/11/07 23:33:39 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10952026/11/07 23:33:39 WARN Found objects in DB but missing from S3, will re-upload count=110962026/11/07 23:33:39 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10972026/11/07 23:33:39 INFO Completed upload id=3 objects=2 duration=1.611792ms1098--- PASS: TestService_verifyS3Integrity (8.04s)1099=== CONT TestService_healthCheckHandler1100--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (8.04s)1101=== CONT TestPendingCleanupUsesOneCutoff11022026/11/07 23:33:39 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo11032026/11/07 23:33:39 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1104--- PASS: TestConcurrentPinUpdatesAgree (8.22s)1105=== CONT TestGracefulShutdownDrainsInflight11062026/11/07 23:33:39 INFO Starting HTTP server address=127.0.0.1:5485511072026/11/07 23:33:39 INFO Shutdown signal received, draining in-flight requests timeout=10s11082026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11092026/11/07 23:33:39 WARN Refused reserved pin name=worker-x86_64-linux11102026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11112026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/my-app11122026/11/07 23:33:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1113--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1114=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1115--- PASS: TestCreatePin_ReservedPins (8.35s)1116=== CONT TestGCTaskStore_Fail1117=== CONT TestServerTLSConfig1118=== RUN TestServerTLSConfig/no_client_CA1119=== PAUSE TestServerTLSConfig/no_client_CA1120--- PASS: TestGCTaskStore_Fail (0.00s)1121=== RUN TestServerTLSConfig/missing_CA_file1122=== PAUSE TestServerTLSConfig/missing_CA_file1123=== RUN TestServerTLSConfig/not_a_PEM_file1124=== PAUSE TestServerTLSConfig/not_a_PEM_file1125=== CONT TestGCTaskStore_PhaseUpdates1126--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1127=== CONT TestMultipartCleanup11282026/11/07 23:33:40 INFO Received create pin request method=POST path=/api/pins/app11292026/11/07 23:33:40 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo11302026/11/07 23:33:40 INFO Received delete pin request method=DELETE path=/api/pins/app11312026/11/07 23:33:40 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11322026/11/07 23:33:40 INFO Received delete pin request method=DELETE path=/api/pins/app11332026/11/07 23:33:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11342026/11/07 23:33:40 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjdlYmJjMmUwLTUxNmQtNDc1OS1hNGM2LWNkNjk2OTExNzg0MHgxNzk0MDk0NDE2NDAyMzk2MDAw parts=1011352026/11/07 23:33:40 INFO Received complete push request method=POST path=/api/pushes/1/complete11362026/11/07 23:33:40 INFO Received uploads request method=POST path=/api/pending_closures11372026/11/07 23:33:40 INFO Deleted pin name=app11382026/11/07 23:33:40 INFO Completed push id=1 objects=4 duration=46.077291ms11392026/11/07 23:33:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11402026/11/07 23:33:40 INFO Completed upload id=2 objects=2 duration=2.774709ms1141--- PASS: TestDeletePinKeepsRowWhenS3Fails (9.16s)1142=== CONT TestParseSize1143--- PASS: TestParseSize (0.00s)1144=== CONT TestService_cleanupPendingClosuresHandler1145--- PASS: TestMetricsCommit (9.20s)1146=== CONT TestService_NativeMTLS11472026/11/07 23:33:40 INFO Aborted multipart uploads count=0 kept=011482026/11/07 23:33:40 WARN Force mode enabled - objects will be deleted immediately without grace period11492026/11/07 23:33:40 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=011502026/11/07 23:33:40 INFO Vacuumed table table=pending_closures11512026/11/07 23:33:41 INFO Vacuumed table table=pending_objects11522026/11/07 23:33:41 INFO Vacuumed table table=multipart_uploads11532026/11/07 23:33:41 INFO Vacuumed table table=closures11542026/11/07 23:33:41 INFO Vacuumed table table=objects11552026/11/07 23:33:41 INFO Received uploads request method=POST path=/api/pending_closures1156--- PASS: TestGCSweepSkipsPendingObjects (9.23s)1157=== CONT TestMetricsInventory1158--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.20s)1159=== CONT TestGCEndsOnShutdown1160=== RUN TestGCEndsOnShutdown/before_the_run1161=== PAUSE TestGCEndsOnShutdown/before_the_run1162=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1163=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1164=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1165=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1166=== CONT TestGCTaskStore_GetReturnsLatest1167--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1168=== CONT TestGCTaskStore_CompletedAllowsNewTask1169--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1170=== CONT TestGCTaskStore_ConflictDifferentParams1171=== CONT TestGCTaskStore_GetEmpty1172--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1173--- PASS: TestGCTaskStore_GetEmpty (0.00s)1174=== CONT TestGCTaskStore_StartNew1175--- PASS: TestGCTaskStore_StartNew (0.00s)1176=== CONT TestReadProxyHead11772026/11/07 23:33:41 INFO Aborted multipart uploads count=0 kept=011782026/11/07 23:33:41 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/11/07 23:33:41 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=011802026/11/07 23:33:41 INFO Vacuumed table table=pending_closures11812026/11/07 23:33:41 INFO Vacuumed table table=pending_objects11822026/11/07 23:33:41 INFO Vacuumed table table=multipart_uploads11832026/11/07 23:33:41 INFO Vacuumed table table=closures11842026/11/07 23:33:41 INFO Vacuumed table table=objects1185--- PASS: TestGCMetrics (8.33s)1186=== CONT TestPush_CompleteCommitsEveryRoot11872026/11/07 23:33:42 INFO Received uploads request method=POST path=/api/pending_closures11882026/11/07 23:33:42 INFO Aborted multipart uploads count=0 kept=011892026/11/07 23:33:42 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=011902026/11/07 23:33:42 INFO Vacuumed table table=pending_closures11912026/11/07 23:33:42 INFO Vacuumed table table=pending_objects11922026/11/07 23:33:42 INFO Vacuumed table table=multipart_uploads11932026/11/07 23:33:42 INFO Vacuumed table table=closures11942026/11/07 23:33:42 INFO Vacuumed table table=objects11952026/11/07 23:33:42 INFO Aborted multipart uploads count=0 kept=011962026/11/07 23:33:42 WARN Force mode enabled - objects will be deleted immediately without grace period11972026/11/07 23:33:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011982026/11/07 23:33:42 INFO Vacuumed table table=pending_closures11992026/11/07 23:33:42 INFO Vacuumed table table=pending_objects12002026/11/07 23:33:42 INFO Vacuumed table table=multipart_uploads12012026/11/07 23:33:42 INFO Vacuumed table table=closures12022026/11/07 23:33:42 INFO Vacuumed table table=objects1203--- PASS: TestPushDedupSurvivesConcurrentGC (10.21s)1204=== CONT TestReadRedirectUsesPublicS3URL1205--- PASS: TestGCBugBareHashReferences (7.87s)1206=== CONT TestReadProxyRangeRequest12072026/11/07 23:33:42 INFO lead: acquired remote=192.0.2.1:123412082026/11/07 23:33:43 INFO lead: acquired remote=192.0.2.1:123412092026/11/07 23:33:43 INFO lead: released remote=192.0.2.1:12341210--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.98s)1211=== CONT TestReadRedirectKeepsNarinfoProxied12122026/11/07 23:33:43 INFO lead: acquired remote=192.0.2.1:12341213--- PASS: TestPresentReportsOnlyClosureRoots (7.72s)1214=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12152026/11/07 23:33:44 INFO lead: released remote=192.0.2.1:12341216--- PASS: TestLeadEndsOnShutdown (8.76s)1217=== CONT TestReadProxyDisabled12182026/11/07 23:33:44 INFO Received push request method=POST path=/api/pushes12192026/11/07 23:33:44 INFO lead: released remote=192.0.2.1:123412202026/11/07 23:33:44 INFO lead: acquired remote=192.0.2.1:123412212026/11/07 23:33:45 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket39 days=21222--- PASS: TestEnsureAbortUploadsRule (7.01s)1223=== CONT TestReadRedirectNar1224--- PASS: TestConnectWaitsForAPeerMigration (8.94s)1225=== CONT TestReadProxyConditionalGet1226--- PASS: TestObjectStatsTrigger (6.75s)1227=== CONT TestReadProxyOutlastsServerWriteTimeout12282026/11/07 23:33:45 WARN readiness check failed error="closed pool"1229--- PASS: TestService_readinessHandler (6.71s)1230=== CONT TestPush_SignsNarinfosOfItsPendingObjects1231--- PASS: TestService_healthCheckHandler (6.27s)1232=== CONT TestPresignedUploadRegisteredBeforeCommit12332026/11/07 23:33:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12342026/11/07 23:33:46 INFO lead: released remote=192.0.2.1:12341235--- PASS: TestLeadElectsOneAndHandsOver (10.36s)1236=== CONT TestCompletedNarNotReofferedAcrossClosures12372026/11/07 23:33:46 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjcwOWM2NGQ5LWYxNDEtNDZiOS1hNTA3LWEwMzQ0ODEwOGYyZXgxNzk0MDk0NDI0MzIwMDQ3MDAw parts=101238--- PASS: TestReconnectLeavesObjectsUnlocked (7.18s)1239=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12402026/11/07 23:33:46 INFO Received uploads request method=POST path=/api/pending_closures12412026/11/07 23:33:46 INFO Received uploads request method=POST path=/api/pending_closures12422026/11/07 23:33:46 INFO Received cleanup request method=DELETE path=/api/pending_closures12432026/11/07 23:33:47 INFO Received uploads request method=POST path=/api/pending_closures1244--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.26s)1245=== CONT TestSharedNarBothUploadsComplete12462026/11/07 23:33:47 INFO Received uploads request method=POST path=/api/pending_closures1247=== NAME TestOrphanedObjectsGCStressTest1248 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains12492026/11/07 23:33:47 INFO Received cleanup request method=DELETE path=/api/pending_closures1250 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion12512026/11/07 23:33:47 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12522026/11/07 23:33:47 INFO Aborted multipart uploads count=0 kept=112532026/11/07 23:33:47 INFO Received cleanup request method=DELETE path=/api/pending_closures12542026/11/07 23:33:47 INFO Aborted multipart uploads count=1 kept=01255--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.29s)1256=== CONT TestGenerateLandingPage1257--- PASS: TestGenerateLandingPage (0.01s)1258=== CONT TestGCTaskStore_DeduplicateSameParams1259--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1260=== CONT TestCommitRacingPendingCleanupKeepsObjects1261--- PASS: TestMultipartCleanup (7.82s)1262=== CONT TestPushWaitsForSweepHoldingRow12632026/11/07 23:33:47 INFO Received cleanup request method=DELETE path=/api/pending_closures12642026/11/07 23:33:47 INFO Aborted multipart uploads count=0 kept=012652026/11/07 23:33:47 INFO Received uploads request method=POST path=/api/pending_closures12662026/11/07 23:33:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12672026/11/07 23:33:48 INFO Received cleanup request method=DELETE path=/api/pending_closures12682026/11/07 23:33:48 INFO Aborted multipart uploads count=1 kept=012692026/11/07 23:33:48 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1Ljc5MjEwMTE2LTlkY2YtNDRhMC1hYWM0LWRiYTYzYzc5NmRiYXgxNzk0MDk0NDI0MzIwNzIwMDAw parts=1012702026/11/07 23:33:48 INFO Received complete push request method=POST path=/api/pushes/1/complete12712026/11/07 23:33:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12722026-11-07 23:33:48.312 UTC [82051] ERROR: Closure does not exist: id=112732026-11-07 23:33:48.312 UTC [82051] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12742026-11-07 23:33:48.312 UTC [82051] STATEMENT: -- name: CommitPendingClosure :one1275 SELECT commit_pending_closure($1::bigint)::bigint1276 12772026/11/07 23:33:48 INFO Completed push id=1 objects=4 duration=57.45125ms1278=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1279--- PASS: TestService_cleanupPendingClosuresHandler (7.55s)1280--- PASS: TestPush_RepeatedRootCommitsOnce (10.85s)1281=== CONT TestPush_RejectsBadRequests12822026/11/07 23:33:48 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12832026/11/07 23:33:48 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1284--- PASS: TestService_NativeMTLS (7.61s)1285=== CONT TestProxyWriteTimeout1286=== RUN TestProxyWriteTimeout/narinfo1287=== PAUSE TestProxyWriteTimeout/narinfo1288=== RUN TestProxyWriteTimeout/1_GiB_nar1289=== PAUSE TestProxyWriteTimeout/1_GiB_nar1290=== RUN TestProxyWriteTimeout/10_GiB_nar1291=== PAUSE TestProxyWriteTimeout/10_GiB_nar1292=== RUN TestProxyWriteTimeout/unknown_size1293=== PAUSE TestProxyWriteTimeout/unknown_size1294=== CONT TestIsValidUploadKey1295=== RUN TestIsValidUploadKey/narinfo1296=== PAUSE TestIsValidUploadKey/narinfo1297=== RUN TestIsValidUploadKey/nar_zst1298=== PAUSE TestIsValidUploadKey/nar_zst1299=== RUN TestIsValidUploadKey/nar_xz1300=== PAUSE TestIsValidUploadKey/nar_xz1301=== RUN TestIsValidUploadKey/nar_plain1302=== PAUSE TestIsValidUploadKey/nar_plain1303=== RUN TestIsValidUploadKey/listing1304=== PAUSE TestIsValidUploadKey/listing1305=== RUN TestIsValidUploadKey/build_log1306=== PAUSE TestIsValidUploadKey/build_log1307=== RUN TestIsValidUploadKey/build_log_home-manager_file1308=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1309=== RUN TestIsValidUploadKey/build_log_plus_in_name1310=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1311=== RUN TestIsValidUploadKey/build_log_question_mark1312=== PAUSE TestIsValidUploadKey/build_log_question_mark1313=== RUN TestIsValidUploadKey/build_log_equals1314=== PAUSE TestIsValidUploadKey/build_log_equals1315=== RUN TestIsValidUploadKey/realisation1316=== PAUSE TestIsValidUploadKey/realisation1317=== RUN TestIsValidUploadKey/realisation_plus_in_output1318=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1319=== RUN TestIsValidUploadKey/nix-cache-info1320=== PAUSE TestIsValidUploadKey/nix-cache-info1321=== RUN TestIsValidUploadKey/index.html1322=== PAUSE TestIsValidUploadKey/index.html1323=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1324=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1325=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1326=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1327=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1328=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1329=== RUN TestIsValidUploadKey/traversal1330=== PAUSE TestIsValidUploadKey/traversal1331=== RUN TestIsValidUploadKey/traversal_nar1332=== PAUSE TestIsValidUploadKey/traversal_nar1333=== RUN TestIsValidUploadKey/absolute1334=== PAUSE TestIsValidUploadKey/absolute1335=== RUN TestIsValidUploadKey/empty_key1336=== PAUSE TestIsValidUploadKey/empty_key1337=== RUN TestIsValidUploadKey/unknown_type1338=== PAUSE TestIsValidUploadKey/unknown_type1339=== CONT TestPendingClosureWriteTimeout1340=== RUN TestPendingClosureWriteTimeout/empty1341=== PAUSE TestPendingClosureWriteTimeout/empty1342=== RUN TestPendingClosureWriteTimeout/400_objects1343=== PAUSE TestPendingClosureWriteTimeout/400_objects1344=== RUN TestPendingClosureWriteTimeout/670k_objects1345=== PAUSE TestPendingClosureWriteTimeout/670k_objects1346=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1347=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1348=== CONT TestCacheStatsHandler1349--- PASS: TestMetricsInventory (7.78s)1350=== CONT TestDeleteClosuresRacingPins1351--- PASS: TestReadProxyHead (8.13s)1352=== CONT TestClientPushesUseOnePush13532026/11/07 23:33:49 INFO Received push request method=POST path=/api/pushes13542026/11/07 23:33:49 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld4 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1355--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (15.11s)1356=== CONT TestClientFallsBackToClosures1357--- PASS: TestReadRedirectUsesPublicS3URL (8.02s)1358=== CONT TestPinProtectsFromGC1359--- PASS: TestReadProxyRangeRequest (8.05s)1360=== CONT TestClientSharedPathCommittedMidPush1361--- PASS: TestReadRedirectKeepsNarinfoProxied (8.10s)1362=== CONT TestClientWithDependencies13632026/11/07 23:33:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13642026/11/07 23:33:51 INFO Received push request method=POST path=/api/pushes13652026/11/07 23:33:51 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjkxNmY2MjhhLTk5NGYtNDJmYi1hZDk4LWFiMmNiYjcyNTBlMXgxNzk0MDk0NDI5NjIxNzk4MDAw parts=101366--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (7.94s)1367=== CONT TestClientIntegration1368--- PASS: TestReadProxyDisabled (8.18s)1369=== CONT TestClientErrorHandling1370=== RUN TestClientErrorHandling/InvalidStorePath1371=== PAUSE TestClientErrorHandling/InvalidStorePath1372=== RUN TestClientErrorHandling/InvalidAuthToken1373=== PAUSE TestClientErrorHandling/InvalidAuthToken1374=== RUN TestClientErrorHandling/ServerNotAvailable1375=== PAUSE TestClientErrorHandling/ServerNotAvailable1376=== CONT TestClientMultipleUploads1377--- PASS: TestReadRedirectNar (7.71s)1378=== CONT TestPush_RootsAreLockedInByteOrder13792026/11/07 23:33:52 INFO Aborted multipart uploads count=1 kept=013802026/11/07 23:33:52 INFO Received cleanup request method=DELETE path=/api/pending_closures13812026/11/07 23:33:52 INFO Aborted multipart uploads count=1 kept=01382--- PASS: TestPendingCleanupUsesOneCutoff (13.30s)1383=== CONT TestService_RequireScope_OIDC13842026/11/07 23:33:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55040/oidc1385=== CONT TestCacheConfigHandler1386--- PASS: TestReadProxyConditionalGet (7.86s)1387=== RUN TestCacheConfigHandler/full_config,_no_issuer1388=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1389=== RUN TestCacheConfigHandler/no_cache_url_configured1390=== PAUSE TestCacheConfigHandler/no_cache_url_configured1391=== RUN TestCacheConfigHandler/no_signing_keys1392=== PAUSE TestCacheConfigHandler/no_signing_keys1393=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1394=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1395=== CONT TestService_ReadScope_PublicByDefault13962026/11/07 23:33:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13972026/11/07 23:33:53 INFO Received push request method=POST path=/api/pushes13982026/11/07 23:33:53 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjFmOWYyZWNmLTNmZmEtNGZkNC1iYjgwLTliMDVmYTdkNmFiYXgxNzk0MDk0NDI5NjIyNjQxMDAw parts=1013992026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14002026/11/07 23:33:53 INFO Signed narinfos id=1 count=114012026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14022026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14032026/11/07 23:33:53 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14042026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14052026/11/07 23:33:53 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14062026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14072026/11/07 23:33:53 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114082026/11/07 23:33:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14092026/11/07 23:33:53 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1410--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (8.37s)1411=== CONT TestClientCADerivations14122026/11/07 23:33:54 INFO Received uploads request method=POST path=/api/pending_closures14132026/11/07 23:33:54 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14142026/11/07 23:33:54 INFO Received uploads request method=POST path=/api/pending_closures1415--- PASS: TestPresignedUploadRegisteredBeforeCommit (8.39s)1416=== CONT TestService_AuthMiddleware_OIDC14172026/11/07 23:33:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55062/oidc14182026/11/07 23:33:54 INFO Received uploads request method=POST path=/api/pending_closures14192026/11/07 23:33:54 INFO Received uploads request method=POST path=/api/pending_closures14202026/11/07 23:33:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14212026/11/07 23:33:55 INFO Received uploads request method=POST path=/api/pending_closures14222026/11/07 23:33:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmVlOGQ2MDAxLTUxYzEtNDllZS05N2NjLTg2NjEyY2ViYmRjYXgxNzk0MDk0NDM1MDUwNDk0MDAw14232026/11/07 23:33:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmVlOGQ2MDAxLTUxYzEtNDllZS05N2NjLTg2NjEyY2ViYmRjYXgxNzk0MDk0NDM1MDUwNDk0MDAw parts=114242026/11/07 23:33:55 INFO Received uploads request method=POST path=/api/pending_closures1425--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (9.26s)1426=== CONT TestReadProxyContentNegotiation14272026/11/07 23:33:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14282026/11/07 23:33:56 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjEyNjgwNjI3LWNlZGMtNDVjNC05ZDA2LWFjMjY3Y2VmNjk4M3gxNzk0MDk0NDI5NjIyNDk5MDAw parts=1014292026/11/07 23:33:56 INFO Received complete push request method=POST path=/api/pushes/1/complete14302026/11/07 23:33:56 INFO Aborted multipart uploads count=0 kept=014312026/11/07 23:33:56 WARN Force mode enabled - objects will be deleted immediately without grace period14322026/11/07 23:33:56 INFO Completed push id=1 objects=6 duration=78.41175ms14332026/11/07 23:33:56 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=01434--- PASS: TestPush_CompleteCommitsEveryRoot (14.70s)1435=== CONT TestReadProxyRootRedirectsToIndexHTML14362026/11/07 23:33:56 INFO Vacuumed table table=pending_closures14372026/11/07 23:33:56 INFO Vacuumed table table=pending_objects14382026/11/07 23:33:56 INFO Vacuumed table table=multipart_uploads14392026/11/07 23:33:56 INFO Vacuumed table table=closures14402026/11/07 23:33:56 INFO Received uploads request method=POST path=/api/pending_closures14412026/11/07 23:33:56 INFO Vacuumed table table=objects1442--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.68s)1443=== CONT TestReadProxy404And4291444=== RUN TestPush_RejectsBadRequests/no_objects1445=== PAUSE TestPush_RejectsBadRequests/no_objects1446=== RUN TestPush_RejectsBadRequests/bad_root1447=== PAUSE TestPush_RejectsBadRequests/bad_root1448=== RUN TestPush_RejectsBadRequests/root_not_in_objects1449=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1450=== RUN TestPush_RejectsBadRequests/no_roots1451=== PAUSE TestPush_RejectsBadRequests/no_roots1452=== CONT TestReadProxyInvalidPath1453--- PASS: TestPushWaitsForSweepHoldingRow (9.13s)1454=== CONT TestReadProxyNarStreaming14552026/11/07 23:33:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14562026/11/07 23:33:57 INFO Received push request method=POST path=/api/pushes14572026/11/07 23:33:57 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjAwMDU4MDY3LWQxNDctNDgyZS1iNjYzLWQ3NmY4ZTdmYTc5NHgxNzk0MDk0NDM0NjIyMzc5MDAw parts=1214582026/11/07 23:33:57 INFO Received uploads request method=POST path=/api/pending_closures1459--- PASS: TestCompletedNarNotReofferedAcrossClosures (11.24s)1460=== CONT TestIsValidCachePath1461=== RUN TestIsValidCachePath/narinfo1462=== PAUSE TestIsValidCachePath/narinfo1463=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1464=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1465=== RUN TestIsValidCachePath/nar_zst1466=== PAUSE TestIsValidCachePath/nar_zst1467=== RUN TestIsValidCachePath/nar_xz1468=== PAUSE TestIsValidCachePath/nar_xz1469=== RUN TestIsValidCachePath/nar_bz21470=== PAUSE TestIsValidCachePath/nar_bz21471=== RUN TestIsValidCachePath/nar_uncompressed1472=== PAUSE TestIsValidCachePath/nar_uncompressed1473=== RUN TestIsValidCachePath/ls1474=== PAUSE TestIsValidCachePath/ls1475=== RUN TestIsValidCachePath/log1476=== PAUSE TestIsValidCachePath/log1477=== RUN TestIsValidCachePath/realisation1478=== PAUSE TestIsValidCachePath/realisation1479=== RUN TestIsValidCachePath/nix-cache-info1480=== PAUSE TestIsValidCachePath/nix-cache-info1481=== RUN TestIsValidCachePath/index.html1482=== PAUSE TestIsValidCachePath/index.html1483=== RUN TestIsValidCachePath/traversal_parent1484=== PAUSE TestIsValidCachePath/traversal_parent1485=== RUN TestIsValidCachePath/traversal_in_middle1486=== PAUSE TestIsValidCachePath/traversal_in_middle1487=== RUN TestIsValidCachePath/invalid_char_e1488=== PAUSE TestIsValidCachePath/invalid_char_e1489=== RUN TestIsValidCachePath/invalid_char_u1490=== PAUSE TestIsValidCachePath/invalid_char_u1491=== RUN TestIsValidCachePath/random_path1492=== PAUSE TestIsValidCachePath/random_path1493=== RUN TestIsValidCachePath/empty1494=== PAUSE TestIsValidCachePath/empty1495=== RUN TestIsValidCachePath/leading_slash1496=== PAUSE TestIsValidCachePath/leading_slash1497=== RUN TestIsValidCachePath/wrong_extension1498=== PAUSE TestIsValidCachePath/wrong_extension1499=== RUN TestIsValidCachePath/short_hash1500=== PAUSE TestIsValidCachePath/short_hash1501=== CONT TestReadProxyNarinfo1502--- PASS: TestCacheStatsHandler (9.26s)1503=== CONT TestService_AuthMiddleware_MTLSProxyHeader1504=== CONT TestService_ReadAuthMiddleware1505--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.42s)15062026/11/07 23:33:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15072026/11/07 23:33:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmM3NGJjOTNkLWU3OTctNDJiMC05ZWU1LTIzOWY5MDRmZGNhZXgxNzk0MDk0NDM1NTgxNDQ0MDAw parts=1215082026/11/07 23:33:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15092026/11/07 23:33:59 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjFlOWUzNzJmLTk3OTctNGE0Mi1iNjJlLTg1ODRiZmQ1YjAwNngxNzk0MDk0NDM3MjQzMDA0MDAw parts=1015102026/11/07 23:33:59 INFO Received push request method=POST path=/api/pushes15112026/11/07 23:33:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15122026/11/07 23:33:59 INFO Uploading 3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9-shared-dep (136B)15132026/11/07 23:33:59 INFO Uploading znrzcalqnjqdcscfr4zibicfsvzhvs41-b (256B)15142026/11/07 23:33:59 WARN Failed to register uploaded object key=aji4rc1r73kgq43bbdzfswxvzn9cgnjn.ls error="server returned 404: 404 page not found\n"15152026/11/07 23:33:59 WARN Failed to register uploaded object key=3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9.ls error="server returned 404: 404 page not found\n"15162026/11/07 23:33:59 WARN Failed to register uploaded object key=znrzcalqnjqdcscfr4zibicfsvzhvs41.ls error="server returned 404: 404 page not found\n"15172026/11/07 23:33:59 WARN Failed to register uploaded object key=nar/1i2cmlbq9rkq97p0qrxwvwk7b6rjscnsbibli6ycd5qa5bfz1g87.nar.zst error="server returned 404: 404 page not found\n"15182026/11/07 23:33:59 INFO Received uploads request method=POST path=/api/pending_closures15192026/11/07 23:33:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/11/07 23:33:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15212026/11/07 23:33:59 INFO Signed narinfos id=1 count=315222026/11/07 23:33:59 INFO Uploading 3 narinfos15232026/11/07 23:33:59 INFO Received uploads request method=POST path=/api/pending_closures15242026/11/07 23:33:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15252026/11/07 23:33:59 INFO Uploading 8fhmd0223y5in3h91pncnrdxdnzy757h-a (256B)15262026/11/07 23:33:59 INFO Uploading j688nbzn341zxqyshki4q8mkhqbr10p0-shared-dep (136B)1527=== NAME TestPinProtectsFromGC1528 client_integration_test.go:854: Pinned store path: /private/var/tb/4/scratch/89da011d463ecd02/build/TestPinProtectsFromGC1233153465/001/store/cq854i3fgmzvq2qg1jwrliyjsa5wxbpx-pinned-file.txt1529 client_integration_test.go:855: Unpinned store path: /private/var/tb/4/scratch/89da011d463ecd02/build/TestPinProtectsFromGC1233153465/001/store/1w1l068i36y4agkwryvkgbw0ap65cw69-unpinned-file.txt15302026/11/07 23:33:59 WARN Failed to register uploaded object key=znrzcalqnjqdcscfr4zibicfsvzhvs41.narinfo error="server returned 404: 404 page not found\n"15312026/11/07 23:33:59 WARN Failed to register uploaded object key=3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9.narinfo error="server returned 404: 404 page not found\n"15322026/11/07 23:33:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15332026/11/07 23:33:59 WARN Failed to register uploaded object key=aji4rc1r73kgq43bbdzfswxvzn9cgnjn.narinfo error="server returned 404: 404 page not found\n"15342026/11/07 23:34:00 WARN Failed to register uploaded object key=2qgj8y3b3lpp4ywji914kr10v7b11wbm.ls error="server returned 404: 404 page not found\n"15352026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15362026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/11a7dhzd90cf7hv2rxfz3yvzmg3apc7qjxf7asgbljr2q4xsisgd.nar.zst error="server returned 404: 404 page not found\n"15372026/11/07 23:34:00 WARN Failed to register uploaded object key=j688nbzn341zxqyshki4q8mkhqbr10p0.ls error="server returned 404: 404 page not found\n"15382026/11/07 23:34:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15392026/11/07 23:34:00 WARN Failed to register uploaded object key=8fhmd0223y5in3h91pncnrdxdnzy757h.ls error="server returned 404: 404 page not found\n"15402026/11/07 23:34:00 INFO Signed narinfos id=1 count=215412026/11/07 23:34:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15422026/11/07 23:34:00 INFO Signed narinfos id=2 count=215432026/11/07 23:34:00 INFO Uploading 4 narinfos15442026/11/07 23:34:00 INFO Completed push id=1 objects=8 duration=167.450917ms15452026/11/07 23:34:00 INFO Upload complete. (665ms)1546=== NAME TestClientPushesUseOnePush1547 client_pushes_test.go:97: Retrieved narinfo from S3:1548 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientPushesUseOnePush1288166012/001/store/3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9-shared-dep1549 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1550 Compression: zstd1551 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y8215522026/11/07 23:34:00 WARN Failed to register uploaded object key=8fhmd0223y5in3h91pncnrdxdnzy757h.narinfo error="server returned 404: 404 page not found\n"1553 NarSize: 1361554 References: 1555 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15562026/11/07 23:34:00 WARN Failed to register uploaded object key=j688nbzn341zxqyshki4q8mkhqbr10p0.narinfo error="server returned 404: 404 page not found\n"1557 client_pushes_test.go:97: Retrieved narinfo from S3:1558 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientPushesUseOnePush1288166012/001/store/aji4rc1r73kgq43bbdzfswxvzn9cgnjn-a15592026/11/07 23:34:00 WARN Failed to register uploaded object key=2qgj8y3b3lpp4ywji914kr10v7b11wbm.narinfo error="server returned 404: 404 page not found\n"1560 URL: nar/1i2cmlbq9rkq97p0qrxwvwk7b6rjscnsbibli6ycd5qa5bfz1g87.nar.zst1561 Compression: zstd15622026/11/07 23:34:00 INFO Received push request method=POST path=/api/pushes1563 NarHash: sha256:1i2cmlbq9rkq97p0qrxwvwk7b6rjscnsbibli6ycd5qa5bfz1g871564 NarSize: 2561565 References: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientPushesUseOnePush1288166012/001/store/3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9-shared-dep1566 CA: text:sha256:133x3c8768b9qrbz7v37b4b2dm489hsvaj6pdkl3dmhrfwj7ypjm1567 client_pushes_test.go:97: Retrieved narinfo from S3:1568 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientPushesUseOnePush1288166012/001/store/znrzcalqnjqdcscfr4zibicfsvzhvs41-b1569 URL: nar/1i2cmlbq9rkq97p0qrxwvwk7b6rjscnsbibli6ycd5qa5bfz1g87.nar.zst1570 Compression: zstd15712026/11/07 23:34:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1572 NarHash: sha256:1i2cmlbq9rkq97p0qrxwvwk7b6rjscnsbibli6ycd5qa5bfz1g8715732026/11/07 23:34:00 INFO Uploading cq854i3fgmzvq2qg1jwrliyjsa5wxbpx-pinned-file.txt (128B)1574 NarSize: 2561575 References: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientPushesUseOnePush1288166012/001/store/3j3ldk10m4yz1lpw6gmxvqxzsmpmajg9-shared-dep1576 CA: text:sha256:133x3c8768b9qrbz7v37b4b2dm489hsvaj6pdkl3dmhrfwj7ypjm15772026/11/07 23:34:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15782026/11/07 23:34:00 WARN Failed to register uploaded object key=j688nbzn341zxqyshki4q8mkhqbr10p0.narinfo error="server returned 404: 404 page not found\n"15792026/11/07 23:34:00 WARN Failed to register uploaded object key=cq854i3fgmzvq2qg1jwrliyjsa5wxbpx.ls error="server returned 404: 404 page not found\n"15802026/11/07 23:34:00 INFO Completed upload id=2 objects=6 duration=42.9605ms15812026/11/07 23:34:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15822026/11/07 23:34:00 INFO Completed upload id=1 objects=6 duration=662.5µs15832026/11/07 23:34:00 INFO Upload complete. (756ms)15842026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1585=== NAME TestClientFallsBackToClosures15862026/11/07 23:34:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1587 client_pushes_test.go:112: Retrieved narinfo from S3:15882026/11/07 23:34:00 INFO Signed narinfos id=1 count=11589 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientFallsBackToClosures4227458659/001/store/j688nbzn341zxqyshki4q8mkhqbr10p0-shared-dep15902026/11/07 23:34:00 INFO Uploading 1 narinfos1591 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1592 Compression: zstd1593 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821594 NarSize: 1361595 References: 1596 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1597 client_pushes_test.go:112: Retrieved narinfo from S3:1598 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientFallsBackToClosures4227458659/001/store/8fhmd0223y5in3h91pncnrdxdnzy757h-a1599 URL: nar/11a7dhzd90cf7hv2rxfz3yvzmg3apc7qjxf7asgbljr2q4xsisgd.nar.zst1600 Compression: zstd1601 NarHash: sha256:11a7dhzd90cf7hv2rxfz3yvzmg3apc7qjxf7asgbljr2q4xsisgd1602 NarSize: 2561603 References: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientFallsBackToClosures4227458659/001/store/j688nbzn341zxqyshki4q8mkhqbr10p0-shared-dep1604 CA: text:sha256:0rwd9xjbdwiyhnlrjwmm86xsf4v6mcj8k4mvlldda9zylqq4ivmv1605 client_pushes_test.go:112: Retrieved narinfo from S3:1606 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientFallsBackToClosures4227458659/001/store/2qgj8y3b3lpp4ywji914kr10v7b11wbm-b1607 URL: nar/11a7dhzd90cf7hv2rxfz3yvzmg3apc7qjxf7asgbljr2q4xsisgd.nar.zst1608 Compression: zstd1609 NarHash: sha256:11a7dhzd90cf7hv2rxfz3yvzmg3apc7qjxf7asgbljr2q4xsisgd1610 NarSize: 2561611 References: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientFallsBackToClosures4227458659/001/store/j688nbzn341zxqyshki4q8mkhqbr10p0-shared-dep16122026/11/07 23:34:00 INFO Received complete push request method=POST path=/api/pushes/1/complete1613 CA: text:sha256:0rwd9xjbdwiyhnlrjwmm86xsf4v6mcj8k4mvlldda9zylqq4ivmv16142026/11/07 23:34:00 WARN Failed to register uploaded object key=cq854i3fgmzvq2qg1jwrliyjsa5wxbpx.narinfo error="server returned 404: 404 page not found\n"16152026/11/07 23:34:00 INFO Completed push id=1 objects=3 duration=15.652584ms16162026/11/07 23:34:00 INFO Upload complete. (441ms)1617--- PASS: TestClientPushesUseOnePush (11.26s)1618=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16192026/11/07 23:34:00 INFO Received push request method=POST path=/api/pushes1620--- PASS: TestClientFallsBackToClosures (10.60s)1621=== CONT TestPush_CompleteWaitsForCleanupOfThePush16222026/11/07 23:34:00 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16232026/11/07 23:34:00 INFO Received push request method=POST path=/api/pushes16242026/11/07 23:34:00 INFO Uploading yv8pxxiqmkdcpn7ll89w1ylklfvlknfk-shared-dep (136B)16252026/11/07 23:34:00 INFO Uploading 7zpibvanrzxzz0c1kcb2iwxn8sr27bv1-top (264B)16262026/11/07 23:34:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16272026/11/07 23:34:00 INFO Uploading 1w1l068i36y4agkwryvkgbw0ap65cw69-unpinned-file.txt (128B)16282026/11/07 23:34:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16292026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/1dcsj8jwhlmp7c16r8qp05ddm9bcjvpy8l1ixxrc7psb5nbr9pn9.nar.zst error="server returned 404: 404 page not found\n"16302026/11/07 23:34:00 WARN Failed to register uploaded object key=7zpibvanrzxzz0c1kcb2iwxn8sr27bv1.ls error="server returned 404: 404 page not found\n"16312026/11/07 23:34:00 WARN Failed to register uploaded object key=yv8pxxiqmkdcpn7ll89w1ylklfvlknfk.ls error="server returned 404: 404 page not found\n"16322026/11/07 23:34:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16332026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16342026/11/07 23:34:00 WARN Failed to register uploaded object key=1w1l068i36y4agkwryvkgbw0ap65cw69.ls error="server returned 404: 404 page not found\n"16352026/11/07 23:34:00 INFO Signed narinfos id=1 count=216362026/11/07 23:34:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16372026/11/07 23:34:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16382026/11/07 23:34:00 INFO Uploading 2 narinfos16392026/11/07 23:34:00 INFO Signed narinfos id=2 count=116402026/11/07 23:34:00 INFO Uploading 1 narinfos16412026/11/07 23:34:00 WARN Failed to register uploaded object key=7zpibvanrzxzz0c1kcb2iwxn8sr27bv1.narinfo error="server returned 404: 404 page not found\n"16422026/11/07 23:34:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjZhMDdlYTk5LTZhMzEtNDU0My1iNWI4LTBiOGU2ODdjN2ViOXgxNzk0MDk0NDM1NjQ4ODYwMDAw parts=1216432026/11/07 23:34:00 INFO Received complete push request method=POST path=/api/pushes/1/complete16442026/11/07 23:34:00 WARN Failed to register uploaded object key=yv8pxxiqmkdcpn7ll89w1ylklfvlknfk.narinfo error="server returned 404: 404 page not found\n"16452026/11/07 23:34:00 INFO Received complete push request method=POST path=/api/pushes/2/complete16462026/11/07 23:34:00 WARN Failed to register uploaded object key=1w1l068i36y4agkwryvkgbw0ap65cw69.narinfo error="server returned 404: 404 page not found\n"1647--- PASS: TestSharedNarBothUploadsComplete (13.77s)1648=== CONT TestAbortSucceeded1649--- PASS: TestAbortSucceeded (0.00s)1650=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16512026/11/07 23:34:01 INFO Completed push id=2 objects=3 duration=2.347375ms16522026/11/07 23:34:01 INFO Upload complete. (414ms)16532026/11/07 23:34:01 INFO Completed push id=1 objects=6 duration=54.402042ms16542026/11/07 23:34:01 INFO Upload complete. (471ms)1655=== NAME TestClientSharedPathCommittedMidPush1656 client_integration_test.go:803: Retrieved narinfo from S3:1657 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientSharedPathCommittedMidPush1514038716/001/store/yv8pxxiqmkdcpn7ll89w1ylklfvlknfk-shared-dep1658 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1659 Compression: zstd1660 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821661 NarSize: 1361662 References: 1663 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1664 client_integration_test.go:803: Retrieved narinfo from S3:1665 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientSharedPathCommittedMidPush1514038716/001/store/7zpibvanrzxzz0c1kcb2iwxn8sr27bv1-top1666 URL: nar/1dcsj8jwhlmp7c16r8qp05ddm9bcjvpy8l1ixxrc7psb5nbr9pn9.nar.zst1667 Compression: zstd1668 NarHash: sha256:1dcsj8jwhlmp7c16r8qp05ddm9bcjvpy8l1ixxrc7psb5nbr9pn91669 NarSize: 2641670 References: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientSharedPathCommittedMidPush1514038716/001/store/yv8pxxiqmkdcpn7ll89w1ylklfvlknfk-shared-dep1671 CA: text:sha256:12cz0ad6rn0ini0lsb9fbcccgnkxcaccxwr0z7alcp3pm00n307716722026/11/07 23:34:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures1673=== NAME TestClientWithDependencies16742026/11/07 23:34:01 INFO Garbage collection started1675 client_integration_test.go:722: Built derivation: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientWithDependencies3854322829/001/store/wrgddkzs6dj9zlh9n5a7k3k9acx44chv-test-script16762026/11/07 23:34:01 INFO Aborted multipart uploads count=0 kept=016772026/11/07 23:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period1678 client_integration_test.go:724: Found 1 dependencies (including self)1679--- PASS: TestClientSharedPathCommittedMidPush (10.16s)1680=== CONT TestSkippedUploadsHandler16812026/11/07 23:34:01 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001682--- PASS: TestSkippedUploadsHandler (0.01s)1683=== CONT TestService_Rustfstest16842026/11/07 23:34:01 INFO Received push request method=POST path=/api/pushes16852026/11/07 23:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16862026/11/07 23:34:01 INFO Uploading wrgddkzs6dj9zlh9n5a7k3k9acx44chv-test-script (136B)16872026/11/07 23:34:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16882026/11/07 23:34:01 WARN Failed to register uploaded object key=wrgddkzs6dj9zlh9n5a7k3k9acx44chv.ls error="server returned 404: 404 page not found\n"16892026/11/07 23:34:01 WARN Failed to register uploaded object key=log/x2f2bkl742wqnvgw4z362nkd1cwcsjv7-test-script.drv error="server returned 404: 404 page not found\n"1690=== NAME TestClientIntegration16912026/11/07 23:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1692 client_integration_test.go:331: Created store path: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientIntegration2242619724/002/store/ipnhakmy5cy52dlysqvdyfhq3xj72qb6-test-file.txt16932026/11/07 23:34:01 INFO Signed narinfos id=1 count=116942026/11/07 23:34:01 INFO Uploading 1 narinfos16952026/11/07 23:34:01 INFO Received complete push request method=POST path=/api/pushes/1/complete16962026/11/07 23:34:01 WARN Failed to register uploaded object key=wrgddkzs6dj9zlh9n5a7k3k9acx44chv.narinfo error="server returned 404: 404 page not found\n"16972026/11/07 23:34:01 INFO Received push request method=POST path=/api/pushes16982026/11/07 23:34:01 INFO Completed push id=1 objects=4 duration=62.95775ms16992026/11/07 23:34:01 INFO Upload complete. (466ms)17002026/11/07 23:34:01 INFO Aborted multipart uploads count=0 kept=017012026/11/07 23:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17022026/11/07 23:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period17032026/11/07 23:34:01 INFO Uploading ipnhakmy5cy52dlysqvdyfhq3xj72qb6-test-file.txt (152B)17042026/11/07 23:34:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017052026/11/07 23:34:01 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=017062026/11/07 23:34:01 WARN Failed to register uploaded object key=ipnhakmy5cy52dlysqvdyfhq3xj72qb6.ls error="server returned 404: 404 page not found\n"17072026/11/07 23:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17082026/11/07 23:34:01 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17092026/11/07 23:34:01 INFO Signed narinfos id=1 count=117102026/11/07 23:34:01 INFO Uploading 1 narinfos17112026/11/07 23:34:01 INFO Vacuumed table table=pending_closures17122026/11/07 23:34:01 INFO Vacuumed table table=pending_closures17132026/11/07 23:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17142026/11/07 23:34:01 INFO Received push request method=POST path=/api/pushes17152026/11/07 23:34:01 INFO Vacuumed table table=pending_objects1716=== NAME TestClientMultipleUploads1717 client_integration_test.go:467: Created store path 0: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientMultipleUploads2308089227/001/store/n81xwfcdk6z71mzh5lzj8v4kxj2xw6ik-test-file-0.txt17182026/11/07 23:34:01 INFO Vacuumed table table=multipart_uploads17192026/11/07 23:34:01 INFO Received complete push request method=POST path=/api/pushes/1/complete17202026/11/07 23:34:01 WARN Failed to register uploaded object key=ipnhakmy5cy52dlysqvdyfhq3xj72qb6.narinfo error="server returned 404: 404 page not found\n"17212026/11/07 23:34:01 INFO Vacuumed table table=pending_objects17222026/11/07 23:34:01 INFO Vacuumed table table=multipart_uploads17232026/11/07 23:34:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjIyZGI1ZDQ3LWYzYzctNDgwZi04ZjE0LWI3Y2FjNTI5YmJhY3gxNzk0MDk0NDM3MjQzNzQxMDAw parts=1017242026/11/07 23:34:01 INFO Completed push id=1 objects=3 duration=65.174958ms17252026/11/07 23:34:02 INFO Upload complete. (489ms)17262026/11/07 23:34:02 INFO Vacuumed table table=closures17272026/11/07 23:34:02 INFO Vacuumed table table=closures17282026/11/07 23:34:02 INFO All 1 paths already cached1729=== NAME TestClientIntegration1730 client_integration_test.go:357: Retrieved narinfo from S3:1731 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientIntegration2242619724/002/store/ipnhakmy5cy52dlysqvdyfhq3xj72qb6-test-file.txt1732 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1733 Compression: zstd1734 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11735 NarSize: 1521736 References: 1737 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117382026/11/07 23:34:02 INFO Vacuumed table table=objects1739 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1740 client_integration_test.go:358: Decompressed .ls content (64 bytes):1741 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}17422026/11/07 23:34:02 INFO Vacuumed table table=objects17432026/11/07 23:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1744=== NAME TestClientWithDependencies1745 client_integration_test.go:740: Skipping nix copy test - isolated store (/private/var/tb/4/scratch/89da011d463ecd02/build/TestClientWithDependencies3854322829/001/store) requires matching store prefix17462026/11/07 23:34:02 INFO Completed push id=1 objects=4 duration=43.160667ms1747=== NAME TestClientMultipleUploads17482026/11/07 23:34:02 INFO Received push request method=POST path=/api/pushes1749 client_integration_test.go:467: Created store path 1: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientMultipleUploads2308089227/001/store/cm6i02ncn22zx70i1f6jpm3g56294si4-test-file-1.txt17502026/11/07 23:34:02 INFO Aborted multipart uploads count=0 kept=017512026/11/07 23:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period1752--- PASS: TestClientWithDependencies (10.90s)1753=== CONT TestSweepSkipsRowsLockedByPush1754=== RUN TestService_RequireScope_OIDC/builder_may_write1755=== PAUSE TestService_RequireScope_OIDC/builder_may_write1756=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1757=== NAME TestClientMultipleUploads1758 client_integration_test.go:467: Created store path 2: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientMultipleUploads2308089227/001/store/rl21fgy1h9v4ghk7akq73vydzw181wbk-test-file-2.txt1759=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1760=== RUN TestService_RequireScope_OIDC/ops_may_admin1761=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1762=== RUN TestService_RequireScope_OIDC/ops_may_not_write1763=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1764=== RUN TestService_RequireScope_OIDC/reader_may_not_write1765=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1766=== RUN TestService_RequireScope_OIDC/static_token_may_admin1767=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1768=== RUN TestService_RequireScope_OIDC/static_token_may_write1769=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1770=== RUN TestService_RequireScope_OIDC/reader_may_read1771=== PAUSE TestService_RequireScope_OIDC/reader_may_read1772=== RUN TestService_RequireScope_OIDC/writer_implies_read1773=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1774=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1775=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1776=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1777=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1778=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1779=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1780=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1781=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1782=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1783=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1784=== CONT TestUploadHandlersRejectInvalidKeys1785=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1786=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1787=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17882026/11/07 23:34:02 INFO Received push request method=POST path=/api/pushes1789=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1790=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17912026/11/07 23:34:02 INFO Received push request method=POST path=/api/pushes1792=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1793=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1794=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1795=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh17962026/11/07 23:34:02 INFO Object in database but missing from S3 key=ipnhakmy5cy52dlysqvdyfhq3xj72qb6.ls17972026/11/07 23:34:02 WARN Found objects in DB but missing from S3, will re-upload count=117982026/11/07 23:34:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17992026/11/07 23:34:02 WARN Failed to register uploaded object key=ipnhakmy5cy52dlysqvdyfhq3xj72qb6.ls error="server returned 404: 404 page not found\n"18002026/11/07 23:34:02 INFO Received complete push request method=POST path=/api/pushes/2/complete18012026/11/07 23:34:02 INFO Completed push id=2 objects=3 duration=42.317667ms18022026/11/07 23:34:02 INFO Upload complete. (216ms)18032026/11/07 23:34:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1804=== NAME TestClientIntegration18052026/11/07 23:34:02 INFO Uploading rl21fgy1h9v4ghk7akq73vydzw181wbk-test-file-2.txt (160B)1806 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)18072026/11/07 23:34:02 INFO Uploading cm6i02ncn22zx70i1f6jpm3g56294si4-test-file-1.txt (160B)1808 client_integration_test.go:375: Decompressed .ls content (49 bytes):18092026/11/07 23:34:02 INFO Uploading n81xwfcdk6z71mzh5lzj8v4kxj2xw6ik-test-file-0.txt (160B)1810 {"version":1,"root":{"type":"regular","size":39}}18112026/11/07 23:34:02 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18122026/11/07 23:34:02 WARN Failed to register uploaded object key=rl21fgy1h9v4ghk7akq73vydzw181wbk.ls error="server returned 404: 404 page not found\n"18132026/11/07 23:34:02 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18142026/11/07 23:34:02 WARN Failed to register uploaded object key=cm6i02ncn22zx70i1f6jpm3g56294si4.ls error="server returned 404: 404 page not found\n"18152026/11/07 23:34:02 WARN Failed to register uploaded object key=n81xwfcdk6z71mzh5lzj8v4kxj2xw6ik.ls error="server returned 404: 404 page not found\n"18162026/11/07 23:34:02 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18172026/11/07 23:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18182026/11/07 23:34:02 INFO Signed narinfos id=1 count=318192026/11/07 23:34:02 INFO Uploading 3 narinfos18202026/11/07 23:34:02 WARN Failed to register uploaded object key=rl21fgy1h9v4ghk7akq73vydzw181wbk.narinfo error="server returned 404: 404 page not found\n"18212026/11/07 23:34:02 WARN Failed to register uploaded object key=n81xwfcdk6z71mzh5lzj8v4kxj2xw6ik.narinfo error="server returned 404: 404 page not found\n"18222026/11/07 23:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete18232026/11/07 23:34:02 WARN Failed to register uploaded object key=cm6i02ncn22zx70i1f6jpm3g56294si4.narinfo error="server returned 404: 404 page not found\n"1824--- PASS: TestService_ReadScope_PublicByDefault (9.80s)1825=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed18262026/11/07 23:34:03 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018272026/11/07 23:34:03 INFO Completed push id=1 objects=9 duration=91.320291ms18282026/11/07 23:34:03 INFO Received create pin request method=POST path=/api/pins/myapp18292026/11/07 23:34:03 INFO Upload complete. (630ms)1830=== NAME TestClientMultipleUploads1831 client_integration_test.go:478: Uploaded 3 paths in 682.779167ms18322026/11/07 23:34:03 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=018332026/11/07 23:34:03 INFO Created/updated pin name=myapp store_path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestPinProtectsFromGC1233153465/001/store/cq854i3fgmzvq2qg1jwrliyjsa5wxbpx-pinned-file.txt narinfo_key=cq854i3fgmzvq2qg1jwrliyjsa5wxbpx.narinfo18342026/11/07 23:34:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures18352026/11/07 23:34:03 INFO Garbage collection started18362026/11/07 23:34:03 INFO Aborted multipart uploads count=0 kept=018372026/11/07 23:34:03 INFO Vacuumed table table=pending_closures18382026/11/07 23:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period18392026/11/07 23:34:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018402026/11/07 23:34:03 INFO Vacuumed table table=pending_closures18412026/11/07 23:34:03 INFO Vacuumed table table=pending_objects18422026/11/07 23:34:03 INFO Vacuumed table table=multipart_uploads18432026/11/07 23:34:03 INFO Vacuumed table table=pending_objects18442026/11/07 23:34:03 INFO Vacuumed table table=closures18452026/11/07 23:34:03 INFO Vacuumed table table=objects18462026/11/07 23:34:03 INFO Vacuumed table table=multipart_uploads1847--- PASS: TestClientMultipleUploads (10.94s)1848=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed18492026/11/07 23:34:03 INFO Vacuumed table table=closures18502026/11/07 23:34:03 INFO Received push request method=POST path=/api/pushes18512026/11/07 23:34:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18522026/11/07 23:34:03 INFO Vacuumed table table=objects18532026/11/07 23:34:03 INFO Received complete push request method=POST path=/api/pushes/3/complete18542026/11/07 23:34:03 WARN Failed to register uploaded object key=ipnhakmy5cy52dlysqvdyfhq3xj72qb6.ls error="server returned 404: 404 page not found\n"18552026/11/07 23:34:03 INFO Completed push id=3 objects=3 duration=1.048875ms18562026/11/07 23:34:03 INFO Upload complete. (144ms)1857=== NAME TestClientIntegration1858 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1859 client_integration_test.go:392: Decompressed .ls content (49 bytes):1860 {"version":1,"root":{"type":"regular","size":39}}18612026/11/07 23:34:03 INFO Received push request method=POST path=/api/pushes18622026/11/07 23:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18632026/11/07 23:34:03 INFO Uploading nipna16xfvbm4by0m3dbbwd5c7riircp-lost-commit.txt (152B)1864=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1865=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1866=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1867=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1868=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1869=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1870=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1871=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1872=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18732026/11/07 23:34:03 WARN Failed to register uploaded object key=nipna16xfvbm4by0m3dbbwd5c7riircp.ls error="server returned 404: 404 page not found\n"18742026/11/07 23:34:03 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"18752026/11/07 23:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign18762026/11/07 23:34:03 INFO Signed narinfos id=4 count=118772026/11/07 23:34:03 INFO Uploading 1 narinfos18782026/11/07 23:34:03 INFO Received complete push request method=POST path=/api/pushes/4/complete18792026/11/07 23:34:03 WARN Failed to register uploaded object key=nipna16xfvbm4by0m3dbbwd5c7riircp.narinfo error="server returned 404: 404 page not found\n"18802026/11/07 23:34:03 INFO Completed push id=4 objects=3 duration=892.583µs18812026/11/07 23:34:03 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:55177/api/pushes/4/complete\": EOF" url=http://127.0.0.1:55177/api/pushes/4/complete18822026/11/07 23:34:04 INFO Received complete push request method=POST path=/api/pushes/4/complete18832026-11-07 23:34:04.041 UTC [82180] ERROR: Push does not exist: id=418842026-11-07 23:34:04.041 UTC [82180] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18852026-11-07 23:34:04.041 UTC [82180] STATEMENT: -- name: CommitPush :one1886 SELECT commit_push($1::bigint)::bigint1887 18882026/11/07 23:34:04 WARN Push not found id=418892026/11/07 23:34:04 INFO Upload complete. (433ms)1890=== NAME TestClientIntegration1891 client_integration_test.go:422: Retrieved narinfo from S3:1892 StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientIntegration2242619724/002/store/nipna16xfvbm4by0m3dbbwd5c7riircp-lost-commit.txt1893 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1894 Compression: zstd1895 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1896 NarSize: 1521897 References: 1898 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1899 client_integration_test.go:425: Testing garbage collection...19002026/11/07 23:34:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures19012026/11/07 23:34:04 INFO Garbage collection started19022026/11/07 23:34:04 INFO Aborted multipart uploads count=0 kept=019032026/11/07 23:34:04 WARN Force mode enabled - objects will be deleted immediately without grace period1904=== NAME TestClientCADerivations1905 client_ca_test.go:136: Built CA derivation: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientCADerivations3168737100/001/store/czzq0k1mgfwqys6f77zsicy6s03pjvkn-ca-test1906 client_ca_test.go:139: Found 1 dependencies (including self)19072026/11/07 23:34:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19082026/11/07 23:34:04 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjNlZjY4OTUyLTc1ZjEtNGZkMi04YjllLWRiNjkyOWQzYjg3N3gxNzk0MDk0NDQyMDA4MjA2MDAw parts=101909--- PASS: TestReadProxyContentNegotiation (9.17s)1910=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost19112026/11/07 23:34:04 INFO Received push request method=POST path=/api/pushes19122026/11/07 23:34:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19132026/11/07 23:34:04 INFO Uploading czzq0k1mgfwqys6f77zsicy6s03pjvkn-ca-test (144B)19142026/11/07 23:34:05 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19152026/11/07 23:34:05 WARN Failed to register uploaded object key=czzq0k1mgfwqys6f77zsicy6s03pjvkn.ls error="server returned 404: 404 page not found\n"19162026/11/07 23:34:05 WARN Failed to register uploaded object key=log/k142p8vbi3v220g1pfqrraxc0q4slhsj-ca-test.drv error="server returned 404: 404 page not found\n"19172026/11/07 23:34:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19182026/11/07 23:34:05 INFO Signed narinfos id=1 count=119192026/11/07 23:34:05 INFO Uploading 1 narinfos19202026/11/07 23:34:05 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=01921=== NAME TestPinProtectsFromGC1922 client_integration_test.go:963: Pin successfully protected closure from garbage collection19232026/11/07 23:34:05 INFO Received complete push request method=POST path=/api/pushes/1/complete19242026/11/07 23:34:05 WARN Failed to register uploaded object key=czzq0k1mgfwqys6f77zsicy6s03pjvkn.narinfo error="server returned 404: 404 page not found\n"19252026/11/07 23:34:05 INFO Completed push id=1 objects=4 duration=110.216708ms19262026/11/07 23:34:05 INFO Upload complete. (844ms)1927=== NAME TestClientCADerivations1928 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientCADerivations3168737100/001/store/czzq0k1mgfwqys6f77zsicy6s03pjvkn-ca-test1929 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1930 Compression: zstd19312026/11/07 23:34:05 INFO Vacuumed table table=pending_closures1932 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1933 NarSize: 1441934 References: 1935 Deriver: /private/var/tb/4/scratch/89da011d463ecd02/build/TestClientCADerivations3168737100/001/store/k142p8vbi3v220g1pfqrraxc0q4slhsj-ca-test.drv1936--- PASS: TestPinProtectsFromGC (14.82s)1937=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed1938=== NAME TestClientCADerivations1939 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1940--- PASS: TestReadProxyRootRedirectsToIndexHTML (9.17s)1941=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1942=== NAME TestClientCADerivations1943 client_ca_test.go:185: Checking for realisation files in S3...1944 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1945 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19462026/11/07 23:34:05 INFO Vacuumed table table=pending_objects19472026/11/07 23:34:05 INFO Vacuumed table table=multipart_uploads19482026/11/07 23:34:05 INFO Vacuumed table table=closures19492026/11/07 23:34:05 INFO Vacuumed table table=objects19502026/11/07 23:34:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1951 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket82?endpoint=http://localhost:54660®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/4/scratch/89da011d463ecd02/build/TestClientCADerivations3168737100/001/store'1952 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119532026/11/07 23:34:05 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjNlYTI2M2VhLWY2NzUtNDQzMC05OGI1LTU5ZjMwYWQ2MWZkZHgxNzk0MDk0NDQyMjEzNDc4MDAw parts=1019542026/11/07 23:34:05 INFO Received complete push request method=POST path=/api/pushes/2/complete19552026/11/07 23:34:05 INFO Completed push id=2 objects=4 duration=16.015291ms1956--- PASS: TestReadProxyInvalidPath (9.15s)1957=== CONT TestParseSingleRange/none1958=== CONT TestParseSingleRange/start_far_past_EOF1959=== CONT TestParseSingleRange/single_byte1960=== CONT TestParseSingleRange/start_past_EOF1961=== CONT TestParseSingleRange/suffix_exceeds_size1962=== CONT TestParseSingleRange/suffix1963=== CONT TestParseSingleRange/end_clamped_to_size1964=== CONT TestParseSingleRange/closed1965=== CONT TestParseSingleRange/malformed_end_before_start1966=== CONT TestParseSingleRange/malformed_both_empty1967=== CONT TestParseSingleRange/open-ended1968=== CONT TestParseSingleRange/malformed_no_dash1969=== CONT TestParseSingleRange/unknown_unit1970=== CONT TestParseSingleRange/multi-range_ignored1971=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1972--- PASS: TestParseSingleRange (0.08s)1973 --- PASS: TestParseSingleRange/none (0.00s)1974 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1975 --- PASS: TestParseSingleRange/single_byte (0.00s)1976 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1977 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1978 --- PASS: TestParseSingleRange/suffix (0.00s)1979 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1980 --- PASS: TestParseSingleRange/closed (0.00s)1981 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1982 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1983 --- PASS: TestParseSingleRange/open-ended (0.00s)1984 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1985 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1986 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1987--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (17.71s)1988=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19892026/11/07 23:34:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01990=== NAME TestClientIntegration1991 client_integration_test.go:432: Objects in database after GC:1992 client_integration_test.go:432: Successfully deleted all objects with GC --force19932026/11/07 23:34:06 WARN Rate limiter enabled after throttle name=s3-test rate=519942026/11/07 23:34:06 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1995--- PASS: TestClientCADerivations (12.16s)1996=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19972026/11/07 23:34:06 INFO Received uploads request method=POST path=/19982026/11/07 23:34:06 WARN Rate limiter backed off name=s3-test rate=519992026/11/07 23:34:06 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."2000--- PASS: TestReadProxy404And429 (9.84s)2001=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts2002--- PASS: TestDeleteClosuresRacingPins (17.41s)20032026/11/07 23:34:06 INFO Received request for more parts method=POST path=/2004=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20052026/11/07 23:34:06 INFO Received complete multipart upload request method=POST path=/2006--- PASS: TestClientIntegration (14.34s)2007=== CONT TestResolveDBConnectionString/flag_wins2008=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2009=== CONT TestResolveDBConnectionString/nothing_configured2010=== CONT TestResolveDBConnectionString/file_when_flag_empty2011=== CONT TestResolveDBConnectionString/missing_file_is_an_error2012=== CONT TestServerTLSConfig/not_a_PEM_file2013--- PASS: TestResolveDBConnectionString (0.06s)2014 --- PASS: TestResolveDBConnectionString/flag_wins (0.02s)2015 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2016 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2017 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2018 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.02s)2019=== CONT TestServerTLSConfig/missing_CA_file2020=== CONT TestServerTLSConfig/no_client_CA2021--- PASS: TestServerTLSConfig (0.00s)2022 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)2023 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2024 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2025=== CONT TestGCEndsOnShutdown/before_the_run2026--- PASS: TestReadProxyNarStreaming (9.56s)2027=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2028=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2029=== CONT TestProxyWriteTimeout/unknown_size2030=== CONT TestProxyWriteTimeout/10_GiB_nar2031=== CONT TestProxyWriteTimeout/1_GiB_nar2032=== CONT TestProxyWriteTimeout/narinfo2033=== CONT TestIsValidUploadKey/narinfo2034=== CONT TestIsValidUploadKey/nix-cache-info2035--- PASS: TestProxyWriteTimeout (0.01s)2036 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2037 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2038 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2039 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2040=== CONT TestIsValidUploadKey/unknown_type2041=== CONT TestIsValidUploadKey/empty_key2042=== CONT TestIsValidUploadKey/traversal_nar2043=== CONT TestIsValidUploadKey/traversal2044=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2045=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2046=== CONT TestIsValidUploadKey/absolute2047=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2048=== CONT TestIsValidUploadKey/index.html2049=== CONT TestIsValidUploadKey/realisation_plus_in_output2050=== CONT TestIsValidUploadKey/build_log2051=== CONT TestIsValidUploadKey/realisation2052=== CONT TestIsValidUploadKey/build_log_question_mark2053=== CONT TestIsValidUploadKey/build_log_equals2054=== CONT TestIsValidUploadKey/build_log_home-manager_file2055=== CONT TestIsValidUploadKey/nar_xz2056=== CONT TestIsValidUploadKey/listing2057=== CONT TestIsValidUploadKey/build_log_plus_in_name2058=== CONT TestIsValidUploadKey/nar_zst2059=== CONT TestIsValidUploadKey/nar_plain2060=== CONT TestPendingClosureWriteTimeout/670k_objects2061--- PASS: TestIsValidUploadKey (0.04s)2062 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2063 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2064 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2065 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2066 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2067 --- PASS: TestIsValidUploadKey/traversal (0.00s)2068 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2069 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2070 --- PASS: TestIsValidUploadKey/absolute (0.00s)2071 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2072 --- PASS: TestIsValidUploadKey/index.html (0.00s)2073 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2074 --- PASS: TestIsValidUploadKey/build_log (0.00s)2075 --- PASS: TestIsValidUploadKey/realisation (0.00s)2076 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2077 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2078 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2079 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2080 --- PASS: TestIsValidUploadKey/listing (0.00s)2081 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2082 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2083 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2084=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20852026/11/07 23:34:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20862026/11/07 23:34:07 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2087--- PASS: TestReadProxyNarinfo (9.90s)2088=== CONT TestPendingClosureWriteTimeout/400_objects2089=== CONT TestPendingClosureWriteTimeout/empty2090=== CONT TestClientErrorHandling/InvalidStorePath2091--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (9.60s)2092=== CONT TestClientErrorHandling/ServerNotAvailable20932026/11/07 23:34:07 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmE5NGRkZWY0LWI3YTItNGYzMi1hNTMzLWFjNjkyY2Q4YmQxMngxNzk0MDk0NDQyMDA3Njg4MDAw parts=1020942026-11-07 23:34:08.203 UTC [81805] LOG: checkpoint starting: wal2095--- PASS: TestService_ReadAuthMiddleware (10.70s)20962026/11/07 23:34:08 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/present2097=== CONT TestClientErrorHandling/InvalidAuthToken20982026/11/07 23:34:08 WARN Request failed, retrying attempt=2 backoff=186.914209ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20992026/11/07 23:34:08 WARN Request failed, retrying attempt=3 backoff=404.99479ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21002026/11/07 23:34:09 WARN Request failed, retrying attempt=4 backoff=765.247813ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21012026/11/07 23:34:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21022026/11/07 23:34:09 WARN mTLS auth: bound subjects configured but subject DN unavailable21032026/11/07 23:34:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"21042026/11/07 23:34:10 WARN Request failed, retrying attempt=5 backoff=1.675812345s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2105--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (9.53s)2106=== CONT TestCacheConfigHandler/no_signing_keys2107=== CONT TestCacheConfigHandler/no_cache_url_configured2108=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2109=== CONT TestCacheConfigHandler/full_config,_no_issuer2110--- PASS: TestCacheConfigHandler (0.03s)2111 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2112 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2113 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2114 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2115=== CONT TestPush_RejectsBadRequests/no_objects21162026/11/07 23:34:10 INFO Received push request method=POST path=/api/pushes2117=== CONT TestPush_RejectsBadRequests/root_not_in_objects21182026/11/07 23:34:10 INFO Received push request method=POST path=/api/pushes2119=== CONT TestPush_RejectsBadRequests/no_roots21202026/11/07 23:34:10 INFO Received push request method=POST path=/api/pushes2121=== CONT TestPush_RejectsBadRequests/bad_root21222026/11/07 23:34:10 INFO Received push request method=POST path=/api/pushes2123=== CONT TestIsValidCachePath/narinfo2124=== CONT TestIsValidCachePath/nix-cache-info2125=== CONT TestIsValidCachePath/wrong_extension2126=== CONT TestIsValidCachePath/leading_slash2127=== CONT TestIsValidCachePath/short_hash2128=== CONT TestIsValidCachePath/random_path2129=== CONT TestIsValidCachePath/empty2130=== CONT TestIsValidCachePath/invalid_char_u2131=== CONT TestIsValidCachePath/traversal_in_middle2132=== CONT TestIsValidCachePath/invalid_char_e2133=== CONT TestIsValidCachePath/index.html2134=== CONT TestIsValidCachePath/nar_bz22135=== CONT TestIsValidCachePath/log2136=== CONT TestIsValidCachePath/nar_uncompressed2137=== CONT TestIsValidCachePath/realisation2138=== CONT TestIsValidCachePath/nar_zst2139=== CONT TestIsValidCachePath/ls2140=== CONT TestIsValidCachePath/traversal_parent2141=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2142=== CONT TestIsValidCachePath/nar_xz2143--- PASS: TestIsValidCachePath (0.07s)2144 --- PASS: TestIsValidCachePath/narinfo (0.00s)2145 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2146 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2147 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2148 --- PASS: TestIsValidCachePath/short_hash (0.00s)2149 --- PASS: TestIsValidCachePath/random_path (0.00s)2150 --- PASS: TestIsValidCachePath/empty (0.00s)2151 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2152 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2153 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2154 --- PASS: TestIsValidCachePath/index.html (0.00s)2155 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2156 --- PASS: TestIsValidCachePath/log (0.00s)2157 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2158 --- PASS: TestIsValidCachePath/realisation (0.00s)2159 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2160 --- PASS: TestIsValidCachePath/ls (0.00s)2161 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2162 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2163 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2164=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21652026/11/07 23:34:10 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]2166=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2167=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2168=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2169=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2170--- PASS: TestPush_RejectsBadRequests (8.59s)2171 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)2172 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.02s)2173 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)2174 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)2175=== CONT TestService_RequireScope_OIDC/writer_implies_read2176=== CONT TestService_RequireScope_OIDC/builder_may_write2177=== CONT TestService_RequireScope_OIDC/reader_may_read2178=== CONT TestService_RequireScope_OIDC/static_token_may_write2179=== CONT TestService_RequireScope_OIDC/static_token_may_admin2180=== CONT TestService_RequireScope_OIDC/ops_may_admin2181=== CONT TestService_RequireScope_OIDC/ops_may_not_write2182=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2183=== CONT TestService_RequireScope_OIDC/reader_may_not_write2184=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21852026/11/07 23:34:10 INFO Received uploads request method=POST path=/2186=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21872026/11/07 23:34:10 INFO Received request for more parts method=POST path=/2188=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21892026/11/07 23:34:10 INFO Received complete multipart upload request method=POST path=/2190=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21912026/11/07 23:34:10 INFO Received uploads request method=POST path=/2192=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2193--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)2194 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)2195 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.01s)2196 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)2197 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)2198=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21992026/11/07 23:34:10 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]2200=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2201=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22022026/11/07 23:34:10 WARN Authentication failed token_preview=eyJhbGciOi...5wOlCm5f7w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2203--- PASS: TestService_RequireScope_OIDC (9.78s)2204 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2205 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2206 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2207 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2208 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2209 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2210 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2211 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2212 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2213 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2214 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2215 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2216 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2217 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2218--- PASS: TestService_AuthMiddleware_OIDC (9.56s)2219 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2220 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.02s)2221 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2222 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)22232026/11/07 23:34:11 INFO Received push request method=POST path=/api/pushes2224--- PASS: TestUploadHandlersRejectOversizedBody (0.26s)2225 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.42s)2226 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.44s)2227 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (5.71s)22282026/11/07 23:34:11 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-config22292026/11/07 23:34:12 WARN Request failed, retrying attempt=2 backoff=190.853975ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22302026/11/07 23:34:12 WARN Request failed, retrying attempt=3 backoff=406.323079ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/11/07 23:34:12 INFO Received uploads request method=POST path=/api/pending_closures22322026/11/07 23:34:12 WARN Request failed, retrying attempt=4 backoff=760.926242ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/11/07 23:34:13 WARN Request failed, retrying attempt=5 backoff=1.470604101s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/11/07 23:34:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22352026/11/07 23:34:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjRhZDBkN2VlLTAzN2EtNDcwOC04NjVjLTZmMDgwZGY1OGIzMHgxNzk0MDk0NDQyMDA4MTc0MDAw parts=102236--- PASS: TestService_Rustfstest (13.16s)22372026/11/07 23:34:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22382026/11/07 23:34:14 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"22392026/11/07 23:34:15 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-config2240=== NAME TestOrphanedObjectsGCStressTest2241 orphaned_objects_gc_test.go:503: Stress test completed successfully:2242 orphaned_objects_gc_test.go:504: - Active objects preserved: 202243 orphaned_objects_gc_test.go:505: - Objects deleted: 2102244 orphaned_objects_gc_test.go:506: - Total GC'd: 21022452026/11/07 23:34:15 WARN Request failed, retrying attempt=2 backoff=202.434754ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/11/07 23:34:15 INFO Aborted multipart uploads count=0 kept=02247--- PASS: TestOrphanedObjectsGCStressTest (43.68s)22482026/11/07 23:34:15 WARN Request failed, retrying attempt=3 backoff=419.837354ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22492026/11/07 23:34:15 WARN Force mode enabled - objects will be deleted immediately without grace period22502026/11/07 23:34:15 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=022512026/11/07 23:34:15 INFO Vacuumed table table=pending_closures22522026/11/07 23:34:15 INFO Vacuumed table table=pending_objects22532026/11/07 23:34:15 INFO Vacuumed table table=multipart_uploads22542026/11/07 23:34:15 INFO Vacuumed table table=closures22552026/11/07 23:34:15 INFO Vacuumed table table=objects22562026/11/07 23:34:15 INFO Aborted multipart uploads count=0 kept=022572026/11/07 23:34:15 WARN Force mode enabled - objects will be deleted immediately without grace period22582026/11/07 23:34:15 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=022592026/11/07 23:34:15 INFO Vacuumed table table=pending_closures22602026/11/07 23:34:15 INFO Vacuumed table table=pending_objects22612026/11/07 23:34:15 INFO Vacuumed table table=multipart_uploads22622026/11/07 23:34:15 INFO Vacuumed table table=closures22632026/11/07 23:34:15 WARN Request failed, retrying attempt=4 backoff=810.333259ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22642026/11/07 23:34:15 INFO Vacuumed table table=objects2265--- PASS: TestSweepSkipsRowsLockedByPush (13.37s)22662026/11/07 23:34:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22672026/11/07 23:34:15 INFO Received uploads request method=POST path=/api/pending_closures22682026/11/07 23:34:15 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1Ljc1MWU2YmMxLTNlYTctNDE1Yy05MjYwLTQxNzlkNWU0YjFlZngxNzk0MDk0NDUxNTQ2MjMzMDAw parts=1022692026/11/07 23:34:16 INFO Received uploads request method=POST path=/api/pending_closures22702026-11-07 23:34:16.236 UTC [82388] ERROR: Push does not exist: id=122712026-11-07 23:34:16.236 UTC [82388] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE22722026-11-07 23:34:16.236 UTC [82388] STATEMENT: SELECT commit_push($1)2273--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (15.57s)22742026/11/07 23:34:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22752026/11/07 23:34:16 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjNkOTE5YTlhLTk5MjMtNGEzZS1hNzkwLWExNDg1ZjY0YzRjNXgxNzk0MDk0NDQyMDA4MTMwMDAw parts=1022762026/11/07 23:34:16 WARN Request failed, retrying attempt=5 backoff=1.607703686s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22772026/11/07 23:34:16 INFO Received uploads request method=POST path=/api/pending_closures2278--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.04s)2279 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (13.58s)2280 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (13.15s)22812026/11/07 23:34:17 INFO Received uploads request method=POST path=/api/pending_closures22822026/11/07 23:34:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22832026/11/07 23:34:17 INFO Received uploads request method=POST path=/api/pending_closures22842026/11/07 23:34:17 INFO Aborted multipart uploads count=0 kept=022852026/11/07 23:34:17 WARN Force mode enabled - objects will be deleted immediately without grace period22862026/11/07 23:34:17 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjI2NWEwMzFhLWYxN2YtNGUzOC05ZTA1LTAyYjE3ODU1YTYxN3gxNzk0MDk0NDU1OTQyMjA1MDAw parts=1022872026/11/07 23:34:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22882026/11/07 23:34:17 INFO Completed upload id=1 objects=3 duration=22.133417ms22892026/11/07 23:34:17 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=022902026/11/07 23:34:17 INFO Vacuumed table table=pending_closures22912026/11/07 23:34:17 INFO Vacuumed table table=pending_objects22922026/11/07 23:34:17 INFO Vacuumed table table=multipart_uploads22932026/11/07 23:34:17 INFO Vacuumed table table=closures22942026/11/07 23:34:17 INFO Received uploads request method=POST path=/api/pending_closures22952026/11/07 23:34:17 INFO Vacuumed table table=objects22962026/11/07 23:34:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22972026/11/07 23:34:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22982026/11/07 23:34:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmE0MDkyZDUyLTlmNTUtNDc0OC1hNWQxLTJhYTJkYzY4N2VhYXgxNzk0MDk0NDU2MTgwMTAyMDAw parts=1022992026/11/07 23:34:18 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjcyYzRkNjgzLWUxMmYtNDgwZC1hZGU2LTMwZDA4YTk2ZDAxMngxNzk0MDk0NDQyMDA4MTc2MDAw parts=1023002026/11/07 23:34:18 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_closures23012026/11/07 23:34:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23022026/11/07 23:34:18 INFO Received uploads request method=POST path=/api/pending_closures23032026/11/07 23:34:18 INFO Completed upload id=1 objects=3 duration=14.758709ms23042026/11/07 23:34:18 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst23052026/11/07 23:34:18 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo23062026/11/07 23:34:18 WARN Request failed, retrying attempt=2 backoff=219.183421ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23072026/11/07 23:34:18 INFO Received uploads request method=POST path=/api/pending_closures23082026/11/07 23:34:18 INFO Aborted multipart uploads count=0 kept=023092026/11/07 23:34:18 WARN Force mode enabled - objects will be deleted immediately without grace period23102026/11/07 23:34:18 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=023112026/11/07 23:34:18 INFO Vacuumed table table=pending_closures23122026/11/07 23:34:18 INFO Vacuumed table table=pending_objects23132026/11/07 23:34:18 INFO Vacuumed table table=multipart_uploads23142026/11/07 23:34:18 INFO Vacuumed table table=closures23152026/11/07 23:34:18 WARN Request failed, retrying attempt=3 backoff=384.735635ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23162026/11/07 23:34:18 INFO Vacuumed table table=objects2317--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2318 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (12.01s)2319 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (12.61s)23202026/11/07 23:34:18 INFO Received uploads request method=POST path=/api/pending_closures23212026/11/07 23:34:18 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst23222026/11/07 23:34:18 WARN Found objects in DB but missing from S3, will re-upload count=123232026/11/07 23:34:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23242026/11/07 23:34:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmZjZmEyMjhmLWQzNTEtNDNjZC05MDE0LWJkNThjZDM2NDI3NngxNzk0MDk0NDU2NzQ3NzMzMDAw parts=1023252026/11/07 23:34:18 WARN Request failed, retrying attempt=4 backoff=769.172959ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23262026/11/07 23:34:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23272026/11/07 23:34:18 INFO Completed upload id=1 objects=3 duration=6.016125ms23282026/11/07 23:34:18 INFO Received uploads request method=POST path=/api/pending_closures23292026/11/07 23:34:19 INFO Aborted multipart uploads count=0 kept=023302026/11/07 23:34:19 WARN Force mode enabled - objects will be deleted immediately without grace period23312026-11-07 23:34:19.061 UTC [82402] ERROR: canceling statement due to user request23322026-11-07 23:34:19.061 UTC [82402] CONTEXT: SQL statement "UPDATE object_stats s2333 SET object_count = s.object_count + n.n - o.n,2334 total_bytes = s.total_bytes + n.bytes - o.bytes2335 FROM (2336 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2337 FROM new_rows WHERE deleted_at IS NULL2338 ) AS n,2339 (2340 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2341 FROM old_rows WHERE deleted_at IS NULL2342 ) AS o2343 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2344 PL/pgSQL function object_stats_update() line 3 at SQL statement23452026-11-07 23:34:19.061 UTC [82402] STATEMENT: -- name: MarkStaleObjects :execrows2346 WITH RECURSIVE ct AS (2347 SELECT timezone('UTC', now()) AS now2348 ),2349 closure_reach AS (2350 -- Start with all closure keys2351 SELECT o.key, o.refs2352 FROM objects o2353 INNER JOIN closures c ON o.key = c.key2354 UNION2355 -- Recursively add all referenced objects2356 SELECT o.key, o.refs2357 FROM objects o2358 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2359 ),2360 reachable_objects AS (2361 SELECT DISTINCT key FROM closure_reach2362 ),2363 stale_objects AS (2364 SELECT o.key2365 FROM objects AS o, ct2366 WHERE2367 NOT EXISTS (2368 SELECT 12369 FROM reachable_objects ro2370 WHERE ro.key = o.key2371 )2372 AND NOT EXISTS (2373 SELECT 12374 FROM pending_objects AS po2375 WHERE po.key = o.key2376 )2377 AND o.deleted_at IS NULL -- Only mark fresh objects2378 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2379 FOR UPDATE2380 )2381 UPDATE objects2382 SET2383 deleted_at = ct.now,2384 first_deleted_at = COALESCE(first_deleted_at, ct.now)2385 FROM stale_objects, ct2386 WHERE objects.key = stale_objects.key2387 23882026/11/07 23:34:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23892026/11/07 23:34:19 WARN Rate limiter enabled after throttle name=s3-test rate=523902026/11/07 23:34:19 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2391=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2392 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102393 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002394--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (18.13s)23952026/11/07 23:34:19 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmIwZDkyMjg3LWQ4YmQtNDdlOC1iMGY0LTQ1NTZhYmY0NDUzMngxNzk0MDk0NDU3MDk0MjkwMDAw parts=1023962026/11/07 23:34:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete23972026/11/07 23:34:19 INFO Completed upload id=1 objects=3 duration=12.496792ms23982026/11/07 23:34:19 INFO Received uploads request method=POST path=/api/pending_closures23992026/11/07 23:34:19 INFO Received uploads request method=POST path=/api/pending_closures24002026/11/07 23:34:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24012026/11/07 23:34:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24022026/11/07 23:34:19 WARN Request failed, retrying attempt=5 backoff=1.684580583s 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:34:19 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmE5ZTNkY2JhLTdjNTYtNGYwYy1iN2E0LTM5NTJmNjIwZjUwYngxNzk0MDk0NDQyMDA4MTM0MDAw parts=1024042026/11/07 23:34:19 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LjE3ZDc2MzNiLTM1NTUtNDQ0ZC05NWU4LTU3ZTk5ZDI4NWMzZngxNzk0MDk0NDU3ODk2NzQyMDAw parts=1024052026-11-07 23:34:19.745 UTC [82283] ERROR: could not obtain lock on row in relation "closures"24062026-11-07 23:34:19.745 UTC [82283] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24072026-11-07 23:34:19.749 UTC [82283] ERROR: could not obtain lock on row in relation "closures"24082026-11-07 23:34:19.749 UTC [82283] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24092026-11-07 23:34:19.752 UTC [82283] ERROR: could not obtain lock on row in relation "closures"24102026-11-07 23:34:19.752 UTC [82283] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24112026-11-07 23:34:19.753 UTC [82283] ERROR: could not obtain lock on row in relation "closures"24122026-11-07 23:34:19.753 UTC [82283] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24132026-11-07 23:34:19.753 UTC [82283] ERROR: could not obtain lock on row in relation "closures"24142026-11-07 23:34:19.753 UTC [82283] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24152026/11/07 23:34:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete24162026/11/07 23:34:19 INFO Completed upload id=1 objects=3 duration=1.222459ms24172026/11/07 23:34:19 INFO Received uploads request method=POST path=/api/pending_closures2418--- PASS: TestPush_RootsAreLockedInByteOrder (26.97s)24192026/11/07 23:34:19 INFO Aborted multipart uploads count=0 kept=024202026/11/07 23:34:19 WARN Force mode enabled - objects will be deleted immediately without grace period24212026/11/07 23:34:19 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:54660/bucket110/?delete=\": context canceled"2422--- PASS: TestGCEndsOnShutdown (0.00s)2423 --- PASS: TestGCEndsOnShutdown/before_the_run (12.26s)2424 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (12.56s)2425 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (13.09s)24262026/11/07 23:34:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2427--- PASS: TestPendingClosureWriteTimeout (0.01s)2428 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2429 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2430 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2431 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (13.21s)24322026/11/07 23:34:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmNjMmM3ZDIwLTEwY2YtNDIyNy1iZDZmLTI5NTI1NTNlZDAwN3gxNzk0MDk0NDU4OTI4MzA0MDAw parts=1024332026/11/07 23:34:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24342026/11/07 23:34:20 INFO Completed upload id=2 objects=3 duration=694.5µs24352026/11/07 23:34:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24362026/11/07 23:34:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24372026/11/07 23:34:20 INFO Received uploads request method=POST path=/api/pending_closures24382026/11/07 23:34:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst24392026/11/07 23:34:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo24402026/11/07 23:34:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete24412026/11/07 23:34:20 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NGE2NjNiNDAtYTlmNi00ZjdmLWI5YzAtNzcyMDA5ZjY3MWY1LmM4Y2Q1NWY2LTFjNDEtNDFjYy1iMjU3LTQyZDc3NDcwMWFjNHgxNzk0MDk0NDU5NzY4NzA4MDAw parts=1024422026/11/07 23:34:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete24432026/11/07 23:34:20 INFO Completed upload id=2 objects=3 duration=1.629916ms24442026/11/07 23:34:20 INFO Received uploads request method=POST path=/api/pending_closures24452026/11/07 23:34:20 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst24462026/11/07 23:34:20 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2447--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.05s)2448 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (15.25s)2449 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (15.52s)2450 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (13.84s)2451 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (15.48s)2452 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (15.27s)2453--- PASS: TestClientErrorHandling (0.02s)2454 --- PASS: TestClientErrorHandling/InvalidStorePath (12.21s)2455 --- PASS: TestClientErrorHandling/InvalidAuthToken (11.72s)2456 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.95s)2457PASS2458{"timestamp":"2026-11-07T23:34:21.380084Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55459","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(3)"}2459{"timestamp":"2026-11-07T23:34:21.380573Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55493","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(3)"}2460{"timestamp":"2026-11-07T23:34:21.382122Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55234","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(10)"}2461{"timestamp":"2026-11-07T23:34:21.38254Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:55474","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(10)"}24622026-11-07 23:34:21.570 UTC [81800] LOG: received smart shutdown request24632026-11-07 23:34:21.571 UTC [81800] LOG: background worker "logical replication launcher" (PID 81810) exited with exit code 124642026-11-07 23:34:22.750 UTC [81805] LOG: checkpoint complete: wrote 5441 buffers (33.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.397 s, sync=0.771 s, total=14.548 s; sync files=38086, longest=0.018 s, average=0.001 s; distance=533104 kB, estimate=533104 kB; lsn=0/241D3D78, redo lsn=0/2202913824652026-11-07 23:34:22.752 UTC [81805] LOG: shutting down24662026-11-07 23:34:22.752 UTC [81805] LOG: checkpoint starting: shutdown immediate24672026-11-07 23:34:23.219 UTC [81805] LOG: checkpoint complete: wrote 6164 buffers (37.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 2 recycled; write=0.430 s, sync=0.035 s, total=0.468 s; sync files=1945, longest=0.001 s, average=0.001 s; distance=34475 kB, estimate=483241 kB; lsn=0/241D3DF0, redo lsn=0/241D3DF024682026-11-07 23:34:23.229 UTC [81800] LOG: database system is shut down2469Running OIDC tests...2470=== RUN TestAudienceForIssuer2471=== PAUSE TestAudienceForIssuer2472=== RUN TestHTTPClientForHasTimeouts2473=== PAUSE TestHTTPClientForHasTimeouts2474=== RUN TestGlobMatch2475=== PAUSE TestGlobMatch2476=== RUN TestValidateToken_ValidToken2477=== PAUSE TestValidateToken_ValidToken2478=== RUN TestValidateToken_WrongAudience2479=== PAUSE TestValidateToken_WrongAudience2480=== RUN TestValidateToken_Expired2481=== PAUSE TestValidateToken_Expired2482=== RUN TestValidateToken_BoundClaimsMismatch2483=== PAUSE TestValidateToken_BoundClaimsMismatch2484=== RUN TestValidateToken_BoundSubjectMismatch2485=== PAUSE TestValidateToken_BoundSubjectMismatch2486=== RUN TestValidateToken_MultipleProviders2487=== PAUSE TestValidateToken_MultipleProviders2488=== RUN TestValidateToken_NoMatchingProvider2489=== PAUSE TestValidateToken_NoMatchingProvider2490=== RUN TestValidateToken_KubernetesServiceAccount2491=== PAUSE TestValidateToken_KubernetesServiceAccount2492=== RUN TestNewValidator_KubernetesRequiresCA2493=== PAUSE TestNewValidator_KubernetesRequiresCA2494=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2495=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2496=== RUN TestPins_ReservedForMatchingRule2497=== PAUSE TestPins_ReservedForMatchingRule2498=== RUN TestPins_TopLevelShorthand2499=== PAUSE TestPins_TopLevelShorthand2500=== RUN TestPins_ConfigValidation2501=== PAUSE TestPins_ConfigValidation2502=== RUN TestScopes_LegacyProviderDefaultsToWrite2503=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2504=== RUN TestScopes_Rules2505=== PAUSE TestScopes_Rules2506=== RUN TestScopes_ConfigValidation2507=== PAUSE TestScopes_ConfigValidation2508=== CONT TestAudienceForIssuer2509=== CONT TestValidateToken_KubernetesServiceAccount2510=== CONT TestScopes_LegacyProviderDefaultsToWrite2511--- PASS: TestAudienceForIssuer (0.00s)2512=== CONT TestValidateToken_NoMatchingProvider2513=== CONT TestValidateToken_MultipleProviders2514=== CONT TestValidateToken_BoundSubjectMismatch2515=== CONT TestValidateToken_Expired2516=== CONT TestValidateToken_WrongAudience2517=== CONT TestValidateToken_BoundClaimsMismatch2518=== CONT TestValidateToken_ValidToken2519=== CONT TestHTTPClientForHasTimeouts2520=== CONT TestGlobMatch2521=== RUN TestGlobMatch/foo_foo2522=== CONT TestPins_ReservedForMatchingRule2523=== PAUSE TestGlobMatch/foo_foo2524=== RUN TestGlobMatch/foo_bar2525=== PAUSE TestGlobMatch/foo_bar2526=== RUN TestGlobMatch/*_2527=== PAUSE TestGlobMatch/*_2528=== RUN TestGlobMatch/*_anything2529=== PAUSE TestGlobMatch/*_anything2530=== RUN TestGlobMatch/foo*_foo2531=== CONT TestScopes_Rules2532=== CONT TestPins_TopLevelShorthand2533=== CONT TestScopes_ConfigValidation2534--- PASS: TestScopes_ConfigValidation (0.00s)2535=== CONT TestPins_ConfigValidation2536--- PASS: TestPins_ConfigValidation (0.00s)2537=== CONT TestNewValidator_KubernetesRequiresCA2538=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2539=== PAUSE TestGlobMatch/foo*_foo2540=== RUN TestGlobMatch/foo*_foobar2541=== PAUSE TestGlobMatch/foo*_foobar2542=== RUN TestGlobMatch/foo*_bar2543=== PAUSE TestGlobMatch/foo*_bar2544=== RUN TestGlobMatch/*bar_bar2545=== PAUSE TestGlobMatch/*bar_bar2546=== RUN TestGlobMatch/*bar_foobar2547=== PAUSE TestGlobMatch/*bar_foobar2548=== RUN TestGlobMatch/*bar_foo2549=== PAUSE TestGlobMatch/*bar_foo2550=== RUN TestGlobMatch/foo*bar_foobar2551=== PAUSE TestGlobMatch/foo*bar_foobar2552=== RUN TestGlobMatch/foo*bar_foo123bar2553=== PAUSE TestGlobMatch/foo*bar_foo123bar2554=== RUN TestGlobMatch/foo*bar_foobarbaz2555=== PAUSE TestGlobMatch/foo*bar_foobarbaz2556=== RUN TestGlobMatch/*/*_foo/bar2557=== PAUSE TestGlobMatch/*/*_foo/bar2558=== RUN TestGlobMatch/*/*_foo2559=== PAUSE TestGlobMatch/*/*_foo2560=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2561=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2562=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02563=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02564=== RUN TestGlobMatch/refs/*/main_refs/heads/main2565=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2566=== RUN TestGlobMatch/fo?_foo2567=== PAUSE TestGlobMatch/fo?_foo2568=== RUN TestGlobMatch/fo?_fo2569=== PAUSE TestGlobMatch/fo?_fo2570=== RUN TestGlobMatch/fo?_fooo2571=== PAUSE TestGlobMatch/fo?_fooo2572=== RUN TestGlobMatch/?oo_foo2573=== PAUSE TestGlobMatch/?oo_foo2574=== RUN TestGlobMatch/?oo_boo2575=== PAUSE TestGlobMatch/?oo_boo2576=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2577=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2578=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2579=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2580=== CONT TestGlobMatch/foo_foo2581=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2582=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2583=== CONT TestGlobMatch/?oo_boo2584=== CONT TestGlobMatch/?oo_foo2585=== CONT TestGlobMatch/fo?_fooo2586=== CONT TestGlobMatch/fo?_fo2587=== CONT TestGlobMatch/fo?_foo2588=== CONT TestGlobMatch/refs/*/main_refs/heads/main2589=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02590=== CONT TestGlobMatch/*/*_foo2591=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2592=== CONT TestGlobMatch/foo*bar_foobarbaz2593=== CONT TestGlobMatch/*/*_foo/bar2594=== CONT TestGlobMatch/foo*bar_foo123bar2595=== CONT TestGlobMatch/*bar_foo2596=== CONT TestGlobMatch/foo*bar_foobar2597=== CONT TestGlobMatch/*bar_foobar2598=== CONT TestGlobMatch/*bar_bar2599=== CONT TestGlobMatch/foo*_bar2600=== CONT TestGlobMatch/foo*_foobar2601=== CONT TestGlobMatch/*_anything2602=== CONT TestGlobMatch/foo*_foo2603=== CONT TestGlobMatch/*_2604=== CONT TestGlobMatch/foo_bar2605--- PASS: TestGlobMatch (0.03s)2606 --- PASS: TestGlobMatch/foo_foo (0.00s)2607 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2608 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2609 --- PASS: TestGlobMatch/?oo_boo (0.00s)2610 --- PASS: TestGlobMatch/?oo_foo (0.00s)2611 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2612 --- PASS: TestGlobMatch/fo?_fo (0.00s)2613 --- PASS: TestGlobMatch/fo?_foo (0.00s)2614 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2615 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2616 --- PASS: TestGlobMatch/*/*_foo (0.00s)2617 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2618 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2619 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2620 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2621 --- PASS: TestGlobMatch/*bar_foo (0.00s)2622 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2623 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2624 --- PASS: TestGlobMatch/*bar_bar (0.00s)2625 --- PASS: TestGlobMatch/foo*_bar (0.00s)2626 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2627 --- PASS: TestGlobMatch/*_anything (0.00s)2628 --- PASS: TestGlobMatch/foo*_foo (0.00s)2629 --- PASS: TestGlobMatch/*_ (0.00s)2630 --- PASS: TestGlobMatch/foo_bar (0.00s)26312026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55541/oidc2632--- PASS: TestValidateToken_WrongAudience (0.08s)26332026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55543/oidc2634--- PASS: TestPins_ReservedForMatchingRule (0.10s)26352026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55545/oidc26362026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55547/oidc26372026/11/07 23:34:26 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232638--- PASS: TestValidateToken_ValidToken (0.13s)2639--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)26402026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55550/oidc2641--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)2642--- PASS: TestScopes_Rules (0.13s)26432026/11/07 23:34:26 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5555426442026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55557/oidc2645--- PASS: TestValidateToken_BoundClaimsMismatch (0.15s)2646--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)26472026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55559/oidc2648--- PASS: TestValidateToken_Expired (0.16s)26492026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55561/oidc2650--- PASS: TestValidateToken_BoundSubjectMismatch (0.18s)26512026/11/07 23:34:26 http: TLS handshake error from 127.0.0.1:55564: remote error: tls: bad certificate2652--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)26532026/11/07 23:34:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55565/oidc2654--- PASS: TestPins_TopLevelShorthand (0.19s)26552026/11/07 23:34:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55552/oidc26562026/11/07 23:34:26 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:55568/oidc2657--- PASS: TestValidateToken_MultipleProviders (0.23s)26582026/11/07 23:34:26 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55571/oidc2659--- PASS: TestValidateToken_NoMatchingProvider (0.32s)2660--- PASS: TestHTTPClientForHasTimeouts (0.41s)2661PASS2662Running hook tests...2663=== RUN TestSendPathsEmpty2664=== PAUSE TestSendPathsEmpty2665=== RUN TestQueueEnqueueAndFetch2666=== PAUSE TestQueueEnqueueAndFetch2667=== RUN TestQueueDeduplication2668=== PAUSE TestQueueDeduplication2669=== RUN TestQueueRemove2670=== PAUSE TestQueueRemove2671=== RUN TestQueueFetchBatchLimit2672=== PAUSE TestQueueFetchBatchLimit2673=== RUN TestQueueRetryMovesToBack2674=== PAUSE TestQueueRetryMovesToBack2675=== RUN TestQueueFetchRemoveLifecycle2676=== PAUSE TestQueueFetchRemoveLifecycle2677=== RUN TestQueueConcurrentWriters2678=== PAUSE TestQueueConcurrentWriters2679=== RUN TestQueueRemoveLargeClosure2680=== PAUSE TestQueueRemoveLargeClosure2681=== RUN TestServerClientIntegration2682--- PASS: TestServerClientIntegration (0.00s)2683=== RUN TestServerQueueError26842026/11/07 23:34:28 ERROR Failed to queue paths error="permission denied" count=12685--- PASS: TestServerQueueError (0.00s)2686=== RUN TestServerRefusesOversizedAndNonStoreRequests2687=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2688=== RUN TestGetListenerSocketActivation2689 server_test.go:236: systemd socket activation does not exist on darwin2690--- SKIP: TestGetListenerSocketActivation (0.00s)2691=== RUN TestServerStalledClientDoesNotBlockShutdown2692=== PAUSE TestServerStalledClientDoesNotBlockShutdown2693=== RUN TestServerBacksOffOnAcceptErrors2694=== PAUSE TestServerBacksOffOnAcceptErrors2695=== RUN TestDrainIsolatesPoisonPath2696=== PAUSE TestDrainIsolatesPoisonPath2697=== RUN TestRunNotBlockedByPoisonHead2698=== PAUSE TestRunNotBlockedByPoisonHead2699=== RUN TestDrainGivesUpWhenServerDown2700=== PAUSE TestDrainGivesUpWhenServerDown2701=== RUN TestFailedPathPrunedByLaterClosure2702=== PAUSE TestFailedPathPrunedByLaterClosure2703=== RUN TestWorkerUploadsAndRemoves2704=== PAUSE TestWorkerUploadsAndRemoves2705=== RUN TestWorkerSkipsGCdPaths2706=== PAUSE TestWorkerSkipsGCdPaths2707=== RUN TestWorkerPrunesClosureDeps2708=== PAUSE TestWorkerPrunesClosureDeps2709=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2710=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2711=== RUN TestDrainTimeout2712=== PAUSE TestDrainTimeout2713=== RUN TestDrainTimeoutDuringIsolation2714=== PAUSE TestDrainTimeoutDuringIsolation2715=== RUN TestShutdownFinishesInFlightPush2716=== PAUSE TestShutdownFinishesInFlightPush2717=== RUN TestWorkerRemoveFailureIsNotProgress2718=== PAUSE TestWorkerRemoveFailureIsNotProgress2719=== RUN TestWorkerKeepsPathItCannotStat2720=== PAUSE TestWorkerKeepsPathItCannotStat2721=== CONT TestSendPathsEmpty2722=== CONT TestFailedPathPrunedByLaterClosure2723=== CONT TestQueueFetchRemoveLifecycle2724=== CONT TestQueueFetchBatchLimit2725=== CONT TestDrainGivesUpWhenServerDown2726=== CONT TestWorkerRemoveFailureIsNotProgress2727=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2728=== CONT TestQueueEnqueueAndFetch2729=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2730=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2731=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2732=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2733=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2734=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2735=== CONT TestWorkerKeepsPathItCannotStat2736=== CONT TestShutdownFinishesInFlightPush2737=== RUN TestShutdownFinishesInFlightPush/completes2738=== PAUSE TestShutdownFinishesInFlightPush/completes2739=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2740=== CONT TestWorkerUploadsAndRemoves2741=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2742=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2743=== CONT TestDrainTimeoutDuringIsolation2744=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2745=== CONT TestDrainTimeout2746=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2747=== CONT TestWorkerPrunesClosureDeps2748=== CONT TestDrainIsolatesPoisonPath2749=== CONT TestWorkerSkipsGCdPaths2750=== CONT TestQueueRemoveLargeClosure2751=== CONT TestQueueRetryMovesToBack2752=== CONT TestServerStalledClientDoesNotBlockShutdown2753=== CONT TestQueueConcurrentWriters2754=== CONT TestQueueDeduplication2755=== CONT TestServerBacksOffOnAcceptErrors2756=== CONT TestQueueRemove27572026/11/07 23:34:28 ERROR Accept failed error="too many open files"2758=== CONT TestServerRefusesOversizedAndNonStoreRequests2759=== CONT TestRunNotBlockedByPoisonHead2760--- PASS: TestSendPathsEmpty (0.00s)2761=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2762=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2763=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27642026/11/07 23:34:28 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2765=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27662026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store store=/nix/store27672026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27682026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27692026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27702026/11/07 23:34:28 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27712026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27722026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27732026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27742026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27752026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27762026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27772026/11/07 23:34:28 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27782026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27792026/11/07 23:34:28 ERROR Accept failed error="too many open files"27802026/11/07 23:34:28 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27812026/11/07 23:34:28 ERROR Failed to decode request error="unexpected EOF"2782--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2783=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27842026/11/07 23:34:28 ERROR Accept failed error="too many open files"27852026/11/07 23:34:28 INFO Uploading batch count=127862026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=127872026/11/07 23:34:28 INFO Upload queue status pending=227882026/11/07 23:34:28 INFO Uploading batch count=127892026/11/07 23:34:28 INFO Upload queue status pending=327902026/11/07 23:34:28 INFO Upload queue status pending=327912026/11/07 23:34:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerSkipsGCdPaths1330595026/002/nonexistent27922026/11/07 23:34:28 INFO Uploading batch count=127932026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=127942026/11/07 23:34:28 INFO Upload queue status pending=227952026/11/07 23:34:28 INFO Uploading batch count=227962026/11/07 23:34:28 INFO Uploading batch count=127972026/11/07 23:34:28 INFO Uploading batch count=227982026/11/07 23:34:28 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa error="lstat /private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa: permission denied"27992026/11/07 23:34:28 INFO Uploading batch count=428002026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=428012026/11/07 23:34:28 INFO Upload queue status pending=228022026/11/07 23:34:28 INFO Uploading batch count=228032026/11/07 23:34:28 INFO Uploading batch count=22804--- PASS: TestQueueEnqueueAndFetch (0.03s)2805=== CONT TestShutdownFinishesInFlightPush/completes28062026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainIsolatesPoisonPath1807557899/002/bbb28072026/11/07 23:34:28 INFO Uploading batch count=228082026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228092026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/a28102026/11/07 23:34:28 INFO Uploading batch count=12811--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2812=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2813--- PASS: TestQueueFetchBatchLimit (0.03s)2814=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline28152026/11/07 23:34:28 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa error="lstat /private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa: permission denied"28162026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/b28172026/11/07 23:34:28 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa error="lstat /private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerKeepsPathItCannotStat238017184/002/locked/aaa: permission denied"28182026/11/07 23:34:28 INFO Uploading batch count=228192026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228202026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128212026/11/07 23:34:28 INFO Upload queue status pending=228222026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128232026/11/07 23:34:28 INFO Uploading batch count=128242026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=12825--- PASS: TestQueueRemove (0.03s)28262026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=128272026/11/07 23:34:28 INFO Uploading batch count=228282026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228292026/11/07 23:34:28 INFO Uploading batch count=228302026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228312026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/c28322026/11/07 23:34:28 INFO Uploading batch count=228332026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128342026/11/07 23:34:28 INFO Uploading batch count=128352026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=128362026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128372026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/d2838--- PASS: TestQueueDeduplication (0.03s)2839--- PASS: TestQueueRetryMovesToBack (0.04s)28402026/11/07 23:34:28 INFO Uploading batch count=228412026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228422026/11/07 23:34:28 ERROR Accept failed error="too many open files"28432026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128442026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128452026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=228462026/11/07 23:34:28 INFO Uploading batch count=228472026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=228482026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/e28492026/11/07 23:34:28 INFO Uploading batch count=128502026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=12851--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)2852--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)28532026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=128542026/11/07 23:34:28 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestDrainGivesUpWhenServerDown3060371238/002/f28552026/11/07 23:34:28 INFO Upload queue status pending=228562026/11/07 23:34:28 INFO Uploading batch count=228572026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=1028582026/11/07 23:34:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerRemoveFailureIsNotProgresscollected_path4283465537/001/nonexistent2859--- PASS: TestDrainIsolatesPoisonPath (0.04s)28602026/11/07 23:34:28 INFO Uploading batch count=228612026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128622026/11/07 23:34:28 INFO Uploading batch count=428632026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=428642026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228652026/11/07 23:34:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerRemoveFailureIsNotProgresscollected_path4283465537/001/nonexistent2866--- PASS: TestDrainGivesUpWhenServerDown (0.05s)28672026/11/07 23:34:28 INFO Uploading batch count=228682026/11/07 23:34:28 INFO Uploading batch count=428692026/11/07 23:34:28 ERROR Upload failed error="upload failed" count=428702026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128712026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228722026/11/07 23:34:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/89da011d463ecd02/build/TestWorkerRemoveFailureIsNotProgresscollected_path4283465537/001/nonexistent28732026/11/07 23:34:28 INFO Uploading batch count=228742026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228752026/11/07 23:34:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12876--- PASS: TestWorkerPrunesClosureDeps (0.05s)28772026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=128782026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=22879--- PASS: TestWorkerSkipsGCdPaths (0.05s)2880--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2881 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)2882 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2883 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2884--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2885--- PASS: TestWorkerUploadsAndRemoves (0.05s)28862026/11/07 23:34:28 ERROR Accept failed error="too many open files"28872026/11/07 23:34:28 ERROR Accept failed error="too many open files"2888--- PASS: TestQueueConcurrentWriters (0.16s)28892026/11/07 23:34:28 ERROR Failed to decode request error="read unix /private/var/tb/4/scratch/89da011d463ecd02/build/hook318833543/test.sock->: i/o timeout"28902026/11/07 23:34:28 ERROR Failed to write response error="write unix /private/var/tb/4/scratch/89da011d463ecd02/build/hook318833543/test.sock->: i/o timeout"2891--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28922026/11/07 23:34:28 ERROR Upload failed error="context canceled" count=228932026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=42894--- PASS: TestDrainTimeout (0.23s)28952026/11/07 23:34:28 ERROR Upload failed error="context canceled" count=228962026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=22897--- PASS: TestShutdownFinishesInFlightPush (0.00s)2898 --- PASS: TestShutdownFinishesInFlightPush/completes (0.12s)2899 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)29002026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=429012026/11/07 23:34:28 ERROR Accept failed error="too many open files"29022026/11/07 23:34:28 ERROR Drain finished with paths left in queue remaining=32903--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2904 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.22s)2905 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.32s)29062026/11/07 23:34:29 ERROR Accept failed error="too many open files"2907--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2908--- PASS: TestQueueRemoveLargeClosure (0.81s)29092026/11/07 23:34:29 INFO Uploading batch count=129102026/11/07 23:34:29 INFO Uploading batch count=129112026/11/07 23:34:29 INFO Uploading batch count=129122026/11/07 23:34:29 ERROR Upload failed error="upload failed" count=129132026/11/07 23:34:29 INFO Uploading batch count=129142026/11/07 23:34:29 ERROR Upload failed error="upload failed" count=129152026/11/07 23:34:29 INFO Uploading batch count=129162026/11/07 23:34:29 ERROR Upload failed error="upload failed" count=129172026/11/07 23:34:29 INFO Uploading batch count=129182026/11/07 23:34:29 ERROR Upload failed error="upload failed" count=129192026/11/07 23:34:29 ERROR Drain finished with paths left in queue remaining=12920--- PASS: TestRunNotBlockedByPoisonHead (1.05s)2921PASS2922Running signing tests...2923=== RUN TestExternalSigner2924=== PAUSE TestExternalSigner2925=== RUN TestExternalSignerWrongPublicKey2926=== PAUSE TestExternalSignerWrongPublicKey2927=== RUN TestExternalSignerErrors2928=== PAUSE TestExternalSignerErrors2929=== RUN TestExternalSignerRestartsAfterCrash2930=== PAUSE TestExternalSignerRestartsAfterCrash2931=== RUN TestExternalSignerProgramErrorKeepsProcess2932=== PAUSE TestExternalSignerProgramErrorKeepsProcess2933=== RUN TestExternalSignerClose2934=== PAUSE TestExternalSignerClose2935=== RUN TestExternalSignerRejectsInvalidPublicKey2936=== PAUSE TestExternalSignerRejectsInvalidPublicKey2937=== RUN TestExternalSignerCancellation2938=== PAUSE TestExternalSignerCancellation2939=== RUN TestGenerateFingerprint2940=== PAUSE TestGenerateFingerprint2941=== RUN TestParseSigningKey2942=== PAUSE TestParseSigningKey2943=== RUN TestSign2944=== PAUSE TestSign2945=== RUN TestSignBatch2946=== PAUSE TestSignBatch2947=== RUN TestNilKeyPublicKey2948=== PAUSE TestNilKeyPublicKey2949=== RUN TestSignErrors2950=== PAUSE TestSignErrors2951=== CONT TestExternalSigner2952=== CONT TestSignBatch2953=== CONT TestExternalSignerRejectsInvalidPublicKey2954=== CONT TestGenerateFingerprint2955=== RUN TestExternalSignerRejectsInvalidPublicKey/#002956=== RUN TestGenerateFingerprint/basic_with_references2957=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002958=== PAUSE TestGenerateFingerprint/basic_with_references2959=== RUN TestGenerateFingerprint/no_references2960=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2961=== PAUSE TestGenerateFingerprint/no_references2962=== CONT TestExternalSignerWrongPublicKey2963=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2964=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2965=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2966=== CONT TestExternalSignerProgramErrorKeepsProcess2967=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2968=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2969=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2970=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2971=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2972=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2973=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2974=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2975=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2976=== CONT TestExternalSignerRejectsInvalidPublicKey/#002977=== CONT TestSignErrors2978--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2979 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2980 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2981 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2982 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2983 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2984=== CONT TestSign2985=== CONT TestNilKeyPublicKey2986--- PASS: TestNilKeyPublicKey (0.00s)2987=== CONT TestParseSigningKey2988=== CONT TestExternalSignerRestartsAfterCrash2989=== CONT TestExternalSignerCancellation2990=== RUN TestParseSigningKey/valid_32-byte_key2991=== CONT TestExternalSignerClose2992=== CONT TestExternalSignerErrors2993=== RUN TestExternalSignerErrors/null2994=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2995=== PAUSE TestParseSigningKey/valid_32-byte_key2996=== PAUSE TestExternalSignerErrors/null2997=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2998=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2999=== RUN TestParseSigningKey/no_colon3000=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix3001=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix3002=== RUN TestGenerateFingerprint/invalid_nar_hash_length3003=== RUN TestExternalSignerErrors/missing_signatures3004=== PAUSE TestParseSigningKey/no_colon3005=== PAUSE TestExternalSignerErrors/missing_signatures3006=== RUN TestParseSigningKey/empty_name3007=== RUN TestExternalSignerErrors/wrong_shape3008=== PAUSE TestExternalSignerErrors/wrong_shape3009=== PAUSE TestParseSigningKey/empty_name3010=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length3011=== RUN TestParseSigningKey/invalid_base643012=== RUN TestGenerateFingerprint/invalid_store_path_prefix3013=== PAUSE TestParseSigningKey/invalid_base643014=== RUN TestExternalSignerErrors/wrong_id3015=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3016=== RUN TestParseSigningKey/wrong_length3017=== RUN TestGenerateFingerprint/invalid_reference_prefix3018=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3019=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3020=== CONT TestGenerateFingerprint/no_references3021=== CONT TestGenerateFingerprint/invalid_nar_hash_length3022=== PAUSE TestParseSigningKey/wrong_length3023=== CONT TestGenerateFingerprint/invalid_store_path_prefix3024=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3025=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3026=== CONT TestParseSigningKey/valid_32-byte_key3027=== CONT TestParseSigningKey/wrong_length3028=== CONT TestParseSigningKey/invalid_base643029=== CONT TestGenerateFingerprint/basic_with_references3030=== PAUSE TestExternalSignerErrors/wrong_id3031=== CONT TestParseSigningKey/empty_name3032=== CONT TestParseSigningKey/no_colon3033=== CONT TestGenerateFingerprint/invalid_reference_prefix3034=== RUN TestExternalSignerErrors/null_signatures3035--- PASS: TestGenerateFingerprint (0.01s)3036 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3037 --- PASS: TestGenerateFingerprint/no_references (0.00s)3038 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3039 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3040 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3041 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3042 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3043=== PAUSE TestExternalSignerErrors/null_signatures3044=== RUN TestExternalSignerErrors/missing_signature_name3045=== PAUSE TestExternalSignerErrors/missing_signature_name3046=== RUN TestExternalSignerErrors/wrong_signature_length3047=== PAUSE TestExternalSignerErrors/wrong_signature_length3048=== RUN TestExternalSignerErrors/exit_on_request3049=== PAUSE TestExternalSignerErrors/exit_on_request3050=== RUN TestExternalSignerErrors/invalid_JSON3051=== PAUSE TestExternalSignerErrors/invalid_JSON3052=== RUN TestExternalSignerErrors/wrong_signatures_shape3053=== RUN TestSignErrors/nil_key3054=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3055=== PAUSE TestSignErrors/nil_key3056=== RUN TestExternalSignerErrors/too_few_signatures3057=== RUN TestSignErrors/nil_narinfo3058=== PAUSE TestExternalSignerErrors/too_few_signatures3059=== RUN TestExternalSignerErrors/wrong_signature_name3060=== PAUSE TestExternalSignerErrors/wrong_signature_name3061=== PAUSE TestSignErrors/nil_narinfo3062=== RUN TestExternalSignerErrors/invalid_signature_base643063=== RUN TestSignErrors/invalid_narinfo3064=== PAUSE TestExternalSignerErrors/invalid_signature_base643065=== PAUSE TestSignErrors/invalid_narinfo3066=== RUN TestExternalSignerErrors/exit_at_startup3067=== PAUSE TestExternalSignerErrors/exit_at_startup3068=== RUN TestExternalSignerErrors/unrequested_key3069=== PAUSE TestExternalSignerErrors/unrequested_key3070=== RUN TestSignErrors/canceled3071=== RUN TestExternalSignerErrors/program_error3072=== PAUSE TestSignErrors/canceled3073=== PAUSE TestExternalSignerErrors/program_error3074--- PASS: TestSign (0.01s)3075=== CONT TestExternalSignerErrors/null3076=== CONT TestExternalSignerErrors/wrong_signatures_shape3077=== CONT TestExternalSignerErrors/missing_signature_name3078=== CONT TestExternalSignerErrors/exit_on_request3079=== CONT TestExternalSignerErrors/too_few_signatures3080=== CONT TestExternalSignerErrors/wrong_id3081=== CONT TestExternalSignerErrors/null_signatures3082--- PASS: TestParseSigningKey (0.01s)3083 --- PASS: TestParseSigningKey/wrong_length (0.00s)3084 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3085 --- PASS: TestParseSigningKey/no_colon (0.00s)3086 --- PASS: TestParseSigningKey/empty_name (0.00s)3087 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3088 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3089=== CONT TestExternalSignerErrors/invalid_JSON3090=== CONT TestExternalSignerErrors/wrong_signature_name3091=== CONT TestExternalSignerErrors/unrequested_key3092=== CONT TestSignErrors/canceled3093=== CONT TestSignErrors/invalid_narinfo3094=== CONT TestExternalSignerErrors/wrong_signature_length3095=== CONT TestSignErrors/nil_narinfo3096=== CONT TestExternalSignerErrors/wrong_shape3097=== CONT TestExternalSignerErrors/missing_signatures3098=== CONT TestSignErrors/nil_key3099=== CONT TestExternalSignerErrors/invalid_signature_base643100=== CONT TestExternalSignerErrors/exit_at_startup3101=== CONT TestExternalSignerErrors/program_error3102--- PASS: TestSignErrors (0.01s)3103 --- PASS: TestSignErrors/canceled (0.00s)3104 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3105 --- PASS: TestSignErrors/nil_key (0.00s)3106 --- PASS: TestSignErrors/nil_narinfo (0.00s)3107--- PASS: TestSignBatch (0.02s)3108--- PASS: TestExternalSignerWrongPublicKey (0.21s)3109--- PASS: TestExternalSigner (0.41s)3110--- PASS: TestExternalSignerRestartsAfterCrash (0.62s)3111--- PASS: TestExternalSignerCancellation (0.80s)3112--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.96s)3113--- PASS: TestExternalSignerClose (1.16s)3114--- PASS: TestExternalSignerErrors (0.01s)3115 --- PASS: TestExternalSignerErrors/missing_signature_name (1.34s)3116 --- PASS: TestExternalSignerErrors/exit_on_request (1.53s)3117 --- PASS: TestExternalSignerErrors/null (1.71s)3118 --- PASS: TestExternalSignerErrors/too_few_signatures (1.92s)3119 --- PASS: TestExternalSignerErrors/null_signatures (2.10s)3120 --- PASS: TestExternalSignerErrors/invalid_JSON (2.59s)3121 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.78s)3122 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.97s)3123 --- PASS: TestExternalSignerErrors/wrong_id (3.16s)3124 --- PASS: TestExternalSignerErrors/exit_at_startup (3.34s)3125 --- PASS: TestExternalSignerErrors/unrequested_key (3.54s)3126 --- PASS: TestExternalSignerErrors/missing_signatures (3.73s)3127 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (3.92s)3128 --- PASS: TestExternalSignerErrors/wrong_signature_length (4.13s)3129 --- PASS: TestExternalSignerErrors/program_error (4.32s)3130 --- PASS: TestExternalSignerErrors/wrong_shape (4.52s)3131PASS3132Running OpenBao signer tests...3133=== RUN TestSign3134=== PAUSE TestSign3135=== RUN TestSignErrors3136=== PAUSE TestSignErrors3137=== RUN TestServe3138=== PAUSE TestServe3139=== RUN TestServeRejectsGarbage3140=== PAUSE TestServeRejectsGarbage3141=== CONT TestSign3142=== CONT TestServe3143=== CONT TestSignErrors3144=== CONT TestServeRejectsGarbage3145=== RUN TestSignErrors/http_error3146--- PASS: TestServeRejectsGarbage (0.00s)3147=== PAUSE TestSignErrors/http_error3148=== RUN TestSignErrors/invalid_json3149=== PAUSE TestSignErrors/invalid_json3150=== RUN TestSignErrors/no_prefix3151=== PAUSE TestSignErrors/no_prefix3152=== RUN TestSignErrors/invalid_base643153=== PAUSE TestSignErrors/invalid_base643154=== CONT TestSignErrors/invalid_json3155=== CONT TestSignErrors/no_prefix3156=== CONT TestSignErrors/invalid_base643157=== CONT TestSignErrors/http_error3158--- PASS: TestServe (0.00s)3159--- PASS: TestSign (0.04s)3160--- PASS: TestSignErrors (0.00s)3161 --- PASS: TestSignErrors/no_prefix (0.00s)3162 --- PASS: TestSignErrors/invalid_json (0.04s)3163 --- PASS: TestSignErrors/http_error (0.01s)3164 --- PASS: TestSignErrors/invalid_base64 (0.01s)3165PASS3166Running niks3-hook command tests...3167=== RUN TestServeSecondSignalEndsDrain3168=== PAUSE TestServeSecondSignalEndsDrain3169=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3170=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3171=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3172=== CONT TestServeSecondSignalEndsDrain31732026/11/07 23:34:38 INFO Upload queue status pending=131742026/11/07 23:34:38 INFO Uploading batch count=13175--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3176--- PASS: TestServeSecondSignalEndsDrain (0.32s)3177PASS3178Running rate limiter tests...3179=== RUN TestAdaptiveRateLimiter_ThreadSafety3180=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3181=== CONT TestAdaptiveRateLimiter_ThreadSafety31822026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=7031832026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=4931842026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=34.331852026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=24.00999999999999831862026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=16.80731872026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=11.76489999999999931882026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=8.2354331892026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=5.76480099999999931902026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531912026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531922026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531932026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531942026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531952026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531962026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531972026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531982026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=531992026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532002026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532012026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532022026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532032026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532042026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532052026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532062026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532072026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532082026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532092026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532102026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532112026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532122026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532132026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532142026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532152026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532162026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532172026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532182026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532192026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=6.200463500000001532202026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532212026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532222026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532232026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532242026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532252026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532262026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532272026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532282026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532292026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532302026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532312026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532322026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532332026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532342026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532352026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532362026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532372026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=8.25281691850000432382026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=5.77697184295000332392026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532402026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532412026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532422026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532432026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532442026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532452026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532462026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532472026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532482026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532492026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532502026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532512026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532522026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532532026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532542026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532552026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532562026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532572026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532582026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532592026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532602026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532612026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532622026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532632026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532642026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532652026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532662026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532672026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532682026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532692026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=6.200463500000001532702026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532712026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532722026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532732026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532742026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532752026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532762026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=9.98590847138500632772026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=6.99013592996950432782026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532792026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532802026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=532812026/11/07 23:34:40 WARN Rate limiter backed off name=test rate=53282--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.74s)3283PASS