niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #426
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.27s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestSetClientTLS118=== CONT TestScriptTokenEmptyCommand119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer121=== CONT TestScriptTokenScriptFails122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing1282026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=server-test rate=51292026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:64755130=== CONT TestFileTokenReadsAndCaches131=== CONT TestStaticToken132--- PASS: TestStaticToken (0.00s)133=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess134=== CONT TestSetClientTLSErrors135--- PASS: TestDoServerRequestAttachesToken (0.00s)136=== CONT TestRateLimiterFeedback137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== PAUSE TestRateLimiterFeedback/429_enables_limiter139=== RUN TestRateLimiterFeedback/503_enables_limiter140=== PAUSE TestRateLimiterFeedback/503_enables_limiter141=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter142=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter143=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter144=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter145=== CONT TestPathInfoCACompatibility146=== RUN TestPathInfoCACompatibility/null_ca_field147=== PAUSE TestPathInfoCACompatibility/null_ca_field148=== RUN TestPathInfoCACompatibility/old_string_format_-_text149=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text150=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive152=== RUN TestPathInfoCACompatibility/new_structured_format_-_text153=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text154=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method155=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1562026/10/25 16:24:46 WARN Rate limiter backed off name=server-test rate=51572026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:64755158=== CONT TestStreamPushIsolatesFailures159=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method160=== CONT TestStreamPushStopsWhenCanceled161=== CONT TestGetStorePathHash162=== CONT TestConvertHashToNix32163=== CONT TestClientSignaturesByStorePath164=== CONT TestEncodeNixBase32WithRealHash165=== CONT TestEncodeNixBase32166=== RUN TestGetStorePathHash/valid_store_path167=== RUN TestConvertHashToNix32/SRI_format_to_Nix32168=== CONT TestShellSplitErrors169=== CONT TestStreamPushBatchesUnderLoad170=== RUN TestEncodeNixBase32/test_string_hash171=== PAUSE TestGetStorePathHash/valid_store_path1722026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=server-test rate=5173=== PAUSE TestEncodeNixBase32/test_string_hash1742026/10/25 16:24:46 ERROR Upload failed error="bad path" count=3175=== RUN TestEncodeNixBase32/empty_input176=== CONT TestStreamPushRequestLine177=== CONT TestStreamPushGivesUpOnDeadServer178=== CONT TestDumpPathWriterError179=== CONT TestResolveStorePath180=== RUN TestSetClientTLSErrors/missing_cert_file181--- PASS: TestFileTokenReadsAndCaches (0.00s)182=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32183=== PAUSE TestSetClientTLSErrors/missing_cert_file184--- PASS: TestFileTokenMissing (0.00s)185--- PASS: TestFileTokenEmpty (0.00s)186=== CONT TestParsePathInfoJSONMultiplePaths1872026/10/25 16:24:46 ERROR Upload failed error="connection refused" count=201882026/10/25 16:24:46 ERROR Server seems unavailable, giving up on batch untried=171892026/10/25 16:24:46 ERROR Upload failed error=boom count=1190--- PASS: TestStreamPushStopsWhenCanceled (0.00s)191--- PASS: TestClientSignaturesByStorePath (0.00s)192--- PASS: TestEncodeNixBase32WithRealHash (0.00s)193=== RUN TestConvertHashToNix32/already_Nix32_format194=== PAUSE TestConvertHashToNix32/already_Nix32_format195=== CONT TestStreamPushReportsSkippedPaths196=== RUN TestConvertHashToNix32/invalid_format197=== PAUSE TestConvertHashToNix32/invalid_format198=== CONT TestStreamPushReportsSignatures199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestEncodeNixBase32/empty_input201=== CONT TestStreamPushReportsEveryPath202=== CONT TestParsePathInfoJSON203=== RUN TestSetClientTLSErrors/missing_key_file204=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths205=== CONT TestPathInfoHashCompatibility206=== CONT TestUploadMultipart_PartsInParallel207=== CONT TestDumpPathSingleFile208=== RUN TestSetClientTLS/rejects_connection_without_client_cert209--- PASS: TestScriptTokenScriptFails (0.01s)210--- PASS: TestShellSplitErrors (0.00s)211=== CONT TestSupersededNARStillUploadsListing212=== RUN TestSupersededNARStillUploadsListing/small_NAR2132026/10/25 16:24:46 ERROR Upload failed error=boom count=1214--- PASS: TestStreamPushIsolatesFailures (0.00s)215--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)216--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)217--- PASS: TestStreamPushReportsSkippedPaths (0.00s)218--- PASS: TestResolveStorePath (0.00s)219--- PASS: TestStreamPushReportsSignatures (0.00s)220=== CONT TestPartSizeForNAR221=== RUN TestPartSizeForNAR/zero_stays_at_minimum222=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum223=== RUN TestPartSizeForNAR/small_stays_at_minimum224=== PAUSE TestPartSizeForNAR/small_stays_at_minimum225=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum226=== CONT TestDumpPathMatchesNix227=== CONT TestFilterOversizedClosures228=== RUN TestFilterOversizedClosures/no_limit_keeps_everything229=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== CONT TestUploadMultipart_FailedPartBufferNotReused234=== PAUSE TestFilterOversizedClosures/all_closures_skipped235=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun236=== RUN TestParsePathInfoJSON/Nix_format237=== PAUSE TestSetClientTLSErrors/missing_key_file238=== CONT TestUploadMultipart_SupersededByPeer239=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error243=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum244--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)245--- PASS: TestStreamPushReportsEveryPath (0.01s)246=== PAUSE TestSupersededNARStillUploadsListing/small_NAR247=== CONT TestCaseHackSuffix248=== PAUSE TestParsePathInfoJSON/Nix_format249=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)250=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA251=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA252=== RUN TestSetClientTLS/preserves_debug_logging_transport253=== PAUSE TestSetClientTLS/preserves_debug_logging_transport254--- PASS: TestScriptTokenEmptyToken (0.02s)255=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica256=== CONT TestRegisterUploadedObjectReusesConnections257=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error258=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts259=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths260=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths261=== CONT TestDoWithRetry_FinalResponseBodyReadable2622026/10/25 16:24:46 INFO Garbage collection started263=== RUN TestSetClientTLSErrors/missing_ca_file264=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts265=== RUN TestSupersededNARStillUploadsListing/dump_cut_short266=== RUN TestParsePathInfoJSON/Lix_format267=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error268=== PAUSE TestParsePathInfoJSON/Lix_format269=== RUN TestUploadMultipart_SupersededByPeer/exists270=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon271=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon272=== PAUSE TestSetClientTLSErrors/missing_ca_file273=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2742026/10/25 16:24:46 INFO Garbage collection started275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI276=== RUN TestPartSizeForNAR/1_TiB277=== RUN TestSetClientTLSErrors/invalid_ca_file278=== PAUSE TestSetClientTLSErrors/invalid_ca_file279=== PAUSE TestUploadMultipart_SupersededByPeer/exists280=== CONT TestShellSplit281--- PASS: TestShellSplit (0.00s)282=== CONT TestRetryTimeoutOutlastsMaxRetries283=== RUN TestParsePathInfoJSON/empty_input284=== RUN TestUploadMultipart_SupersededByPeer/missing285=== PAUSE TestUploadMultipart_SupersededByPeer/missing286=== PAUSE TestParsePathInfoJSON/empty_input287=== RUN TestParsePathInfoJSON/whitespace_only288=== PAUSE TestParsePathInfoJSON/whitespace_only289=== RUN TestParsePathInfoJSON/invalid_JSON290=== PAUSE TestParsePathInfoJSON/invalid_JSON291=== CONT TestRateLimiterFeedback/429_enables_limiter292=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short293=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails294=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails295=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter296=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter297=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512299=== PAUSE TestPartSizeForNAR/1_TiB300=== RUN TestPartSizeForNAR/5_TiB_S3_max_object301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestPartSizeForNAR/capped_at_5_GiB303=== PAUSE TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestRateLimiterFeedback/503_enables_limiter305--- PASS: TestScriptTokenBadJSON (0.03s)306=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry307=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error308=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error309=== CONT TestPathInfoCACompatibility/null_ca_field310=== CONT TestPathInfoCACompatibility/new_structured_format_-_text311=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive312=== CONT TestPathInfoCACompatibility/old_string_format_-_text313=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method314--- PASS: TestPathInfoCACompatibility (0.00s)315 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)318 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)319 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)320=== CONT TestConvertHashToNix32/invalid_format321=== CONT TestConvertHashToNix32/SRI_format_to_Nix32322=== CONT TestConvertHashToNix32/already_Nix32_format323--- PASS: TestConvertHashToNix32 (0.00s)324 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)325 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)326 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)327=== CONT TestEncodeNixBase32/test_string_hash328=== CONT TestEncodeNixBase32/empty_input329--- PASS: TestEncodeNixBase32 (0.00s)330 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)331 --- PASS: TestEncodeNixBase32/empty_input (0.00s)332=== CONT TestFilterOversizedClosures/no_limit_keeps_everything333=== CONT TestFilterOversizedClosures/all_closures_skipped3342026/10/25 16:24:46 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=50335=== CONT TestSetClientTLS/rejects_connection_without_client_cert336=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3372026/10/25 16:24:46 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=20003382026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=server-test rate=53392026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:647753402026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=server-test rate=53412026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:647733422026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:64771343=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA344--- PASS: TestFilterOversizedClosures (0.00s)345 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)346 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)347 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)348=== CONT TestSetClientTLS/preserves_debug_logging_transport3492026/10/25 16:24:46 WARN Rate limiter backed off name=server-test rate=53502026/10/25 16:24:46 WARN Rate limiter backed off name=server-test rate=5351--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)352=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths353=== CONT TestSetClientTLSErrors/missing_cert_file354=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths355--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)356 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)357 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)358=== CONT TestSetClientTLSErrors/missing_ca_file359=== CONT TestSetClientTLSErrors/invalid_ca_file360=== CONT TestUploadMultipart_SupersededByPeer/exists361=== CONT TestSetClientTLSErrors/missing_key_file362--- PASS: TestSetClientTLSErrors (0.03s)363 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)365 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)366 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)367=== CONT TestParsePathInfoJSON/Nix_format368=== CONT TestParsePathInfoJSON/invalid_JSON369=== CONT TestUploadMultipart_SupersededByPeer/missing370=== CONT TestSupersededNARStillUploadsListing/small_NAR3712026/10/25 16:24:46 INFO Uploading abc-hello (1.0GB)3722026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:647713732026/10/25 16:24:46 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=0374=== CONT TestParsePathInfoJSON/whitespace_only375=== CONT TestParsePathInfoJSON/empty_input376=== CONT TestParsePathInfoJSON/Lix_format377--- PASS: TestParsePathInfoJSON (0.02s)378 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)379 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)380 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)381 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)382 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)383=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)384=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3852026/10/25 16:24:46 INFO Uploading abc-hello (1.0GB)3862026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=s3-test rate=53872026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:648643882026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=server-test rate=53892026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:64858390=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3912026/10/25 16:24:46 WARN Rate limiter enabled after throttle name=s3-test rate=53922026/10/25 16:24:46 WARN Garbage collection finished on another replica. Its statistics are not available here393--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)394=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI395=== CONT TestPartSizeForNAR/zero_stays_at_minimum3962026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:64771397=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon398=== CONT TestPartSizeForNAR/capped_at_5_GiB399=== CONT TestPartSizeForNAR/5_TiB_S3_max_object400=== CONT TestPartSizeForNAR/1_TiB401=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts402=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum403=== CONT TestPartSizeForNAR/small_stays_at_minimum404--- PASS: TestPartSizeForNAR (0.02s)405 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)406 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)407 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)408 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)409 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)410 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)411 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)412=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512413--- PASS: TestPathInfoHashCompatibility (0.02s)414 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)416 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)417 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)418=== CONT TestGetStorePathHash/valid_store_path419=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error420=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error421=== CONT TestGetStorePathHash/basename_without_hyphen_should_error422--- PASS: TestGetStorePathHash (0.02s)423 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)424 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)425 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)426 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)427--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)428 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)429 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)430--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)4312026/10/25 16:24:46 WARN Rate limiter backed off name=server-test rate=54322026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:64771433--- PASS: TestRateLimiterFeedback (0.00s)434 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)435 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)436 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)437 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.03s)438--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)4392026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:647714402026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:647714412026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:64771442--- PASS: TestStreamPushRequestLine (0.06s)4432026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:647714442026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:647714452026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:647714462026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:647714472026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:647714482026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:647714492026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:647714502026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:647714512026/10/25 16:24:46 http: TLS handshake error from 127.0.0.1:64784: read tcp 127.0.0.1:64762->127.0.0.1:64784: use of closed network connection452--- PASS: TestSetClientTLS (0.03s)453 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)454 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.05s)455 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.07s)4562026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:647714572026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:647714582026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:647714592026/10/25 16:24:46 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:64771460--- PASS: TestStreamPushBatchesUnderLoad (0.11s)461--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.09s)462--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.12s)463--- PASS: TestRegisterUploadedObjectReusesConnections (0.10s)464--- PASS: TestScriptTokenCachesUntilRefresh (0.14s)465--- PASS: TestDumpPathWriterError (0.14s)466--- PASS: TestDumpPathSingleFile (0.16s)4672026/10/25 16:24:46 INFO Uploading abc-hello (1.0GB)468--- PASS: TestCaseHackSuffix (0.21s)4692026/10/25 16:24:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:64873/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:64873/part/24702026/10/25 16:24:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:64873/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:64873/part/34712026/10/25 16:24:46 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"472--- PASS: TestDumpPathMatchesNix (0.32s)473--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.59s)474--- PASS: TestUploadMultipart_PartsInParallel (0.64s)475--- PASS: TestSupersededNARStillUploadsListing (0.02s)476 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)477 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.03s)478 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.68s)4792026/10/25 16:24:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:64756/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:64756/api/uploads/complete4802026/10/25 16:24:47 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4812026/10/25 16:24:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:64756/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:64756/api/uploads/complete4822026/10/25 16:24:47 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4832026/10/25 16:24:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:64756/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:64756/api/uploads/complete4842026/10/25 16:24:47 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)486--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)487PASS488Running server tests...489The files belonging to this database system will be owned by user "_tribuchetbld2".490This user must also own the server process.491492The database cluster will be initialized with locale "C".493The default database encoding has accordingly been set to "SQL_ASCII".494The default text search configuration will be set to "english".495496Data page checksums are enabled.497498creating directory /private/var/tb/2/scratch/97c492293bae0eec/build/postgres1637804406/data ... ok499creating subdirectories ... ok500selecting dynamic shared memory implementation ... posix501selecting default "max_connections" ... 100502selecting default "shared_buffers" ... 128MB503selecting default time zone ... UTC504creating configuration files ... ok505running bootstrap script ... ok506performing post-bootstrap initialization ... ok507syncing data to disk ... ok508509initdb: warning: enabling "trust" authentication for local connections510initdb: 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.511512Success. You can now start the database server using:513514 pg_ctl -D /private/var/tb/2/scratch/97c492293bae0eec/build/postgres1637804406/data -l logfile start5155162026-10-25 16:24:51.266 UTC [35079] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5172026-10-25 16:24:51.267 UTC [35079] LOG: listening on Unix socket "/private/var/tb/2/scratch/97c492293bae0eec/build/postgres1637804406/.s.PGSQL.5432"5182026-10-25 16:24:51.276 UTC [35103] LOG: database system was shut down at 2026-10-25 16:24:51 UTC5192026-10-25 16:24:51.279 UTC [35079] LOG: database system is ready to accept connections520/private/var/tb/2/scratch/97c492293bae0eec/build/postgres1637804406:5432 - accepting connections521{"timestamp":"2026-10-25T16:24:56.296802Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"36427d3f-2d1d-4d0c-a0af-48d9fe8d5ef6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}522{"timestamp":"2026-10-25T16:24:56.400084Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3ca4f235-78a9-474d-800c-dffe210045ad","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}523=== RUN TestService_AuthMiddleware524=== PAUSE TestService_AuthMiddleware525=== RUN TestService_AuthMiddleware_MTLSProxyHeader526=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader527=== RUN TestService_AuthMiddleware_MTLSBoundSubjects528=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects529=== RUN TestService_ReadAuthMiddleware530=== PAUSE TestService_ReadAuthMiddleware531=== RUN TestService_AuthMiddleware_OIDC532=== PAUSE TestService_AuthMiddleware_OIDC533=== RUN TestService_RequireScope_OIDC534=== PAUSE TestService_RequireScope_OIDC535=== RUN TestService_ReadScope_PublicByDefault536=== PAUSE TestService_ReadScope_PublicByDefault537=== RUN TestCacheConfigHandler538=== PAUSE TestCacheConfigHandler539=== RUN TestCacheStatsHandler540=== PAUSE TestCacheStatsHandler541=== RUN TestClientCADerivations542=== PAUSE TestClientCADerivations543=== RUN TestClientErrorHandling544=== PAUSE TestClientErrorHandling545=== RUN TestClientIntegration546=== PAUSE TestClientIntegration547=== RUN TestClientMultipleUploads548=== PAUSE TestClientMultipleUploads549=== RUN TestClientWithDependencies550=== PAUSE TestClientWithDependencies551=== RUN TestClientSharedPathCommittedMidPush552=== PAUSE TestClientSharedPathCommittedMidPush553=== RUN TestPinProtectsFromGC554=== PAUSE TestPinProtectsFromGC555=== RUN TestClientPushesUseOnePush556=== PAUSE TestClientPushesUseOnePush557=== RUN TestClientFallsBackToClosures558=== PAUSE TestClientFallsBackToClosures559=== RUN TestDeleteClosuresRacingPins560=== PAUSE TestDeleteClosuresRacingPins561=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock562=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock563=== RUN TestResolveDBConnectionString564=== PAUSE TestResolveDBConnectionString565=== RUN TestConnectWaitsForAPeerMigration566=== PAUSE TestConnectWaitsForAPeerMigration567=== RUN TestLeadElectsOneAndHandsOver568=== PAUSE TestLeadElectsOneAndHandsOver569=== RUN TestLeadIncumbentWinsAfterRestart5702026/10/25 16:24:57 INFO lead: acquired remote=192.0.2.1:12345712026/10/25 16:24:58 INFO lead: released remote=192.0.2.1:12345722026/10/25 16:24:58 INFO lead: acquired remote=192.0.2.1:12345732026/10/25 16:24:59 INFO lead: released remote=192.0.2.1:1234574--- PASS: TestLeadIncumbentWinsAfterRestart (3.00s)575=== RUN TestLeadIncumbentAnnouncesAtOnce576=== PAUSE TestLeadIncumbentAnnouncesAtOnce577=== RUN TestLeadEndsOnShutdown578=== PAUSE TestLeadEndsOnShutdown579=== RUN TestLeadEndsWhenItsConnectionHangs5802026/10/25 16:24:59 INFO lead: acquired remote=192.0.2.1:12345812026-10-25 16:25:01.182 UTC [37471] FATAL: terminating connection due to administrator command5822026/10/25 16:25:01 INFO lead: acquired remote=192.0.2.1:12345832026/10/25 16:25:02 WARN lead: lock connection lost error="timeout: context deadline exceeded"5842026/10/25 16:25:02 INFO lead: released remote=192.0.2.1:12345852026/10/25 16:25:02 INFO lead: released remote=192.0.2.1:1234586--- PASS: TestLeadEndsWhenItsConnectionHangs (3.08s)587=== RUN TestGCAdvisoryLockBlocksConcurrentRun588=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun589=== RUN TestGCBugBareHashReferences590=== PAUSE TestGCBugBareHashReferences591=== RUN TestGCMetrics592=== PAUSE TestGCMetrics593=== RUN TestPushDedupSurvivesConcurrentGC594=== PAUSE TestPushDedupSurvivesConcurrentGC595=== RUN TestDeduplicatedObjectsRecordedAsPending596=== PAUSE TestDeduplicatedObjectsRecordedAsPending597=== RUN TestGCSweepSkipsPendingObjects598=== PAUSE TestGCSweepSkipsPendingObjects599=== RUN TestTombstonedObjectOfferedWithoutWaiting600=== PAUSE TestTombstonedObjectOfferedWithoutWaiting601=== RUN TestGCSweepDeliversEachKeyOnce602=== PAUSE TestGCSweepDeliversEachKeyOnce603=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection604=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection605=== RUN TestForceGCDuringPushOffersSweptObject606=== PAUSE TestForceGCDuringPushOffersSweptObject607=== RUN TestFailedS3DeleteKeepsTombstone608=== PAUSE TestFailedS3DeleteKeepsTombstone609=== RUN TestSweepSkipsRowsLockedByPush610=== PAUSE TestSweepSkipsRowsLockedByPush611=== RUN TestRegisterCompletedObjectNeedsPendingRow612=== PAUSE TestRegisterCompletedObjectNeedsPendingRow613=== RUN TestGetExistingObjectsLocksRows614=== PAUSE TestGetExistingObjectsLocksRows615=== RUN TestSweepRechecksPendingAfterLocking616=== PAUSE TestSweepRechecksPendingAfterLocking617=== RUN TestPushWaitsForSweepHoldingRow618=== PAUSE TestPushWaitsForSweepHoldingRow619=== RUN TestCommitRacingPendingCleanupKeepsObjects620=== PAUSE TestCommitRacingPendingCleanupKeepsObjects621=== RUN TestGCEndsOnShutdown622=== PAUSE TestGCEndsOnShutdown623=== RUN TestGCTaskStore_StartNew624=== PAUSE TestGCTaskStore_StartNew625=== RUN TestGCTaskStore_DeduplicateSameParams626=== PAUSE TestGCTaskStore_DeduplicateSameParams627=== RUN TestGCTaskStore_ConflictDifferentParams628=== PAUSE TestGCTaskStore_ConflictDifferentParams629=== RUN TestGCTaskStore_GetEmpty630=== PAUSE TestGCTaskStore_GetEmpty631=== RUN TestGCTaskStore_GetReturnsLatest632=== PAUSE TestGCTaskStore_GetReturnsLatest633=== RUN TestGCTaskStore_CompletedAllowsNewTask634=== PAUSE TestGCTaskStore_CompletedAllowsNewTask635=== RUN TestGCTaskStore_PhaseUpdates636=== PAUSE TestGCTaskStore_PhaseUpdates637=== RUN TestGCTaskStore_Fail638=== PAUSE TestGCTaskStore_Fail639=== RUN TestGracefulShutdownDrainsInflight640=== PAUSE TestGracefulShutdownDrainsInflight641=== RUN TestService_healthCheckHandler642=== PAUSE TestService_healthCheckHandler643=== RUN TestService_readinessHandler644=== PAUSE TestService_readinessHandler645=== RUN TestGenerateLandingPage646=== PAUSE TestGenerateLandingPage647=== RUN TestCacheConfigHandlerMaxNarSize648=== PAUSE TestCacheConfigHandlerMaxNarSize649=== RUN TestCreatePendingClosureRejectsOversizedNAR650=== PAUSE TestCreatePendingClosureRejectsOversizedNAR651=== RUN TestNARDeduplicationMetadataUploadBug652=== PAUSE TestNARDeduplicationMetadataUploadBug653=== RUN TestMetricsInventory654=== PAUSE TestMetricsInventory655=== RUN TestMetricsCommit656=== PAUSE TestMetricsCommit657=== RUN TestService_NativeMTLS658=== PAUSE TestService_NativeMTLS659=== RUN TestServerTLSConfig660=== PAUSE TestServerTLSConfig661=== RUN TestMultipartCleanup662=== PAUSE TestMultipartCleanup663=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded664=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded665=== RUN TestPendingCleanupUsesOneCutoff666=== PAUSE TestPendingCleanupUsesOneCutoff667=== RUN TestObjectStatsTrigger668=== PAUSE TestObjectStatsTrigger669=== RUN TestObjectStatsUpdatedOncePerCommit670=== PAUSE TestObjectStatsUpdatedOncePerCommit671=== RUN TestOrphanedObjectsGC672=== PAUSE TestOrphanedObjectsGC673=== RUN TestOrphanedObjectsGCStressTest674=== PAUSE TestOrphanedObjectsGCStressTest675=== RUN TestCreatePin_ReservedPins676=== PAUSE TestCreatePin_ReservedPins677=== RUN TestPresentReportsOnlyClosureRoots678=== PAUSE TestPresentReportsOnlyClosureRoots679=== RUN TestPresentRefreshesOnlyStaleClosures680=== PAUSE TestPresentRefreshesOnlyStaleClosures681=== RUN TestPresentNotReportedWhileGCDeletesClosure682=== PAUSE TestPresentNotReportedWhileGCDeletesClosure683=== RUN TestParseSingleRange684=== PAUSE TestParseSingleRange685=== RUN TestProxyHeadersOnlyTrustedOnSocket6862026/10/25 16:25:02 INFO Starting HTTP server address=127.0.0.1:649856872026/10/25 16:25:02 INFO Starting HTTP server address=proxy.sock6882026/10/25 16:25:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6892026/10/25 16:25:02 INFO Shutdown signal received, draining in-flight requests timeout=10s690--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.26s)691=== RUN TestIsValidCachePath692=== PAUSE TestIsValidCachePath693=== RUN TestReadProxyNarinfo694=== PAUSE TestReadProxyNarinfo695=== RUN TestReadProxyNarinfoAlreadyDecompressed696=== PAUSE TestReadProxyNarinfoAlreadyDecompressed697=== RUN TestReadProxyContentNegotiation698=== PAUSE TestReadProxyContentNegotiation699=== RUN TestReadProxyNarStreaming700=== PAUSE TestReadProxyNarStreaming701=== RUN TestReadProxy404702=== PAUSE TestReadProxy404703=== RUN TestReadProxyInvalidPath704=== PAUSE TestReadProxyInvalidPath705=== RUN TestReadProxyHead706=== PAUSE TestReadProxyHead707=== RUN TestReadProxyOutlastsServerWriteTimeout708=== PAUSE TestReadProxyOutlastsServerWriteTimeout709=== RUN TestReadProxyConditionalGet710=== PAUSE TestReadProxyConditionalGet711=== RUN TestReadProxyRootRedirectsToIndexHTML712=== PAUSE TestReadProxyRootRedirectsToIndexHTML713=== RUN TestReadProxyDisabled714=== PAUSE TestReadProxyDisabled715=== RUN TestReadRedirectNar716=== PAUSE TestReadRedirectNar717=== RUN TestReadRedirectKeepsNarinfoProxied718=== PAUSE TestReadRedirectKeepsNarinfoProxied719=== RUN TestReadProxyRangeRequest720=== PAUSE TestReadProxyRangeRequest721=== RUN TestReadRedirectUsesPublicS3URL722=== PAUSE TestReadRedirectUsesPublicS3URL723=== RUN TestPush_OverlappingRootsStoreOneRowPerKey724=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey725=== RUN TestPush_CompleteCommitsEveryRoot726=== PAUSE TestPush_CompleteCommitsEveryRoot727=== RUN TestPush_RepeatedRootCommitsOnce728=== PAUSE TestPush_RepeatedRootCommitsOnce729=== RUN TestPush_CompleteWaitsForCleanupOfThePush730=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush731=== RUN TestPush_RootsAreLockedInByteOrder732=== PAUSE TestPush_RootsAreLockedInByteOrder733=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit734=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit735=== RUN TestPush_RejectsBadRequests736=== PAUSE TestPush_RejectsBadRequests737=== RUN TestPush_SignsNarinfosOfItsPendingObjects738=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects739=== RUN TestRedundantMultipartUpload740=== PAUSE TestRedundantMultipartUpload741=== RUN TestCompleteMultipartUpload_ErrorButObjectExists742=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists743=== RUN TestCompletedNarNotReofferedAcrossClosures744=== PAUSE TestCompletedNarNotReofferedAcrossClosures745=== RUN TestPresignedUploadRegisteredBeforeCommit746=== PAUSE TestPresignedUploadRegisteredBeforeCommit747=== RUN TestService_Rustfstest748=== PAUSE TestService_Rustfstest749=== RUN TestParseSize750=== PAUSE TestParseSize751=== RUN TestSkippedUploadsHandler752=== PAUSE TestSkippedUploadsHandler753=== RUN TestSystemdListenerNotActivated754--- PASS: TestSystemdListenerNotActivated (0.00s)755=== RUN TestWatchdogBeatsWhenHealthy756--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)757=== RUN TestWatchdogSkipsWhenUnhealthy7582026/10/25 16:25:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/25 16:25:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/25 16:25:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 16:25:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 16:25:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 16:25:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 16:25:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 16:25:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 16:25:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/25 16:25:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"768--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)769=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle770=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle771=== RUN TestProxyWriteTimeout772=== PAUSE TestProxyWriteTimeout773=== RUN TestPendingClosureWriteTimeout774=== PAUSE TestPendingClosureWriteTimeout775=== RUN TestIsValidUploadKey776=== PAUSE TestIsValidUploadKey777=== RUN TestUploadHandlersRejectInvalidKeys778=== PAUSE TestUploadHandlersRejectInvalidKeys779=== RUN TestUploadHandlersRejectOversizedBody780=== PAUSE TestUploadHandlersRejectOversizedBody781=== RUN TestService_cleanupPendingClosuresHandler782=== PAUSE TestService_cleanupPendingClosuresHandler783=== RUN TestService_createPendingClosureHandler784=== PAUSE TestService_createPendingClosureHandler785=== RUN TestService_verifyS3Integrity786=== PAUSE TestService_verifyS3Integrity787=== RUN TestCompleteMultipartUnregistered788=== PAUSE TestCompleteMultipartUnregistered789=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT790=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT791=== CONT TestPresentNotReportedWhileGCDeletesClosure792=== CONT TestObjectStatsUpdatedOncePerCommit793=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale794=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale795=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh796=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh797=== CONT TestService_AuthMiddleware798=== CONT TestGCTaskStore_Fail799--- PASS: TestGCTaskStore_Fail (0.00s)800=== CONT TestGCTaskStore_PhaseUpdates801--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)802=== CONT TestGCTaskStore_CompletedAllowsNewTask803--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)804=== CONT TestGCTaskStore_GetReturnsLatest805--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)806=== CONT TestGCTaskStore_GetEmpty807--- PASS: TestGCTaskStore_GetEmpty (0.00s)808=== CONT TestGCTaskStore_ConflictDifferentParams809--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)810=== CONT TestGCTaskStore_DeduplicateSameParams811--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)812=== CONT TestGCTaskStore_StartNew813--- PASS: TestGCTaskStore_StartNew (0.00s)814=== CONT TestGCEndsOnShutdown815=== RUN TestGCEndsOnShutdown/before_the_run816=== PAUSE TestGCEndsOnShutdown/before_the_run817=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete818=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete819=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark820=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark821=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection822=== CONT TestCommitRacingPendingCleanupKeepsObjects823=== CONT TestPresentRefreshesOnlyStaleClosures824=== CONT TestCreatePin_ReservedPins825=== CONT TestPresentReportsOnlyClosureRoots826=== CONT TestOrphanedObjectsGC827=== CONT TestObjectStatsTrigger828=== CONT TestOrphanedObjectsGCStressTest829=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded830=== CONT TestMultipartCleanup831=== CONT TestServerTLSConfig832=== RUN TestServerTLSConfig/no_client_CA833=== PAUSE TestServerTLSConfig/no_client_CA834=== RUN TestServerTLSConfig/missing_CA_file835=== PAUSE TestServerTLSConfig/missing_CA_file836=== RUN TestServerTLSConfig/not_a_PEM_file837=== PAUSE TestServerTLSConfig/not_a_PEM_file838=== CONT TestService_NativeMTLS839=== CONT TestMetricsCommit840=== CONT TestMetricsInventory841=== CONT TestNARDeduplicationMetadataUploadBug842=== CONT TestCreatePendingClosureRejectsOversizedNAR8432026/10/25 16:25:03 INFO Received uploads request method=POST path=/api/pending_closures844--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)845=== CONT TestSweepRechecksPendingAfterLocking846=== CONT TestPushWaitsForSweepHoldingRow847=== CONT TestCacheConfigHandlerMaxNarSize848--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)849=== CONT TestGetExistingObjectsLocksRows850=== CONT TestGenerateLandingPage851--- PASS: TestGenerateLandingPage (0.00s)852=== CONT TestRegisterCompletedObjectNeedsPendingRow853=== CONT TestService_readinessHandler854=== CONT TestService_healthCheckHandler855=== CONT TestGracefulShutdownDrainsInflight856=== CONT TestPendingCleanupUsesOneCutoff8572026/10/25 16:25:03 INFO Starting HTTP server address=127.0.0.1:649878582026/10/25 16:25:03 INFO Shutdown signal received, draining in-flight requests timeout=10s859--- PASS: TestGracefulShutdownDrainsInflight (0.12s)860=== CONT TestSweepSkipsRowsLockedByPush8612026/10/25 16:25:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64989/oidc862--- PASS: TestPresentRefreshesOnlyStaleClosures (2.48s)863=== CONT TestFailedS3DeleteKeepsTombstone8642026/10/25 16:25:06 INFO Aborted multipart uploads count=0 kept=08652026/10/25 16:25:06 WARN Force mode enabled - objects will be deleted immediately without grace period8662026/10/25 16:25:06 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=08672026/10/25 16:25:06 INFO Vacuumed table table=pending_closures8682026/10/25 16:25:06 INFO Vacuumed table table=pending_objects8692026/10/25 16:25:06 INFO Vacuumed table table=multipart_uploads8702026/10/25 16:25:06 INFO Vacuumed table table=closures8712026/10/25 16:25:06 INFO Vacuumed table table=objects872--- PASS: TestSweepRechecksPendingAfterLocking (3.36s)873=== CONT TestForceGCDuringPushOffersSweptObject874=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows875=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows876=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check877=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check878=== CONT TestPush_CompleteWaitsForCleanupOfThePush879--- PASS: TestObjectStatsUpdatedOncePerCommit (3.66s)880=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT8812026/10/25 16:25:06 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"882--- PASS: TestService_AuthMiddleware (3.87s)883=== CONT TestCompleteMultipartUnregistered8842026/10/25 16:25:07 INFO Received uploads request method=POST path=/api/pending_closures885--- PASS: TestRegisterCompletedObjectNeedsPendingRow (4.18s)886=== CONT TestService_verifyS3Integrity8872026/10/25 16:25:07 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/25 16:25:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8892026/10/25 16:25:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"890--- PASS: TestService_NativeMTLS (4.47s)891=== CONT TestService_createPendingClosureHandler892--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (4.57s)893=== CONT TestService_cleanupPendingClosuresHandler894--- PASS: TestPushWaitsForSweepHoldingRow (4.57s)895=== CONT TestUploadHandlersRejectOversizedBody896=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure897=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure898=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart899=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart900=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts901=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts902=== CONT TestUploadHandlersRejectInvalidKeys903=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info904=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info905=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal906=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal907=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key908=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key909=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key910=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key911=== CONT TestIsValidUploadKey912=== RUN TestIsValidUploadKey/narinfo913=== PAUSE TestIsValidUploadKey/narinfo914=== RUN TestIsValidUploadKey/nar_zst915=== PAUSE TestIsValidUploadKey/nar_zst916=== RUN TestIsValidUploadKey/nar_xz917=== PAUSE TestIsValidUploadKey/nar_xz918=== RUN TestIsValidUploadKey/nar_plain919=== PAUSE TestIsValidUploadKey/nar_plain920=== RUN TestIsValidUploadKey/listing921=== PAUSE TestIsValidUploadKey/listing922=== RUN TestIsValidUploadKey/build_log923=== PAUSE TestIsValidUploadKey/build_log924=== RUN TestIsValidUploadKey/build_log_home-manager_file925=== PAUSE TestIsValidUploadKey/build_log_home-manager_file926=== RUN TestIsValidUploadKey/build_log_plus_in_name927=== PAUSE TestIsValidUploadKey/build_log_plus_in_name928=== RUN TestIsValidUploadKey/build_log_question_mark929=== PAUSE TestIsValidUploadKey/build_log_question_mark930=== RUN TestIsValidUploadKey/build_log_equals931=== PAUSE TestIsValidUploadKey/build_log_equals932=== RUN TestIsValidUploadKey/realisation933=== PAUSE TestIsValidUploadKey/realisation934=== RUN TestIsValidUploadKey/realisation_plus_in_output935=== PAUSE TestIsValidUploadKey/realisation_plus_in_output936=== RUN TestIsValidUploadKey/nix-cache-info937=== PAUSE TestIsValidUploadKey/nix-cache-info938=== RUN TestIsValidUploadKey/index.html939=== PAUSE TestIsValidUploadKey/index.html940=== RUN TestIsValidUploadKey/narinfo_key,_nar_type941=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type942=== RUN TestIsValidUploadKey/nar_key,_narinfo_type943=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type944=== RUN TestIsValidUploadKey/listing_key,_narinfo_type945=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type946=== RUN TestIsValidUploadKey/traversal947=== PAUSE TestIsValidUploadKey/traversal948=== RUN TestIsValidUploadKey/traversal_nar949=== PAUSE TestIsValidUploadKey/traversal_nar950=== RUN TestIsValidUploadKey/absolute951=== PAUSE TestIsValidUploadKey/absolute952=== RUN TestIsValidUploadKey/empty_key953=== PAUSE TestIsValidUploadKey/empty_key954=== RUN TestIsValidUploadKey/unknown_type955=== PAUSE TestIsValidUploadKey/unknown_type956=== CONT TestPendingClosureWriteTimeout957=== RUN TestPendingClosureWriteTimeout/empty958=== PAUSE TestPendingClosureWriteTimeout/empty959=== RUN TestPendingClosureWriteTimeout/400_objects960=== PAUSE TestPendingClosureWriteTimeout/400_objects961=== RUN TestPendingClosureWriteTimeout/670k_objects962=== PAUSE TestPendingClosureWriteTimeout/670k_objects963=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline964=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline965=== CONT TestProxyWriteTimeout966=== RUN TestProxyWriteTimeout/narinfo967=== PAUSE TestProxyWriteTimeout/narinfo968=== RUN TestProxyWriteTimeout/1_GiB_nar969=== PAUSE TestProxyWriteTimeout/1_GiB_nar970=== RUN TestProxyWriteTimeout/10_GiB_nar971=== PAUSE TestProxyWriteTimeout/10_GiB_nar972=== RUN TestProxyWriteTimeout/unknown_size973=== PAUSE TestProxyWriteTimeout/unknown_size974=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle975--- PASS: TestPresentReportsOnlyClosureRoots (5.01s)976=== CONT TestSkippedUploadsHandler9772026/10/25 16:25:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000978--- PASS: TestSkippedUploadsHandler (0.00s)979=== CONT TestParseSize980--- PASS: TestParseSize (0.00s)981=== CONT TestService_Rustfstest9822026/10/25 16:25:08 INFO Received uploads request method=POST path=/api/pending_closures9832026/10/25 16:25:08 INFO Received cleanup request method=DELETE path=/api/pending_closures9842026/10/25 16:25:08 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9852026/10/25 16:25:08 INFO Aborted multipart uploads count=0 kept=19862026/10/25 16:25:08 INFO Received cleanup request method=DELETE path=/api/pending_closures9872026/10/25 16:25:08 INFO Aborted multipart uploads count=1 kept=0988--- PASS: TestMultipartCleanup (5.42s)989=== CONT TestPresignedUploadRegisteredBeforeCommit990--- PASS: TestGetExistingObjectsLocksRows (5.47s)991=== CONT TestCompletedNarNotReofferedAcrossClosures9922026/10/25 16:25:09 INFO Aborted multipart uploads count=0 kept=09932026/10/25 16:25:09 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/10/25 16:25:09 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=09952026/10/25 16:25:09 INFO Vacuumed table table=pending_closures9962026/10/25 16:25:09 INFO Vacuumed table table=pending_objects9972026/10/25 16:25:09 INFO Vacuumed table table=multipart_uploads9982026/10/25 16:25:09 INFO Vacuumed table table=closures9992026/10/25 16:25:09 INFO Vacuumed table table=objects10002026/10/25 16:25:09 WARN readiness check failed error="closed pool"1001--- PASS: TestService_readinessHandler (6.39s)1002=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1003--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.42s)1004=== CONT TestRedundantMultipartUpload10052026/10/25 16:25:09 INFO Received uploads request method=POST path=/api/pending_closures1006--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.91s)1007=== CONT TestPush_SignsNarinfosOfItsPendingObjects1008--- PASS: TestObjectStatsTrigger (7.96s)1009=== CONT TestPush_RejectsBadRequests1010=== NAME TestOrphanedObjectsGC1011 orphaned_objects_gc_test.go:287: GC Test Summary:1012 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1013 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1014 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1015 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1016 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1017--- PASS: TestOrphanedObjectsGC (8.19s)1018=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1019=== NAME TestNARDeduplicationMetadataUploadBug1020 metadata_upload_test.go:48: First store path: /private/var/tb/2/scratch/97c492293bae0eec/build/TestNARDeduplicationMetadataUploadBug2807763793/001/store/0fiw3fcghabvdjx6797ifpaspbxih6sx-file1.txt10212026/10/25 16:25:11 INFO Received uploads request method=POST path=/api/pending_closures10222026/10/25 16:25:11 INFO Received uploads request method=POST path=/api/pending_closures10232026/10/25 16:25:11 INFO Received push request method=POST path=/api/pushes10242026/10/25 16:25:11 INFO Received cleanup request method=DELETE path=/api/pending_closures10252026/10/25 16:25:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10262026/10/25 16:25:11 INFO Uploading 0fiw3fcghabvdjx6797ifpaspbxih6sx-file1.txt (160B)10272026/10/25 16:25:11 WARN Failed to register uploaded object key=0fiw3fcghabvdjx6797ifpaspbxih6sx.ls error="server returned 404: 404 page not found\n"10282026/10/25 16:25:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10292026/10/25 16:25:11 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10302026/10/25 16:25:11 INFO Signed narinfos id=1 count=110312026/10/25 16:25:11 INFO Uploading 1 narinfos10322026/10/25 16:25:11 INFO Received complete push request method=POST path=/api/pushes/1/complete10332026/10/25 16:25:11 WARN Failed to register uploaded object key=0fiw3fcghabvdjx6797ifpaspbxih6sx.narinfo error="server returned 404: 404 page not found\n"10342026/10/25 16:25:11 INFO Received push request method=POST path=/api/pushes10352026/10/25 16:25:11 INFO Completed push id=1 objects=3 duration=30.7775ms10362026/10/25 16:25:11 INFO Upload complete. (414ms)1037 metadata_upload_test.go:54: Retrieved narinfo from S3:1038 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestNARDeduplicationMetadataUploadBug2807763793/001/store/0fiw3fcghabvdjx6797ifpaspbxih6sx-file1.txt1039 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1040 Compression: zstd1041 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1042 NarSize: 1601043 References: 1044 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1045 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1046 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1047 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10482026/10/25 16:25:11 INFO Received complete push request method=POST path=/api/pushes/1/complete10492026/10/25 16:25:12 INFO Completed push id=1 objects=4 duration=78.926958ms10502026/10/25 16:25:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10512026/10/25 16:25:12 INFO Completed upload id=2 objects=2 duration=1.542458ms1052--- PASS: TestMetricsCommit (8.92s)1053=== CONT TestPush_RootsAreLockedInByteOrder1054=== NAME TestNARDeduplicationMetadataUploadBug1055 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/2/scratch/97c492293bae0eec/build/TestNARDeduplicationMetadataUploadBug2807763793/001/store/kmfvx0s8b1skpi26iwaylyiif2n0m3x5-file2.txt10562026/10/25 16:25:12 INFO Received push request method=POST path=/api/pushes10572026/10/25 16:25:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10582026/10/25 16:25:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10592026/10/25 16:25:12 INFO Signed narinfos id=2 count=110602026/10/25 16:25:12 WARN Failed to register uploaded object key=kmfvx0s8b1skpi26iwaylyiif2n0m3x5.ls error="server returned 404: 404 page not found\n"10612026/10/25 16:25:12 INFO Uploading 1 narinfos10622026/10/25 16:25:12 INFO Aborted multipart uploads count=0 kept=010632026/10/25 16:25:12 WARN Force mode enabled - objects will be deleted immediately without grace period10642026/10/25 16:25:12 INFO Received complete push request method=POST path=/api/pushes/2/complete10652026/10/25 16:25:12 WARN Failed to register uploaded object key=kmfvx0s8b1skpi26iwaylyiif2n0m3x5.narinfo error="server returned 404: 404 page not found\n"10662026/10/25 16:25:12 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=010672026/10/25 16:25:12 INFO Completed push id=2 objects=3 duration=1.830125ms10682026/10/25 16:25:12 INFO Upload complete. (435ms)10692026/10/25 16:25:12 INFO Vacuumed table table=pending_closures1070 metadata_upload_test.go:76: Retrieved narinfo from S3:1071 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestNARDeduplicationMetadataUploadBug2807763793/001/store/kmfvx0s8b1skpi26iwaylyiif2n0m3x5-file2.txt1072 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1073 Compression: zstd1074 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1075 NarSize: 1601076 References: 1077 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1078 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1079 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):10802026/10/25 16:25:12 INFO Vacuumed table table=pending_objects1081 {"version":1,"root":{"type":"regular","size":44}}10822026/10/25 16:25:12 INFO Vacuumed table table=multipart_uploads10832026/10/25 16:25:12 INFO Vacuumed table table=closures10842026/10/25 16:25:12 INFO Vacuumed table table=objects1085--- PASS: TestNARDeduplicationMetadataUploadBug (9.57s)1086=== CONT TestClientFallsBackToClosures10872026/10/25 16:25:12 INFO Aborted multipart uploads count=0 kept=010882026/10/25 16:25:12 WARN Force mode enabled - objects will be deleted immediately without grace period1089--- PASS: TestService_healthCheckHandler (9.66s)1090=== CONT TestGCSweepDeliversEachKeyOnce10912026/10/25 16:25:13 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=010922026/10/25 16:25:13 INFO Vacuumed table table=pending_closures10932026/10/25 16:25:13 INFO Vacuumed table table=pending_objects10942026/10/25 16:25:13 INFO Vacuumed table table=multipart_uploads10952026/10/25 16:25:13 INFO Vacuumed table table=closures10962026/10/25 16:25:13 INFO Vacuumed table table=objects1097--- PASS: TestSweepSkipsRowsLockedByPush (9.79s)1098=== CONT TestTombstonedObjectOfferedWithoutWaiting1099--- PASS: TestMetricsInventory (10.26s)1100=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale11012026/10/25 16:25:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11022026/10/25 16:25:13 WARN Refused reserved pin name=worker-x86_64-linux11032026/10/25 16:25:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11042026/10/25 16:25:13 INFO Received create pin request method=POST path=/api/pins/my-app11052026/10/25 16:25:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1106--- PASS: TestCreatePin_ReservedPins (10.54s)1107=== CONT TestPush_RepeatedRootCommitsOnce11082026/10/25 16:25:14 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/25 16:25:14 INFO Aborted multipart uploads count=0 kept=011102026/10/25 16:25:14 WARN Force mode enabled - objects will be deleted immediately without grace period11112026/10/25 16:25:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11122026/10/25 16:25:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1113--- PASS: TestFailedS3DeleteKeepsTombstone (8.81s)1114=== CONT TestGCSweepSkipsPendingObjects11152026/10/25 16:25:14 INFO Received push request method=POST path=/api/pushes11162026/10/25 16:25:14 INFO Received uploads request method=POST path=/api/pending_closures11172026-10-25 16:25:15.037 UTC [42651] ERROR: Push does not exist: id=111182026-10-25 16:25:15.037 UTC [42651] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11192026-10-25 16:25:15.037 UTC [42651] STATEMENT: SELECT commit_push($1)1120--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (8.57s)1121=== CONT TestPush_CompleteCommitsEveryRoot1122--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (8.40s)1123=== CONT TestDeduplicatedObjectsRecordedAsPending11242026/10/25 16:25:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11252026/10/25 16:25:15 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1126--- PASS: TestCompleteMultipartUnregistered (8.55s)1127=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11282026/10/25 16:25:15 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/25 16:25:16 INFO Received uploads request method=POST path=/api/pending_closures11302026/10/25 16:25:16 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/25 16:25:16 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/25 16:25:16 INFO Received cleanup request method=DELETE path=/api/pending_closures11332026/10/25 16:25:17 INFO Aborted multipart uploads count=0 kept=011342026/10/25 16:25:17 INFO Received uploads request method=POST path=/api/pending_closures11352026/10/25 16:25:17 INFO Received cleanup request method=DELETE path=/api/pending_closures11362026/10/25 16:25:17 INFO Aborted multipart uploads count=1 kept=011372026/10/25 16:25:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11382026-10-25 16:25:17.227 UTC [40596] ERROR: Closure does not exist: id=111392026-10-25 16:25:17.227 UTC [40596] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11402026-10-25 16:25:17.227 UTC [40596] STATEMENT: -- name: CommitPendingClosure :one1141 SELECT commit_pending_closure($1::bigint)::bigint1142 1143--- PASS: TestService_cleanupPendingClosuresHandler (9.55s)1144=== CONT TestPushDedupSurvivesConcurrentGC11452026/10/25 16:25:17 INFO Received uploads request method=POST path=/api/pending_closures11462026/10/25 16:25:17 INFO Aborted multipart uploads count=1 kept=011472026/10/25 16:25:17 INFO Received cleanup request method=DELETE path=/api/pending_closures11482026/10/25 16:25:17 INFO Aborted multipart uploads count=1 kept=01149--- PASS: TestPendingCleanupUsesOneCutoff (14.68s)1150=== CONT TestReadRedirectUsesPublicS3URL1151--- PASS: TestService_Rustfstest (9.99s)1152=== CONT TestGCMetrics11532026/10/25 16:25:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11542026/10/25 16:25:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11552026/10/25 16:25:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LjAzYjc4OGQxLTA5NTUtNGI0OC05YmZmLWMxNGM4ODQxNjgyOXgxNzkyOTQ1NTE2MDYyMjQ0MDAw parts=1011562026/10/25 16:25:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11572026/10/25 16:25:18 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/25 16:25:18 INFO Completed upload id=1 objects=2 duration=18.771791ms11592026/10/25 16:25:18 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/25 16:25:18 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/25 16:25:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11622026/10/25 16:25:18 WARN Found objects in DB but missing from S3, will re-upload count=11163--- PASS: TestService_verifyS3Integrity (11.35s)1164=== CONT TestReadProxyRangeRequest11652026/10/25 16:25:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11662026/10/25 16:25:19 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/25 16:25:19 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0Ljk4MDJkYWI5LTVmMDctNDUwNy04YWJlLWU1MWZhM2ExMzYxYXgxNzkyOTQ1NTE2NTUwODI5MDAw parts=1011682026/10/25 16:25:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11692026/10/25 16:25:19 INFO Completed upload id=1 objects=2 duration=15.704708ms11702026/10/25 16:25:19 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011712026/10/25 16:25:19 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/25 16:25:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures11732026/10/25 16:25:19 INFO Aborted multipart uploads count=0 kept=011742026/10/25 16:25:19 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11752026/10/25 16:25:19 INFO Received uploads request method=POST path=/api/pending_closures1176--- PASS: TestPresignedUploadRegisteredBeforeCommit (10.82s)1177=== CONT TestGCBugBareHashReferences11782026/10/25 16:25:19 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=011792026/10/25 16:25:19 INFO Vacuumed table table=pending_closures11802026/10/25 16:25:19 INFO Vacuumed table table=pending_objects11812026/10/25 16:25:19 INFO Vacuumed table table=multipart_uploads11822026/10/25 16:25:19 INFO Vacuumed table table=closures11832026/10/25 16:25:19 INFO Received push request method=POST path=/api/pushes11842026/10/25 16:25:19 INFO Vacuumed table table=objects11852026/10/25 16:25:19 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001186--- PASS: TestService_createPendingClosureHandler (11.92s)1187=== CONT TestReadRedirectKeepsNarinfoProxied11882026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11892026/10/25 16:25:19 INFO Signed narinfos id=1 count=111902026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11912026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11922026/10/25 16:25:19 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11932026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11942026/10/25 16:25:19 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11952026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11962026/10/25 16:25:19 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111972026/10/25 16:25:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11982026/10/25 16:25:19 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1199--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (9.58s)1200=== CONT TestReadRedirectNar12012026/10/25 16:25:19 INFO Received uploads request method=POST path=/api/pending_closures12022026/10/25 16:25:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12032026/10/25 16:25:20 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LjEzMDIyN2QzLTcyMTItNGQwOS1iYjUwLTdlN2EwMjkwMzg2MXgxNzkyOTQ1NTE5OTM1ODM3MDAw12042026/10/25 16:25:20 INFO Received uploads request method=POST path=/api/pending_closures12052026/10/25 16:25:20 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LjEzMDIyN2QzLTcyMTItNGQwOS1iYjUwLTdlN2EwMjkwMzg2MXgxNzkyOTQ1NTE5OTM1ODM3MDAw parts=11206--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (10.81s)1207=== CONT TestReadProxyDisabled12082026/10/25 16:25:20 INFO Received uploads request method=POST path=/api/pending_closures1209=== RUN TestPush_RejectsBadRequests/no_roots1210=== PAUSE TestPush_RejectsBadRequests/no_roots1211=== RUN TestPush_RejectsBadRequests/no_objects1212=== PAUSE TestPush_RejectsBadRequests/no_objects1213=== RUN TestPush_RejectsBadRequests/bad_root1214=== PAUSE TestPush_RejectsBadRequests/bad_root1215=== RUN TestPush_RejectsBadRequests/root_not_in_objects1216=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1217=== CONT TestReadProxyRootRedirectsToIndexHTML12182026/10/25 16:25:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12192026/10/25 16:25:21 INFO Received push request method=POST path=/api/pushes12202026/10/25 16:25:21 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LjNmMDdkMmRiLTQ0ZjktNGNmNS1iMjQzLTIyZGZkZTRjOGEzOXgxNzkyOTQ1NTE4Njg2MDQ3MDAw parts=1212212026/10/25 16:25:21 INFO Received uploads request method=POST path=/api/pending_closures1222--- PASS: TestCompletedNarNotReofferedAcrossClosures (12.62s)1223=== CONT TestReadProxyConditionalGet12242026/10/25 16:25:21 INFO Received complete push request method=POST path=/api/pushes/1/complete12252026/10/25 16:25:21 INFO Completed push id=1 objects=4 duration=65.916833ms12262026/10/25 16:25:21 INFO Received push request method=POST path=/api/pushes12272026/10/25 16:25:21 INFO Aborted multipart uploads count=0 kept=012282026/10/25 16:25:21 WARN Force mode enabled - objects will be deleted immediately without grace period12292026/10/25 16:25:21 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=012302026/10/25 16:25:21 INFO Received push request method=POST path=/api/pushes12312026/10/25 16:25:21 INFO Vacuumed table table=pending_closures12322026/10/25 16:25:21 INFO Vacuumed table table=pending_objects12332026/10/25 16:25:21 INFO Vacuumed table table=multipart_uploads12342026/10/25 16:25:21 INFO Vacuumed table table=closures12352026-10-25 16:25:21.799 UTC [42664] ERROR: could not obtain lock on row in relation "closures"12362026-10-25 16:25:21.799 UTC [42664] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12372026-10-25 16:25:21.808 UTC [42664] ERROR: could not obtain lock on row in relation "closures"12382026-10-25 16:25:21.808 UTC [42664] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12392026-10-25 16:25:21.814 UTC [42664] ERROR: could not obtain lock on row in relation "closures"12402026-10-25 16:25:21.814 UTC [42664] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12412026-10-25 16:25:21.815 UTC [42664] ERROR: could not obtain lock on row in relation "closures"12422026-10-25 16:25:21.815 UTC [42664] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12432026/10/25 16:25:21 INFO Vacuumed table table=objects12442026-10-25 16:25:21.825 UTC [42664] ERROR: could not obtain lock on row in relation "closures"12452026-10-25 16:25:21.825 UTC [42664] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12462026/10/25 16:25:21 INFO Received complete push request method=POST path=/api/pushes/2/complete12472026/10/25 16:25:21 INFO Completed push id=2 objects=4 duration=8.642292ms1248--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (10.56s)1249=== CONT TestGCAdvisoryLockBlocksConcurrentRun1250--- PASS: TestPush_RootsAreLockedInByteOrder (9.83s)1251=== CONT TestReadProxyOutlastsServerWriteTimeout12522026/10/25 16:25:22 INFO Received uploads request method=POST path=/api/pending_closures1253--- PASS: TestTombstonedObjectOfferedWithoutWaiting (9.44s)1254=== CONT TestLeadEndsOnShutdown12552026/10/25 16:25:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12562026/10/25 16:25:23 WARN Rate limiter enabled after throttle name=s3-test rate=512572026/10/25 16:25:23 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1258=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1259 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101260 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001261--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (15.31s)1262=== CONT TestLeadIncumbentAnnouncesAtOnce12632026/10/25 16:25:23 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/25 16:25:23 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/25 16:25:23 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12662026/10/25 16:25:23 INFO Uploading zc8kl8wm746kqk0309salslylzws1qp0-shared-dep (136B)12672026/10/25 16:25:23 INFO Uploading sa92h8gc9nra6cvfxrf7q2vg4pxwbzk9-a (256B)12682026/10/25 16:25:23 WARN Failed to register uploaded object key=sa92h8gc9nra6cvfxrf7q2vg4pxwbzk9.ls error="server returned 404: 404 page not found\n"12692026/10/25 16:25:23 INFO Aborted multipart uploads count=0 kept=012702026/10/25 16:25:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12712026/10/25 16:25:23 WARN Failed to register uploaded object key=8bhrngqkcb795p8r4213w0qssmdd6wd2.ls error="server returned 404: 404 page not found\n"12722026/10/25 16:25:23 WARN Failed to register uploaded object key=zc8kl8wm746kqk0309salslylzws1qp0.ls error="server returned 404: 404 page not found\n"12732026/10/25 16:25:23 WARN Force mode enabled - objects will be deleted immediately without grace period12742026/10/25 16:25:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12752026/10/25 16:25:23 WARN Failed to register uploaded object key=nar/0kd84zb1b8jgcwm2acrsrjx2vr9m3l8059izdlz6bw46i6awfy4k.nar.zst error="server returned 404: 404 page not found\n"12762026/10/25 16:25:23 INFO Signed narinfos id=2 count=212772026/10/25 16:25:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12782026/10/25 16:25:23 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LmY3YTRlZTJiLWRjNTUtNDQ4Zi05OTViLTRjODcyNTUwZTNlNXgxNzkyOTQ1NTIwMzYwNTIwMDAw parts=1212792026/10/25 16:25:23 INFO Signed narinfos id=1 count=212802026/10/25 16:25:23 INFO Uploading 4 narinfos12812026/10/25 16:25:23 INFO Received uploads request method=POST path=/api/pending_closures12822026/10/25 16:25:23 WARN Failed to register uploaded object key=sa92h8gc9nra6cvfxrf7q2vg4pxwbzk9.narinfo error="server returned 404: 404 page not found\n"12832026/10/25 16:25:23 INFO Received uploads request method=POST path=/api/pending_closures12842026/10/25 16:25:23 WARN Failed to register uploaded object key=8bhrngqkcb795p8r4213w0qssmdd6wd2.narinfo error="server returned 404: 404 page not found\n"12852026/10/25 16:25:23 WARN Failed to register uploaded object key=zc8kl8wm746kqk0309salslylzws1qp0.narinfo error="server returned 404: 404 page not found\n"12862026/10/25 16:25:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12872026/10/25 16:25:23 WARN Failed to register uploaded object key=zc8kl8wm746kqk0309salslylzws1qp0.narinfo error="server returned 404: 404 page not found\n"12882026/10/25 16:25:23 INFO Completed upload id=2 objects=6 duration=37.105458ms12892026/10/25 16:25:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12902026/10/25 16:25:23 INFO Completed upload id=1 objects=6 duration=944.167µs12912026/10/25 16:25:23 INFO Upload complete. (514ms)1292=== NAME TestClientFallsBackToClosures1293 client_pushes_test.go:112: Retrieved narinfo from S3:1294 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientFallsBackToClosures2037437259/001/store/zc8kl8wm746kqk0309salslylzws1qp0-shared-dep1295 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1296 Compression: zstd1297 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821298 NarSize: 1361299 References: 1300 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1301 client_pushes_test.go:112: Retrieved narinfo from S3:1302 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientFallsBackToClosures2037437259/001/store/sa92h8gc9nra6cvfxrf7q2vg4pxwbzk9-a1303 URL: nar/0kd84zb1b8jgcwm2acrsrjx2vr9m3l8059izdlz6bw46i6awfy4k.nar.zst1304 Compression: zstd1305 NarHash: sha256:0kd84zb1b8jgcwm2acrsrjx2vr9m3l8059izdlz6bw46i6awfy4k1306 NarSize: 2561307 References: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientFallsBackToClosures2037437259/001/store/zc8kl8wm746kqk0309salslylzws1qp0-shared-dep1308 CA: text:sha256:15cjhhryqr6k2ihc2x0bypv5563dzjmjln8zq2hmcxxs0i6qim011309 client_pushes_test.go:112: Retrieved narinfo from S3:1310 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientFallsBackToClosures2037437259/001/store/8bhrngqkcb795p8r4213w0qssmdd6wd2-b1311 URL: nar/0kd84zb1b8jgcwm2acrsrjx2vr9m3l8059izdlz6bw46i6awfy4k.nar.zst1312 Compression: zstd1313 NarHash: sha256:0kd84zb1b8jgcwm2acrsrjx2vr9m3l8059izdlz6bw46i6awfy4k1314 NarSize: 2561315 References: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientFallsBackToClosures2037437259/001/store/zc8kl8wm746kqk0309salslylzws1qp0-shared-dep1316 CA: text:sha256:15cjhhryqr6k2ihc2x0bypv5563dzjmjln8zq2hmcxxs0i6qim011317--- PASS: TestClientFallsBackToClosures (11.00s)1318=== CONT TestReadProxyHead13192026/10/25 16:25:23 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=013202026/10/25 16:25:23 INFO Received push request method=POST path=/api/pushes13212026/10/25 16:25:23 INFO Vacuumed table table=pending_closures13222026/10/25 16:25:23 INFO Vacuumed table table=pending_objects13232026/10/25 16:25:23 INFO Vacuumed table table=multipart_uploads13242026/10/25 16:25:23 INFO Vacuumed table table=closures13252026/10/25 16:25:23 INFO Vacuumed table table=objects1326--- PASS: TestGCSweepDeliversEachKeyOnce (11.18s)1327=== CONT TestLeadElectsOneAndHandsOver1328=== CONT TestReadProxyInvalidPath13292026/10/25 16:25:24 INFO Received complete push request method=POST path=/api/pushes/1/complete13302026/10/25 16:25:24 INFO Completed push id=1 objects=4 duration=46.994833ms1331--- PASS: TestPush_RepeatedRootCommitsOnce (10.44s)1332=== CONT TestConnectWaitsForAPeerMigration13332026/10/25 16:25:24 INFO Received uploads request method=POST path=/api/pending_closures1334=== NAME TestOrphanedObjectsGCStressTest1335 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13362026/10/25 16:25:24 INFO Aborted multipart uploads count=0 kept=013372026/10/25 16:25:24 WARN Force mode enabled - objects will be deleted immediately without grace period13382026/10/25 16:25:24 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=01339 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion13402026/10/25 16:25:24 INFO Vacuumed table table=pending_closures13412026/10/25 16:25:24 INFO Vacuumed table table=pending_objects13422026/10/25 16:25:24 INFO Vacuumed table table=multipart_uploads13432026/10/25 16:25:24 INFO Vacuumed table table=closures13442026/10/25 16:25:24 INFO Vacuumed table table=objects1345--- PASS: TestGCSweepSkipsPendingObjects (10.24s)1346=== CONT TestReadProxy40413472026/10/25 16:25:24 INFO Received uploads request method=POST path=/api/pending_closures1348--- PASS: TestDeduplicatedObjectsRecordedAsPending (9.55s)1349=== CONT TestResolveDBConnectionString1350=== RUN TestResolveDBConnectionString/flag_wins1351=== PAUSE TestResolveDBConnectionString/flag_wins1352=== RUN TestResolveDBConnectionString/file_when_flag_empty1353=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1354=== RUN TestResolveDBConnectionString/missing_file_is_an_error1355=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1356=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1357=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1358=== RUN TestResolveDBConnectionString/nothing_configured1359=== PAUSE TestResolveDBConnectionString/nothing_configured1360=== CONT TestReadProxyNarStreaming13612026/10/25 16:25:25 INFO Received push request method=POST path=/api/pushes13622026/10/25 16:25:25 INFO Received complete push request method=POST path=/api/pushes/1/complete13632026/10/25 16:25:25 INFO Completed push id=1 objects=6 duration=119.878208ms1364--- PASS: TestPush_CompleteCommitsEveryRoot (10.35s)1365=== CONT TestReadProxyContentNegotiation13662026/10/25 16:25:25 INFO Received push request method=POST path=/api/pushes1367--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (10.11s)1368=== CONT TestReadProxyNarinfoAlreadyDecompressed13692026/10/25 16:25:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13702026/10/25 16:25:25 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LmYwZDU2ZmU2LThkMjYtNGJhYi04ZWZkLTBmZjIyNDgyMTZjZXgxNzkyOTQ1NTIzMzM4MzE0MDAw error="Get \"http://127.0.0.1:1/bucket41/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13712026/10/25 16:25:25 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGYwOGQ1OGItNzFjZC00ZjgzLWJlM2QtODkwNWEyZTdhM2I0LjdmMDBkMzQxLTM3ZGQtNDE0Yy04Y2I2LWNhYzc5YmFhNWFjZHgxNzkyOTQ1NTIzMjY5NDQyMDAw parts=1213722026/10/25 16:25:25 INFO Received cleanup request method=DELETE path=/api/pending_closures13732026/10/25 16:25:25 INFO Aborted multipart uploads count=1 kept=01374--- PASS: TestRedundantMultipartUpload (16.47s)1375=== CONT TestReadProxyNarinfo13762026/10/25 16:25:26 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/25 16:25:26 INFO Aborted multipart uploads count=0 kept=013782026/10/25 16:25:26 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=01379--- PASS: TestReadRedirectUsesPublicS3URL (8.66s)1380=== CONT TestIsValidCachePath1381=== RUN TestIsValidCachePath/narinfo1382=== PAUSE TestIsValidCachePath/narinfo1383=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars13842026/10/25 16:25:26 INFO Vacuumed table table=pending_closures1385=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1386=== RUN TestIsValidCachePath/nar_zst1387=== PAUSE TestIsValidCachePath/nar_zst1388=== RUN TestIsValidCachePath/nar_xz1389=== PAUSE TestIsValidCachePath/nar_xz1390=== RUN TestIsValidCachePath/nar_bz21391=== PAUSE TestIsValidCachePath/nar_bz21392=== RUN TestIsValidCachePath/nar_uncompressed1393=== PAUSE TestIsValidCachePath/nar_uncompressed1394=== RUN TestIsValidCachePath/ls1395=== PAUSE TestIsValidCachePath/ls1396=== RUN TestIsValidCachePath/log1397=== PAUSE TestIsValidCachePath/log1398=== RUN TestIsValidCachePath/realisation1399=== PAUSE TestIsValidCachePath/realisation1400=== RUN TestIsValidCachePath/nix-cache-info1401=== PAUSE TestIsValidCachePath/nix-cache-info1402=== RUN TestIsValidCachePath/index.html1403=== PAUSE TestIsValidCachePath/index.html1404=== RUN TestIsValidCachePath/traversal_parent1405=== PAUSE TestIsValidCachePath/traversal_parent1406=== RUN TestIsValidCachePath/traversal_in_middle1407=== PAUSE TestIsValidCachePath/traversal_in_middle1408=== RUN TestIsValidCachePath/invalid_char_e1409=== PAUSE TestIsValidCachePath/invalid_char_e1410=== RUN TestIsValidCachePath/invalid_char_u1411=== PAUSE TestIsValidCachePath/invalid_char_u1412=== RUN TestIsValidCachePath/random_path1413=== PAUSE TestIsValidCachePath/random_path1414=== RUN TestIsValidCachePath/empty1415=== PAUSE TestIsValidCachePath/empty1416=== RUN TestIsValidCachePath/leading_slash1417=== PAUSE TestIsValidCachePath/leading_slash1418=== RUN TestIsValidCachePath/wrong_extension1419=== PAUSE TestIsValidCachePath/wrong_extension1420=== RUN TestIsValidCachePath/short_hash1421=== PAUSE TestIsValidCachePath/short_hash1422=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14232026/10/25 16:25:26 INFO Vacuumed table table=pending_objects14242026/10/25 16:25:26 INFO Vacuumed table table=multipart_uploads14252026/10/25 16:25:26 INFO Vacuumed table table=closures14262026/10/25 16:25:26 INFO Vacuumed table table=objects14272026/10/25 16:25:26 INFO Aborted multipart uploads count=0 kept=014282026/10/25 16:25:26 WARN Force mode enabled - objects will be deleted immediately without grace period14292026/10/25 16:25:26 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=014302026/10/25 16:25:26 INFO Vacuumed table table=pending_closures14312026/10/25 16:25:26 INFO Vacuumed table table=pending_objects14322026/10/25 16:25:26 INFO Vacuumed table table=multipart_uploads14332026/10/25 16:25:26 INFO Vacuumed table table=closures14342026/10/25 16:25:26 INFO Vacuumed table table=objects1435--- PASS: TestPushDedupSurvivesConcurrentGC (9.54s)1436=== CONT TestParseSingleRange1437=== RUN TestParseSingleRange/none1438=== PAUSE TestParseSingleRange/none1439=== RUN TestParseSingleRange/unknown_unit1440=== PAUSE TestParseSingleRange/unknown_unit1441=== RUN TestParseSingleRange/multi-range_ignored1442=== PAUSE TestParseSingleRange/multi-range_ignored1443=== RUN TestParseSingleRange/malformed_no_dash1444=== PAUSE TestParseSingleRange/malformed_no_dash1445=== RUN TestParseSingleRange/malformed_both_empty1446=== PAUSE TestParseSingleRange/malformed_both_empty1447=== RUN TestParseSingleRange/malformed_end_before_start1448=== PAUSE TestParseSingleRange/malformed_end_before_start1449=== RUN TestParseSingleRange/closed1450=== PAUSE TestParseSingleRange/closed1451=== RUN TestParseSingleRange/open-ended1452=== PAUSE TestParseSingleRange/open-ended1453=== RUN TestParseSingleRange/end_clamped_to_size1454=== PAUSE TestParseSingleRange/end_clamped_to_size1455=== RUN TestParseSingleRange/suffix1456=== PAUSE TestParseSingleRange/suffix1457=== RUN TestParseSingleRange/suffix_exceeds_size1458=== PAUSE TestParseSingleRange/suffix_exceeds_size1459=== RUN TestParseSingleRange/single_byte1460=== PAUSE TestParseSingleRange/single_byte1461=== RUN TestParseSingleRange/start_past_EOF1462=== PAUSE TestParseSingleRange/start_past_EOF1463=== RUN TestParseSingleRange/start_far_past_EOF1464=== PAUSE TestParseSingleRange/start_far_past_EOF1465=== CONT TestDeleteClosuresRacingPins14662026/10/25 16:25:26 INFO Aborted multipart uploads count=0 kept=014672026/10/25 16:25:26 WARN Force mode enabled - objects will be deleted immediately without grace period14682026/10/25 16:25:26 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=014692026/10/25 16:25:26 INFO Vacuumed table table=pending_closures14702026/10/25 16:25:26 INFO Vacuumed table table=pending_objects14712026/10/25 16:25:26 INFO Vacuumed table table=multipart_uploads14722026/10/25 16:25:26 INFO Vacuumed table table=closures14732026/10/25 16:25:26 INFO Vacuumed table table=objects1474--- PASS: TestGCMetrics (8.81s)1475=== CONT TestClientCADerivations1476--- PASS: TestReadProxyRangeRequest (8.74s)1477=== CONT TestClientPushesUseOnePush1478--- PASS: TestReadRedirectNar (8.26s)1479=== CONT TestPinProtectsFromGC1480--- PASS: TestGCBugBareHashReferences (9.16s)1481=== CONT TestClientSharedPathCommittedMidPush1482--- PASS: TestReadRedirectKeepsNarinfoProxied (9.20s)1483=== CONT TestClientWithDependencies1484--- PASS: TestReadProxyDisabled (8.73s)1485=== CONT TestClientMultipleUploads1486--- PASS: TestReadProxyRootRedirectsToIndexHTML (8.81s)1487=== CONT TestClientIntegration1488--- PASS: TestReadProxyConditionalGet (8.77s)1489=== CONT TestClientErrorHandling1490=== RUN TestClientErrorHandling/InvalidStorePath1491=== PAUSE TestClientErrorHandling/InvalidStorePath1492=== RUN TestClientErrorHandling/InvalidAuthToken1493=== PAUSE TestClientErrorHandling/InvalidAuthToken1494=== RUN TestClientErrorHandling/ServerNotAvailable1495=== PAUSE TestClientErrorHandling/ServerNotAvailable1496=== CONT TestGCEndsOnShutdown/before_the_run14972026/10/25 16:25:30 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld2 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1498--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (8.85s)1499=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh15002026/10/25 16:25:31 INFO lead: acquired remote=192.0.2.1:123415012026/10/25 16:25:31 INFO lead: acquired remote=192.0.2.1:123415022026/10/25 16:25:31 INFO lead: released remote=192.0.2.1:12341503--- PASS: TestLeadIncumbentAnnouncesAtOnce (8.52s)1504=== CONT TestService_RequireScope_OIDC15052026/10/25 16:25:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65308/oidc15062026/10/25 16:25:31 INFO lead: acquired remote=192.0.2.1:123415072026/10/25 16:25:32 INFO lead: released remote=192.0.2.1:12341508--- PASS: TestLeadEndsOnShutdown (9.62s)1509=== CONT TestCacheStatsHandler1510--- PASS: TestReadProxyHead (8.73s)1511=== CONT TestCacheConfigHandler1512=== RUN TestCacheConfigHandler/full_config,_no_issuer1513=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1514=== RUN TestCacheConfigHandler/no_cache_url_configured1515=== PAUSE TestCacheConfigHandler/no_cache_url_configured1516=== RUN TestCacheConfigHandler/no_signing_keys1517=== PAUSE TestCacheConfigHandler/no_signing_keys1518=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1519=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1520=== CONT TestService_ReadScope_PublicByDefault1521--- PASS: TestReadProxyInvalidPath (8.87s)1522=== CONT TestService_ReadAuthMiddleware15232026/10/25 16:25:33 INFO lead: released remote=192.0.2.1:123415242026/10/25 16:25:33 INFO lead: acquired remote=192.0.2.1:12341525--- PASS: TestConnectWaitsForAPeerMigration (9.78s)1526=== CONT TestService_AuthMiddleware_OIDC15272026/10/25 16:25:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65331/oidc1528--- PASS: TestReadProxyNarStreaming (9.22s)1529=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1530--- PASS: TestReadProxy404 (9.59s)1531=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15322026/10/25 16:25:34 INFO lead: released remote=192.0.2.1:12341533--- PASS: TestLeadElectsOneAndHandsOver (10.32s)1534=== CONT TestService_AuthMiddleware_MTLSProxyHeader1535--- PASS: TestReadProxyContentNegotiation (9.20s)1536=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1537--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.78s)1538=== CONT TestServerTLSConfig/no_client_CA1539=== CONT TestServerTLSConfig/not_a_PEM_file1540=== CONT TestServerTLSConfig/missing_CA_file1541--- PASS: TestServerTLSConfig (0.00s)1542 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1543 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1544 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1545=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1546--- PASS: TestReadProxyNarinfoAlreadyDecompressed (9.23s)1547=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check15482026/10/25 16:25:35 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1549--- PASS: TestReadProxyNarinfo (9.40s)1550=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15512026/10/25 16:25:35 INFO Received uploads request method=POST path=/1552=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15532026/10/25 16:25:36 INFO Received uploads request method=POST path=/1554=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15552026/10/25 16:25:36 INFO Received request for more parts method=POST path=/1556=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15572026/10/25 16:25:36 INFO Received complete multipart upload request method=POST path=/1558--- PASS: TestUploadHandlersRejectOversizedBody (0.05s)1559 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)1560 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1561 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.08s)1562=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15632026/10/25 16:25:36 INFO Received complete multipart upload request method=POST path=/1564=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15652026/10/25 16:25:36 INFO Received request for more parts method=POST path=/1566=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15672026/10/25 16:25:36 INFO Received uploads request method=POST path=/1568--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1569 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1570 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1571 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1572 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1573=== CONT TestIsValidUploadKey/narinfo1574=== CONT TestPendingClosureWriteTimeout/empty1575=== CONT TestIsValidUploadKey/unknown_type1576=== CONT TestIsValidUploadKey/empty_key1577=== CONT TestIsValidUploadKey/absolute1578=== CONT TestIsValidUploadKey/traversal_nar1579=== CONT TestIsValidUploadKey/traversal1580=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1581=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1582=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1583=== CONT TestIsValidUploadKey/index.html1584=== CONT TestIsValidUploadKey/nix-cache-info1585=== CONT TestIsValidUploadKey/realisation_plus_in_output1586=== CONT TestIsValidUploadKey/realisation1587=== CONT TestIsValidUploadKey/build_log_equals1588=== CONT TestIsValidUploadKey/build_log_question_mark1589=== CONT TestIsValidUploadKey/build_log_plus_in_name1590=== CONT TestIsValidUploadKey/build_log_home-manager_file1591=== CONT TestIsValidUploadKey/build_log1592=== CONT TestIsValidUploadKey/listing1593=== CONT TestIsValidUploadKey/nar_plain1594=== CONT TestIsValidUploadKey/nar_xz1595=== CONT TestIsValidUploadKey/nar_zst1596--- PASS: TestIsValidUploadKey (0.00s)1597 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1598 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1599 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1600 --- PASS: TestIsValidUploadKey/absolute (0.00s)1601 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1602 --- PASS: TestIsValidUploadKey/traversal (0.00s)1603 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1604 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1605 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1606 --- PASS: TestIsValidUploadKey/index.html (0.00s)1607 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1608 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1609 --- PASS: TestIsValidUploadKey/realisation (0.00s)1610 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1611 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1612 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1613 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1614 --- PASS: TestIsValidUploadKey/build_log (0.00s)1615 --- PASS: TestIsValidUploadKey/listing (0.00s)1616 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1617 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1618 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1619=== CONT TestPendingClosureWriteTimeout/670k_objects1620=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1621--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.83s)1622=== CONT TestPendingClosureWriteTimeout/400_objects1623=== CONT TestProxyWriteTimeout/narinfo1624=== CONT TestProxyWriteTimeout/10_GiB_nar1625=== CONT TestProxyWriteTimeout/unknown_size1626=== CONT TestProxyWriteTimeout/1_GiB_nar1627--- PASS: TestProxyWriteTimeout (0.00s)1628 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1629 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1630 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1631 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1632=== CONT TestPush_RejectsBadRequests/no_roots16332026/10/25 16:25:37 INFO Received push request method=POST path=/api/pushes1634=== CONT TestPush_RejectsBadRequests/bad_root16352026/10/25 16:25:37 INFO Received push request method=POST path=/api/pushes1636=== CONT TestPush_RejectsBadRequests/root_not_in_objects16372026/10/25 16:25:37 INFO Received push request method=POST path=/api/pushes1638=== CONT TestPush_RejectsBadRequests/no_objects16392026/10/25 16:25:37 INFO Received push request method=POST path=/api/pushes1640--- PASS: TestPush_RejectsBadRequests (9.63s)1641 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1642 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1643 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1644 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1645=== CONT TestResolveDBConnectionString/flag_wins1646=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1647=== CONT TestResolveDBConnectionString/nothing_configured1648=== CONT TestResolveDBConnectionString/missing_file_is_an_error1649=== CONT TestResolveDBConnectionString/file_when_flag_empty1650--- PASS: TestResolveDBConnectionString (0.05s)1651 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1652 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1653 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1654 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1655 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1656=== CONT TestIsValidCachePath/narinfo1657=== CONT TestIsValidCachePath/index.html1658=== CONT TestIsValidCachePath/short_hash1659=== CONT TestIsValidCachePath/wrong_extension1660=== CONT TestIsValidCachePath/leading_slash1661=== CONT TestIsValidCachePath/empty1662=== CONT TestIsValidCachePath/random_path1663=== CONT TestIsValidCachePath/invalid_char_u1664=== CONT TestIsValidCachePath/invalid_char_e1665=== CONT TestIsValidCachePath/traversal_in_middle1666=== CONT TestIsValidCachePath/traversal_parent1667=== CONT TestIsValidCachePath/nar_uncompressed1668=== CONT TestIsValidCachePath/nix-cache-info1669=== CONT TestIsValidCachePath/realisation1670=== CONT TestIsValidCachePath/log1671=== CONT TestIsValidCachePath/ls1672=== CONT TestIsValidCachePath/nar_xz1673=== CONT TestIsValidCachePath/nar_bz21674=== CONT TestIsValidCachePath/nar_zst1675=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1676--- PASS: TestIsValidCachePath (0.01s)1677 --- PASS: TestIsValidCachePath/narinfo (0.00s)1678 --- PASS: TestIsValidCachePath/index.html (0.00s)1679 --- PASS: TestIsValidCachePath/short_hash (0.00s)1680 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1681 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1682 --- PASS: TestIsValidCachePath/empty (0.00s)1683 --- PASS: TestIsValidCachePath/random_path (0.00s)1684 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1685 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1686 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1687 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1688 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1689 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1690 --- PASS: TestIsValidCachePath/realisation (0.00s)1691 --- PASS: TestIsValidCachePath/log (0.00s)1692 --- PASS: TestIsValidCachePath/ls (0.00s)1693 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1694 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1695 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1696 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1697=== CONT TestParseSingleRange/none1698=== CONT TestParseSingleRange/open-ended1699=== CONT TestParseSingleRange/start_far_past_EOF1700=== CONT TestParseSingleRange/start_past_EOF1701=== CONT TestParseSingleRange/single_byte1702=== CONT TestParseSingleRange/suffix_exceeds_size1703=== CONT TestParseSingleRange/suffix1704=== CONT TestParseSingleRange/end_clamped_to_size1705=== CONT TestParseSingleRange/malformed_both_empty1706=== CONT TestParseSingleRange/closed1707=== CONT TestParseSingleRange/malformed_end_before_start1708=== CONT TestParseSingleRange/multi-range_ignored1709=== CONT TestParseSingleRange/malformed_no_dash1710=== CONT TestParseSingleRange/unknown_unit1711--- PASS: TestParseSingleRange (0.02s)1712 --- PASS: TestParseSingleRange/none (0.00s)1713 --- PASS: TestParseSingleRange/open-ended (0.00s)1714 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1715 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1716 --- PASS: TestParseSingleRange/single_byte (0.00s)1717 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1718 --- PASS: TestParseSingleRange/suffix (0.00s)1719 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1720 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1721 --- PASS: TestParseSingleRange/closed (0.00s)1722 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1723 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1724 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1725 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1726=== CONT TestClientErrorHandling/InvalidStorePath1727=== NAME TestClientCADerivations1728 client_ca_test.go:136: Built CA derivation: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientCADerivations3573037460/001/store/f338cgy6bpbclzgnsmlgci9llsvcgy2i-ca-test1729 client_ca_test.go:139: Found 1 dependencies (including self)17302026/10/25 16:25:37 INFO Received push request method=POST path=/api/pushes17312026/10/25 16:25:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17322026/10/25 16:25:37 INFO Uploading f338cgy6bpbclzgnsmlgci9llsvcgy2i-ca-test (144B)17332026/10/25 16:25:37 WARN Failed to register uploaded object key=log/n007vgjcspbag73yn0niyay07nsl6qaa-ca-test.drv error="server returned 404: 404 page not found\n"17342026/10/25 16:25:37 WARN Failed to register uploaded object key=f338cgy6bpbclzgnsmlgci9llsvcgy2i.ls error="server returned 404: 404 page not found\n"17352026/10/25 16:25:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17362026/10/25 16:25:37 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17372026/10/25 16:25:37 INFO Signed narinfos id=1 count=117382026/10/25 16:25:37 INFO Uploading 1 narinfos17392026/10/25 16:25:37 INFO Received complete push request method=POST path=/api/pushes/1/complete17402026/10/25 16:25:37 WARN Failed to register uploaded object key=f338cgy6bpbclzgnsmlgci9llsvcgy2i.narinfo error="server returned 404: 404 page not found\n"17412026/10/25 16:25:38 INFO Completed push id=1 objects=4 duration=36.841625ms17422026/10/25 16:25:38 INFO Upload complete. (421ms)1743 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientCADerivations3573037460/001/store/f338cgy6bpbclzgnsmlgci9llsvcgy2i-ca-test1744 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1745 Compression: zstd1746 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1747 NarSize: 1441748 References: 1749 Deriver: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientCADerivations3573037460/001/store/n007vgjcspbag73yn0niyay07nsl6qaa-ca-test.drv1750 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1751 client_ca_test.go:185: Checking for realisation files in S3...1752 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1753 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1754 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket77?endpoint=http://localhost:64879®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/2/scratch/97c492293bae0eec/build/TestClientCADerivations3573037460/001/store'1755 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11756--- PASS: TestClientCADerivations (11.33s)1757=== CONT TestClientErrorHandling/ServerNotAvailable1758=== NAME TestPinProtectsFromGC1759 client_integration_test.go:731: Pinned store path: /private/var/tb/2/scratch/97c492293bae0eec/build/TestPinProtectsFromGC1486579334/001/store/vl979h8psras3ccrnxn0llg7sg10pmlw-pinned-file.txt1760 client_integration_test.go:732: Unpinned store path: /private/var/tb/2/scratch/97c492293bae0eec/build/TestPinProtectsFromGC1486579334/001/store/a17hz24sbw3f8zc1ry9csn5vg0kpp5iq-unpinned-file.txt17612026/10/25 16:25:38 INFO Received push request method=POST path=/api/pushes17622026/10/25 16:25:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17632026/10/25 16:25:38 INFO Uploading 37qrrnk205hny8x5mkxfxm6z8pbavd6w-b (256B)17642026/10/25 16:25:38 INFO Uploading vchrhzx6kmi27w60vmr7cw2k7vh9s0iv-shared-dep (136B)17652026/10/25 16:25:38 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17662026/10/25 16:25:38 WARN Failed to register uploaded object key=vchrhzx6kmi27w60vmr7cw2k7vh9s0iv.ls error="server returned 404: 404 page not found\n"17672026/10/25 16:25:38 WARN Failed to register uploaded object key=wxy9pn9c7fi5sqpc5xy0f662f1jp1cy4.ls error="server returned 404: 404 page not found\n"17682026/10/25 16:25:38 INFO Received push request method=POST path=/api/pushes17692026/10/25 16:25:38 WARN Failed to register uploaded object key=37qrrnk205hny8x5mkxfxm6z8pbavd6w.ls error="server returned 404: 404 page not found\n"17702026/10/25 16:25:38 WARN Failed to register uploaded object key=nar/0qhmc31fmdp66b96bi5ldgrq2d73fn1z57j75pv1khfrrax9wp2k.nar.zst error="server returned 404: 404 page not found\n"17712026/10/25 16:25:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17722026/10/25 16:25:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17732026/10/25 16:25:38 INFO Signed narinfos id=1 count=317742026/10/25 16:25:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17752026/10/25 16:25:38 INFO Uploading vl979h8psras3ccrnxn0llg7sg10pmlw-pinned-file.txt (128B)17762026/10/25 16:25:38 INFO Uploading 3 narinfos17772026/10/25 16:25:38 WARN Request failed, retrying attempt=2 backoff=184.662897ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17782026/10/25 16:25:38 WARN Failed to register uploaded object key=vchrhzx6kmi27w60vmr7cw2k7vh9s0iv.narinfo error="server returned 404: 404 page not found\n"17792026/10/25 16:25:38 WARN Failed to register uploaded object key=wxy9pn9c7fi5sqpc5xy0f662f1jp1cy4.narinfo error="server returned 404: 404 page not found\n"17802026/10/25 16:25:38 WARN Failed to register uploaded object key=vl979h8psras3ccrnxn0llg7sg10pmlw.ls error="server returned 404: 404 page not found\n"17812026/10/25 16:25:38 INFO Received complete push request method=POST path=/api/pushes/1/complete17822026/10/25 16:25:38 WARN Failed to register uploaded object key=37qrrnk205hny8x5mkxfxm6z8pbavd6w.narinfo error="server returned 404: 404 page not found\n"17832026/10/25 16:25:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17842026/10/25 16:25:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17852026/10/25 16:25:38 INFO Completed push id=1 objects=8 duration=17.307083ms17862026/10/25 16:25:38 INFO Signed narinfos id=1 count=117872026/10/25 16:25:38 INFO Upload complete. (577ms)17882026/10/25 16:25:38 INFO Uploading 1 narinfos1789=== NAME TestClientPushesUseOnePush1790 client_pushes_test.go:97: Retrieved narinfo from S3:1791 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientPushesUseOnePush1183955734/001/store/vchrhzx6kmi27w60vmr7cw2k7vh9s0iv-shared-dep1792 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1793 Compression: zstd1794 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821795 NarSize: 1361796 References: 1797 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1798 client_pushes_test.go:97: Retrieved narinfo from S3:1799 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientPushesUseOnePush1183955734/001/store/wxy9pn9c7fi5sqpc5xy0f662f1jp1cy4-a1800 URL: nar/0qhmc31fmdp66b96bi5ldgrq2d73fn1z57j75pv1khfrrax9wp2k.nar.zst1801 Compression: zstd1802 NarHash: sha256:0qhmc31fmdp66b96bi5ldgrq2d73fn1z57j75pv1khfrrax9wp2k1803 NarSize: 2561804 References: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientPushesUseOnePush1183955734/001/store/vchrhzx6kmi27w60vmr7cw2k7vh9s0iv-shared-dep1805 CA: text:sha256:025xwrqs5sgrdpbk2zlwh2pw4zjb4hys7ri6lgp138j8a0vk1wr91806 client_pushes_test.go:97: Retrieved narinfo from S3:1807 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientPushesUseOnePush1183955734/001/store/37qrrnk205hny8x5mkxfxm6z8pbavd6w-b1808 URL: nar/0qhmc31fmdp66b96bi5ldgrq2d73fn1z57j75pv1khfrrax9wp2k.nar.zst1809 Compression: zstd1810 NarHash: sha256:0qhmc31fmdp66b96bi5ldgrq2d73fn1z57j75pv1khfrrax9wp2k1811 NarSize: 2561812 References: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientPushesUseOnePush1183955734/001/store/vchrhzx6kmi27w60vmr7cw2k7vh9s0iv-shared-dep1813 CA: text:sha256:025xwrqs5sgrdpbk2zlwh2pw4zjb4hys7ri6lgp138j8a0vk1wr918142026/10/25 16:25:38 WARN Request failed, retrying attempt=3 backoff=405.485295ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18152026/10/25 16:25:38 INFO Received complete push request method=POST path=/api/pushes/1/complete18162026/10/25 16:25:38 WARN Failed to register uploaded object key=vl979h8psras3ccrnxn0llg7sg10pmlw.narinfo error="server returned 404: 404 page not found\n"18172026/10/25 16:25:39 INFO Completed push id=1 objects=3 duration=21.036292ms18182026/10/25 16:25:39 INFO Upload complete. (462ms)1819--- PASS: TestClientPushesUseOnePush (11.64s)1820=== CONT TestClientErrorHandling/InvalidAuthToken18212026/10/25 16:25:39 INFO Received push request method=POST path=/api/pushes18222026/10/25 16:25:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18232026/10/25 16:25:39 INFO Uploading a17hz24sbw3f8zc1ry9csn5vg0kpp5iq-unpinned-file.txt (128B)18242026/10/25 16:25:39 WARN Request failed, retrying attempt=4 backoff=819.954126ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18252026/10/25 16:25:39 WARN Failed to register uploaded object key=a17hz24sbw3f8zc1ry9csn5vg0kpp5iq.ls error="server returned 404: 404 page not found\n"18262026/10/25 16:25:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18272026/10/25 16:25:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18282026/10/25 16:25:39 INFO Signed narinfos id=2 count=118292026/10/25 16:25:39 INFO Uploading 1 narinfos18302026/10/25 16:25:39 INFO Received push request method=POST path=/api/pushes18312026/10/25 16:25:39 INFO Received complete push request method=POST path=/api/pushes/2/complete18322026/10/25 16:25:39 WARN Failed to register uploaded object key=a17hz24sbw3f8zc1ry9csn5vg0kpp5iq.narinfo error="server returned 404: 404 page not found\n"18332026/10/25 16:25:39 INFO Completed push id=2 objects=3 duration=6.59275ms18342026/10/25 16:25:39 INFO Upload complete. (435ms)18352026/10/25 16:25:39 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18362026/10/25 16:25:39 INFO Uploading krzd4lsp3v1hn4q85h03mqawyijngk4l-top (264B)18372026/10/25 16:25:39 INFO Uploading lhqx5vfrpn9ri1ihwiwwbmfwxr8cbihs-shared-dep (136B)18382026/10/25 16:25:39 WARN Failed to register uploaded object key=nar/0w87h70s4pk06979paywmvs77z4x22q6vaqz0jr0dxbh2rr1gyy6.nar.zst error="server returned 404: 404 page not found\n"18392026/10/25 16:25:39 WARN Failed to register uploaded object key=lhqx5vfrpn9ri1ihwiwwbmfwxr8cbihs.ls error="server returned 404: 404 page not found\n"18402026/10/25 16:25:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18412026/10/25 16:25:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18422026/10/25 16:25:39 WARN Failed to register uploaded object key=krzd4lsp3v1hn4q85h03mqawyijngk4l.ls error="server returned 404: 404 page not found\n"18432026/10/25 16:25:39 INFO Signed narinfos id=1 count=218442026/10/25 16:25:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures18452026/10/25 16:25:39 INFO Uploading 2 narinfos18462026/10/25 16:25:39 INFO Garbage collection started18472026/10/25 16:25:39 INFO Aborted multipart uploads count=0 kept=018482026/10/25 16:25:39 WARN Failed to register uploaded object key=lhqx5vfrpn9ri1ihwiwwbmfwxr8cbihs.narinfo error="server returned 404: 404 page not found\n"18492026/10/25 16:25:39 INFO Received complete push request method=POST path=/api/pushes/1/complete18502026/10/25 16:25:39 WARN Failed to register uploaded object key=krzd4lsp3v1hn4q85h03mqawyijngk4l.narinfo error="server returned 404: 404 page not found\n"18512026/10/25 16:25:39 WARN Force mode enabled - objects will be deleted immediately without grace period18522026/10/25 16:25:39 INFO Completed push id=1 objects=6 duration=36.107583ms18532026/10/25 16:25:39 INFO Upload complete. (547ms)1854=== NAME TestClientSharedPathCommittedMidPush1855 client_integration_test.go:680: Retrieved narinfo from S3:1856 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientSharedPathCommittedMidPush2841144301/001/store/lhqx5vfrpn9ri1ihwiwwbmfwxr8cbihs-shared-dep1857 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1858 Compression: zstd1859 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821860 NarSize: 1361861 References: 1862 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1863 client_integration_test.go:680: Retrieved narinfo from S3:1864 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientSharedPathCommittedMidPush2841144301/001/store/krzd4lsp3v1hn4q85h03mqawyijngk4l-top1865 URL: nar/0w87h70s4pk06979paywmvs77z4x22q6vaqz0jr0dxbh2rr1gyy6.nar.zst1866 Compression: zstd1867 NarHash: sha256:0w87h70s4pk06979paywmvs77z4x22q6vaqz0jr0dxbh2rr1gyy61868 NarSize: 2641869 References: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientSharedPathCommittedMidPush2841144301/001/store/lhqx5vfrpn9ri1ihwiwwbmfwxr8cbihs-shared-dep1870 CA: text:sha256:1j5ccw9wfxhf1s963dj0wvmh3zkvb4af184y6p90bzb4hrrbh32q1871--- PASS: TestClientSharedPathCommittedMidPush (11.48s)1872=== CONT TestCacheConfigHandler/full_config,_no_issuer1873=== CONT TestCacheConfigHandler/no_signing_keys1874=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1875=== CONT TestCacheConfigHandler/no_cache_url_configured1876--- PASS: TestCacheConfigHandler (0.00s)1877 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1878 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1879 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1880 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1881=== NAME TestClientWithDependencies1882 client_integration_test.go:613: Built derivation: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientWithDependencies2990153698/001/store/3jsrrhkih9dlpv1i54kgy217678ydgii-test-script1883 client_integration_test.go:615: Found 1 dependencies (including self)1884=== NAME TestClientMultipleUploads1885 client_integration_test.go:358: Created store path 0: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientMultipleUploads2048469295/001/store/i5ca5ixbzpp0ryiy4rc6v7wm9rj8l573-test-file-0.txt18862026/10/25 16:25:40 WARN Request failed, retrying attempt=5 backoff=1.586145931s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1887 client_integration_test.go:358: Created store path 1: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientMultipleUploads2048469295/001/store/82zgb7h2r2kal4zyhv458zhimblxdbdc-test-file-1.txt1888--- PASS: TestDeleteClosuresRacingPins (13.91s)18892026/10/25 16:25:40 INFO Received push request method=POST path=/api/pushes1890=== NAME TestClientIntegration1891 client_integration_test.go:286: Created store path: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientIntegration1891260787/002/store/hx9g2rs0z16yn9rf3hp4il5zwnmga979-test-file.txt18922026/10/25 16:25:40 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=018932026/10/25 16:25:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18942026/10/25 16:25:40 INFO Uploading 3jsrrhkih9dlpv1i54kgy217678ydgii-test-script (136B)18952026/10/25 16:25:40 INFO Vacuumed table table=pending_closures18962026/10/25 16:25:40 INFO Vacuumed table table=pending_objects18972026/10/25 16:25:40 INFO Vacuumed table table=multipart_uploads18982026/10/25 16:25:40 INFO Vacuumed table table=closures18992026/10/25 16:25:40 INFO Vacuumed table table=objects19002026/10/25 16:25:40 WARN Failed to register uploaded object key=log/d0bzpb64cidjh32447gci6qygz45i1sh-test-script.drv error="server returned 404: 404 page not found\n"19012026/10/25 16:25:40 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19022026/10/25 16:25:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19032026/10/25 16:25:40 WARN Failed to register uploaded object key=3jsrrhkih9dlpv1i54kgy217678ydgii.ls error="server returned 404: 404 page not found\n"1904=== NAME TestClientMultipleUploads1905 client_integration_test.go:358: Created store path 2: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientMultipleUploads2048469295/001/store/82qqwhn954aqw677k3krddcghmy6s3nj-test-file-2.txt19062026/10/25 16:25:40 INFO Signed narinfos id=1 count=119072026/10/25 16:25:40 INFO Uploading 1 narinfos19082026/10/25 16:25:41 INFO Received complete push request method=POST path=/api/pushes/1/complete19092026/10/25 16:25:41 WARN Failed to register uploaded object key=3jsrrhkih9dlpv1i54kgy217678ydgii.narinfo error="server returned 404: 404 page not found\n"19102026/10/25 16:25:41 INFO Completed push id=1 objects=4 duration=23.995708ms19112026/10/25 16:25:41 INFO Upload complete. (586ms)1912=== NAME TestClientWithDependencies1913 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/2/scratch/97c492293bae0eec/build/TestClientWithDependencies2990153698/001/store) requires matching store prefix19142026/10/25 16:25:41 INFO Received push request method=POST path=/api/pushes1915--- PASS: TestClientWithDependencies (12.47s)19162026/10/25 16:25:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19172026/10/25 16:25:41 INFO Uploading hx9g2rs0z16yn9rf3hp4il5zwnmga979-test-file.txt (152B)19182026/10/25 16:25:41 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19192026/10/25 16:25:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19202026/10/25 16:25:41 WARN Failed to register uploaded object key=hx9g2rs0z16yn9rf3hp4il5zwnmga979.ls error="server returned 404: 404 page not found\n"19212026/10/25 16:25:41 INFO Signed narinfos id=1 count=119222026/10/25 16:25:41 INFO Received push request method=POST path=/api/pushes19232026/10/25 16:25:41 INFO Uploading 1 narinfos19242026/10/25 16:25:41 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19252026/10/25 16:25:41 INFO Uploading 82zgb7h2r2kal4zyhv458zhimblxdbdc-test-file-1.txt (160B)19262026/10/25 16:25:41 INFO Uploading i5ca5ixbzpp0ryiy4rc6v7wm9rj8l573-test-file-0.txt (160B)19272026/10/25 16:25:41 INFO Uploading 82qqwhn954aqw677k3krddcghmy6s3nj-test-file-2.txt (160B)19282026/10/25 16:25:41 INFO Received complete push request method=POST path=/api/pushes/1/complete19292026/10/25 16:25:41 WARN Failed to register uploaded object key=hx9g2rs0z16yn9rf3hp4il5zwnmga979.narinfo error="server returned 404: 404 page not found\n"19302026/10/25 16:25:41 INFO Completed push id=1 objects=3 duration=39.998458ms19312026/10/25 16:25:41 WARN Failed to register uploaded object key=82zgb7h2r2kal4zyhv458zhimblxdbdc.ls error="server returned 404: 404 page not found\n"19322026/10/25 16:25:41 INFO Upload complete. (566ms)19332026/10/25 16:25:41 WARN Failed to register uploaded object key=i5ca5ixbzpp0ryiy4rc6v7wm9rj8l573.ls error="server returned 404: 404 page not found\n"19342026/10/25 16:25:41 WARN Failed to register uploaded object key=82qqwhn954aqw677k3krddcghmy6s3nj.ls error="server returned 404: 404 page not found\n"19352026/10/25 16:25:41 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19362026/10/25 16:25:41 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19372026/10/25 16:25:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19382026/10/25 16:25:41 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19392026/10/25 16:25:41 INFO Signed narinfos id=1 count=319402026/10/25 16:25:41 INFO Uploading 3 narinfos19412026/10/25 16:25:41 INFO All 1 paths already cached19422026/10/25 16:25:41 WARN Failed to register uploaded object key=82qqwhn954aqw677k3krddcghmy6s3nj.narinfo error="server returned 404: 404 page not found\n"19432026/10/25 16:25:41 WARN Failed to register uploaded object key=82zgb7h2r2kal4zyhv458zhimblxdbdc.narinfo error="server returned 404: 404 page not found\n"1944=== NAME TestClientIntegration1945 client_integration_test.go:312: Retrieved narinfo from S3:1946 StorePath: /private/var/tb/2/scratch/97c492293bae0eec/build/TestClientIntegration1891260787/002/store/hx9g2rs0z16yn9rf3hp4il5zwnmga979-test-file.txt1947 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1948 Compression: zstd1949 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11950 NarSize: 1521951 References: 1952 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119532026/10/25 16:25:41 INFO Received complete push request method=POST path=/api/pushes/1/complete19542026/10/25 16:25:41 WARN Failed to register uploaded object key=i5ca5ixbzpp0ryiy4rc6v7wm9rj8l573.narinfo error="server returned 404: 404 page not found\n"19552026/10/25 16:25:41 INFO Completed push id=1 objects=9 duration=11.265708ms1956 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1957 client_integration_test.go:313: Decompressed .ls content (64 bytes):1958 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1959 client_integration_test.go:316: Testing garbage collection...19602026/10/25 16:25:41 INFO Upload complete. (538ms)1961=== NAME TestClientMultipleUploads1962 client_integration_test.go:369: Uploaded 3 paths in 735.438167ms1963--- PASS: TestClientMultipleUploads (12.68s)19642026/10/25 16:25:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019652026/10/25 16:25:41 INFO Received create pin request method=POST path=/api/pins/myapp19662026/10/25 16:25:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures19672026/10/25 16:25:41 INFO Garbage collection started19682026/10/25 16:25:41 INFO Aborted multipart uploads count=0 kept=019692026/10/25 16:25:41 WARN Force mode enabled - objects will be deleted immediately without grace period19702026/10/25 16:25:41 INFO Created/updated pin name=myapp store_path=/private/var/tb/2/scratch/97c492293bae0eec/build/TestPinProtectsFromGC1486579334/001/store/vl979h8psras3ccrnxn0llg7sg10pmlw-pinned-file.txt narinfo_key=vl979h8psras3ccrnxn0llg7sg10pmlw.narinfo19712026/10/25 16:25:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures19722026/10/25 16:25:41 INFO Garbage collection started19732026/10/25 16:25:41 INFO Aborted multipart uploads count=0 kept=019742026/10/25 16:25:41 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19752026/10/25 16:25:41 WARN Force mode enabled - objects will be deleted immediately without grace period19762026/10/25 16:25:41 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019772026/10/25 16:25:41 INFO Vacuumed table table=pending_closures19782026/10/25 16:25:41 INFO Vacuumed table table=pending_objects19792026/10/25 16:25:41 INFO Vacuumed table table=multipart_uploads19802026/10/25 16:25:41 INFO Vacuumed table table=closures19812026/10/25 16:25:42 INFO Vacuumed table table=objects1982=== RUN TestService_RequireScope_OIDC/builder_may_write1983=== PAUSE TestService_RequireScope_OIDC/builder_may_write19842026/10/25 16:25:42 WARN Request failed, retrying attempt=2 backoff=183.429242ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1985=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1986=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1987=== RUN TestService_RequireScope_OIDC/ops_may_admin1988=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1989=== RUN TestService_RequireScope_OIDC/ops_may_not_write1990=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1991=== RUN TestService_RequireScope_OIDC/reader_may_not_write1992=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1993=== RUN TestService_RequireScope_OIDC/static_token_may_admin1994=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1995=== RUN TestService_RequireScope_OIDC/static_token_may_write1996=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1997=== RUN TestService_RequireScope_OIDC/reader_may_read1998=== PAUSE TestService_RequireScope_OIDC/reader_may_read1999=== RUN TestService_RequireScope_OIDC/writer_implies_read2000=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2001=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2002=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2003=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2004=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2005=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2006=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2007=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2008=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2009=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2010=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2011=== CONT TestService_RequireScope_OIDC/builder_may_write2012=== CONT TestService_RequireScope_OIDC/reader_may_read2013=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2014=== CONT TestService_RequireScope_OIDC/static_token_may_admin2015=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2016=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2017=== CONT TestService_RequireScope_OIDC/reader_may_not_write2018=== CONT TestService_RequireScope_OIDC/static_token_may_write2019=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2020=== CONT TestService_RequireScope_OIDC/ops_may_admin20212026/10/25 16:25:42 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]2022=== CONT TestService_RequireScope_OIDC/writer_implies_read2023=== CONT TestService_RequireScope_OIDC/ops_may_not_write2024=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2025=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2026--- PASS: TestService_RequireScope_OIDC (10.54s)2027 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2041--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2042 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (10.62s)2043 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (11.39s)20442026/10/25 16:25:42 WARN Request failed, retrying attempt=3 backoff=436.265314ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20452026/10/25 16:25:42 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=020462026/10/25 16:25:42 INFO Vacuumed table table=pending_closures20472026/10/25 16:25:42 INFO Vacuumed table table=pending_objects20482026/10/25 16:25:42 INFO Vacuumed table table=multipart_uploads20492026/10/25 16:25:42 INFO Vacuumed table table=closures2050--- PASS: TestService_ReadAuthMiddleware (9.55s)20512026/10/25 16:25:42 INFO Vacuumed table table=objects20522026/10/25 16:25:42 WARN Request failed, retrying attempt=4 backoff=732.767093ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2053--- PASS: TestCacheStatsHandler (10.63s)2054--- PASS: TestService_ReadScope_PublicByDefault (10.55s)20552026/10/25 16:25:43 INFO Aborted multipart uploads count=0 kept=020562026/10/25 16:25:43 WARN Force mode enabled - objects will be deleted immediately without grace period20572026/10/25 16:25:43 WARN Request failed, retrying attempt=5 backoff=1.596614724s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2058=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2059=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2060=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2061=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2062=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2063=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2064=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2065=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2066=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2067=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20682026/10/25 16:25:43 WARN Authentication failed token_preview=eyJhbGciOi...hlc7MPvT1A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2069=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20702026/10/25 16:25:43 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]2071=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2072--- PASS: TestService_AuthMiddleware_OIDC (9.73s)2073 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2074 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2075 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2076 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)20772026/10/25 16:25:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02078=== NAME TestClientIntegration2079 client_integration_test.go:323: Objects in database after GC:2080 client_integration_test.go:323: Successfully deleted all objects with GC --force2081--- PASS: TestClientIntegration (14.42s)2082=== NAME TestPinProtectsFromGC2083 client_integration_test.go:840: Pin successfully protected closure from garbage collection20842026/10/25 16:25:44 INFO Received uploads request method=POST path=/api/pending_closures20852026/10/25 16:25:44 INFO Aborted multipart uploads count=0 kept=020862026/10/25 16:25:44 WARN Force mode enabled - objects will be deleted immediately without grace period2087--- PASS: TestPinProtectsFromGC (16.25s)20882026/10/25 16:25:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20892026/10/25 16:25:44 WARN mTLS auth: bound subjects configured but subject DN unavailable20902026/10/25 16:25:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2091--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (10.06s)20922026/10/25 16:25:44 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=020932026/10/25 16:25:44 INFO Vacuumed table table=pending_closures20942026/10/25 16:25:44 INFO Vacuumed table table=pending_objects20952026/10/25 16:25:44 INFO Vacuumed table table=multipart_uploads20962026/10/25 16:25:44 INFO Vacuumed table table=closures20972026/10/25 16:25:44 INFO Vacuumed table table=objects20982026/10/25 16:25: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 [::1]:19999: connect: connection refused"20992026/10/25 16:25:45 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21002026/10/25 16:25:45 INFO Received uploads request method=POST path=/api/pending_closures21012026/10/25 16:25:45 INFO Aborted multipart uploads count=0 kept=021022026/10/25 16:25:45 WARN Force mode enabled - objects will be deleted immediately without grace period21032026/10/25 16:25:45 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=021042026/10/25 16:25:45 WARN Request failed, retrying attempt=2 backoff=207.687744ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21052026/10/25 16:25:45 INFO Vacuumed table table=pending_closures21062026/10/25 16:25:45 INFO Vacuumed table table=pending_objects21072026/10/25 16:25:45 INFO Vacuumed table table=multipart_uploads21082026/10/25 16:25:45 INFO Vacuumed table table=closures21092026/10/25 16:25:45 INFO Vacuumed table table=objects21102026/10/25 16:25:45 WARN Request failed, retrying attempt=3 backoff=418.185056ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2111--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2112 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (9.89s)2113 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (10.76s)21142026/10/25 16:25:45 WARN Request failed, retrying attempt=4 backoff=873.075826ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2115--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (11.58s)21162026/10/25 16:25:46 WARN Request failed, retrying attempt=5 backoff=1.636492854s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2117=== NAME TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2118 gc_shutdown_test.go:34: unexpected error: Put "http://localhost:64879/bucket97/": context deadline exceeded2119 2120--- FAIL: TestGCEndsOnShutdown (0.00s)2121 --- PASS: TestGCEndsOnShutdown/before_the_run (11.17s)2122 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (9.37s)2123 --- FAIL: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (12.23s)21242026/10/25 16:25:47 INFO Received uploads request method=POST path=/api/pending_closures21252026/10/25 16:25:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21262026/10/25 16:25:48 WARN Request failed, retrying attempt=2 backoff=182.975657ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2127=== NAME TestClientErrorHandling/InvalidStorePath2128 client_errors_test.go:18: unexpected error: Put "http://localhost:64879/bucket99/": context deadline exceeded2129 21302026/10/25 16:25:48 WARN Request failed, retrying attempt=3 backoff=365.332081ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2131--- PASS: TestPendingClosureWriteTimeout (0.00s)2132 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2133 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2134 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2135 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (12.19s)21362026/10/25 16:25:49 WARN Request failed, retrying attempt=4 backoff=848.832676ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21372026/10/25 16:25:49 WARN Request failed, retrying attempt=5 backoff=1.493406355s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2138=== NAME TestOrphanedObjectsGCStressTest2139 orphaned_objects_gc_test.go:503: Stress test completed successfully:2140 orphaned_objects_gc_test.go:504: - Active objects preserved: 202141 orphaned_objects_gc_test.go:505: - Objects deleted: 2102142 orphaned_objects_gc_test.go:506: - Total GC'd: 2102143--- PASS: TestOrphanedObjectsGCStressTest (47.38s)21442026/10/25 16:25:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21452026/10/25 16:25:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2146--- FAIL: TestClientErrorHandling (0.01s)2147 --- FAIL: TestClientErrorHandling/InvalidStorePath (11.26s)2148 --- PASS: TestClientErrorHandling/InvalidAuthToken (11.59s)2149 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.10s)2150FAIL21512026-10-25 16:25:51.536 UTC [35079] LOG: received smart shutdown request21522026/10/25 16:26:01 INFO killed process group pgid=3507921532026-10-25 16:26:01.541 UTC [52472] FATAL: terminating connection due to unexpected postmaster exit21542026-10-25 16:26:01.541 UTC [51873] FATAL: terminating connection due to unexpected postmaster exit21552026/10/25 16:26:01 ERROR failed to wait for process error="signal: killed"