niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #403
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.21s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestRetryTimeoutOutlastsMaxRetries56=== PAUSE TestRetryTimeoutOutlastsMaxRetries57=== RUN TestShellSplit58=== PAUSE TestShellSplit59=== RUN TestShellSplitErrors60=== PAUSE TestShellSplitErrors61=== RUN TestStreamPushReportsEveryPath62=== PAUSE TestStreamPushReportsEveryPath63=== RUN TestStreamPushBatchesUnderLoad64=== PAUSE TestStreamPushBatchesUnderLoad65=== RUN TestStreamPushIsolatesFailures66=== PAUSE TestStreamPushIsolatesFailures67=== RUN TestStreamPushGivesUpOnDeadServer68=== PAUSE TestStreamPushGivesUpOnDeadServer69=== RUN TestStreamPushRequestLine70=== PAUSE TestStreamPushRequestLine71=== RUN TestStreamPushReportsSignatures72=== PAUSE TestStreamPushReportsSignatures73=== RUN TestStreamPushReportsSkippedPaths74=== PAUSE TestStreamPushReportsSkippedPaths75=== RUN TestClientSignaturesByStorePath76=== PAUSE TestClientSignaturesByStorePath77=== RUN TestStreamPushStopsWhenCanceled78=== PAUSE TestStreamPushStopsWhenCanceled79=== RUN TestSetClientTLS80=== PAUSE TestSetClientTLS81=== RUN TestSetClientTLSDoesNotMutateDefaultTransport82=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport83=== RUN TestSetClientTLSErrors84=== PAUSE TestSetClientTLSErrors85=== RUN TestStaticToken86=== PAUSE TestStaticToken87=== RUN TestFileTokenReadsAndCaches88=== PAUSE TestFileTokenReadsAndCaches89=== RUN TestFileTokenMissing90=== PAUSE TestFileTokenMissing91=== RUN TestFileTokenEmpty92=== PAUSE TestFileTokenEmpty93=== RUN TestScriptTokenNoExpiryRerunsEveryCall94=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall95=== RUN TestScriptTokenCachesUntilRefresh96=== PAUSE TestScriptTokenCachesUntilRefresh97=== RUN TestScriptTokenEmptyToken98=== PAUSE TestScriptTokenEmptyToken99=== RUN TestScriptTokenBadJSON100=== PAUSE TestScriptTokenBadJSON101=== RUN TestScriptTokenScriptFails102=== PAUSE TestScriptTokenScriptFails103=== RUN TestScriptTokenEmptyCommand104=== PAUSE TestScriptTokenEmptyCommand105=== CONT TestDoServerRequestAttachesToken106=== CONT TestScriptTokenScriptFails107=== CONT TestShellSplit108=== CONT TestSetClientTLS109=== CONT TestScriptTokenEmptyCommand110=== CONT TestStreamPushReportsSkippedPaths111=== CONT TestScriptTokenBadJSON112=== CONT TestScriptTokenCachesUntilRefresh113=== CONT TestScriptTokenNoExpiryRerunsEveryCall114=== CONT TestFileTokenEmpty115=== CONT TestFileTokenMissing116=== CONT TestFileTokenReadsAndCaches117=== CONT TestStaticToken118=== CONT TestSetClientTLSErrors119=== CONT TestSetClientTLSDoesNotMutateDefaultTransport120=== CONT TestPartSizeForNAR121=== CONT TestEncodeNixBase32122=== CONT TestDumpPathWriterError123=== CONT TestDumpPathSingleFile124=== CONT TestDumpPathMatchesNix125=== CONT TestUploadMultipart_SupersededByPeer126=== CONT TestStreamPushRequestLine127=== CONT TestStreamPushStopsWhenCanceled128=== CONT TestEncodeNixBase32WithRealHash129--- PASS: TestShellSplit (0.00s)130--- PASS: TestScriptTokenEmptyCommand (0.00s)131--- PASS: TestStreamPushReportsSkippedPaths (0.00s)132=== CONT TestClientSignaturesByStorePath133=== CONT TestScriptTokenEmptyToken134=== CONT TestStreamPushReportsSignatures135--- PASS: TestFileTokenEmpty (0.00s)136--- PASS: TestStaticToken (0.00s)137--- PASS: TestFileTokenMissing (0.00s)138--- PASS: TestStreamPushStopsWhenCanceled (0.00s)139--- PASS: TestEncodeNixBase32WithRealHash (0.00s)140--- PASS: TestClientSignaturesByStorePath (0.00s)141=== CONT TestStreamPushBatchesUnderLoad142=== CONT TestStreamPushGivesUpOnDeadServer143--- PASS: TestFileTokenReadsAndCaches (0.00s)144=== CONT TestDoWithRetry_BodyReplayedViaGetBody145=== RUN TestPartSizeForNAR/zero_stays_at_minimum146=== RUN TestEncodeNixBase32/test_string_hash147=== RUN TestUploadMultipart_SupersededByPeer/exists148=== CONT TestPathInfoCACompatibility149=== CONT TestRetryTimeoutOutlastsMaxRetries150=== CONT TestStreamPushIsolatesFailures151=== RUN TestSetClientTLSErrors/missing_cert_file152=== PAUSE TestSetClientTLSErrors/missing_cert_file153=== RUN TestSetClientTLSErrors/missing_key_file154=== PAUSE TestSetClientTLSErrors/missing_key_file155=== RUN TestSetClientTLSErrors/missing_ca_file1562026/10/09 17:38:07 ERROR Upload failed error=boom count=1157=== PAUSE TestSetClientTLSErrors/missing_ca_file158=== RUN TestSetClientTLSErrors/invalid_ca_file159=== PAUSE TestSetClientTLSErrors/invalid_ca_file160=== RUN TestPathInfoCACompatibility/null_ca_field161--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)162=== PAUSE TestPathInfoCACompatibility/null_ca_field163=== CONT TestRateLimiterFeedback164=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess165=== CONT TestResolveStorePath166=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168=== RUN TestRateLimiterFeedback/429_enables_limiter169=== PAUSE TestRateLimiterFeedback/429_enables_limiter170=== RUN TestRateLimiterFeedback/503_enables_limiter1712026/10/09 17:38:07 WARN Rate limiter enabled after throttle name=server-test rate=5172=== PAUSE TestRateLimiterFeedback/503_enables_limiter173=== RUN TestPartSizeForNAR/small_stays_at_minimum174=== PAUSE TestPartSizeForNAR/small_stays_at_minimum175=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum176=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum177=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts178=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts179=== RUN TestPartSizeForNAR/1_TiB180=== PAUSE TestPartSizeForNAR/1_TiB181=== RUN TestPartSizeForNAR/5_TiB_S3_max_object182=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object183=== RUN TestPartSizeForNAR/capped_at_5_GiB184=== PAUSE TestPartSizeForNAR/capped_at_5_GiB1852026/10/09 17:38:07 ERROR Upload failed error="connection refused" count=201862026/10/09 17:38:07 ERROR Server seems unavailable, giving up on batch untried=17187--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)188=== CONT TestPathInfoHashCompatibility1892026/10/09 17:38:07 ERROR Upload failed error="bad path" count=3190--- PASS: TestStreamPushIsolatesFailures (0.00s)191=== CONT TestParsePathInfoJSONMultiplePaths192--- PASS: TestScriptTokenScriptFails (0.01s)193=== CONT TestParsePathInfoJSON1942026/10/09 17:38:07 ERROR Upload failed error=boom count=1195--- PASS: TestStreamPushReportsSignatures (0.00s)196=== CONT TestGetStorePathHash197=== RUN TestUploadMultipart_SupersededByPeer/missing198=== PAUSE TestUploadMultipart_SupersededByPeer/missing199=== CONT TestShellSplitErrors200--- PASS: TestShellSplitErrors (0.00s)201=== CONT TestConvertHashToNix32202=== RUN TestConvertHashToNix32/SRI_format_to_Nix32203=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32204=== RUN TestConvertHashToNix32/already_Nix32_format205=== PAUSE TestConvertHashToNix32/already_Nix32_format206=== RUN TestConvertHashToNix32/invalid_format207=== PAUSE TestConvertHashToNix32/invalid_format208=== RUN TestPathInfoCACompatibility/old_string_format_-_text209=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text210=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive211=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== RUN TestPathInfoCACompatibility/new_structured_format_-_text213=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text214=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method216=== CONT TestStreamPushReportsEveryPath217=== PAUSE TestEncodeNixBase32/test_string_hash218=== RUN TestEncodeNixBase32/empty_input219=== PAUSE TestEncodeNixBase32/empty_input220=== CONT TestCaseHackSuffix221=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter222=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)223=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths224=== RUN TestParsePathInfoJSON/Nix_format225=== RUN TestGetStorePathHash/valid_store_path226--- PASS: TestResolveStorePath (0.01s)227=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica228=== RUN TestSetClientTLS/rejects_connection_without_client_cert229=== CONT TestFilterOversizedClosures230=== RUN TestFilterOversizedClosures/no_limit_keeps_everything231=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything232=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped233=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped234--- PASS: TestStreamPushReportsEveryPath (0.00s)235=== RUN TestFilterOversizedClosures/all_closures_skipped236=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun237=== CONT TestUploadMultipart_PartsInParallel238=== PAUSE TestFilterOversizedClosures/all_closures_skipped239=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert240=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA241=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA242=== RUN TestSetClientTLS/preserves_debug_logging_transport243=== PAUSE TestSetClientTLS/preserves_debug_logging_transport244=== CONT TestRegisterUploadedObjectReusesConnections2452026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:634882462026/10/09 17:38:07 WARN Rate limiter enabled after throttle name=server-test rate=52472026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:634872482026/10/09 17:38:07 INFO Garbage collection started2492026/10/09 17:38:07 INFO Garbage collection started2502026/10/09 17:38:07 WARN Rate limiter backed off name=server-test rate=52512026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:634872522026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:634882532026/10/09 17:38:07 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0254=== CONT TestSetClientTLSErrors/missing_cert_file255=== CONT TestPartSizeForNAR/1_TiB256=== CONT TestPartSizeForNAR/capped_at_5_GiB257=== CONT TestPartSizeForNAR/5_TiB_S3_max_object258=== CONT TestPartSizeForNAR/small_stays_at_minimum259=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts260=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum261=== CONT TestUploadMultipart_SupersededByPeer/exists262--- PASS: TestScriptTokenBadJSON (0.02s)263--- PASS: TestDoServerRequestAttachesToken (0.02s)264=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter265=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter266=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter267--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)268--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)269=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)270=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon271=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon272=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI273=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI274=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512276=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths277=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths278=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths279=== CONT TestConvertHashToNix32/SRI_format_to_Nix32280=== CONT TestPathInfoCACompatibility/null_ca_field2812026/10/09 17:38:07 WARN Garbage collection finished on another replica. Its statistics are not available here282=== CONT TestSetClientTLSErrors/missing_ca_file283--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)284=== CONT TestConvertHashToNix32/invalid_format285=== PAUSE TestParsePathInfoJSON/Nix_format286=== RUN TestParsePathInfoJSON/Lix_format287=== PAUSE TestParsePathInfoJSON/Lix_format288=== RUN TestParsePathInfoJSON/empty_input289=== PAUSE TestParsePathInfoJSON/empty_input290=== RUN TestParsePathInfoJSON/whitespace_only291=== PAUSE TestParsePathInfoJSON/whitespace_only292=== CONT TestUploadMultipart_SupersededByPeer/missing293=== PAUSE TestGetStorePathHash/valid_store_path294=== CONT TestSetClientTLSErrors/missing_key_file295=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== CONT TestPartSizeForNAR/zero_stays_at_minimum297--- PASS: TestPartSizeForNAR (0.01s)298 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)299 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)300 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)301 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)302 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)303 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)304 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)305=== RUN TestParsePathInfoJSON/invalid_JSON306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== CONT TestPathInfoCACompatibility/old_string_format_-_text308=== CONT TestEncodeNixBase32/empty_input309=== CONT TestFilterOversizedClosures/no_limit_keeps_everything310=== PAUSE TestParsePathInfoJSON/invalid_JSON311=== CONT TestSetClientTLS/rejects_connection_without_client_cert312=== CONT TestSetClientTLS/preserves_debug_logging_transport313=== RUN TestGetStorePathHash/basename_without_hyphen_should_error314=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error315=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error316=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error317=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error318=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error319=== CONT TestPathInfoCACompatibility/new_structured_format_-_text320=== CONT TestFilterOversizedClosures/all_closures_skipped3212026/10/09 17:38:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50322=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA323=== CONT TestSetClientTLSErrors/invalid_ca_file324=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3252026/10/09 17:38:07 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000326--- PASS: TestFilterOversizedClosures (0.00s)327 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)328 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)329 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)330=== CONT TestRateLimiterFeedback/429_enables_limiter331--- PASS: TestSetClientTLSErrors (0.00s)332 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)336=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3372026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:63488338--- PASS: TestStreamPushRequestLine (0.03s)339=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter340--- PASS: TestPathInfoCACompatibility (0.01s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)343 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)345 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)346=== CONT TestConvertHashToNix32/already_Nix32_format347--- PASS: TestConvertHashToNix32 (0.00s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)350 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)351=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)352=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths353=== CONT TestRateLimiterFeedback/503_enables_limiter354=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths355--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)356 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)357 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)358=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI359=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512360=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon361--- PASS: TestPathInfoHashCompatibility (0.01s)362 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)363 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)365 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)366=== CONT TestGetStorePathHash/valid_store_path367=== CONT TestGetStorePathHash/basename_without_hyphen_should_error368=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error369=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error370--- PASS: TestGetStorePathHash (0.02s)371 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)372 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)373 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)3752026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:634883762026/10/09 17:38:07 WARN Rate limiter enabled after throttle name=server-test rate=53772026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:63574378=== CONT TestParsePathInfoJSON/Nix_format379=== CONT TestEncodeNixBase32/test_string_hash380--- PASS: TestEncodeNixBase32 (0.01s)381 --- PASS: TestEncodeNixBase32/empty_input (0.00s)382 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)383=== CONT TestParsePathInfoJSON/invalid_JSON384=== CONT TestParsePathInfoJSON/whitespace_only385=== CONT TestParsePathInfoJSON/empty_input386=== CONT TestParsePathInfoJSON/Lix_format3872026/10/09 17:38:07 WARN Rate limiter enabled after throttle name=server-test rate=53882026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:63564389--- PASS: TestParsePathInfoJSON (0.02s)390 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)391 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)392 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)393 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)394 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)3952026/10/09 17:38:07 WARN Rate limiter backed off name=server-test rate=53962026/10/09 17:38:07 WARN Rate limiter backed off name=server-test rate=5397--- PASS: TestRateLimiterFeedback (0.02s)398 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)399 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)400 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)401 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)402--- PASS: TestScriptTokenEmptyToken (0.03s)4032026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:634884042026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:63488405--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)406 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)407 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)4082026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:634884092026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:634884102026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:634884112026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:634884122026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:634884132026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:634884142026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:63488415--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4162026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:634884172026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:634884182026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:634884192026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:63488420--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)4212026/10/09 17:38:07 http: TLS handshake error from 127.0.0.1:63577: remote error: tls: bad certificate422--- PASS: TestSetClientTLS (0.02s)423 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)424 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)425 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4262026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:634884272026/10/09 17:38:07 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:63488428--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)429--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)430--- PASS: TestStreamPushBatchesUnderLoad (0.10s)431--- PASS: TestDumpPathWriterError (0.12s)432--- PASS: TestDumpPathSingleFile (0.19s)433--- PASS: TestCaseHackSuffix (0.22s)434--- PASS: TestDumpPathMatchesNix (0.28s)435--- PASS: TestUploadMultipart_PartsInParallel (0.63s)436--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)437PASS438Running server tests...439The files belonging to this database system will be owned by user "_tribuchetbld7".440This user must also own the server process.441442The database cluster will be initialized with locale "C".443The default database encoding has accordingly been set to "SQL_ASCII".444The default text search configuration will be set to "english".445446Data page checksums are enabled.447448creating directory /private/var/tb/7/scratch/294f6b975c717bac/build/postgres3302399558/data ... ok449creating subdirectories ... ok450selecting dynamic shared memory implementation ... posix451selecting default "max_connections" ... 100452selecting default "shared_buffers" ... 128MB453selecting default time zone ... UTC454creating configuration files ... ok455running bootstrap script ... ok456performing post-bootstrap initialization ... ok457syncing data to disk ... ok458459initdb: warning: enabling "trust" authentication for local connections460initdb: 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.461462Success. You can now start the database server using:463464 pg_ctl -D /private/var/tb/7/scratch/294f6b975c717bac/build/postgres3302399558/data -l logfile start465466/private/var/tb/7/scratch/294f6b975c717bac/build/postgres3302399558:5432 - no response4672026-10-09 17:38:09.116 UTC [59080] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4682026-10-09 17:38:09.116 UTC [59080] LOG: listening on Unix socket "/private/var/tb/7/scratch/294f6b975c717bac/build/postgres3302399558/.s.PGSQL.5432"4692026-10-09 17:38:09.123 UTC [59087] LOG: database system was shut down at 2026-10-09 17:38:09 UTC4702026-10-09 17:38:09.128 UTC [59080] LOG: database system is ready to accept connections471/private/var/tb/7/scratch/294f6b975c717bac/build/postgres3302399558:5432 - accepting connections472{"timestamp":"2026-10-09T17:38:09.373545Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"13139329-44d3-40b3-9a44-53907c100105","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":12,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}473{"timestamp":"2026-10-09T17:38:09.481253Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"20d59810-c128-4b0d-8c52-46181bef0044","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}474=== RUN TestFarmLeadRoutes475=== PAUSE TestFarmLeadRoutes476=== RUN TestService_AuthMiddleware477=== PAUSE TestService_AuthMiddleware478=== RUN TestService_AuthMiddleware_MTLSProxyHeader479=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader480=== RUN TestService_AuthMiddleware_MTLSBoundSubjects481=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects482=== RUN TestService_ReadAuthMiddleware483=== PAUSE TestService_ReadAuthMiddleware484=== RUN TestService_AuthMiddleware_OIDC485=== PAUSE TestService_AuthMiddleware_OIDC486=== RUN TestService_RequireScope_OIDC487=== PAUSE TestService_RequireScope_OIDC488=== RUN TestService_ReadScope_PublicByDefault489=== PAUSE TestService_ReadScope_PublicByDefault490=== RUN TestCacheConfigHandler491=== PAUSE TestCacheConfigHandler492=== RUN TestCacheStatsHandler493=== PAUSE TestCacheStatsHandler494=== RUN TestClientCADerivations495=== PAUSE TestClientCADerivations496=== RUN TestClientErrorHandling497=== PAUSE TestClientErrorHandling498=== RUN TestClientIntegration499=== PAUSE TestClientIntegration500=== RUN TestClientMultipleUploads501=== PAUSE TestClientMultipleUploads502=== RUN TestClientWithDependencies503=== PAUSE TestClientWithDependencies504=== RUN TestClientSharedPathCommittedMidPush505=== PAUSE TestClientSharedPathCommittedMidPush506=== RUN TestPinProtectsFromGC507=== PAUSE TestPinProtectsFromGC508=== RUN TestClientPushesUseOnePush509=== PAUSE TestClientPushesUseOnePush510=== RUN TestClientFallsBackToClosures511=== PAUSE TestClientFallsBackToClosures512=== RUN TestDeleteClosuresRacingPins513=== PAUSE TestDeleteClosuresRacingPins514=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock515=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock516=== RUN TestResolveDBConnectionString517=== PAUSE TestResolveDBConnectionString518=== RUN TestConnectWaitsForAPeerMigration519=== PAUSE TestConnectWaitsForAPeerMigration520=== RUN TestLeadElectsOneAndHandsOver521=== PAUSE TestLeadElectsOneAndHandsOver522=== RUN TestLeadScopedToFarm523=== PAUSE TestLeadScopedToFarm524=== RUN TestLeadIncumbentWinsAfterRestart5252026/10/09 17:38:09 INFO lead: acquired remote=192.0.2.1:12345262026/10/09 17:38:10 INFO lead: released remote=192.0.2.1:12345272026/10/09 17:38:10 INFO lead: acquired remote=192.0.2.1:12345282026/10/09 17:38:11 INFO lead: released remote=192.0.2.1:1234529--- PASS: TestLeadIncumbentWinsAfterRestart (2.09s)530=== RUN TestLeadIncumbentAnnouncesAtOnce531=== PAUSE TestLeadIncumbentAnnouncesAtOnce532=== RUN TestLeadEndsOnShutdown533=== PAUSE TestLeadEndsOnShutdown534=== RUN TestLeadEndsWhenItsConnectionHangs5352026/10/09 17:38:11 INFO lead: acquired remote=192.0.2.1:12345362026-10-09 17:38:13.249 UTC [59176] FATAL: terminating connection due to administrator command5372026/10/09 17:38:13 INFO lead: acquired remote=192.0.2.1:12345382026/10/09 17:38:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5392026/10/09 17:38:14 INFO lead: released remote=192.0.2.1:12345402026/10/09 17:38:14 INFO lead: released remote=192.0.2.1:1234541--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)542=== RUN TestGCAdvisoryLockBlocksConcurrentRun543=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun544=== RUN TestGCBugBareHashReferences545=== PAUSE TestGCBugBareHashReferences546=== RUN TestGCMetrics547=== PAUSE TestGCMetrics548=== RUN TestPushDedupSurvivesConcurrentGC549=== PAUSE TestPushDedupSurvivesConcurrentGC550=== RUN TestDeduplicatedObjectsRecordedAsPending551=== PAUSE TestDeduplicatedObjectsRecordedAsPending552=== RUN TestGCSweepSkipsPendingObjects553=== PAUSE TestGCSweepSkipsPendingObjects554=== RUN TestTombstonedObjectOfferedWithoutWaiting555=== PAUSE TestTombstonedObjectOfferedWithoutWaiting556=== RUN TestGCSweepDeliversEachKeyOnce557=== PAUSE TestGCSweepDeliversEachKeyOnce558=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection559=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection560=== RUN TestForceGCDuringPushOffersSweptObject561=== PAUSE TestForceGCDuringPushOffersSweptObject562=== RUN TestFailedS3DeleteKeepsTombstone563=== PAUSE TestFailedS3DeleteKeepsTombstone564=== RUN TestSweepSkipsRowsLockedByPush565=== PAUSE TestSweepSkipsRowsLockedByPush566=== RUN TestRegisterCompletedObjectNeedsPendingRow567=== PAUSE TestRegisterCompletedObjectNeedsPendingRow568=== RUN TestGetExistingObjectsLocksRows569=== PAUSE TestGetExistingObjectsLocksRows570=== RUN TestSweepRechecksPendingAfterLocking571=== PAUSE TestSweepRechecksPendingAfterLocking572=== RUN TestPushWaitsForSweepHoldingRow573=== PAUSE TestPushWaitsForSweepHoldingRow574=== RUN TestCommitRacingPendingCleanupKeepsObjects575=== PAUSE TestCommitRacingPendingCleanupKeepsObjects576=== RUN TestGCEndsOnShutdown577=== PAUSE TestGCEndsOnShutdown578=== RUN TestGCTaskStore_StartNew579=== PAUSE TestGCTaskStore_StartNew580=== RUN TestGCTaskStore_DeduplicateSameParams581=== PAUSE TestGCTaskStore_DeduplicateSameParams582=== RUN TestGCTaskStore_ConflictDifferentParams583=== PAUSE TestGCTaskStore_ConflictDifferentParams584=== RUN TestGCTaskStore_GetEmpty585=== PAUSE TestGCTaskStore_GetEmpty586=== RUN TestGCTaskStore_GetReturnsLatest587=== PAUSE TestGCTaskStore_GetReturnsLatest588=== RUN TestGCTaskStore_CompletedAllowsNewTask589=== PAUSE TestGCTaskStore_CompletedAllowsNewTask590=== RUN TestGCTaskStore_PhaseUpdates591=== PAUSE TestGCTaskStore_PhaseUpdates592=== RUN TestGCTaskStore_Fail593=== PAUSE TestGCTaskStore_Fail594=== RUN TestGracefulShutdownDrainsInflight595=== PAUSE TestGracefulShutdownDrainsInflight596=== RUN TestService_healthCheckHandler597=== PAUSE TestService_healthCheckHandler598=== RUN TestService_readinessHandler599=== PAUSE TestService_readinessHandler600=== RUN TestGenerateLandingPage601=== PAUSE TestGenerateLandingPage602=== RUN TestCacheConfigHandlerMaxNarSize603=== PAUSE TestCacheConfigHandlerMaxNarSize604=== RUN TestCreatePendingClosureRejectsOversizedNAR605=== PAUSE TestCreatePendingClosureRejectsOversizedNAR606=== RUN TestNARDeduplicationMetadataUploadBug607=== PAUSE TestNARDeduplicationMetadataUploadBug608=== RUN TestMetricsInventory609=== PAUSE TestMetricsInventory610=== RUN TestMetricsCommit611=== PAUSE TestMetricsCommit612=== RUN TestService_NativeMTLS613=== PAUSE TestService_NativeMTLS614=== RUN TestServerTLSConfig615=== PAUSE TestServerTLSConfig616=== RUN TestMultipartCleanup617=== PAUSE TestMultipartCleanup618=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded619=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded620=== RUN TestPendingCleanupUsesOneCutoff621=== PAUSE TestPendingCleanupUsesOneCutoff622=== RUN TestObjectStatsTrigger623=== PAUSE TestObjectStatsTrigger624=== RUN TestObjectStatsLargeCommit625=== PAUSE TestObjectStatsLargeCommit626=== RUN TestOrphanedObjectsGC627=== PAUSE TestOrphanedObjectsGC628=== RUN TestOrphanedObjectsGCStressTest629=== PAUSE TestOrphanedObjectsGCStressTest630=== RUN TestCreatePin_ReservedPins631=== PAUSE TestCreatePin_ReservedPins632=== RUN TestPresentReportsOnlyClosureRoots633=== PAUSE TestPresentReportsOnlyClosureRoots634=== RUN TestPresentRefreshesOnlyStaleClosures635=== PAUSE TestPresentRefreshesOnlyStaleClosures636=== RUN TestPresentNotReportedWhileGCDeletesClosure637=== PAUSE TestPresentNotReportedWhileGCDeletesClosure638=== RUN TestParseSingleRange639=== PAUSE TestParseSingleRange640=== RUN TestProxyHeadersOnlyTrustedOnSocket6412026/10/09 17:38:14 INFO Starting HTTP server address=127.0.0.1:636016422026/10/09 17:38:14 INFO Starting HTTP server address=proxy.sock6432026/10/09 17:38:14 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6442026/10/09 17:38:14 INFO Shutdown signal received, draining in-flight requests timeout=10s645--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)646=== RUN TestIsValidCachePath647=== PAUSE TestIsValidCachePath648=== RUN TestReadProxyNarinfo649=== PAUSE TestReadProxyNarinfo650=== RUN TestReadProxyNarinfoAlreadyDecompressed651=== PAUSE TestReadProxyNarinfoAlreadyDecompressed652=== RUN TestReadProxyContentNegotiation653=== PAUSE TestReadProxyContentNegotiation654=== RUN TestReadProxyNarStreaming655=== PAUSE TestReadProxyNarStreaming656=== RUN TestReadProxy404657=== PAUSE TestReadProxy404658=== RUN TestReadProxyInvalidPath659=== PAUSE TestReadProxyInvalidPath660=== RUN TestReadProxyHead661=== PAUSE TestReadProxyHead662=== RUN TestReadProxyOutlastsServerWriteTimeout663=== PAUSE TestReadProxyOutlastsServerWriteTimeout664=== RUN TestReadProxyConditionalGet665=== PAUSE TestReadProxyConditionalGet666=== RUN TestReadProxyRootRedirectsToIndexHTML667=== PAUSE TestReadProxyRootRedirectsToIndexHTML668=== RUN TestReadProxyDisabled669=== PAUSE TestReadProxyDisabled670=== RUN TestReadRedirectNar671=== PAUSE TestReadRedirectNar672=== RUN TestReadRedirectKeepsNarinfoProxied673=== PAUSE TestReadRedirectKeepsNarinfoProxied674=== RUN TestReadProxyRangeRequest675=== PAUSE TestReadProxyRangeRequest676=== RUN TestReadRedirectUsesPublicS3URL677=== PAUSE TestReadRedirectUsesPublicS3URL678=== RUN TestPush_OverlappingRootsStoreOneRowPerKey679=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey680=== RUN TestPush_CompleteCommitsEveryRoot681=== PAUSE TestPush_CompleteCommitsEveryRoot682=== RUN TestPush_RepeatedRootCommitsOnce683=== PAUSE TestPush_RepeatedRootCommitsOnce684=== RUN TestPush_CompleteWaitsForCleanupOfThePush685=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush686=== RUN TestPush_RootsAreLockedInByteOrder687=== PAUSE TestPush_RootsAreLockedInByteOrder688=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit689=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit690=== RUN TestPush_RejectsBadRequests691=== PAUSE TestPush_RejectsBadRequests692=== RUN TestPush_SignsNarinfosOfItsPendingObjects693=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects694=== RUN TestRedundantMultipartUpload695=== PAUSE TestRedundantMultipartUpload696=== RUN TestCompleteMultipartUpload_ErrorButObjectExists697=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists698=== RUN TestCompletedNarNotReofferedAcrossClosures699=== PAUSE TestCompletedNarNotReofferedAcrossClosures700=== RUN TestPresignedUploadRegisteredBeforeCommit701=== PAUSE TestPresignedUploadRegisteredBeforeCommit702=== RUN TestService_Rustfstest703=== PAUSE TestService_Rustfstest704=== RUN TestParseSize705=== PAUSE TestParseSize706=== RUN TestSkippedUploadsHandler707=== PAUSE TestSkippedUploadsHandler708=== RUN TestSystemdListenerNotActivated709--- PASS: TestSystemdListenerNotActivated (0.00s)710=== RUN TestWatchdogBeatsWhenHealthy711--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)712=== RUN TestWatchdogSkipsWhenUnhealthy7132026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7142026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7152026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7162026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7172026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7182026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7192026/10/09 17:38:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7202026/10/09 17:38:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7212026/10/09 17:38:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7222026/10/09 17:38:15 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"723--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)724=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle725=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle726=== RUN TestProxyWriteTimeout727=== PAUSE TestProxyWriteTimeout728=== RUN TestPendingClosureWriteTimeout729=== PAUSE TestPendingClosureWriteTimeout730=== RUN TestIsValidUploadKey731=== PAUSE TestIsValidUploadKey732=== RUN TestUploadHandlersRejectInvalidKeys733=== PAUSE TestUploadHandlersRejectInvalidKeys734=== RUN TestUploadHandlersRejectOversizedBody735=== PAUSE TestUploadHandlersRejectOversizedBody736=== RUN TestService_cleanupPendingClosuresHandler737=== PAUSE TestService_cleanupPendingClosuresHandler738=== RUN TestService_createPendingClosureHandler739=== PAUSE TestService_createPendingClosureHandler740=== RUN TestService_verifyS3Integrity741=== PAUSE TestService_verifyS3Integrity742=== RUN TestCompleteMultipartUnregistered743=== PAUSE TestCompleteMultipartUnregistered744=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT745=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT746=== CONT TestCompleteMultipartUpload_ErrorButObjectExists747=== CONT TestPush_SignsNarinfosOfItsPendingObjects748=== CONT TestFailedS3DeleteKeepsTombstone749=== CONT TestParseSingleRange750=== RUN TestParseSingleRange/none751=== PAUSE TestParseSingleRange/none752=== RUN TestParseSingleRange/unknown_unit753=== PAUSE TestParseSingleRange/unknown_unit754=== RUN TestParseSingleRange/multi-range_ignored755=== PAUSE TestParseSingleRange/multi-range_ignored756=== RUN TestParseSingleRange/malformed_no_dash757=== PAUSE TestParseSingleRange/malformed_no_dash758=== RUN TestParseSingleRange/malformed_both_empty759=== CONT TestFarmLeadRoutes760=== CONT TestGCTaskStore_CompletedAllowsNewTask761--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)762=== CONT TestPush_CompleteWaitsForCleanupOfThePush763=== CONT TestRedundantMultipartUpload764=== RUN TestFarmLeadRoutes//api/farm/lead765=== PAUSE TestFarmLeadRoutes//api/farm/lead766=== RUN TestFarmLeadRoutes//api/farm/lead/build-x86767=== CONT TestGCTaskStore_GetReturnsLatest768--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)769=== CONT TestGCTaskStore_GetEmpty770--- PASS: TestGCTaskStore_GetEmpty (0.00s)771=== CONT TestGCTaskStore_ConflictDifferentParams772--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)773=== CONT TestGCTaskStore_DeduplicateSameParams774=== CONT TestGCSweepDeliversEachKeyOnce775=== CONT TestGCTaskStore_StartNew776=== CONT TestTombstonedObjectOfferedWithoutWaiting777--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)778--- PASS: TestGCTaskStore_StartNew (0.00s)779=== CONT TestCommitRacingPendingCleanupKeepsObjects780=== CONT TestGCEndsOnShutdown781=== CONT TestPushWaitsForSweepHoldingRow782=== CONT TestGetExistingObjectsLocksRows783=== CONT TestRegisterCompletedObjectNeedsPendingRow784=== CONT TestSweepSkipsRowsLockedByPush785=== PAUSE TestParseSingleRange/malformed_both_empty786=== RUN TestParseSingleRange/malformed_end_before_start787=== CONT TestPush_RejectsBadRequests788=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit789=== CONT TestPush_RootsAreLockedInByteOrder790=== CONT TestForceGCDuringPushOffersSweptObject791=== CONT TestGCTaskStore_PhaseUpdates792=== PAUSE TestFarmLeadRoutes//api/farm/lead/build-x86793=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows794=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection795=== CONT TestPush_OverlappingRootsStoreOneRowPerKey796--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)797=== CONT TestGCSweepSkipsPendingObjects798=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows799=== CONT TestPush_CompleteCommitsEveryRoot800=== RUN TestGCEndsOnShutdown/before_the_run801=== PAUSE TestGCEndsOnShutdown/before_the_run802=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete803=== CONT TestSweepRechecksPendingAfterLocking804=== PAUSE TestParseSingleRange/malformed_end_before_start805=== RUN TestParseSingleRange/closed806=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete807=== PAUSE TestParseSingleRange/closed808=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check809=== RUN TestParseSingleRange/open-ended810=== PAUSE TestParseSingleRange/open-ended811=== RUN TestParseSingleRange/end_clamped_to_size812=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check813=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark814=== CONT TestPush_RepeatedRootCommitsOnce815=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark816=== CONT TestDeduplicatedObjectsRecordedAsPending817=== PAUSE TestParseSingleRange/end_clamped_to_size818=== RUN TestParseSingleRange/suffix819=== CONT TestReadRedirectUsesPublicS3URL820=== PAUSE TestParseSingleRange/suffix821=== RUN TestParseSingleRange/suffix_exceeds_size822=== PAUSE TestParseSingleRange/suffix_exceeds_size823=== RUN TestParseSingleRange/single_byte824=== PAUSE TestParseSingleRange/single_byte825=== RUN TestParseSingleRange/start_past_EOF826=== PAUSE TestParseSingleRange/start_past_EOF827=== RUN TestParseSingleRange/start_far_past_EOF828=== PAUSE TestParseSingleRange/start_far_past_EOF829=== CONT TestReadProxyRangeRequest8302026/10/09 17:38:16 INFO Received uploads request method=POST path=/api/pending_closures8312026/10/09 17:38:16 INFO Received push request method=POST path=/api/pushes8322026/10/09 17:38:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8332026/10/09 17:38:16 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLjYxYjg3ZDlkLWJiYzgtNDhmYS1iMmZiLWEyNzJjYzQ2OGRkOHgxNzkxNTY3NDk2MzM4NTU0MDAw8342026/10/09 17:38:16 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLjYxYjg3ZDlkLWJiYzgtNDhmYS1iMmZiLWEyNzJjYzQ2OGRkOHgxNzkxNTY3NDk2MzM4NTU0MDAw parts=1835--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.71s)836=== CONT TestReadRedirectKeepsNarinfoProxied8372026-10-09 17:38:17.017 UTC [59317] ERROR: Push does not exist: id=18382026-10-09 17:38:17.017 UTC [59317] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE8392026-10-09 17:38:17.017 UTC [59317] STATEMENT: SELECT commit_push($1)840--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.96s)841--- PASS: TestReadProxyRangeRequest (1.96s)842=== CONT TestReadRedirectNar843=== CONT TestReadProxyDisabled844=== RUN TestPush_RejectsBadRequests/no_roots845=== PAUSE TestPush_RejectsBadRequests/no_roots846=== RUN TestPush_RejectsBadRequests/no_objects847=== PAUSE TestPush_RejectsBadRequests/no_objects848=== RUN TestPush_RejectsBadRequests/bad_root849=== PAUSE TestPush_RejectsBadRequests/bad_root850=== RUN TestPush_RejectsBadRequests/root_not_in_objects851=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects852=== CONT TestPushDedupSurvivesConcurrentGC8532026/10/09 17:38:17 INFO Received uploads request method=POST path=/api/pending_closures8542026/10/09 17:38:17 INFO Aborted multipart uploads count=0 kept=08552026/10/09 17:38:17 WARN Force mode enabled - objects will be deleted immediately without grace period8562026/10/09 17:38:17 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8572026/10/09 17:38:17 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."858--- PASS: TestFailedS3DeleteKeepsTombstone (2.77s)859=== CONT TestReadProxyRootRedirectsToIndexHTML8602026/10/09 17:38:17 INFO Received push request method=POST path=/api/pushes8612026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8622026/10/09 17:38:17 INFO Signed narinfos id=1 count=18632026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8642026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8652026/10/09 17:38:17 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8662026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8672026/10/09 17:38:17 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8682026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8692026/10/09 17:38:17 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18702026/10/09 17:38:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8712026/10/09 17:38:17 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo872--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.93s)873=== CONT TestGCMetrics8742026/10/09 17:38:18 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/09 17:38:18 INFO Received uploads request method=POST path=/api/pending_closures8762026/10/09 17:38:18 INFO Aborted multipart uploads count=0 kept=08772026/10/09 17:38:18 WARN Force mode enabled - objects will be deleted immediately without grace period8782026/10/09 17:38: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=08792026/10/09 17:38:18 INFO Vacuumed table table=pending_closures8802026/10/09 17:38:18 INFO Vacuumed table table=pending_objects8812026/10/09 17:38:18 INFO Vacuumed table table=multipart_uploads8822026/10/09 17:38:18 INFO Vacuumed table table=closures8832026/10/09 17:38:18 INFO Vacuumed table table=objects884--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.55s)885=== CONT TestReadProxyConditionalGet8862026/10/09 17:38:18 INFO Received uploads request method=POST path=/api/pending_closures887--- PASS: TestTombstonedObjectOfferedWithoutWaiting (3.67s)888=== CONT TestReadProxyOutlastsServerWriteTimeout8892026/10/09 17:38:19 INFO Aborted multipart uploads count=0 kept=08902026/10/09 17:38:19 WARN Force mode enabled - objects will be deleted immediately without grace period8912026/10/09 17:38:19 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=08922026/10/09 17:38:19 INFO Vacuumed table table=pending_closures8932026/10/09 17:38:19 INFO Vacuumed table table=pending_objects8942026/10/09 17:38:19 INFO Vacuumed table table=multipart_uploads8952026/10/09 17:38:19 INFO Vacuumed table table=closures8962026/10/09 17:38:19 INFO Vacuumed table table=objects897--- PASS: TestGCSweepDeliversEachKeyOnce (4.21s)898=== CONT TestGCBugBareHashReferences8992026/10/09 17:38:19 INFO Received uploads request method=POST path=/api/pending_closures900--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (4.50s)901=== CONT TestGCAdvisoryLockBlocksConcurrentRun9022026/10/09 17:38:19 INFO Aborted multipart uploads count=0 kept=09032026/10/09 17:38:19 WARN Force mode enabled - objects will be deleted immediately without grace period9042026/10/09 17:38:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09052026/10/09 17:38:19 INFO Vacuumed table table=pending_closures9062026/10/09 17:38:19 INFO Vacuumed table table=pending_objects9072026/10/09 17:38:19 INFO Vacuumed table table=multipart_uploads9082026/10/09 17:38:19 INFO Vacuumed table table=closures9092026/10/09 17:38:19 INFO Vacuumed table table=objects9102026/10/09 17:38:19 INFO Received push request method=POST path=/api/pushes911--- PASS: TestSweepRechecksPendingAfterLocking (4.82s)912=== CONT TestReadProxyHead9132026/10/09 17:38:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9142026-10-09 17:38:20.046 UTC [59378] ERROR: could not obtain lock on row in relation "closures"9152026-10-09 17:38:20.046 UTC [59378] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9162026-10-09 17:38:20.053 UTC [59378] ERROR: could not obtain lock on row in relation "closures"9172026-10-09 17:38:20.053 UTC [59378] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9182026/10/09 17:38:20 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLmNlYjIwNjg3LWFjNWYtNDQ4Zi1hNjk2LWY4MjdlMTdmYzNlMHgxNzkxNTY3NDk4MTI4NjA3MDAw parts=129192026-10-09 17:38:20.054 UTC [59378] ERROR: could not obtain lock on row in relation "closures"9202026-10-09 17:38:20.054 UTC [59378] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9212026/10/09 17:38:20 INFO Received uploads request method=POST path=/api/pending_closures9222026-10-09 17:38:20.061 UTC [59378] ERROR: could not obtain lock on row in relation "closures"9232026-10-09 17:38:20.061 UTC [59378] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9242026-10-09 17:38:20.062 UTC [59378] ERROR: could not obtain lock on row in relation "closures"9252026-10-09 17:38:20.062 UTC [59378] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT926--- PASS: TestPush_RootsAreLockedInByteOrder (5.03s)927=== CONT TestLeadEndsOnShutdown9282026/10/09 17:38:20 INFO Received uploads request method=POST path=/api/pending_closures9292026/10/09 17:38:20 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/09 17:38:20 INFO Aborted multipart uploads count=0 kept=09312026/10/09 17:38:20 WARN Force mode enabled - objects will be deleted immediately without grace period9322026/10/09 17:38:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09332026/10/09 17:38:20 INFO Vacuumed table table=pending_closures9342026/10/09 17:38:20 INFO Vacuumed table table=pending_objects9352026/10/09 17:38:20 INFO Vacuumed table table=multipart_uploads9362026/10/09 17:38:20 INFO Vacuumed table table=closures9372026/10/09 17:38:20 INFO Vacuumed table table=objects9382026/10/09 17:38:20 INFO Aborted multipart uploads count=0 kept=09392026/10/09 17:38:20 WARN Force mode enabled - objects will be deleted immediately without grace period9402026/10/09 17:38:20 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=09412026/10/09 17:38:20 INFO Vacuumed table table=pending_closures9422026/10/09 17:38:20 INFO Vacuumed table table=pending_objects9432026/10/09 17:38:20 INFO Vacuumed table table=multipart_uploads9442026/10/09 17:38:20 INFO Vacuumed table table=closures9452026/10/09 17:38:20 INFO Vacuumed table table=objects946--- PASS: TestPushWaitsForSweepHoldingRow (5.73s)947--- PASS: TestSweepSkipsRowsLockedByPush (5.73s)948=== CONT TestReadProxyInvalidPath949=== CONT TestLeadIncumbentAnnouncesAtOnce950--- PASS: TestGetExistingObjectsLocksRows (5.84s)951=== CONT TestReadProxy4049522026/10/09 17:38:21 INFO Received push request method=POST path=/api/pushes9532026/10/09 17:38:21 INFO Received complete push request method=POST path=/api/pushes/1/complete9542026/10/09 17:38:21 INFO Completed push id=1 objects=6 duration=43.084875ms955--- PASS: TestPush_CompleteCommitsEveryRoot (6.26s)956=== CONT TestReadProxyNarStreaming957--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.42s)958=== CONT TestReadProxyContentNegotiation9592026/10/09 17:38:21 INFO Received push request method=POST path=/api/pushes9602026/10/09 17:38:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9612026/10/09 17:38:21 INFO Received complete push request method=POST path=/api/pushes/1/complete9622026/10/09 17:38:21 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLjgyMjM4YWNmLWM4MzYtNDU5MC04OWMwLThhZDgzM2QyNGRlY3gxNzkxNTY3NTAwMTE3NjMwMDAw error="Get \"http://127.0.0.1:1/bucket10/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9632026/10/09 17:38:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLmIzN2YyZDIwLTI3ZGUtNGY5MS05Y2Y1LWIyM2YyYzE0ZTNmN3gxNzkxNTY3NTAwMDYzODIxMDAw parts=129642026/10/09 17:38:21 INFO Received cleanup request method=DELETE path=/api/pending_closures9652026/10/09 17:38:22 INFO Completed push id=1 objects=4 duration=92.900584ms966--- PASS: TestPush_RepeatedRootCommitsOnce (6.95s)967=== CONT TestReadProxyNarinfoAlreadyDecompressed9682026/10/09 17:38:22 INFO Aborted multipart uploads count=1 kept=0969--- PASS: TestRedundantMultipartUpload (6.99s)970=== CONT TestReadProxyNarinfo9712026/10/09 17:38:22 INFO Received push request method=POST path=/api/pushes9722026/10/09 17:38:22 INFO Received complete push request method=POST path=/api/pushes/1/complete9732026/10/09 17:38:22 INFO Completed push id=1 objects=4 duration=29.252167ms9742026/10/09 17:38:22 INFO Received push request method=POST path=/api/pushes9752026/10/09 17:38:22 INFO Aborted multipart uploads count=0 kept=09762026/10/09 17:38:22 WARN Force mode enabled - objects will be deleted immediately without grace period9772026/10/09 17:38:22 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=09782026/10/09 17:38:22 INFO Vacuumed table table=pending_closures9792026/10/09 17:38:22 INFO Received uploads request method=POST path=/api/pending_closures9802026/10/09 17:38:22 INFO Vacuumed table table=pending_objects9812026/10/09 17:38:22 INFO Vacuumed table table=multipart_uploads9822026/10/09 17:38:22 INFO Vacuumed table table=closures9832026/10/09 17:38:22 INFO Vacuumed table table=objects9842026/10/09 17:38:22 INFO Received complete push request method=POST path=/api/pushes/2/complete9852026/10/09 17:38:22 INFO Completed push id=2 objects=4 duration=14.652834ms9862026/10/09 17:38:22 INFO Aborted multipart uploads count=0 kept=0987--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.55s)988=== CONT TestIsValidCachePath989=== RUN TestIsValidCachePath/narinfo990=== PAUSE TestIsValidCachePath/narinfo991=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars992=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars993=== RUN TestIsValidCachePath/nar_zst994=== PAUSE TestIsValidCachePath/nar_zst995=== RUN TestIsValidCachePath/nar_xz996=== PAUSE TestIsValidCachePath/nar_xz997=== RUN TestIsValidCachePath/nar_bz2998=== PAUSE TestIsValidCachePath/nar_bz2999=== RUN TestIsValidCachePath/nar_uncompressed1000=== PAUSE TestIsValidCachePath/nar_uncompressed1001=== RUN TestIsValidCachePath/ls1002=== PAUSE TestIsValidCachePath/ls1003=== RUN TestIsValidCachePath/log1004=== PAUSE TestIsValidCachePath/log1005=== RUN TestIsValidCachePath/realisation1006=== PAUSE TestIsValidCachePath/realisation1007=== RUN TestIsValidCachePath/nix-cache-info1008=== PAUSE TestIsValidCachePath/nix-cache-info1009=== RUN TestIsValidCachePath/index.html1010=== PAUSE TestIsValidCachePath/index.html1011=== RUN TestIsValidCachePath/traversal_parent1012=== PAUSE TestIsValidCachePath/traversal_parent1013=== RUN TestIsValidCachePath/traversal_in_middle1014=== PAUSE TestIsValidCachePath/traversal_in_middle1015=== RUN TestIsValidCachePath/invalid_char_e1016=== PAUSE TestIsValidCachePath/invalid_char_e1017=== RUN TestIsValidCachePath/invalid_char_u1018=== PAUSE TestIsValidCachePath/invalid_char_u1019=== RUN TestIsValidCachePath/random_path1020=== PAUSE TestIsValidCachePath/random_path1021=== RUN TestIsValidCachePath/empty1022=== PAUSE TestIsValidCachePath/empty1023=== RUN TestIsValidCachePath/leading_slash1024=== PAUSE TestIsValidCachePath/leading_slash1025=== RUN TestIsValidCachePath/wrong_extension1026=== PAUSE TestIsValidCachePath/wrong_extension1027=== RUN TestIsValidCachePath/short_hash1028=== PAUSE TestIsValidCachePath/short_hash1029=== CONT TestIsValidUploadKey1030=== RUN TestIsValidUploadKey/narinfo1031=== PAUSE TestIsValidUploadKey/narinfo1032=== RUN TestIsValidUploadKey/nar_zst1033=== PAUSE TestIsValidUploadKey/nar_zst1034=== RUN TestIsValidUploadKey/nar_xz1035=== PAUSE TestIsValidUploadKey/nar_xz1036=== RUN TestIsValidUploadKey/nar_plain1037=== PAUSE TestIsValidUploadKey/nar_plain1038=== RUN TestIsValidUploadKey/listing1039=== PAUSE TestIsValidUploadKey/listing1040=== RUN TestIsValidUploadKey/build_log1041=== PAUSE TestIsValidUploadKey/build_log1042=== RUN TestIsValidUploadKey/build_log_home-manager_file1043=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1044=== RUN TestIsValidUploadKey/build_log_plus_in_name1045=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1046=== RUN TestIsValidUploadKey/build_log_question_mark1047=== PAUSE TestIsValidUploadKey/build_log_question_mark1048=== RUN TestIsValidUploadKey/build_log_equals1049=== PAUSE TestIsValidUploadKey/build_log_equals1050=== RUN TestIsValidUploadKey/realisation1051=== PAUSE TestIsValidUploadKey/realisation1052=== RUN TestIsValidUploadKey/realisation_plus_in_output1053=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1054=== RUN TestIsValidUploadKey/nix-cache-info1055=== PAUSE TestIsValidUploadKey/nix-cache-info1056=== RUN TestIsValidUploadKey/index.html1057=== PAUSE TestIsValidUploadKey/index.html10582026/10/09 17:38:22 WARN Force mode enabled - objects will be deleted immediately without grace period1059=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1060=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1061=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1062=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1063=== RUN TestIsValidUploadKey/listing_key,_narinfo_type10642026/10/09 17:38:22 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=01065=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1066=== RUN TestIsValidUploadKey/traversal1067=== PAUSE TestIsValidUploadKey/traversal1068=== RUN TestIsValidUploadKey/traversal_nar1069=== PAUSE TestIsValidUploadKey/traversal_nar1070=== RUN TestIsValidUploadKey/absolute1071=== PAUSE TestIsValidUploadKey/absolute1072=== RUN TestIsValidUploadKey/empty_key1073=== PAUSE TestIsValidUploadKey/empty_key1074=== RUN TestIsValidUploadKey/unknown_type1075=== PAUSE TestIsValidUploadKey/unknown_type1076=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10772026/10/09 17:38:22 INFO Vacuumed table table=pending_closures10782026/10/09 17:38:22 INFO Vacuumed table table=pending_objects10792026/10/09 17:38:22 INFO Vacuumed table table=multipart_uploads10802026/10/09 17:38:22 INFO Vacuumed table table=closures10812026/10/09 17:38:22 INFO Vacuumed table table=objects1082--- PASS: TestGCSweepSkipsPendingObjects (7.70s)1083=== CONT TestCompleteMultipartUnregistered10842026/10/09 17:38:22 INFO Received push request method=POST path=/api/pushes1085--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (7.92s)1086=== CONT TestService_verifyS3Integrity1087--- PASS: TestReadRedirectUsesPublicS3URL (8.13s)1088=== CONT TestService_createPendingClosureHandler10892026/10/09 17:38:23 INFO Received uploads request method=POST path=/api/pending_closures1090--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.56s)1091=== CONT TestService_cleanupPendingClosuresHandler1092--- PASS: TestReadProxyDisabled (6.82s)1093=== CONT TestUploadHandlersRejectOversizedBody1094=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1095=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1096=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1097=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1098=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1099=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1100=== CONT TestUploadHandlersRejectInvalidKeys1101=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1102=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1103=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1104=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1105=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1106=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1107=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1108=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1109=== CONT TestLeadScopedToFarm1110--- PASS: TestReadRedirectKeepsNarinfoProxied (7.40s)1111=== CONT TestClientIntegration1112--- PASS: TestReadRedirectNar (7.51s)1113=== CONT TestLeadElectsOneAndHandsOver11142026/10/09 17:38:24 INFO Received uploads request method=POST path=/api/pending_closures11152026/10/09 17:38:25 INFO Aborted multipart uploads count=0 kept=011162026/10/09 17:38:25 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=011172026/10/09 17:38:25 INFO Vacuumed table table=pending_closures11182026/10/09 17:38:25 INFO Vacuumed table table=pending_objects11192026/10/09 17:38:25 INFO Vacuumed table table=multipart_uploads1120--- PASS: TestReadProxyRootRedirectsToIndexHTML (7.41s)1121=== CONT TestClientErrorHandling1122=== RUN TestClientErrorHandling/InvalidStorePath1123=== PAUSE TestClientErrorHandling/InvalidStorePath1124=== RUN TestClientErrorHandling/InvalidAuthToken1125=== PAUSE TestClientErrorHandling/InvalidAuthToken1126=== RUN TestClientErrorHandling/ServerNotAvailable1127=== PAUSE TestClientErrorHandling/ServerNotAvailable1128=== CONT TestConnectWaitsForAPeerMigration11292026/10/09 17:38:25 INFO Vacuumed table table=closures11302026/10/09 17:38:25 INFO Vacuumed table table=objects11312026/10/09 17:38:25 INFO Aborted multipart uploads count=0 kept=011322026/10/09 17:38:25 WARN Force mode enabled - objects will be deleted immediately without grace period11332026/10/09 17:38:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011342026/10/09 17:38:25 INFO Vacuumed table table=pending_closures11352026/10/09 17:38:25 INFO Vacuumed table table=pending_objects11362026/10/09 17:38:25 INFO Vacuumed table table=multipart_uploads11372026/10/09 17:38:25 INFO Vacuumed table table=closures11382026/10/09 17:38:25 INFO Vacuumed table table=objects1139--- PASS: TestPushDedupSurvivesConcurrentGC (8.12s)1140=== CONT TestClientCADerivations11412026/10/09 17:38:25 INFO Aborted multipart uploads count=0 kept=011422026/10/09 17:38:25 WARN Force mode enabled - objects will be deleted immediately without grace period11432026/10/09 17:38:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011442026/10/09 17:38:25 INFO Vacuumed table table=pending_closures11452026/10/09 17:38:25 INFO Vacuumed table table=pending_objects11462026/10/09 17:38:25 INFO Vacuumed table table=multipart_uploads11472026/10/09 17:38:25 INFO Vacuumed table table=closures11482026/10/09 17:38:25 INFO Vacuumed table table=objects1149--- PASS: TestGCMetrics (7.71s)1150=== CONT TestResolveDBConnectionString1151=== RUN TestResolveDBConnectionString/flag_wins1152=== PAUSE TestResolveDBConnectionString/flag_wins1153=== RUN TestResolveDBConnectionString/file_when_flag_empty1154=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1155=== RUN TestResolveDBConnectionString/missing_file_is_an_error1156=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1157=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1158=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1159=== RUN TestResolveDBConnectionString/nothing_configured1160=== PAUSE TestResolveDBConnectionString/nothing_configured1161=== CONT TestCacheStatsHandler1162--- PASS: TestReadProxyConditionalGet (7.30s)1163=== CONT TestCacheConfigHandler1164=== RUN TestCacheConfigHandler/full_config,_no_issuer1165=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1166=== RUN TestCacheConfigHandler/no_cache_url_configured1167=== PAUSE TestCacheConfigHandler/no_cache_url_configured1168=== RUN TestCacheConfigHandler/no_signing_keys1169=== PAUSE TestCacheConfigHandler/no_signing_keys1170=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1171=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1172=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11732026/10/09 17:38:26 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld7 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1174--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.19s)1175=== CONT TestDeleteClosuresRacingPins1176--- PASS: TestGCBugBareHashReferences (7.52s)1177=== CONT TestClientFallsBackToClosures1178--- PASS: TestReadProxyHead (7.11s)1179=== CONT TestClientPushesUseOnePush11802026/10/09 17:38:27 INFO lead: acquired remote=192.0.2.1:12341181--- PASS: TestReadProxyInvalidPath (6.64s)1182=== CONT TestService_ReadScope_PublicByDefault1183--- PASS: TestReadProxy404 (6.84s)1184=== CONT TestService_RequireScope_OIDC11852026/10/09 17:38:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63684/oidc11862026/10/09 17:38:27 INFO lead: acquired remote=192.0.2.1:123411872026/10/09 17:38:27 INFO lead: released remote=192.0.2.1:12341188--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.07s)1189=== CONT TestService_AuthMiddleware_OIDC11902026/10/09 17:38:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63687/oidc1191--- PASS: TestReadProxyNarStreaming (6.80s)1192=== CONT TestService_ReadAuthMiddleware11932026/10/09 17:38:28 INFO lead: released remote=192.0.2.1:12341194--- PASS: TestLeadEndsOnShutdown (8.17s)1195=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1196--- PASS: TestReadProxyContentNegotiation (6.96s)1197=== CONT TestService_AuthMiddleware_MTLSProxyHeader1198--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.61s)1199=== CONT TestService_AuthMiddleware12002026/10/09 17:38:28 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1201--- PASS: TestReadProxyNarinfo (6.91s)1202=== CONT TestPinProtectsFromGC12032026/10/09 17:38:29 INFO Received uploads request method=POST path=/api/pending_closures1204--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (6.58s)1205=== CONT TestClientSharedPathCommittedMidPush12062026/10/09 17:38:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12072026/10/09 17:38:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1208--- PASS: TestCompleteMultipartUnregistered (6.65s)1209=== CONT TestClientWithDependencies12102026/10/09 17:38:29 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/09 17:38:29 INFO Received uploads request method=POST path=/api/pending_closures12122026/10/09 17:38:29 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/09 17:38:29 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/09 17:38:30 INFO Received cleanup request method=DELETE path=/api/pending_closures12152026/10/09 17:38:30 INFO Aborted multipart uploads count=0 kept=012162026/10/09 17:38:30 INFO Received uploads request method=POST path=/api/pending_closures1217--- PASS: TestReadProxyOutlastsServerWriteTimeout (11.72s)1218=== CONT TestClientMultipleUploads12192026/10/09 17:38:30 INFO Received cleanup request method=DELETE path=/api/pending_closures12202026/10/09 17:38:30 INFO Aborted multipart uploads count=1 kept=012212026/10/09 17:38:30 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12222026-10-09 17:38:30.581 UTC [59470] ERROR: Closure does not exist: id=112232026-10-09 17:38:30.581 UTC [59470] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12242026-10-09 17:38:30.581 UTC [59470] STATEMENT: -- name: CommitPendingClosure :one1225 SELECT commit_pending_closure($1::bigint)::bigint1226 1227--- PASS: TestService_cleanupPendingClosuresHandler (6.97s)1228=== CONT TestServerTLSConfig1229=== RUN TestServerTLSConfig/no_client_CA1230=== PAUSE TestServerTLSConfig/no_client_CA1231=== RUN TestServerTLSConfig/missing_CA_file1232=== PAUSE TestServerTLSConfig/missing_CA_file1233=== RUN TestServerTLSConfig/not_a_PEM_file1234=== PAUSE TestServerTLSConfig/not_a_PEM_file1235=== CONT TestPresentNotReportedWhileGCDeletesClosure1236=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1237=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1238=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1239=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1240=== CONT TestSkippedUploadsHandler12412026/10/09 17:38:30 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001242--- PASS: TestSkippedUploadsHandler (0.01s)1243=== CONT TestPresentRefreshesOnlyStaleClosures12442026/10/09 17:38:30 INFO lead: acquired remote=192.0.2.1:123412452026/10/09 17:38:30 INFO lead: acquired remote=192.0.2.1:123412462026/10/09 17:38:30 INFO lead: acquired remote=192.0.2.1:123412472026/10/09 17:38:30 INFO lead: released remote=192.0.2.1:123412482026/10/09 17:38:30 INFO lead: acquired remote=192.0.2.1:123412492026/10/09 17:38:30 INFO lead: released remote=192.0.2.1:123412502026/10/09 17:38:30 INFO lead: released remote=192.0.2.1:123412512026/10/09 17:38:30 INFO lead: released remote=192.0.2.1:12341252--- PASS: TestLeadScopedToFarm (6.90s)1253=== CONT TestPendingClosureWriteTimeout1254=== RUN TestPendingClosureWriteTimeout/empty1255=== PAUSE TestPendingClosureWriteTimeout/empty1256=== RUN TestPendingClosureWriteTimeout/400_objects1257=== PAUSE TestPendingClosureWriteTimeout/400_objects1258=== RUN TestPendingClosureWriteTimeout/670k_objects1259=== PAUSE TestPendingClosureWriteTimeout/670k_objects1260=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1261=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1262=== CONT TestPresentReportsOnlyClosureRoots12632026/10/09 17:38:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12642026/10/09 17:38:31 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLjJmY2NkNTM4LTg4M2QtNDZlYi05ZTJhLWRjMTlmZDM4OWYyOHgxNzkxNTY3NTA5NzIyNjE3MDAw parts=1012652026/10/09 17:38:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12662026/10/09 17:38:31 INFO Completed upload id=1 objects=2 duration=18.068375ms12672026/10/09 17:38:31 INFO Received uploads request method=POST path=/api/pending_closures1268=== NAME TestClientIntegration1269 client_integration_test.go:286: Created store path: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientIntegration3929648909/002/store/pj0wjgpi1g7bxsk5vj3azibzgykxxkz1-test-file.txt12702026/10/09 17:38:31 INFO Received uploads request method=POST path=/api/pending_closures12712026/10/09 17:38:31 INFO lead: acquired remote=192.0.2.1:123412722026/10/09 17:38:31 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12732026/10/09 17:38:31 WARN Found objects in DB but missing from S3, will re-upload count=11274--- PASS: TestService_verifyS3Integrity (8.49s)1275=== CONT TestProxyWriteTimeout1276=== RUN TestProxyWriteTimeout/narinfo1277=== PAUSE TestProxyWriteTimeout/narinfo1278=== RUN TestProxyWriteTimeout/1_GiB_nar1279=== PAUSE TestProxyWriteTimeout/1_GiB_nar1280=== RUN TestProxyWriteTimeout/10_GiB_nar1281=== PAUSE TestProxyWriteTimeout/10_GiB_nar1282=== RUN TestProxyWriteTimeout/unknown_size1283=== PAUSE TestProxyWriteTimeout/unknown_size1284=== CONT TestCreatePin_ReservedPins12852026/10/09 17:38:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63716/oidc12862026/10/09 17:38:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12872026/10/09 17:38:31 INFO Received push request method=POST path=/api/pushes12882026/10/09 17:38:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12892026/10/09 17:38:31 INFO Uploading pj0wjgpi1g7bxsk5vj3azibzgykxxkz1-test-file.txt (152B)12902026/10/09 17:38:31 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLjA1ZTlkMTQxLWZlNGMtNGVmNy1hNWUzLWVlMmJiY2IxYThmZngxNzkxNTY3NTEwMDI1OTgzMDAw parts=1012912026/10/09 17:38:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12922026/10/09 17:38:31 INFO Completed upload id=1 objects=2 duration=14.448375ms12932026/10/09 17:38:31 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012942026/10/09 17:38:31 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12952026/10/09 17:38:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12962026/10/09 17:38:31 WARN Failed to register uploaded object key=pj0wjgpi1g7bxsk5vj3azibzgykxxkz1.ls error="server returned 404: 404 page not found\n"12972026/10/09 17:38:31 INFO Signed narinfos id=1 count=112982026/10/09 17:38:31 INFO Uploading 1 narinfos12992026/10/09 17:38:31 INFO Received uploads request method=POST path=/api/pending_closures13002026/10/09 17:38:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures13012026/10/09 17:38:31 INFO Received complete push request method=POST path=/api/pushes/1/complete13022026/10/09 17:38:31 WARN Failed to register uploaded object key=pj0wjgpi1g7bxsk5vj3azibzgykxxkz1.narinfo error="server returned 404: 404 page not found\n"13032026/10/09 17:38:31 INFO Aborted multipart uploads count=0 kept=013042026/10/09 17:38:31 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=013052026/10/09 17:38:31 INFO Completed push id=1 objects=3 duration=23.275125ms13062026/10/09 17:38:31 INFO Upload complete. (234ms)13072026/10/09 17:38:31 INFO Vacuumed table table=pending_closures13082026/10/09 17:38:31 INFO All 1 paths already cached13092026/10/09 17:38:31 INFO Vacuumed table table=pending_objects1310=== NAME TestClientIntegration1311 client_integration_test.go:312: Retrieved narinfo from S3:1312 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientIntegration3929648909/002/store/pj0wjgpi1g7bxsk5vj3azibzgykxxkz1-test-file.txt1313 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1314 Compression: zstd1315 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11316 NarSize: 1521317 References: 1318 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113192026/10/09 17:38:31 INFO Vacuumed table table=multipart_uploads13202026/10/09 17:38:31 INFO Vacuumed table table=closures1321 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1322 client_integration_test.go:313: Decompressed .ls content (64 bytes):13232026/10/09 17:38:31 INFO Vacuumed table table=objects1324 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1325 client_integration_test.go:316: Testing garbage collection...13262026/10/09 17:38:31 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001327--- PASS: TestService_createPendingClosureHandler (8.74s)1328=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13292026/10/09 17:38:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures13302026/10/09 17:38:32 INFO Garbage collection started13312026/10/09 17:38:32 INFO Aborted multipart uploads count=0 kept=013322026/10/09 17:38:32 WARN Force mode enabled - objects will be deleted immediately without grace period13332026/10/09 17:38:32 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=01334--- PASS: TestCacheStatsHandler (6.47s)1335=== CONT TestOrphanedObjectsGCStressTest13362026/10/09 17:38:32 INFO Vacuumed table table=pending_closures13372026/10/09 17:38:32 INFO Vacuumed table table=pending_objects13382026/10/09 17:38:32 INFO Vacuumed table table=multipart_uploads13392026/10/09 17:38:32 INFO Vacuumed table table=closures13402026/10/09 17:38:32 INFO Vacuumed table table=objects1341--- PASS: TestConnectWaitsForAPeerMigration (7.16s)1342=== CONT TestObjectStatsTrigger1343=== NAME TestClientCADerivations1344 client_ca_test.go:136: Built CA derivation: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientCADerivations1600871411/001/store/hfg1qw8pqwi1p0i4m5agg0zqn1ayim5r-ca-test13452026/10/09 17:38:32 INFO lead: released remote=192.0.2.1:123413462026/10/09 17:38:32 INFO lead: acquired remote=192.0.2.1:12341347 client_ca_test.go:139: Found 1 dependencies (including self)1348--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.16s)1349=== CONT TestPendingCleanupUsesOneCutoff13502026/10/09 17:38:33 INFO Received push request method=POST path=/api/pushes13512026/10/09 17:38:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13522026/10/09 17:38:33 INFO Uploading hfg1qw8pqwi1p0i4m5agg0zqn1ayim5r-ca-test (144B)13532026/10/09 17:38:33 WARN Failed to register uploaded object key=log/x8b7h52zj7nmfjc53aqlmkadyl0vg91h-ca-test.drv error="server returned 404: 404 page not found\n"13542026/10/09 17:38:33 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13552026/10/09 17:38:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13562026/10/09 17:38:33 WARN Failed to register uploaded object key=hfg1qw8pqwi1p0i4m5agg0zqn1ayim5r.ls error="server returned 404: 404 page not found\n"13572026/10/09 17:38:33 INFO Signed narinfos id=1 count=113582026/10/09 17:38:33 INFO Uploading 1 narinfos13592026/10/09 17:38:33 INFO Received complete push request method=POST path=/api/pushes/1/complete13602026/10/09 17:38:33 WARN Failed to register uploaded object key=hfg1qw8pqwi1p0i4m5agg0zqn1ayim5r.narinfo error="server returned 404: 404 page not found\n"13612026/10/09 17:38:33 INFO Completed push id=1 objects=4 duration=29.86875ms13622026/10/09 17:38:33 INFO Upload complete. (496ms)1363=== NAME TestClientCADerivations1364 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientCADerivations1600871411/001/store/hfg1qw8pqwi1p0i4m5agg0zqn1ayim5r-ca-test1365 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1366 Compression: zstd1367 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1368 NarSize: 1441369 References: 1370 Deriver: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientCADerivations1600871411/001/store/x8b7h52zj7nmfjc53aqlmkadyl0vg91h-ca-test.drv1371 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1372 client_ca_test.go:185: Checking for realisation files in S3...1373 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1374 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache13752026/10/09 17:38:33 INFO Received uploads request method=POST path=/api/pending_closures13762026/10/09 17:38:33 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/09 17:38:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13782026/10/09 17:38:33 INFO Uploading gipqr22w0i1y3n3b2px3harqgi2i91i7-shared-dep (136B)13792026/10/09 17:38:33 INFO Uploading hjjzwy65a0kcmsm0b2xllkac0adqrb41-a (256B)13802026/10/09 17:38:33 WARN Failed to register uploaded object key=5mcn62961qw9rmr174432z6dg972zhh7.ls error="server returned 404: 404 page not found\n"13812026/10/09 17:38:33 WARN Failed to register uploaded object key=gipqr22w0i1y3n3b2px3harqgi2i91i7.ls error="server returned 404: 404 page not found\n"13822026/10/09 17:38:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13832026/10/09 17:38:33 WARN Failed to register uploaded object key=hjjzwy65a0kcmsm0b2xllkac0adqrb41.ls error="server returned 404: 404 page not found\n"13842026/10/09 17:38:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13852026/10/09 17:38:33 WARN Failed to register uploaded object key=nar/1s8sg7dl5bshh5q243b24wg1yb5ngck4dnhvhhkjfj2m0gd4jmmz.nar.zst error="server returned 404: 404 page not found\n"1386 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket55?endpoint=http://localhost:63585®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/7/scratch/294f6b975c717bac/build/TestClientCADerivations1600871411/001/store'1387 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 113882026/10/09 17:38:33 INFO Signed narinfos id=1 count=21389--- PASS: TestClientCADerivations (8.36s)1390=== CONT TestOrphanedObjectsGC13912026/10/09 17:38:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13922026/10/09 17:38:33 INFO Signed narinfos id=2 count=213932026/10/09 17:38:33 INFO Uploading 4 narinfos1394--- PASS: TestService_ReadScope_PublicByDefault (6.38s)1395=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13962026/10/09 17:38:33 WARN Failed to register uploaded object key=5mcn62961qw9rmr174432z6dg972zhh7.narinfo error="server returned 404: 404 page not found\n"13972026/10/09 17:38:33 WARN Failed to register uploaded object key=hjjzwy65a0kcmsm0b2xllkac0adqrb41.narinfo error="server returned 404: 404 page not found\n"13982026/10/09 17:38:33 WARN Failed to register uploaded object key=gipqr22w0i1y3n3b2px3harqgi2i91i7.narinfo error="server returned 404: 404 page not found\n"13992026/10/09 17:38:33 INFO lead: released remote=192.0.2.1:12341400--- PASS: TestLeadElectsOneAndHandsOver (9.31s)1401=== CONT TestObjectStatsLargeCommit14022026/10/09 17:38:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14032026/10/09 17:38:33 WARN Failed to register uploaded object key=gipqr22w0i1y3n3b2px3harqgi2i91i7.narinfo error="server returned 404: 404 page not found\n"14042026/10/09 17:38:33 INFO Completed upload id=2 objects=6 duration=17.289542ms14052026/10/09 17:38:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14062026/10/09 17:38:33 INFO Completed upload id=1 objects=6 duration=2.387833ms14072026/10/09 17:38:33 INFO Upload complete. (467ms)1408=== NAME TestClientFallsBackToClosures1409 client_pushes_test.go:112: Retrieved narinfo from S3:1410 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientFallsBackToClosures3897976061/001/store/gipqr22w0i1y3n3b2px3harqgi2i91i7-shared-dep1411 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1412 Compression: zstd1413 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821414 NarSize: 1361415 References: 1416 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1417 client_pushes_test.go:112: Retrieved narinfo from S3:1418 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientFallsBackToClosures3897976061/001/store/hjjzwy65a0kcmsm0b2xllkac0adqrb41-a1419 URL: nar/1s8sg7dl5bshh5q243b24wg1yb5ngck4dnhvhhkjfj2m0gd4jmmz.nar.zst1420 Compression: zstd1421 NarHash: sha256:1s8sg7dl5bshh5q243b24wg1yb5ngck4dnhvhhkjfj2m0gd4jmmz1422 NarSize: 2561423 References: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientFallsBackToClosures3897976061/001/store/gipqr22w0i1y3n3b2px3harqgi2i91i7-shared-dep1424 CA: text:sha256:07ckrdkswwwascbq6abmlm22yzg6yqrxp283m1jf7n34zp7jpmdz1425 client_pushes_test.go:112: Retrieved narinfo from S3:1426 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientFallsBackToClosures3897976061/001/store/5mcn62961qw9rmr174432z6dg972zhh7-b1427 URL: nar/1s8sg7dl5bshh5q243b24wg1yb5ngck4dnhvhhkjfj2m0gd4jmmz.nar.zst1428 Compression: zstd1429 NarHash: sha256:1s8sg7dl5bshh5q243b24wg1yb5ngck4dnhvhhkjfj2m0gd4jmmz1430 NarSize: 2561431 References: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientFallsBackToClosures3897976061/001/store/gipqr22w0i1y3n3b2px3harqgi2i91i7-shared-dep1432 CA: text:sha256:07ckrdkswwwascbq6abmlm22yzg6yqrxp283m1jf7n34zp7jpmdz1433--- PASS: TestClientFallsBackToClosures (7.17s)1434=== CONT TestMultipartCleanup14352026/10/09 17:38:34 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01436=== NAME TestClientIntegration1437 client_integration_test.go:323: Objects in database after GC:1438 client_integration_test.go:323: Successfully deleted all objects with GC --force1439--- PASS: TestClientIntegration (9.88s)1440=== CONT TestMetricsInventory1441=== RUN TestService_RequireScope_OIDC/builder_may_write1442=== PAUSE TestService_RequireScope_OIDC/builder_may_write1443=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1444=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1445=== RUN TestService_RequireScope_OIDC/ops_may_admin1446=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1447=== RUN TestService_RequireScope_OIDC/ops_may_not_write1448=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1449=== RUN TestService_RequireScope_OIDC/reader_may_not_write1450=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1451=== RUN TestService_RequireScope_OIDC/static_token_may_admin1452=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1453=== RUN TestService_RequireScope_OIDC/static_token_may_write1454=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1455=== RUN TestService_RequireScope_OIDC/reader_may_read1456=== PAUSE TestService_RequireScope_OIDC/reader_may_read1457=== RUN TestService_RequireScope_OIDC/writer_implies_read1458=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1459=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1460=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1461=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1462=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1463=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1464=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1465=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1466=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1467=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1468=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1469=== CONT TestCacheConfigHandlerMaxNarSize1470--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1471=== CONT TestService_NativeMTLS14722026/10/09 17:38:34 INFO Received push request method=POST path=/api/pushes14732026/10/09 17:38:34 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14742026/10/09 17:38:34 INFO Uploading hvjdfj9ma64ccq2kha4214nfcblsb096-shared-dep (136B)14752026/10/09 17:38:34 INFO Uploading 3cji1qm3np7livpd4515ccb0kvvgiskw-b (256B)14762026/10/09 17:38:34 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14772026/10/09 17:38:34 WARN Failed to register uploaded object key=i7k45phzdfn64z4lwrskak7ylmh825hd.ls error="server returned 404: 404 page not found\n"14782026/10/09 17:38:34 WARN Failed to register uploaded object key=3cji1qm3np7livpd4515ccb0kvvgiskw.ls error="server returned 404: 404 page not found\n"14792026/10/09 17:38:34 WARN Failed to register uploaded object key=hvjdfj9ma64ccq2kha4214nfcblsb096.ls error="server returned 404: 404 page not found\n"14802026/10/09 17:38:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14812026/10/09 17:38:34 WARN Failed to register uploaded object key=nar/0vpj13vcfl6glm3xl6h1gj6k5r8alai7cr3ssz1lq48axg4ppp1k.nar.zst error="server returned 404: 404 page not found\n"14822026/10/09 17:38:34 INFO Signed narinfos id=1 count=314832026/10/09 17:38:34 INFO Uploading 3 narinfos14842026/10/09 17:38:34 WARN Failed to register uploaded object key=i7k45phzdfn64z4lwrskak7ylmh825hd.narinfo error="server returned 404: 404 page not found\n"14852026/10/09 17:38:34 WARN Failed to register uploaded object key=3cji1qm3np7livpd4515ccb0kvvgiskw.narinfo error="server returned 404: 404 page not found\n"14862026/10/09 17:38:34 INFO Received complete push request method=POST path=/api/pushes/1/complete14872026/10/09 17:38:34 WARN Failed to register uploaded object key=hvjdfj9ma64ccq2kha4214nfcblsb096.narinfo error="server returned 404: 404 page not found\n"14882026/10/09 17:38:34 INFO Completed push id=1 objects=8 duration=20.530208ms14892026/10/09 17:38:34 INFO Upload complete. (314ms)1490=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1491=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1492=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1493=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1494=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1495=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1496=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1497=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1498=== NAME TestClientPushesUseOnePush1499 client_pushes_test.go:97: Retrieved narinfo from S3:1500 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientPushesUseOnePush2106540580/001/store/hvjdfj9ma64ccq2kha4214nfcblsb096-shared-dep1501 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1502 Compression: zstd1503 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821504 NarSize: 1361505 References: 1506 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1507=== CONT TestNARDeduplicationMetadataUploadBug1508=== NAME TestClientPushesUseOnePush1509 client_pushes_test.go:97: Retrieved narinfo from S3:1510 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientPushesUseOnePush2106540580/001/store/i7k45phzdfn64z4lwrskak7ylmh825hd-a1511 URL: nar/0vpj13vcfl6glm3xl6h1gj6k5r8alai7cr3ssz1lq48axg4ppp1k.nar.zst1512 Compression: zstd1513 NarHash: sha256:0vpj13vcfl6glm3xl6h1gj6k5r8alai7cr3ssz1lq48axg4ppp1k1514 NarSize: 2561515 References: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientPushesUseOnePush2106540580/001/store/hvjdfj9ma64ccq2kha4214nfcblsb096-shared-dep1516 CA: text:sha256:1j8xh35n3kis07m5nnfarb1xq38mylwfysw8hr4qmdm71f537gj41517 client_pushes_test.go:97: Retrieved narinfo from S3:1518 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientPushesUseOnePush2106540580/001/store/3cji1qm3np7livpd4515ccb0kvvgiskw-b1519 URL: nar/0vpj13vcfl6glm3xl6h1gj6k5r8alai7cr3ssz1lq48axg4ppp1k.nar.zst1520 Compression: zstd1521 NarHash: sha256:0vpj13vcfl6glm3xl6h1gj6k5r8alai7cr3ssz1lq48axg4ppp1k1522 NarSize: 2561523 References: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientPushesUseOnePush2106540580/001/store/hvjdfj9ma64ccq2kha4214nfcblsb096-shared-dep1524 CA: text:sha256:1j8xh35n3kis07m5nnfarb1xq38mylwfysw8hr4qmdm71f537gj41525--- PASS: TestClientPushesUseOnePush (7.58s)1526=== CONT TestMetricsCommit1527--- PASS: TestService_ReadAuthMiddleware (6.73s)1528=== CONT TestCreatePendingClosureRejectsOversizedNAR15292026/10/09 17:38:34 INFO Received uploads request method=POST path=/api/pending_closures1530--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1531=== CONT TestService_healthCheckHandler15322026/10/09 17:38:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15332026/10/09 17:38:35 WARN mTLS auth: bound subjects configured but subject DN unavailable15342026/10/09 17:38:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1535--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.93s)1536=== CONT TestGracefulShutdownDrainsInflight15372026/10/09 17:38:35 INFO Starting HTTP server address=127.0.0.1:6376115382026/10/09 17:38:35 INFO Shutdown signal received, draining in-flight requests timeout=10s1539--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1540=== CONT TestGenerateLandingPage1541--- PASS: TestGenerateLandingPage (0.00s)1542=== CONT TestGCTaskStore_Fail1543--- PASS: TestGCTaskStore_Fail (0.00s)1544=== CONT TestService_readinessHandler15452026/10/09 17:38:35 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1546--- PASS: TestService_AuthMiddleware (6.84s)1547=== CONT TestService_Rustfstest1548--- PASS: TestDeleteClosuresRacingPins (8.85s)1549=== CONT TestParseSize1550--- PASS: TestParseSize (0.00s)1551=== CONT TestPresignedUploadRegisteredBeforeCommit1552--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.29s)1553=== CONT TestCompletedNarNotReofferedAcrossClosures1554=== NAME TestPinProtectsFromGC1555 client_integration_test.go:731: Pinned store path: /private/var/tb/7/scratch/294f6b975c717bac/build/TestPinProtectsFromGC2292963012/001/store/7bi1ad7pf1h1c5fq52r7zvvrc79asxfw-pinned-file.txt1556 client_integration_test.go:732: Unpinned store path: /private/var/tb/7/scratch/294f6b975c717bac/build/TestPinProtectsFromGC2292963012/001/store/j1ww5pf5n7sqc780qxppv40jypyb2xnj-unpinned-file.txt15572026/10/09 17:38:36 INFO Received push request method=POST path=/api/pushes15582026/10/09 17:38:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/10/09 17:38:36 INFO Uploading 7bi1ad7pf1h1c5fq52r7zvvrc79asxfw-pinned-file.txt (128B)15602026/10/09 17:38:36 WARN Failed to register uploaded object key=7bi1ad7pf1h1c5fq52r7zvvrc79asxfw.ls error="server returned 404: 404 page not found\n"15612026/10/09 17:38:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15622026/10/09 17:38:36 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15632026/10/09 17:38:36 INFO Signed narinfos id=1 count=115642026/10/09 17:38:36 INFO Uploading 1 narinfos15652026/10/09 17:38:36 INFO Received complete push request method=POST path=/api/pushes/1/complete15662026/10/09 17:38:36 WARN Failed to register uploaded object key=7bi1ad7pf1h1c5fq52r7zvvrc79asxfw.narinfo error="server returned 404: 404 page not found\n"15672026/10/09 17:38:36 INFO Completed push id=1 objects=3 duration=27.217208ms15682026/10/09 17:38:36 INFO Upload complete. (299ms)1569--- PASS: TestPresentRefreshesOnlyStaleClosures (6.17s)1570=== CONT TestFarmLeadRoutes//api/farm/lead1571=== CONT TestFarmLeadRoutes//api/farm/lead/build-x861572--- PASS: TestFarmLeadRoutes (0.00s)1573 --- PASS: TestFarmLeadRoutes//api/farm/lead (0.00s)1574 --- PASS: TestFarmLeadRoutes//api/farm/lead/build-x86 (0.00s)1575=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows15762026/10/09 17:38:36 INFO Received push request method=POST path=/api/pushes15772026/10/09 17:38:36 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15782026/10/09 17:38:36 INFO Uploading wzrczkhgmrh8vzpplsarn55l7yi8wbp9-shared-dep (136B)15792026/10/09 17:38:36 INFO Uploading dg1x10pcaddij1bfkixfwlwxi16z3ydz-top (264B)15802026/10/09 17:38:36 WARN Failed to register uploaded object key=wzrczkhgmrh8vzpplsarn55l7yi8wbp9.ls error="server returned 404: 404 page not found\n"15812026/10/09 17:38:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15822026/10/09 17:38:36 WARN Failed to register uploaded object key=dg1x10pcaddij1bfkixfwlwxi16z3ydz.ls error="server returned 404: 404 page not found\n"15832026/10/09 17:38:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15842026/10/09 17:38:36 WARN Failed to register uploaded object key=nar/08p457f1jwnxh13p3xl6z5mnc6rkz77xlicidwryp2v4vn7v2jzr.nar.zst error="server returned 404: 404 page not found\n"15852026/10/09 17:38:36 INFO Signed narinfos id=1 count=215862026/10/09 17:38:36 INFO Uploading 2 narinfos15872026/10/09 17:38:36 INFO Received push request method=POST path=/api/pushes15882026/10/09 17:38:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15892026/10/09 17:38:36 INFO Uploading j1ww5pf5n7sqc780qxppv40jypyb2xnj-unpinned-file.txt (128B)15902026/10/09 17:38:36 WARN Failed to register uploaded object key=wzrczkhgmrh8vzpplsarn55l7yi8wbp9.narinfo error="server returned 404: 404 page not found\n"15912026/10/09 17:38:36 INFO Received complete push request method=POST path=/api/pushes/1/complete15922026/10/09 17:38:36 WARN Failed to register uploaded object key=dg1x10pcaddij1bfkixfwlwxi16z3ydz.narinfo error="server returned 404: 404 page not found\n"1593=== NAME TestClientWithDependencies1594 client_integration_test.go:613: Built derivation: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientWithDependencies129613007/001/store/n9cqvhsdglxyg80l6nllhirfj7d9s1vf-test-script15952026/10/09 17:38:37 INFO Completed push id=1 objects=6 duration=19.186542ms15962026/10/09 17:38:37 INFO Upload complete. (396ms)1597=== NAME TestClientSharedPathCommittedMidPush1598 client_integration_test.go:680: Retrieved narinfo from S3:1599 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientSharedPathCommittedMidPush1230989202/001/store/wzrczkhgmrh8vzpplsarn55l7yi8wbp9-shared-dep1600 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1601 Compression: zstd1602 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821603 NarSize: 1361604 References: 1605 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16062026/10/09 17:38:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16072026/10/09 17:38:37 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16082026/10/09 17:38:37 WARN Failed to register uploaded object key=j1ww5pf5n7sqc780qxppv40jypyb2xnj.ls error="server returned 404: 404 page not found\n"16092026/10/09 17:38:37 INFO Signed narinfos id=2 count=116102026/10/09 17:38:37 INFO Uploading 1 narinfos1611 client_integration_test.go:680: Retrieved narinfo from S3:1612 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientSharedPathCommittedMidPush1230989202/001/store/dg1x10pcaddij1bfkixfwlwxi16z3ydz-top1613 URL: nar/08p457f1jwnxh13p3xl6z5mnc6rkz77xlicidwryp2v4vn7v2jzr.nar.zst1614 Compression: zstd1615 NarHash: sha256:08p457f1jwnxh13p3xl6z5mnc6rkz77xlicidwryp2v4vn7v2jzr1616 NarSize: 2641617 References: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientSharedPathCommittedMidPush1230989202/001/store/wzrczkhgmrh8vzpplsarn55l7yi8wbp9-shared-dep1618 CA: text:sha256:1a4sf0i01cvbj9zi5m6ghjnz5v8jxh1rjl2vcv0j5irv3y70l0vl16192026/10/09 17:38:37 INFO Received complete push request method=POST path=/api/pushes/2/complete16202026/10/09 17:38:37 WARN Failed to register uploaded object key=j1ww5pf5n7sqc780qxppv40jypyb2xnj.narinfo error="server returned 404: 404 page not found\n"16212026/10/09 17:38:37 INFO Completed push id=2 objects=3 duration=5.183375ms16222026/10/09 17:38:37 INFO Upload complete. (327ms)1623--- PASS: TestClientSharedPathCommittedMidPush (7.85s)1624=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1625=== NAME TestClientWithDependencies1626 client_integration_test.go:615: Found 1 dependencies (including self)1627--- PASS: TestPresentReportsOnlyClosureRoots (6.42s)1628=== CONT TestGCEndsOnShutdown/before_the_run16292026/10/09 17:38:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures16302026/10/09 17:38:37 INFO Garbage collection started16312026/10/09 17:38:37 INFO Aborted multipart uploads count=0 kept=016322026/10/09 17:38:37 WARN Force mode enabled - objects will be deleted immediately without grace period16332026/10/09 17:38:37 INFO Received push request method=POST path=/api/pushes16342026/10/09 17:38:37 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=016352026/10/09 17:38:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16362026/10/09 17:38:37 INFO Uploading n9cqvhsdglxyg80l6nllhirfj7d9s1vf-test-script (136B)16372026/10/09 17:38:37 INFO Vacuumed table table=pending_closures16382026/10/09 17:38:37 INFO Vacuumed table table=pending_objects16392026/10/09 17:38:37 INFO Vacuumed table table=multipart_uploads16402026/10/09 17:38:37 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16412026/10/09 17:38:37 WARN Failed to register uploaded object key=n9cqvhsdglxyg80l6nllhirfj7d9s1vf.ls error="server returned 404: 404 page not found\n"16422026/10/09 17:38:37 INFO Vacuumed table table=closures16432026/10/09 17:38:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16442026/10/09 17:38:37 WARN Failed to register uploaded object key=log/bdgjwg2df43kzwaaxpw3i5igp1g2q9vk-test-script.drv error="server returned 404: 404 page not found\n"16452026/10/09 17:38:37 INFO Signed narinfos id=1 count=116462026/10/09 17:38:37 INFO Uploading 1 narinfos16472026/10/09 17:38:37 INFO Vacuumed table table=objects16482026/10/09 17:38:37 INFO Received complete push request method=POST path=/api/pushes/1/complete16492026/10/09 17:38:37 WARN Failed to register uploaded object key=n9cqvhsdglxyg80l6nllhirfj7d9s1vf.narinfo error="server returned 404: 404 page not found\n"16502026/10/09 17:38:37 INFO Completed push id=1 objects=4 duration=41.728709ms16512026/10/09 17:38:37 INFO Upload complete. (377ms)1652=== NAME TestClientWithDependencies1653 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/7/scratch/294f6b975c717bac/build/TestClientWithDependencies129613007/001/store) requires matching store prefix1654--- PASS: TestClientWithDependencies (8.29s)1655=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1656=== NAME TestClientMultipleUploads1657 client_integration_test.go:358: Created store path 0: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientMultipleUploads1426460314/001/store/43wkwzh2c22vva73gma36dh64ipbl2qf-test-file-0.txt16582026/10/09 17:38:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16592026/10/09 17:38:37 WARN Refused reserved pin name=worker-x86_64-linux16602026/10/09 17:38:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16612026/10/09 17:38:37 INFO Received create pin request method=POST path=/api/pins/my-app16622026/10/09 17:38:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1663--- PASS: TestCreatePin_ReservedPins (6.39s)1664=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1665=== NAME TestClientMultipleUploads1666 client_integration_test.go:358: Created store path 1: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientMultipleUploads1426460314/001/store/zxvkc0jm81rny7sx2rip8972c5c0i7sr-test-file-1.txt1667 client_integration_test.go:358: Created store path 2: /private/var/tb/7/scratch/294f6b975c717bac/build/TestClientMultipleUploads1426460314/001/store/clccz70znzgd0cnydam0rjc9m57yq1fg-test-file-2.txt16682026/10/09 17:38:38 INFO Received uploads request method=POST path=/api/pending_closures16692026/10/09 17:38:38 INFO Received push request method=POST path=/api/pushes16702026/10/09 17:38:38 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16712026/10/09 17:38:38 INFO Uploading zxvkc0jm81rny7sx2rip8972c5c0i7sr-test-file-1.txt (160B)16722026/10/09 17:38:38 INFO Uploading 43wkwzh2c22vva73gma36dh64ipbl2qf-test-file-0.txt (160B)16732026/10/09 17:38:38 INFO Uploading clccz70znzgd0cnydam0rjc9m57yq1fg-test-file-2.txt (160B)16742026/10/09 17:38:38 WARN Failed to register uploaded object key=zxvkc0jm81rny7sx2rip8972c5c0i7sr.ls error="server returned 404: 404 page not found\n"16752026/10/09 17:38:38 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16762026/10/09 17:38:38 WARN Failed to register uploaded object key=43wkwzh2c22vva73gma36dh64ipbl2qf.ls error="server returned 404: 404 page not found\n"16772026/10/09 17:38:38 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16782026/10/09 17:38:38 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16792026/10/09 17:38:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16802026/10/09 17:38:38 WARN Failed to register uploaded object key=clccz70znzgd0cnydam0rjc9m57yq1fg.ls error="server returned 404: 404 page not found\n"16812026/10/09 17:38:38 INFO Signed narinfos id=1 count=316822026/10/09 17:38:38 INFO Uploading 3 narinfos16832026/10/09 17:38:38 INFO Received complete push request method=POST path=/api/pushes/1/complete16842026/10/09 17:38:38 WARN Failed to register uploaded object key=zxvkc0jm81rny7sx2rip8972c5c0i7sr.narinfo error="server returned 404: 404 page not found\n"16852026/10/09 17:38:38 WARN Failed to register uploaded object key=43wkwzh2c22vva73gma36dh64ipbl2qf.narinfo error="server returned 404: 404 page not found\n"16862026/10/09 17:38:38 WARN Failed to register uploaded object key=clccz70znzgd0cnydam0rjc9m57yq1fg.narinfo error="server returned 404: 404 page not found\n"16872026/10/09 17:38:38 INFO Completed push id=1 objects=9 duration=30.666583ms16882026/10/09 17:38:38 INFO Upload complete. (285ms)1689 client_integration_test.go:369: Uploaded 3 paths in 390.361875ms1690--- PASS: TestClientMultipleUploads (8.08s)1691=== CONT TestParseSingleRange/end_clamped_to_size1692=== CONT TestParseSingleRange/none1693=== CONT TestParseSingleRange/open-ended1694=== CONT TestParseSingleRange/closed1695=== CONT TestParseSingleRange/malformed_end_before_start1696=== CONT TestParseSingleRange/malformed_both_empty1697=== CONT TestParseSingleRange/malformed_no_dash1698=== CONT TestParseSingleRange/single_byte1699=== CONT TestParseSingleRange/multi-range_ignored1700=== CONT TestParseSingleRange/start_far_past_EOF1701=== CONT TestParseSingleRange/start_past_EOF1702=== CONT TestParseSingleRange/suffix_exceeds_size1703=== CONT TestParseSingleRange/suffix1704=== CONT TestParseSingleRange/unknown_unit1705--- PASS: TestParseSingleRange (0.00s)1706 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1707 --- PASS: TestParseSingleRange/none (0.00s)1708 --- PASS: TestParseSingleRange/open-ended (0.00s)1709 --- PASS: TestParseSingleRange/closed (0.00s)1710 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1711 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1712 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1713 --- PASS: TestParseSingleRange/single_byte (0.00s)1714 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1715 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1716 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1717 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1718 --- PASS: TestParseSingleRange/suffix (0.00s)1719 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1720=== CONT TestPush_RejectsBadRequests/no_roots17212026/10/09 17:38:38 INFO Received push request method=POST path=/api/pushes17222026/10/09 17:38:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1723=== CONT TestPush_RejectsBadRequests/root_not_in_objects17242026/10/09 17:38:38 INFO Received push request method=POST path=/api/pushes1725=== CONT TestPush_RejectsBadRequests/bad_root17262026/10/09 17:38:38 INFO Received push request method=POST path=/api/pushes1727=== CONT TestPush_RejectsBadRequests/no_objects17282026/10/09 17:38:38 INFO Received push request method=POST path=/api/pushes1729=== CONT TestIsValidCachePath/narinfo1730--- PASS: TestPush_RejectsBadRequests (2.23s)1731 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1732 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1733 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1734 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1735=== CONT TestIsValidCachePath/index.html1736=== CONT TestIsValidCachePath/short_hash1737=== CONT TestIsValidCachePath/wrong_extension1738=== CONT TestIsValidCachePath/leading_slash1739=== CONT TestIsValidCachePath/empty1740=== CONT TestIsValidCachePath/random_path1741=== CONT TestIsValidCachePath/invalid_char_u1742=== CONT TestIsValidCachePath/invalid_char_e1743=== CONT TestIsValidCachePath/traversal_in_middle1744=== CONT TestIsValidCachePath/traversal_parent1745=== CONT TestIsValidCachePath/nar_uncompressed1746=== CONT TestIsValidCachePath/nix-cache-info1747=== CONT TestIsValidCachePath/realisation1748=== CONT TestIsValidCachePath/log1749=== CONT TestIsValidCachePath/ls1750=== CONT TestIsValidCachePath/nar_xz1751=== CONT TestIsValidCachePath/nar_bz21752=== CONT TestIsValidCachePath/nar_zst1753=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1754--- PASS: TestIsValidCachePath (0.01s)1755 --- PASS: TestIsValidCachePath/narinfo (0.00s)1756 --- PASS: TestIsValidCachePath/index.html (0.00s)1757 --- PASS: TestIsValidCachePath/short_hash (0.00s)1758 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1759 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1760 --- PASS: TestIsValidCachePath/empty (0.00s)1761 --- PASS: TestIsValidCachePath/random_path (0.00s)1762 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1763 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1764 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1765 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1766 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1767 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1768 --- PASS: TestIsValidCachePath/realisation (0.00s)1769 --- PASS: TestIsValidCachePath/log (0.00s)1770 --- PASS: TestIsValidCachePath/ls (0.00s)1771 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1772 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1773 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1774 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1775=== CONT TestIsValidUploadKey/narinfo1776=== CONT TestIsValidUploadKey/realisation_plus_in_output1777=== CONT TestIsValidUploadKey/unknown_type1778=== CONT TestIsValidUploadKey/empty_key1779=== CONT TestIsValidUploadKey/absolute1780=== CONT TestIsValidUploadKey/traversal_nar1781=== CONT TestIsValidUploadKey/traversal1782=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1783=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1784=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1785=== CONT TestIsValidUploadKey/index.html1786=== CONT TestIsValidUploadKey/nix-cache-info1787=== CONT TestIsValidUploadKey/build_log_home-manager_file1788=== CONT TestIsValidUploadKey/realisation1789=== CONT TestIsValidUploadKey/build_log_equals1790=== CONT TestIsValidUploadKey/build_log_question_mark1791=== CONT TestIsValidUploadKey/build_log_plus_in_name1792=== CONT TestIsValidUploadKey/nar_plain1793=== CONT TestIsValidUploadKey/build_log1794=== CONT TestIsValidUploadKey/listing1795=== CONT TestIsValidUploadKey/nar_xz1796=== CONT TestIsValidUploadKey/nar_zst1797--- PASS: TestIsValidUploadKey (0.04s)1798 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1799 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1800 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1801 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1802 --- PASS: TestIsValidUploadKey/absolute (0.00s)1803 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1804 --- PASS: TestIsValidUploadKey/traversal (0.00s)1805 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1806 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1807 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1808 --- PASS: TestIsValidUploadKey/index.html (0.00s)1809 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1810 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1811 --- PASS: TestIsValidUploadKey/realisation (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1813 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1814 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1815 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1816 --- PASS: TestIsValidUploadKey/build_log (0.00s)1817 --- PASS: TestIsValidUploadKey/listing (0.00s)1818 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1819 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1820=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18212026/10/09 17:38:38 INFO Received uploads request method=POST path=/1822--- PASS: TestObjectStatsTrigger (6.41s)1823=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18242026/10/09 17:38:38 INFO Received request for more parts method=POST path=/1825=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18262026/10/09 17:38:38 INFO Received complete multipart upload request method=POST path=/1827=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18282026/10/09 17:38:38 INFO Received uploads request method=POST path=/1829=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18302026/10/09 17:38:38 INFO Received complete multipart upload request method=POST path=/1831=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18322026/10/09 17:38:38 INFO Received request for more parts method=POST path=/1833=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18342026/10/09 17:38:38 INFO Received uploads request method=POST path=/1835--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1836 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1837 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1838 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1839 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1840=== CONT TestClientErrorHandling/InvalidStorePath1841--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1842 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1843 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1844 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.41s)1845=== CONT TestClientErrorHandling/ServerNotAvailable18462026/10/09 17:38:39 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/09 17:38:39 INFO Received uploads request method=POST path=/api/pending_closures18482026/10/09 17:38:39 INFO Received cleanup request method=DELETE path=/api/pending_closures18492026/10/09 17:38:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018502026/10/09 17:38:39 INFO Received create pin request method=POST path=/api/pins/myapp18512026/10/09 17:38:39 INFO Created/updated pin name=myapp store_path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestPinProtectsFromGC2292963012/001/store/7bi1ad7pf1h1c5fq52r7zvvrc79asxfw-pinned-file.txt narinfo_key=7bi1ad7pf1h1c5fq52r7zvvrc79asxfw.narinfo18522026/10/09 17:38:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures18532026/10/09 17:38:39 INFO Garbage collection started18542026/10/09 17:38:39 INFO Aborted multipart uploads count=0 kept=018552026/10/09 17:38:39 WARN Force mode enabled - objects will be deleted immediately without grace period18562026/10/09 17:38:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018572026/10/09 17:38:39 INFO Vacuumed table table=pending_closures18582026/10/09 17:38:39 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18592026/10/09 17:38:39 INFO Vacuumed table table=pending_objects18602026/10/09 17:38:39 INFO Vacuumed table table=multipart_uploads18612026/10/09 17:38:39 INFO Vacuumed table table=closures18622026/10/09 17:38:39 INFO Vacuumed table table=objects18632026/10/09 17:38:39 WARN Request failed, retrying attempt=2 backoff=214.397302ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18642026/10/09 17:38:39 WARN Request failed, retrying attempt=3 backoff=364.062286ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18652026/10/09 17:38:39 INFO Received uploads request method=POST path=/api/pending_closures18662026/10/09 17:38:40 WARN Request failed, retrying attempt=4 backoff=739.463976ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1867--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.24s)1868=== CONT TestClientErrorHandling/InvalidAuthToken1869=== NAME TestOrphanedObjectsGC1870 orphaned_objects_gc_test.go:287: GC Test Summary:1871 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1872 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1873 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1874 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1875 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1876--- PASS: TestOrphanedObjectsGC (6.41s)1877=== CONT TestResolveDBConnectionString/flag_wins1878=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1879=== CONT TestResolveDBConnectionString/nothing_configured1880=== CONT TestResolveDBConnectionString/missing_file_is_an_error1881=== CONT TestResolveDBConnectionString/file_when_flag_empty1882=== CONT TestCacheConfigHandler/full_config,_no_issuer1883=== CONT TestCacheConfigHandler/no_signing_keys1884=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1885=== CONT TestCacheConfigHandler/no_cache_url_configured1886--- PASS: TestCacheConfigHandler (0.00s)1887 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1888 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1889 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1890 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1891=== CONT TestServerTLSConfig/no_client_CA1892=== CONT TestServerTLSConfig/not_a_PEM_file1893--- PASS: TestResolveDBConnectionString (0.01s)1894 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1895 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1896 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1897 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1898 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1899=== CONT TestServerTLSConfig/missing_CA_file1900--- PASS: TestServerTLSConfig (0.01s)1901 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1902 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1903 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1904=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19052026/10/09 17:38:40 INFO Received uploads request method=POST path=/api/pending_closures19062026/10/09 17:38:40 INFO Received cleanup request method=DELETE path=/api/pending_closures19072026/10/09 17:38:40 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""19082026/10/09 17:38:40 INFO Aborted multipart uploads count=0 kept=119092026/10/09 17:38:40 INFO Received cleanup request method=DELETE path=/api/pending_closures19102026/10/09 17:38:40 INFO Aborted multipart uploads count=1 kept=01911--- PASS: TestMultipartCleanup (6.53s)1912=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1913--- PASS: TestMetricsInventory (6.51s)1914=== CONT TestPendingClosureWriteTimeout/empty1915=== CONT TestPendingClosureWriteTimeout/670k_objects1916=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19172026/10/09 17:38:40 WARN Request failed, retrying attempt=5 backoff=1.721626376s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19182026/10/09 17:38:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19192026/10/09 17:38:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1920--- PASS: TestService_NativeMTLS (6.65s)1921=== CONT TestPendingClosureWriteTimeout/400_objects1922=== CONT TestProxyWriteTimeout/narinfo1923=== CONT TestProxyWriteTimeout/10_GiB_nar1924=== CONT TestProxyWriteTimeout/unknown_size1925=== CONT TestProxyWriteTimeout/1_GiB_nar1926--- PASS: TestProxyWriteTimeout (0.00s)1927 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1928 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1929 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1930 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1931=== CONT TestService_RequireScope_OIDC/builder_may_write1932=== CONT TestService_RequireScope_OIDC/reader_may_read1933=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1934=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19352026/10/09 17:38:40 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]1936=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1937=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1938=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1939=== CONT TestService_RequireScope_OIDC/writer_implies_read1940=== CONT TestService_RequireScope_OIDC/reader_may_not_write1941=== CONT TestService_RequireScope_OIDC/static_token_may_write1942=== CONT TestService_RequireScope_OIDC/static_token_may_admin1943=== CONT TestService_RequireScope_OIDC/ops_may_admin1944=== CONT TestService_RequireScope_OIDC/ops_may_not_write1945=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1946=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1947--- PASS: TestService_RequireScope_OIDC (6.46s)1948 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1962=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1963=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19642026/10/09 17:38:40 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]1965=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19662026/10/09 17:38:40 WARN Authentication failed token_preview=eyJhbGciOi...6hek-1FnLA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1967--- PASS: TestService_AuthMiddleware_OIDC (6.61s)1968 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1969 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1970 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1971 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1972=== NAME TestPinProtectsFromGC1973 client_integration_test.go:840: Pin successfully protected closure from garbage collection1974--- PASS: TestPinProtectsFromGC (12.47s)1975=== NAME TestNARDeduplicationMetadataUploadBug1976 metadata_upload_test.go:48: First store path: /private/var/tb/7/scratch/294f6b975c717bac/build/TestNARDeduplicationMetadataUploadBug1655309812/001/store/3bxf7f7jfr5dsjbf0yr52537kvsy6rqy-file1.txt19772026/10/09 17:38:41 INFO Received push request method=POST path=/api/pushes19782026/10/09 17:38:41 INFO Received complete push request method=POST path=/api/pushes/1/complete19792026/10/09 17:38:41 INFO Completed push id=1 objects=4 duration=42.913042ms19802026/10/09 17:38:41 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19812026/10/09 17:38:41 INFO Completed upload id=2 objects=2 duration=1.040333ms19822026/10/09 17:38:41 INFO Received push request method=POST path=/api/pushes1983--- PASS: TestMetricsCommit (7.09s)19842026/10/09 17:38:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19852026/10/09 17:38:41 INFO Uploading 3bxf7f7jfr5dsjbf0yr52537kvsy6rqy-file1.txt (160B)19862026/10/09 17:38:41 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19872026/10/09 17:38:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19882026/10/09 17:38:41 WARN Failed to register uploaded object key=3bxf7f7jfr5dsjbf0yr52537kvsy6rqy.ls error="server returned 404: 404 page not found\n"19892026/10/09 17:38:41 INFO Signed narinfos id=1 count=119902026/10/09 17:38:41 INFO Uploading 1 narinfos19912026/10/09 17:38:41 INFO Received complete push request method=POST path=/api/pushes/1/complete19922026/10/09 17:38:41 WARN Failed to register uploaded object key=3bxf7f7jfr5dsjbf0yr52537kvsy6rqy.narinfo error="server returned 404: 404 page not found\n"19932026/10/09 17:38:41 INFO Completed push id=1 objects=3 duration=29.297083ms19942026/10/09 17:38:41 INFO Upload complete. (252ms)1995=== NAME TestNARDeduplicationMetadataUploadBug1996 metadata_upload_test.go:54: Retrieved narinfo from S3:1997 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestNARDeduplicationMetadataUploadBug1655309812/001/store/3bxf7f7jfr5dsjbf0yr52537kvsy6rqy-file1.txt1998 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1999 Compression: zstd2000 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2001 NarSize: 1602002 References: 2003 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2004 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2005 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2006 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2007--- PASS: TestService_healthCheckHandler (6.96s)2008=== NAME TestNARDeduplicationMetadataUploadBug2009 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/7/scratch/294f6b975c717bac/build/TestNARDeduplicationMetadataUploadBug1655309812/001/store/w4117i0zdan9siaqy9sijlhzcxa9pdnh-file2.txt20102026/10/09 17:38:42 INFO Received push request method=POST path=/api/pushes20112026/10/09 17:38:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20122026/10/09 17:38:42 WARN readiness check failed error="closed pool"2013--- PASS: TestService_readinessHandler (6.85s)20142026/10/09 17:38:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20152026/10/09 17:38:42 WARN Failed to register uploaded object key=w4117i0zdan9siaqy9sijlhzcxa9pdnh.ls error="server returned 404: 404 page not found\n"20162026/10/09 17:38:42 INFO Signed narinfos id=2 count=120172026/10/09 17:38:42 INFO Uploading 1 narinfos20182026/10/09 17:38:42 INFO Received complete push request method=POST path=/api/pushes/2/complete20192026/10/09 17:38:42 WARN Failed to register uploaded object key=w4117i0zdan9siaqy9sijlhzcxa9pdnh.narinfo error="server returned 404: 404 page not found\n"20202026/10/09 17:38:42 INFO Completed push id=2 objects=3 duration=1.270791ms20212026/10/09 17:38:42 INFO Upload complete. (180ms)2022=== NAME TestNARDeduplicationMetadataUploadBug2023 metadata_upload_test.go:76: Retrieved narinfo from S3:2024 StorePath: /private/var/tb/7/scratch/294f6b975c717bac/build/TestNARDeduplicationMetadataUploadBug1655309812/001/store/w4117i0zdan9siaqy9sijlhzcxa9pdnh-file2.txt2025 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2026 Compression: zstd2027 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2028 NarSize: 1602029 References: 2030 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2031 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2032 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2033 {"version":1,"root":{"type":"regular","size":44}}2034--- PASS: TestNARDeduplicationMetadataUploadBug (7.82s)2035--- PASS: TestService_Rustfstest (6.98s)20362026/10/09 17:38:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/09 17:38:42 WARN Request failed, retrying attempt=2 backoff=217.082833ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20382026/10/09 17:38:42 INFO Received uploads request method=POST path=/api/pending_closures20392026/10/09 17:38:42 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20402026/10/09 17:38:42 INFO Received uploads request method=POST path=/api/pending_closures20412026/10/09 17:38:42 WARN Request failed, retrying attempt=3 backoff=369.007677ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2042--- PASS: TestPresignedUploadRegisteredBeforeCommit (7.32s)20432026/10/09 17:38:43 INFO Received uploads request method=POST path=/api/pending_closures20442026/10/09 17:38:43 WARN Request failed, retrying attempt=4 backoff=848.153574ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20452026/10/09 17:38:43 WARN Rate limiter enabled after throttle name=s3-test rate=520462026/10/09 17:38:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2047=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2048 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102049 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002050--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.36s)20512026/10/09 17:38:43 INFO Received uploads request method=POST path=/api/pending_closures20522026/10/09 17:38:43 INFO Aborted multipart uploads count=0 kept=020532026/10/09 17:38:43 WARN Force mode enabled - objects will be deleted immediately without grace period20542026/10/09 17:38:43 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=020552026/10/09 17:38:43 INFO Vacuumed table table=pending_closures20562026/10/09 17:38:43 INFO Vacuumed table table=pending_objects20572026/10/09 17:38:43 INFO Vacuumed table table=multipart_uploads20582026/10/09 17:38:43 INFO Vacuumed table table=closures20592026/10/09 17:38:43 INFO Vacuumed table table=objects20602026/10/09 17:38:43 INFO Received uploads request method=POST path=/api/pending_closures20612026/10/09 17:38:43 INFO Aborted multipart uploads count=0 kept=020622026/10/09 17:38:43 WARN Force mode enabled - objects will be deleted immediately without grace period20632026/10/09 17:38:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020642026/10/09 17:38:43 INFO Vacuumed table table=pending_closures20652026/10/09 17:38:43 INFO Vacuumed table table=pending_objects20662026/10/09 17:38:43 INFO Vacuumed table table=multipart_uploads20672026/10/09 17:38:43 INFO Vacuumed table table=closures20682026/10/09 17:38:43 INFO Vacuumed table table=objects2069--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2070 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.94s)2071 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.93s)20722026/10/09 17:38:44 WARN Request failed, retrying attempt=5 backoff=1.634549126s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20732026/10/09 17:38:44 INFO Aborted multipart uploads count=0 kept=020742026/10/09 17:38:44 WARN Force mode enabled - objects will be deleted immediately without grace period20752026-10-09 17:38:44.466 UTC [60967] ERROR: canceling statement due to user request20762026-10-09 17:38:44.466 UTC [60967] STATEMENT: -- name: MarkStaleObjects :execrows2077 WITH RECURSIVE ct AS (2078 SELECT timezone('UTC', now()) AS now2079 ),2080 closure_reach AS (2081 -- Start with all closure keys2082 SELECT o.key, o.refs2083 FROM objects o2084 INNER JOIN closures c ON o.key = c.key2085 UNION2086 -- Recursively add all referenced objects2087 SELECT o.key, o.refs2088 FROM objects o2089 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2090 ),2091 reachable_objects AS (2092 SELECT DISTINCT key FROM closure_reach2093 ),2094 stale_objects AS (2095 SELECT o.key2096 FROM objects AS o, ct2097 WHERE2098 NOT EXISTS (2099 SELECT 12100 FROM reachable_objects ro2101 WHERE ro.key = o.key2102 )2103 AND NOT EXISTS (2104 SELECT 12105 FROM pending_objects AS po2106 WHERE po.key = o.key2107 )2108 AND o.deleted_at IS NULL -- Only mark fresh objects2109 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2110 FOR UPDATE2111 )2112 UPDATE objects2113 SET2114 deleted_at = ct.now,2115 first_deleted_at = COALESCE(first_deleted_at, ct.now)2116 FROM stale_objects, ct2117 WHERE objects.key = stale_objects.key2118 2119=== NAME TestOrphanedObjectsGCStressTest2120 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2121 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21222026/10/09 17:38:44 INFO Aborted multipart uploads count=0 kept=021232026/10/09 17:38:44 WARN Force mode enabled - objects will be deleted immediately without grace period21242026/10/09 17:38:44 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:63585/bucket96/?delete=\": context canceled"2125--- PASS: TestGCEndsOnShutdown (0.00s)2126 --- PASS: TestGCEndsOnShutdown/before_the_run (6.95s)2127 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (6.76s)2128 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.86s)21292026/10/09 17:38:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21302026/10/09 17:38:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTM3YTQzOTgtYzczNi00MWZiLTlmY2EtODQ4Zjk1MDU5MzliLmY1MDllNDY1LTZiZDgtNDlkOC04YzBkLWQ3YjM0YjBmOWExYXgxNzkxNTY3NTIzMTQwMTQ4MDAw parts=1221312026/10/09 17:38:44 INFO Received uploads request method=POST path=/api/pending_closures2132--- PASS: TestCompletedNarNotReofferedAcrossClosures (9.25s)21332026/10/09 17:38:45 INFO Aborted multipart uploads count=1 kept=021342026-10-09 17:38:45.194 UTC [59085] LOG: checkpoint starting: wal21352026/10/09 17:38:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21362026/10/09 17:38:45 INFO Received cleanup request method=DELETE path=/api/pending_closures21372026/10/09 17:38:45 INFO Aborted multipart uploads count=1 kept=02138--- PASS: TestPendingCleanupUsesOneCutoff (12.17s)21392026/10/09 17:38:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21402026/10/09 17:38:45 INFO Received uploads request method=POST path=/api/pending_closures2141--- PASS: TestObjectStatsLargeCommit (11.73s)21422026/10/09 17:38:45 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 127.0.0.1:19999: connect: connection refused"21432026/10/09 17:38:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2144=== NAME TestOrphanedObjectsGCStressTest2145 orphaned_objects_gc_test.go:503: Stress test completed successfully:2146 orphaned_objects_gc_test.go:504: - Active objects preserved: 202147 orphaned_objects_gc_test.go:505: - Objects deleted: 2102148 orphaned_objects_gc_test.go:506: - Total GC'd: 2102149--- PASS: TestOrphanedObjectsGCStressTest (13.68s)2150--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2151 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.53s)2152 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.38s)21532026/10/09 17:38:45 WARN Request failed, retrying attempt=2 backoff=182.925935ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21542026/10/09 17:38:46 WARN Request failed, retrying attempt=3 backoff=433.950369ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2155--- PASS: TestPendingClosureWriteTimeout (0.00s)2156 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2157 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2158 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2159 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (5.73s)21602026/10/09 17:38:46 WARN Request failed, retrying attempt=4 backoff=761.335658ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21612026/10/09 17:38:47 WARN Request failed, retrying attempt=5 backoff=1.532526086s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21622026/10/09 17:38:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21632026/10/09 17:38:48 WARN Request failed, retrying attempt=2 backoff=204.912832ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21642026/10/09 17:38:49 WARN Request failed, retrying attempt=3 backoff=391.064149ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21652026/10/09 17:38:49 WARN Request failed, retrying attempt=4 backoff=748.288441ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21662026/10/09 17:38:50 WARN Request failed, retrying attempt=5 backoff=1.721034418s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2167--- PASS: TestClientErrorHandling (0.00s)2168 --- PASS: TestClientErrorHandling/InvalidStorePath (6.07s)2169 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.23s)2170 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.04s)2171PASS21722026-10-09 17:38:52.160 UTC [59080] LOG: received smart shutdown request21732026-10-09 17:38:52.162 UTC [59080] LOG: background worker "logical replication launcher" (PID 59090) exited with exit code 121742026-10-09 17:38:53.420 UTC [59085] LOG: checkpoint complete: wrote 12257 buffers (74.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=7.399 s, sync=0.660 s, total=8.226 s; sync files=34382, longest=0.001 s, average=0.001 s; distance=533306 kB, estimate=533306 kB; lsn=0/230DE9A0, redo lsn=0/2205B76021752026-10-09 17:38:53.421 UTC [59085] LOG: shutting down21762026-10-09 17:38:53.421 UTC [59085] LOG: checkpoint starting: shutdown immediate21772026-10-09 17:38:53.423 UTC [59085] LOG: checkpoint complete: wrote 458 buffers (2.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.002 s, sync=0.001 s, total=0.003 s; sync files=15, longest=0.001 s, average=0.001 s; distance=16908 kB, estimate=481666 kB; lsn=0/230DEA18, redo lsn=0/230DEA1821782026-10-09 17:38:53.431 UTC [59080] LOG: database system is shut down2179Running OIDC tests...2180=== RUN TestAudienceForIssuer2181=== PAUSE TestAudienceForIssuer2182=== RUN TestGlobMatch2183=== PAUSE TestGlobMatch2184=== RUN TestValidateToken_ValidToken2185=== PAUSE TestValidateToken_ValidToken2186=== RUN TestValidateToken_WrongAudience2187=== PAUSE TestValidateToken_WrongAudience2188=== RUN TestValidateToken_Expired2189=== PAUSE TestValidateToken_Expired2190=== RUN TestValidateToken_BoundClaimsMismatch2191=== PAUSE TestValidateToken_BoundClaimsMismatch2192=== RUN TestValidateToken_BoundSubjectMismatch2193=== PAUSE TestValidateToken_BoundSubjectMismatch2194=== RUN TestValidateToken_MultipleProviders2195=== PAUSE TestValidateToken_MultipleProviders2196=== RUN TestValidateToken_NoMatchingProvider2197=== PAUSE TestValidateToken_NoMatchingProvider2198=== RUN TestValidateToken_KubernetesServiceAccount2199=== PAUSE TestValidateToken_KubernetesServiceAccount2200=== RUN TestNewValidator_KubernetesRequiresCA2201=== PAUSE TestNewValidator_KubernetesRequiresCA2202=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2203=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2204=== RUN TestPins_ReservedForMatchingRule2205=== PAUSE TestPins_ReservedForMatchingRule2206=== RUN TestPins_TopLevelShorthand2207=== PAUSE TestPins_TopLevelShorthand2208=== RUN TestPins_ConfigValidation2209=== PAUSE TestPins_ConfigValidation2210=== RUN TestScopes_LegacyProviderDefaultsToWrite2211=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2212=== RUN TestScopes_Rules2213=== PAUSE TestScopes_Rules2214=== RUN TestScopes_ConfigValidation2215=== PAUSE TestScopes_ConfigValidation2216=== CONT TestAudienceForIssuer2217--- PASS: TestAudienceForIssuer (0.00s)2218=== CONT TestValidateToken_BoundClaimsMismatch2219=== CONT TestValidateToken_WrongAudience2220=== CONT TestValidateToken_ValidToken2221=== CONT TestGlobMatch2222=== RUN TestGlobMatch/foo_foo2223=== PAUSE TestGlobMatch/foo_foo2224=== CONT TestPins_ConfigValidation2225=== RUN TestGlobMatch/foo_bar2226=== PAUSE TestGlobMatch/foo_bar2227=== RUN TestGlobMatch/*_2228=== CONT TestScopes_ConfigValidation2229=== CONT TestScopes_Rules2230=== CONT TestScopes_LegacyProviderDefaultsToWrite2231=== CONT TestPins_ReservedForMatchingRule2232--- PASS: TestPins_ConfigValidation (0.00s)2233=== CONT TestPins_TopLevelShorthand2234--- PASS: TestScopes_ConfigValidation (0.00s)2235=== CONT TestValidateToken_MultipleProviders2236=== CONT TestValidateToken_NoMatchingProvider2237=== CONT TestValidateToken_Expired2238=== CONT TestValidateToken_BoundSubjectMismatch2239=== CONT TestValidateToken_KubernetesServiceAccount2240=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2241=== CONT TestNewValidator_KubernetesRequiresCA2242=== PAUSE TestGlobMatch/*_2243=== RUN TestGlobMatch/*_anything2244=== PAUSE TestGlobMatch/*_anything2245=== RUN TestGlobMatch/foo*_foo2246=== PAUSE TestGlobMatch/foo*_foo2247=== RUN TestGlobMatch/foo*_foobar2248=== PAUSE TestGlobMatch/foo*_foobar2249=== RUN TestGlobMatch/foo*_bar2250=== PAUSE TestGlobMatch/foo*_bar2251=== RUN TestGlobMatch/*bar_bar2252=== PAUSE TestGlobMatch/*bar_bar2253=== RUN TestGlobMatch/*bar_foobar2254=== PAUSE TestGlobMatch/*bar_foobar2255=== RUN TestGlobMatch/*bar_foo2256=== PAUSE TestGlobMatch/*bar_foo2257=== RUN TestGlobMatch/foo*bar_foobar2258=== PAUSE TestGlobMatch/foo*bar_foobar2259=== RUN TestGlobMatch/foo*bar_foo123bar2260=== PAUSE TestGlobMatch/foo*bar_foo123bar2261=== RUN TestGlobMatch/foo*bar_foobarbaz2262=== PAUSE TestGlobMatch/foo*bar_foobarbaz2263=== RUN TestGlobMatch/*/*_foo/bar2264=== PAUSE TestGlobMatch/*/*_foo/bar2265=== RUN TestGlobMatch/*/*_foo2266=== PAUSE TestGlobMatch/*/*_foo2267=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2268=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2269=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02270=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02271=== RUN TestGlobMatch/refs/*/main_refs/heads/main2272=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2273=== RUN TestGlobMatch/fo?_foo2274=== PAUSE TestGlobMatch/fo?_foo2275=== RUN TestGlobMatch/fo?_fo2276=== PAUSE TestGlobMatch/fo?_fo2277=== RUN TestGlobMatch/fo?_fooo2278=== PAUSE TestGlobMatch/fo?_fooo2279=== RUN TestGlobMatch/?oo_foo2280=== PAUSE TestGlobMatch/?oo_foo2281=== RUN TestGlobMatch/?oo_boo2282=== PAUSE TestGlobMatch/?oo_boo2283=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2284=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2285=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2286=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2287=== CONT TestGlobMatch/foo_foo2288=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2289=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2290=== CONT TestGlobMatch/?oo_boo2291=== CONT TestGlobMatch/?oo_foo2292=== CONT TestGlobMatch/fo?_fooo2293=== CONT TestGlobMatch/fo?_fo2294=== CONT TestGlobMatch/fo?_foo2295=== CONT TestGlobMatch/refs/*/main_refs/heads/main2296=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02297=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2298=== CONT TestGlobMatch/*/*_foo2299=== CONT TestGlobMatch/*/*_foo/bar2300=== CONT TestGlobMatch/foo*bar_foobarbaz2301=== CONT TestGlobMatch/foo*bar_foo123bar2302=== CONT TestGlobMatch/foo*bar_foobar2303=== CONT TestGlobMatch/*bar_foo2304=== CONT TestGlobMatch/*bar_foobar2305=== CONT TestGlobMatch/*bar_bar2306=== CONT TestGlobMatch/foo*_bar2307=== CONT TestGlobMatch/foo*_foobar2308=== CONT TestGlobMatch/foo*_foo2309=== CONT TestGlobMatch/*_anything2310=== CONT TestGlobMatch/*_2311=== CONT TestGlobMatch/foo_bar2312--- PASS: TestGlobMatch (0.05s)2313 --- PASS: TestGlobMatch/foo_foo (0.00s)2314 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2315 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2316 --- PASS: TestGlobMatch/?oo_boo (0.00s)2317 --- PASS: TestGlobMatch/?oo_foo (0.00s)2318 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2319 --- PASS: TestGlobMatch/fo?_fo (0.00s)2320 --- PASS: TestGlobMatch/fo?_foo (0.00s)2321 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2322 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2323 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2324 --- PASS: TestGlobMatch/*/*_foo (0.00s)2325 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2326 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2327 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2328 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2329 --- PASS: TestGlobMatch/*bar_foo (0.00s)2330 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2331 --- PASS: TestGlobMatch/*bar_bar (0.00s)2332 --- PASS: TestGlobMatch/foo*_bar (0.00s)2333 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2334 --- PASS: TestGlobMatch/foo*_foo (0.00s)2335 --- PASS: TestGlobMatch/*_anything (0.00s)2336 --- PASS: TestGlobMatch/*_ (0.00s)2337 --- PASS: TestGlobMatch/foo_bar (0.00s)23382026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63939/oidc23392026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63938/oidc2340--- PASS: TestPins_ReservedForMatchingRule (0.06s)2341--- PASS: TestValidateToken_Expired (0.05s)23422026/10/09 17:38:55 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323432026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63944/oidc2344--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)23452026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63947/oidc2346--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)2347--- PASS: TestPins_TopLevelShorthand (0.08s)23482026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63952/oidc2349--- PASS: TestValidateToken_WrongAudience (0.10s)23502026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63954/oidc2351--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)23522026/10/09 17:38:55 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6395823532026/10/09 17:38:55 http: TLS handshake error from 127.0.0.1:63957: remote error: tls: bad certificate2354--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)23552026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63960/oidc2356--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)2357--- PASS: TestValidateToken_ValidToken (0.12s)23582026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63963/oidc2359--- PASS: TestScopes_Rules (0.15s)23602026/10/09 17:38:55 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63950/oidc23612026/10/09 17:38:55 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:63965/oidc2362--- PASS: TestValidateToken_MultipleProviders (0.15s)23632026/10/09 17:38:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63968/oidc2364--- PASS: TestValidateToken_BoundSubjectMismatch (0.17s)23652026/10/09 17:38:55 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:63951/oidc2366--- PASS: TestValidateToken_NoMatchingProvider (0.18s)2367PASS2368Running hook tests...2369=== RUN TestSendPathsEmpty2370=== PAUSE TestSendPathsEmpty2371=== RUN TestQueueEnqueueAndFetch2372=== PAUSE TestQueueEnqueueAndFetch2373=== RUN TestQueueDeduplication2374=== PAUSE TestQueueDeduplication2375=== RUN TestQueueRemove2376=== PAUSE TestQueueRemove2377=== RUN TestQueueFetchBatchLimit2378=== PAUSE TestQueueFetchBatchLimit2379=== RUN TestQueueRetryMovesToBack2380=== PAUSE TestQueueRetryMovesToBack2381=== RUN TestQueueFetchRemoveLifecycle2382=== PAUSE TestQueueFetchRemoveLifecycle2383=== RUN TestQueueConcurrentWriters2384=== PAUSE TestQueueConcurrentWriters2385=== RUN TestQueueRemoveLargeClosure2386=== PAUSE TestQueueRemoveLargeClosure2387=== RUN TestServerClientIntegration2388--- PASS: TestServerClientIntegration (0.00s)2389=== RUN TestServerQueueError23902026/10/09 17:38:55 ERROR Failed to queue paths error="permission denied" count=12391--- PASS: TestServerQueueError (0.00s)2392=== RUN TestGetListenerSocketActivation2393 server_test.go:146: systemd socket activation does not exist on darwin2394--- SKIP: TestGetListenerSocketActivation (0.00s)2395=== RUN TestDrainIsolatesPoisonPath2396=== PAUSE TestDrainIsolatesPoisonPath2397=== RUN TestRunNotBlockedByPoisonHead2398=== PAUSE TestRunNotBlockedByPoisonHead2399=== RUN TestDrainGivesUpWhenServerDown2400=== PAUSE TestDrainGivesUpWhenServerDown2401=== RUN TestFailedPathPrunedByLaterClosure2402=== PAUSE TestFailedPathPrunedByLaterClosure2403=== RUN TestWorkerUploadsAndRemoves2404=== PAUSE TestWorkerUploadsAndRemoves2405=== RUN TestWorkerSkipsGCdPaths2406=== PAUSE TestWorkerSkipsGCdPaths2407=== RUN TestWorkerPrunesClosureDeps2408=== PAUSE TestWorkerPrunesClosureDeps2409=== RUN TestDrainTimeout2410=== PAUSE TestDrainTimeout2411=== CONT TestSendPathsEmpty2412=== CONT TestWorkerUploadsAndRemoves2413=== CONT TestRunNotBlockedByPoisonHead2414--- PASS: TestSendPathsEmpty (0.00s)2415=== CONT TestWorkerPrunesClosureDeps2416=== CONT TestWorkerSkipsGCdPaths2417=== CONT TestDrainIsolatesPoisonPath2418=== CONT TestQueueRemoveLargeClosure2419=== CONT TestQueueConcurrentWriters2420=== CONT TestQueueFetchRemoveLifecycle2421=== CONT TestQueueRetryMovesToBack2422=== CONT TestQueueDeduplication2423=== CONT TestQueueEnqueueAndFetch2424=== CONT TestQueueFetchBatchLimit2425=== CONT TestDrainGivesUpWhenServerDown2426=== CONT TestQueueRemove2427=== CONT TestFailedPathPrunedByLaterClosure2428=== CONT TestDrainTimeout24292026/10/09 17:38:55 INFO Upload queue status pending=224302026/10/09 17:38:55 INFO Uploading batch count=224312026/10/09 17:38:55 INFO Upload queue status pending=324322026/10/09 17:38:55 INFO Uploading batch count=124332026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=124342026/10/09 17:38:55 INFO Uploading batch count=424352026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=424362026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainIsolatesPoisonPath3377323881/002/bbb24372026/10/09 17:38:55 INFO Uploading batch count=224382026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=224392026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/a24402026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/b2441--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2442--- PASS: TestQueueRetryMovesToBack (0.01s)24432026/10/09 17:38:55 INFO Upload queue status pending=224442026/10/09 17:38:55 INFO Uploading batch count=124452026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=124462026/10/09 17:38:55 INFO Uploading batch count=124472026/10/09 17:38:55 INFO Upload queue status pending=224482026/10/09 17:38:55 INFO Uploading batch count=224492026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=224502026/10/09 17:38:55 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestWorkerSkipsGCdPaths1721220327/002/nonexistent24512026/10/09 17:38:55 INFO Uploading batch count=224522026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/c2453--- PASS: TestQueueRemove (0.01s)2454--- PASS: TestQueueEnqueueAndFetch (0.01s)24552026/10/09 17:38:55 INFO Uploading batch count=124562026/10/09 17:38:55 INFO Uploading batch count=124572026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=124582026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/d2459--- PASS: TestQueueDeduplication (0.01s)24602026/10/09 17:38:55 INFO Uploading batch count=124612026/10/09 17:38:55 INFO Uploading batch count=124622026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=124632026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=124642026/10/09 17:38:55 INFO Uploading batch count=224652026/10/09 17:38:55 ERROR Upload failed error="upload failed" count=224662026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/e2467--- PASS: TestQueueFetchBatchLimit (0.01s)24682026/10/09 17:38:55 ERROR Drain finished with paths left in queue remaining=124692026/10/09 17:38:55 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/294f6b975c717bac/build/TestDrainGivesUpWhenServerDown1642845425/002/f24702026/10/09 17:38:55 INFO Uploading batch count=124712026/10/09 17:38:55 ERROR Drain finished with paths left in queue remaining=1024722026/10/09 17:38:55 INFO Uploading batch count=12473--- PASS: TestDrainIsolatesPoisonPath (0.02s)2474--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2475--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2476--- PASS: TestWorkerUploadsAndRemoves (0.03s)2477--- PASS: TestWorkerPrunesClosureDeps (0.03s)2478--- PASS: TestWorkerSkipsGCdPaths (0.04s)2479--- PASS: TestQueueRemoveLargeClosure (0.05s)2480--- PASS: TestQueueConcurrentWriters (0.12s)24812026/10/09 17:38:55 ERROR Upload failed error="context deadline exceeded" count=224822026/10/09 17:38:55 ERROR Drain finished with paths left in queue remaining=42483--- PASS: TestDrainTimeout (0.22s)24842026/10/09 17:38:56 INFO Uploading batch count=124852026/10/09 17:38:56 INFO Uploading batch count=124862026/10/09 17:38:56 INFO Uploading batch count=124872026/10/09 17:38:56 ERROR Upload failed error="upload failed" count=124882026/10/09 17:38:56 INFO Uploading batch count=124892026/10/09 17:38:56 ERROR Upload failed error="upload failed" count=124902026/10/09 17:38:56 INFO Uploading batch count=124912026/10/09 17:38:56 ERROR Upload failed error="upload failed" count=124922026/10/09 17:38:56 INFO Uploading batch count=124932026/10/09 17:38:56 ERROR Upload failed error="upload failed" count=124942026/10/09 17:38:56 ERROR Drain finished with paths left in queue remaining=12495--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2496PASS2497Running signing tests...2498=== RUN TestExternalSigner2499=== PAUSE TestExternalSigner2500=== RUN TestExternalSignerWrongPublicKey2501=== PAUSE TestExternalSignerWrongPublicKey2502=== RUN TestExternalSignerErrors2503=== PAUSE TestExternalSignerErrors2504=== RUN TestExternalSignerRestartsAfterCrash2505=== PAUSE TestExternalSignerRestartsAfterCrash2506=== RUN TestExternalSignerProgramErrorKeepsProcess2507=== PAUSE TestExternalSignerProgramErrorKeepsProcess2508=== RUN TestExternalSignerClose2509=== PAUSE TestExternalSignerClose2510=== RUN TestExternalSignerRejectsInvalidPublicKey2511=== PAUSE TestExternalSignerRejectsInvalidPublicKey2512=== RUN TestExternalSignerCancellation2513=== PAUSE TestExternalSignerCancellation2514=== RUN TestGenerateFingerprint2515=== PAUSE TestGenerateFingerprint2516=== RUN TestParseSigningKey2517=== PAUSE TestParseSigningKey2518=== RUN TestSign2519=== PAUSE TestSign2520=== RUN TestSignBatch2521=== PAUSE TestSignBatch2522=== RUN TestNilKeyPublicKey2523=== PAUSE TestNilKeyPublicKey2524=== RUN TestSignErrors2525=== PAUSE TestSignErrors2526=== CONT TestExternalSigner2527=== CONT TestExternalSignerCancellation2528=== CONT TestSignBatch2529=== CONT TestExternalSignerProgramErrorKeepsProcess2530=== CONT TestExternalSignerErrors2531=== CONT TestExternalSignerRestartsAfterCrash2532=== CONT TestNilKeyPublicKey2533--- PASS: TestNilKeyPublicKey (0.00s)2534=== CONT TestExternalSignerWrongPublicKey2535=== RUN TestExternalSignerErrors/wrong_signatures_shape2536=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2537=== RUN TestExternalSignerErrors/unrequested_key2538=== PAUSE TestExternalSignerErrors/unrequested_key2539=== RUN TestExternalSignerErrors/wrong_signature_name2540=== CONT TestParseSigningKey2541=== RUN TestParseSigningKey/valid_32-byte_key2542=== CONT TestSign2543=== CONT TestGenerateFingerprint2544=== CONT TestExternalSignerRejectsInvalidPublicKey2545=== CONT TestExternalSignerClose2546=== CONT TestSignErrors2547=== PAUSE TestExternalSignerErrors/wrong_signature_name2548=== PAUSE TestParseSigningKey/valid_32-byte_key2549=== RUN TestGenerateFingerprint/basic_with_references2550=== PAUSE TestGenerateFingerprint/basic_with_references2551=== RUN TestExternalSignerRejectsInvalidPublicKey/#002552=== RUN TestExternalSignerErrors/invalid_signature_base642553=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2554=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002555=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2556=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2557=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2558=== PAUSE TestExternalSignerErrors/invalid_signature_base642559=== RUN TestExternalSignerErrors/wrong_signature_length2560=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2561=== PAUSE TestExternalSignerErrors/wrong_signature_length2562=== RUN TestGenerateFingerprint/no_references2563=== RUN TestExternalSignerErrors/missing_signatures2564=== PAUSE TestGenerateFingerprint/no_references2565=== RUN TestParseSigningKey/no_colon2566=== PAUSE TestExternalSignerErrors/missing_signatures2567=== PAUSE TestParseSigningKey/no_colon2568=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2569=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2570=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2571=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2572=== RUN TestGenerateFingerprint/invalid_nar_hash_length2573=== RUN TestExternalSignerErrors/missing_signature_name2574=== RUN TestParseSigningKey/empty_name2575=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2576=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2577=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2578=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2579=== PAUSE TestExternalSignerErrors/missing_signature_name2580=== PAUSE TestParseSigningKey/empty_name2581=== RUN TestGenerateFingerprint/invalid_store_path_prefix2582=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2583=== RUN TestParseSigningKey/invalid_base642584=== PAUSE TestParseSigningKey/invalid_base642585=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2586=== RUN TestParseSigningKey/wrong_length2587=== RUN TestGenerateFingerprint/invalid_reference_prefix2588=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2589=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2590=== CONT TestGenerateFingerprint/basic_with_references2591=== CONT TestGenerateFingerprint/invalid_nar_hash_length2592=== CONT TestGenerateFingerprint/invalid_store_path_prefix2593=== CONT TestExternalSignerRejectsInvalidPublicKey/#002594=== CONT TestGenerateFingerprint/no_references2595=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2596=== PAUSE TestParseSigningKey/wrong_length2597=== CONT TestParseSigningKey/valid_32-byte_key2598=== CONT TestParseSigningKey/wrong_length2599=== CONT TestParseSigningKey/no_colon2600=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2601=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2602=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2603=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2604=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2605--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2606 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2607 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2608 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2609 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2610 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2611=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2612=== CONT TestGenerateFingerprint/invalid_reference_prefix2613--- PASS: TestGenerateFingerprint (0.00s)2614 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2615 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2616 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2617 --- PASS: TestGenerateFingerprint/no_references (0.00s)2618 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2619 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2620 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2621=== CONT TestParseSigningKey/empty_name2622=== CONT TestParseSigningKey/invalid_base642623=== RUN TestExternalSignerErrors/program_error2624=== PAUSE TestExternalSignerErrors/program_error2625--- PASS: TestSign (0.00s)2626=== RUN TestSignErrors/nil_key2627=== PAUSE TestSignErrors/nil_key2628--- PASS: TestParseSigningKey (0.00s)2629 --- PASS: TestParseSigningKey/wrong_length (0.00s)2630 --- PASS: TestParseSigningKey/no_colon (0.00s)2631 --- PASS: TestParseSigningKey/empty_name (0.00s)2632 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2633 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2634 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2635=== RUN TestExternalSignerErrors/exit_at_startup2636=== PAUSE TestExternalSignerErrors/exit_at_startup2637=== RUN TestSignErrors/nil_narinfo2638=== PAUSE TestSignErrors/nil_narinfo2639=== RUN TestSignErrors/invalid_narinfo2640=== PAUSE TestSignErrors/invalid_narinfo2641=== RUN TestSignErrors/canceled2642=== PAUSE TestSignErrors/canceled2643=== CONT TestSignErrors/nil_key2644=== RUN TestExternalSignerErrors/invalid_JSON2645=== PAUSE TestExternalSignerErrors/invalid_JSON2646=== RUN TestExternalSignerErrors/null2647=== PAUSE TestExternalSignerErrors/null2648=== RUN TestExternalSignerErrors/too_few_signatures2649=== CONT TestSignErrors/invalid_narinfo2650=== PAUSE TestExternalSignerErrors/too_few_signatures2651=== CONT TestSignErrors/canceled2652=== CONT TestSignErrors/nil_narinfo2653--- PASS: TestSignBatch (0.00s)2654=== RUN TestExternalSignerErrors/exit_on_request2655--- PASS: TestSignErrors (0.00s)2656 --- PASS: TestSignErrors/nil_key (0.00s)2657 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2658 --- PASS: TestSignErrors/canceled (0.00s)2659 --- PASS: TestSignErrors/nil_narinfo (0.00s)2660=== PAUSE TestExternalSignerErrors/exit_on_request2661=== RUN TestExternalSignerErrors/wrong_shape2662=== PAUSE TestExternalSignerErrors/wrong_shape2663=== RUN TestExternalSignerErrors/wrong_id2664=== PAUSE TestExternalSignerErrors/wrong_id2665=== RUN TestExternalSignerErrors/null_signatures2666=== PAUSE TestExternalSignerErrors/null_signatures2667=== CONT TestExternalSignerErrors/wrong_signatures_shape2668=== CONT TestExternalSignerErrors/exit_at_startup2669=== CONT TestExternalSignerErrors/exit_on_request2670=== CONT TestExternalSignerErrors/null2671=== CONT TestExternalSignerErrors/invalid_JSON2672=== CONT TestExternalSignerErrors/wrong_signature_length2673=== CONT TestExternalSignerErrors/missing_signature_name2674=== CONT TestExternalSignerErrors/null_signatures2675=== CONT TestExternalSignerErrors/wrong_shape2676=== CONT TestExternalSignerErrors/invalid_signature_base642677=== CONT TestExternalSignerErrors/wrong_signature_name2678=== CONT TestExternalSignerErrors/missing_signatures2679=== CONT TestExternalSignerErrors/too_few_signatures2680=== CONT TestExternalSignerErrors/unrequested_key2681=== CONT TestExternalSignerErrors/program_error2682=== CONT TestExternalSignerErrors/wrong_id2683--- PASS: TestExternalSigner (0.23s)2684--- PASS: TestExternalSignerWrongPublicKey (0.41s)2685--- PASS: TestExternalSignerRestartsAfterCrash (0.62s)2686/private/var/tb/7/scratch/294f6b975c717bac/build/TestExternalSignerRestartsAfterCrash1552086319/001/sign program: line 7: /private/var/tb/7/scratch/294f6b975c717bac/build/TestExternalSignerRestartsAfterCrash1552086319/001/sign program.starts: No such file or directory2687--- PASS: TestExternalSignerClose (0.79s)2688--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.99s)2689--- PASS: TestExternalSignerCancellation (1.19s)2690--- PASS: TestExternalSignerErrors (0.00s)2691 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.36s)2692 --- PASS: TestExternalSignerErrors/missing_signatures (1.55s)2693 --- PASS: TestExternalSignerErrors/null (1.74s)2694 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.93s)2695 --- PASS: TestExternalSignerErrors/wrong_shape (2.13s)2696 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.32s)2697 --- PASS: TestExternalSignerErrors/program_error (2.51s)2698 --- PASS: TestExternalSignerErrors/too_few_signatures (2.71s)2699 --- PASS: TestExternalSignerErrors/exit_at_startup (2.90s)2700 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.09s)2701 --- PASS: TestExternalSignerErrors/unrequested_key (3.29s)2702 --- PASS: TestExternalSignerErrors/exit_on_request (3.48s)2703 --- PASS: TestExternalSignerErrors/null_signatures (3.67s)2704 --- PASS: TestExternalSignerErrors/invalid_JSON (3.85s)2705 --- PASS: TestExternalSignerErrors/missing_signature_name (4.03s)2706 --- PASS: TestExternalSignerErrors/wrong_id (4.23s)2707PASS2708Running OpenBao signer tests...2709=== RUN TestSign2710=== PAUSE TestSign2711=== RUN TestSignErrors2712=== PAUSE TestSignErrors2713=== RUN TestServe2714=== PAUSE TestServe2715=== RUN TestServeRejectsGarbage2716=== PAUSE TestServeRejectsGarbage2717=== CONT TestSign2718=== CONT TestServe2719=== CONT TestServeRejectsGarbage2720=== CONT TestSignErrors2721=== RUN TestSignErrors/invalid_json2722=== PAUSE TestSignErrors/invalid_json2723=== RUN TestSignErrors/no_prefix2724=== PAUSE TestSignErrors/no_prefix2725--- PASS: TestServeRejectsGarbage (0.00s)2726=== RUN TestSignErrors/invalid_base642727=== PAUSE TestSignErrors/invalid_base642728=== RUN TestSignErrors/http_error2729=== PAUSE TestSignErrors/http_error2730=== CONT TestSignErrors/invalid_json2731=== CONT TestSignErrors/http_error2732=== CONT TestSignErrors/invalid_base642733=== CONT TestSignErrors/no_prefix2734--- PASS: TestServe (0.00s)2735--- PASS: TestSign (0.00s)2736--- PASS: TestSignErrors (0.00s)2737 --- PASS: TestSignErrors/http_error (0.00s)2738 --- PASS: TestSignErrors/no_prefix (0.00s)2739 --- PASS: TestSignErrors/invalid_json (0.00s)2740 --- PASS: TestSignErrors/invalid_base64 (0.00s)2741PASS