niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #395
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.18s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestEncodeNixBase32102=== RUN TestEncodeNixBase32/test_string_hash103=== PAUSE TestEncodeNixBase32/test_string_hash104=== RUN TestEncodeNixBase32/empty_input105=== PAUSE TestEncodeNixBase32/empty_input106=== CONT TestResolveStorePath107=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess108=== CONT TestRateLimiterFeedback109=== RUN TestRateLimiterFeedback/429_enables_limiter110=== PAUSE TestRateLimiterFeedback/429_enables_limiter111=== RUN TestRateLimiterFeedback/503_enables_limiter112=== PAUSE TestRateLimiterFeedback/503_enables_limiter113=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter114=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter115=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter116=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter117=== CONT TestStreamPushIsolatesFailures118=== CONT TestPathInfoCACompatibility119=== RUN TestPathInfoCACompatibility/null_ca_field120=== PAUSE TestPathInfoCACompatibility/null_ca_field121=== CONT TestParsePathInfoJSONMultiplePaths122=== CONT TestParsePathInfoJSON123=== RUN TestPathInfoCACompatibility/old_string_format_-_text1242026/10/07 07:42:38 WARN Rate limiter enabled after throttle name=server-test rate=5125=== RUN TestParsePathInfoJSON/Nix_format1262026/10/07 07:42:38 ERROR Upload failed error="bad path" count=3127=== CONT TestGetStorePathHash128=== CONT TestConvertHashToNix32129=== CONT TestEncodeNixBase32WithRealHash130=== CONT TestSetClientTLSErrors131=== CONT TestScriptTokenEmptyCommand132=== CONT TestSetClientTLSDoesNotMutateDefaultTransport133=== CONT TestScriptTokenScriptFails134=== CONT TestSetClientTLS135=== CONT TestScriptTokenBadJSON136=== CONT TestScriptTokenEmptyToken1372026/10/07 07:42:38 WARN Rate limiter enabled after throttle name=server-test rate=51382026/10/07 07:42:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56713139=== CONT TestScriptTokenCachesUntilRefresh140=== CONT TestScriptTokenNoExpiryRerunsEveryCall141=== CONT TestFileTokenEmpty142=== CONT TestFileTokenMissing1432026/10/07 07:42:38 WARN Rate limiter backed off name=server-test rate=51442026/10/07 07:42:38 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:56713145=== CONT TestFileTokenReadsAndCaches146=== CONT TestStreamPushGivesUpOnDeadServer147=== CONT TestStaticToken148=== CONT TestStreamPushReportsEveryPath1492026/10/07 07:42:38 ERROR Upload failed error="connection refused" count=201502026/10/07 07:42:38 ERROR Server seems unavailable, giving up on batch untried=17151=== CONT TestPathInfoHashCompatibility152=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon155=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon156=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text157=== CONT TestShellSplitErrors158=== CONT TestDumpPathSingleFile159=== CONT TestUploadMultipart_PartsInParallel160=== RUN TestSetClientTLSErrors/missing_cert_file161=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun162=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== PAUSE TestSetClientTLSErrors/missing_cert_file164=== RUN TestGetStorePathHash/valid_store_path165--- PASS: TestResolveStorePath (0.00s)166--- PASS: TestEncodeNixBase32WithRealHash (0.00s)167--- PASS: TestScriptTokenEmptyCommand (0.00s)168=== CONT TestStreamPushBatchesUnderLoad169=== RUN TestConvertHashToNix32/SRI_format_to_Nix32170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== RUN TestConvertHashToNix32/already_Nix32_format172=== PAUSE TestConvertHashToNix32/already_Nix32_format173=== RUN TestConvertHashToNix32/invalid_format174=== PAUSE TestConvertHashToNix32/invalid_format175=== CONT TestClientSignaturesByStorePath176=== CONT TestUploadMultipart_SupersededByPeer177=== RUN TestUploadMultipart_SupersededByPeer/exists178=== PAUSE TestUploadMultipart_SupersededByPeer/exists179=== PAUSE TestParsePathInfoJSON/Nix_format180=== CONT TestCaseHackSuffix181=== RUN TestParsePathInfoJSON/Lix_format182=== CONT TestStreamPushRequestLine183=== CONT TestStreamPushReportsSignatures184=== CONT TestDumpPathWriterError185=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI186=== CONT TestShellSplit187=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189--- PASS: TestStreamPushIsolatesFailures (0.00s)190=== RUN TestSetClientTLSErrors/missing_key_file191=== PAUSE TestSetClientTLSErrors/missing_key_file192=== RUN TestSetClientTLSErrors/missing_ca_file193=== PAUSE TestSetClientTLSErrors/missing_ca_file194=== RUN TestSetClientTLSErrors/invalid_ca_file1952026/10/07 07:42:38 ERROR Upload failed error=boom count=11962026/10/07 07:42:38 ERROR Upload failed error=boom count=1197=== PAUSE TestSetClientTLSErrors/invalid_ca_file198=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== RUN TestPathInfoCACompatibility/new_structured_format_-_text200--- PASS: TestDoServerRequestAttachesToken (0.00s)201=== RUN TestSetClientTLS/rejects_connection_without_client_cert202=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI203=== PAUSE TestGetStorePathHash/valid_store_path204=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert205=== RUN TestUploadMultipart_SupersededByPeer/missing206=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512207=== RUN TestGetStorePathHash/basename_without_hyphen_should_error208=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512209=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error210=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error211=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA212=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error213=== PAUSE TestUploadMultipart_SupersededByPeer/missing214=== CONT TestEncodeNixBase32/test_string_hash215=== PAUSE TestParsePathInfoJSON/Lix_format216=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica217=== CONT TestFilterOversizedClosures218=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths219=== CONT TestDumpPathMatchesNix220=== CONT TestRegisterUploadedObjectReusesConnections221--- PASS: TestStaticToken (0.00s)222=== RUN TestParsePathInfoJSON/empty_input223--- PASS: TestFileTokenEmpty (0.00s)224=== PAUSE TestParsePathInfoJSON/empty_input225=== RUN TestParsePathInfoJSON/whitespace_only226=== RUN TestFilterOversizedClosures/no_limit_keeps_everything227=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything228=== PAUSE TestParsePathInfoJSON/whitespace_only2292026/10/07 07:42:38 INFO Garbage collection started230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== PAUSE TestFilterOversizedClosures/all_closures_skipped234=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error235=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error236=== CONT TestRateLimiterFeedback/503_enables_limiter237--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)238--- PASS: TestScriptTokenScriptFails (0.01s)239--- PASS: TestStreamPushReportsEveryPath (0.00s)240--- PASS: TestFileTokenReadsAndCaches (0.00s)241--- PASS: TestShellSplitErrors (0.00s)242--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)243--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)244--- PASS: TestFileTokenMissing (0.01s)245--- PASS: TestClientSignaturesByStorePath (0.00s)246--- PASS: TestScriptTokenBadJSON (0.01s)247--- PASS: TestStreamPushReportsSignatures (0.00s)248--- PASS: TestShellSplit (0.00s)249=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter250=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter251--- PASS: TestScriptTokenEmptyToken (0.01s)252=== CONT TestConvertHashToNix32/SRI_format_to_Nix32253=== CONT TestConvertHashToNix32/invalid_format254=== CONT TestConvertHashToNix32/already_Nix32_format255--- PASS: TestConvertHashToNix32 (0.01s)256 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)257 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)258 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)259=== CONT TestSetClientTLSErrors/missing_cert_file260=== CONT TestSetClientTLSErrors/missing_key_file261=== CONT TestSetClientTLSErrors/missing_ca_file262=== RUN TestParsePathInfoJSON/invalid_JSON263=== CONT TestSetClientTLSErrors/invalid_ca_file264--- PASS: TestSetClientTLSErrors (0.01s)265 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)266 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)267 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)268 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)269=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)270=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestUploadMultipart_SupersededByPeer/exists272--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)273=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI274=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon275--- PASS: TestPathInfoHashCompatibility (0.01s)276 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)277 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)278 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)279 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)280=== CONT TestUploadMultipart_SupersededByPeer/missing281=== PAUSE TestParsePathInfoJSON/invalid_JSON282=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA283=== RUN TestSetClientTLS/preserves_debug_logging_transport284=== PAUSE TestSetClientTLS/preserves_debug_logging_transport285=== CONT TestFilterOversizedClosures/no_limit_keeps_everything286=== CONT TestPartSizeForNAR287=== RUN TestPartSizeForNAR/zero_stays_at_minimum288=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum289=== RUN TestPartSizeForNAR/small_stays_at_minimum290=== PAUSE TestPartSizeForNAR/small_stays_at_minimum291=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum292=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum293=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts294=== CONT TestEncodeNixBase32/empty_input295=== CONT TestRateLimiterFeedback/429_enables_limiter296=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text297=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2992026/10/07 07:42:38 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=2000300=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error301=== CONT TestGetStorePathHash/basename_without_hyphen_should_error302=== CONT TestParsePathInfoJSON/Nix_format303=== CONT TestSetClientTLS/rejects_connection_without_client_cert304=== CONT TestGetStorePathHash/valid_store_path305=== CONT TestFilterOversizedClosures/all_closures_skipped3062026/10/07 07:42:38 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=50307=== CONT TestParsePathInfoJSON/invalid_JSON308=== CONT TestParsePathInfoJSON/whitespace_only309=== CONT TestParsePathInfoJSON/empty_input310=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA311=== CONT TestParsePathInfoJSON/Lix_format312=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths313=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths314--- PASS: TestFilterOversizedClosures (0.00s)315 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)316 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)317 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)318--- PASS: TestParsePathInfoJSON (0.02s)319 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)320 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)321 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)322 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)323 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)324=== CONT TestSetClientTLS/preserves_debug_logging_transport325--- PASS: TestEncodeNixBase32 (0.00s)326 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)327 --- PASS: TestEncodeNixBase32/empty_input (0.00s)328=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method329=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method330=== CONT TestPathInfoCACompatibility/null_ca_field331--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)332 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)334=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method335=== CONT TestPathInfoCACompatibility/new_structured_format_-_text336=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive337=== CONT TestPathInfoCACompatibility/old_string_format_-_text338--- PASS: TestPathInfoCACompatibility (0.02s)339 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)340 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)341 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)342 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)343 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)344=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts345=== RUN TestPartSizeForNAR/1_TiB346=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error347--- PASS: TestGetStorePathHash (0.01s)348 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)349 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)350 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)351 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)352=== PAUSE TestPartSizeForNAR/1_TiB353=== RUN TestPartSizeForNAR/5_TiB_S3_max_object354=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object355=== RUN TestPartSizeForNAR/capped_at_5_GiB356=== PAUSE TestPartSizeForNAR/capped_at_5_GiB357=== CONT TestPartSizeForNAR/zero_stays_at_minimum358=== CONT TestPartSizeForNAR/capped_at_5_GiB359=== CONT TestPartSizeForNAR/5_TiB_S3_max_object360=== CONT TestPartSizeForNAR/1_TiB361=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts362=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum363=== CONT TestPartSizeForNAR/small_stays_at_minimum364--- PASS: TestPartSizeForNAR (0.01s)365 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)366 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)367 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)368 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)369 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)370 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)3722026/10/07 07:42:38 WARN Rate limiter enabled after throttle name=server-test rate=53732026/10/07 07:42:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:567983742026/10/07 07:42:38 INFO Garbage collection started375--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)376 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)377 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)3782026/10/07 07:42:38 WARN Rate limiter backed off name=server-test rate=53792026/10/07 07:42:38 WARN Rate limiter enabled after throttle name=server-test rate=53802026/10/07 07:42:38 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:567243812026/10/07 07:42:38 WARN Rate limiter backed off name=server-test rate=5382--- PASS: TestRateLimiterFeedback (0.00s)383 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)384 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)385 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)386 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)387--- PASS: TestStreamPushRequestLine (0.02s)3882026/10/07 07:42:38 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=03892026/10/07 07:42:38 WARN Garbage collection finished on another replica. Its statistics are not available here390--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)391--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)392--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)3932026/10/07 07:42:38 http: TLS handshake error from 127.0.0.1:56797: remote error: tls: bad certificate394--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)395--- PASS: TestSetClientTLS (0.02s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)399--- PASS: TestDumpPathWriterError (0.06s)400--- PASS: TestDumpPathSingleFile (0.07s)401--- PASS: TestCaseHackSuffix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.10s)404--- PASS: TestUploadMultipart_PartsInParallel (0.62s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "_tribuchetbld8".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /private/var/tb/8/scratch/75ba4e933cbdf169/build/postgres126771999/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /private/var/tb/8/scratch/75ba4e933cbdf169/build/postgres126771999/data -l logfile start4344352026-10-07 07:42:40.430 UTC [42722] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-07 07:42:40.430 UTC [42722] LOG: listening on Unix socket "/private/var/tb/8/scratch/75ba4e933cbdf169/build/postgres126771999/.s.PGSQL.5432"4372026-10-07 07:42:40.432 UTC [42729] LOG: database system was shut down at 2026-10-07 07:42:40 UTC4382026-10-07 07:42:40.432 UTC [42730] FATAL: the database system is starting up439/private/var/tb/8/scratch/75ba4e933cbdf169/build/postgres126771999:5432 - rejecting connections4402026-10-07 07:42:40.433 UTC [42722] LOG: database system is ready to accept connections441/private/var/tb/8/scratch/75ba4e933cbdf169/build/postgres126771999:5432 - accepting connections442{"timestamp":"2026-10-07T07:42:40.691633Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"82dd7f0a-4626-4ec4-bcab-bab25d1ec54b","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":10,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}443{"timestamp":"2026-10-07T07:42:40.799476Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"cd2e307f-2243-4900-9c6e-fb576ee1464e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}444{"timestamp":"2026-10-07T07:42:40.901518Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b455904b-26e9-4d28-8615-e634c0cf5eb8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}445{"timestamp":"2026-10-07T07:42:41.006148Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"40506c62-e681-4472-834c-637c8bcd2b37","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}446=== RUN TestService_AuthMiddleware447=== PAUSE TestService_AuthMiddleware448=== RUN TestService_AuthMiddleware_MTLSProxyHeader449=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader450=== RUN TestService_AuthMiddleware_MTLSBoundSubjects451=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects452=== RUN TestService_ReadAuthMiddleware453=== PAUSE TestService_ReadAuthMiddleware454=== RUN TestService_AuthMiddleware_OIDC455=== PAUSE TestService_AuthMiddleware_OIDC456=== RUN TestService_RequireScope_OIDC457=== PAUSE TestService_RequireScope_OIDC458=== RUN TestService_ReadScope_PublicByDefault459=== PAUSE TestService_ReadScope_PublicByDefault460=== RUN TestCacheConfigHandler461=== PAUSE TestCacheConfigHandler462=== RUN TestCacheStatsHandler463=== PAUSE TestCacheStatsHandler464=== RUN TestClientCADerivations465=== PAUSE TestClientCADerivations466=== RUN TestClientErrorHandling467=== PAUSE TestClientErrorHandling468=== RUN TestClientIntegration469=== PAUSE TestClientIntegration470=== RUN TestClientMultipleUploads471=== PAUSE TestClientMultipleUploads472=== RUN TestClientWithDependencies473=== PAUSE TestClientWithDependencies474=== RUN TestClientSharedPathCommittedMidPush475=== PAUSE TestClientSharedPathCommittedMidPush476=== RUN TestPinProtectsFromGC477=== PAUSE TestPinProtectsFromGC478=== RUN TestClientPushesUseOnePush479=== PAUSE TestClientPushesUseOnePush480=== RUN TestClientFallsBackToClosures481=== PAUSE TestClientFallsBackToClosures482=== RUN TestDeleteClosuresRacingPins483=== PAUSE TestDeleteClosuresRacingPins484=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock485=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock486=== RUN TestResolveDBConnectionString487=== PAUSE TestResolveDBConnectionString488=== RUN TestConnectWaitsForAPeerMigration489=== PAUSE TestConnectWaitsForAPeerMigration490=== RUN TestLeadElectsOneAndHandsOver491=== PAUSE TestLeadElectsOneAndHandsOver492=== RUN TestLeadIncumbentWinsAfterRestart4932026/10/07 07:42:41 INFO lead: acquired remote=192.0.2.1:12344942026/10/07 07:42:41 INFO lead: released remote=192.0.2.1:12344952026/10/07 07:42:42 INFO lead: acquired remote=192.0.2.1:12344962026/10/07 07:42:43 INFO lead: released remote=192.0.2.1:1234497--- PASS: TestLeadIncumbentWinsAfterRestart (1.99s)498=== RUN TestLeadIncumbentAnnouncesAtOnce499=== PAUSE TestLeadIncumbentAnnouncesAtOnce500=== RUN TestLeadEndsOnShutdown501=== PAUSE TestLeadEndsOnShutdown502=== RUN TestLeadEndsWhenItsConnectionHangs5032026/10/07 07:42:43 INFO lead: acquired remote=192.0.2.1:12345042026-10-07 07:42:44.717 UTC [42789] FATAL: terminating connection due to administrator command5052026/10/07 07:42:44 INFO lead: acquired remote=192.0.2.1:12345062026/10/07 07:42:45 WARN lead: lock connection lost error="timeout: context deadline exceeded"5072026/10/07 07:42:45 INFO lead: released remote=192.0.2.1:12345082026/10/07 07:42:46 INFO lead: released remote=192.0.2.1:1234509--- PASS: TestLeadEndsWhenItsConnectionHangs (3.02s)510=== RUN TestGCAdvisoryLockBlocksConcurrentRun511=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun512=== RUN TestGCBugBareHashReferences513=== PAUSE TestGCBugBareHashReferences514=== RUN TestGCMetrics515=== PAUSE TestGCMetrics516=== RUN TestPushDedupSurvivesConcurrentGC517=== PAUSE TestPushDedupSurvivesConcurrentGC518=== RUN TestDeduplicatedObjectsRecordedAsPending519=== PAUSE TestDeduplicatedObjectsRecordedAsPending520=== RUN TestGCSweepSkipsPendingObjects521=== PAUSE TestGCSweepSkipsPendingObjects522=== RUN TestTombstonedObjectOfferedWithoutWaiting523=== PAUSE TestTombstonedObjectOfferedWithoutWaiting524=== RUN TestGCSweepDeliversEachKeyOnce525=== PAUSE TestGCSweepDeliversEachKeyOnce526=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection527=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection528=== RUN TestForceGCDuringPushOffersSweptObject529=== PAUSE TestForceGCDuringPushOffersSweptObject530=== RUN TestFailedS3DeleteKeepsTombstone531=== PAUSE TestFailedS3DeleteKeepsTombstone532=== RUN TestSweepSkipsRowsLockedByPush533=== PAUSE TestSweepSkipsRowsLockedByPush534=== RUN TestRegisterCompletedObjectNeedsPendingRow535=== PAUSE TestRegisterCompletedObjectNeedsPendingRow536=== RUN TestGetExistingObjectsLocksRows537=== PAUSE TestGetExistingObjectsLocksRows538=== RUN TestSweepRechecksPendingAfterLocking539=== PAUSE TestSweepRechecksPendingAfterLocking540=== RUN TestPushWaitsForSweepHoldingRow541=== PAUSE TestPushWaitsForSweepHoldingRow542=== RUN TestCommitRacingPendingCleanupKeepsObjects543=== PAUSE TestCommitRacingPendingCleanupKeepsObjects544=== RUN TestGCEndsOnShutdown545=== PAUSE TestGCEndsOnShutdown546=== RUN TestGCTaskStore_StartNew547=== PAUSE TestGCTaskStore_StartNew548=== RUN TestGCTaskStore_DeduplicateSameParams549=== PAUSE TestGCTaskStore_DeduplicateSameParams550=== RUN TestGCTaskStore_ConflictDifferentParams551=== PAUSE TestGCTaskStore_ConflictDifferentParams552=== RUN TestGCTaskStore_GetEmpty553=== PAUSE TestGCTaskStore_GetEmpty554=== RUN TestGCTaskStore_GetReturnsLatest555=== PAUSE TestGCTaskStore_GetReturnsLatest556=== RUN TestGCTaskStore_CompletedAllowsNewTask557=== PAUSE TestGCTaskStore_CompletedAllowsNewTask558=== RUN TestGCTaskStore_PhaseUpdates559=== PAUSE TestGCTaskStore_PhaseUpdates560=== RUN TestGCTaskStore_Fail561=== PAUSE TestGCTaskStore_Fail562=== RUN TestGracefulShutdownDrainsInflight563=== PAUSE TestGracefulShutdownDrainsInflight564=== RUN TestService_healthCheckHandler565=== PAUSE TestService_healthCheckHandler566=== RUN TestService_readinessHandler567=== PAUSE TestService_readinessHandler568=== RUN TestGenerateLandingPage569=== PAUSE TestGenerateLandingPage570=== RUN TestCacheConfigHandlerMaxNarSize571=== PAUSE TestCacheConfigHandlerMaxNarSize572=== RUN TestCreatePendingClosureRejectsOversizedNAR573=== PAUSE TestCreatePendingClosureRejectsOversizedNAR574=== RUN TestNARDeduplicationMetadataUploadBug575=== PAUSE TestNARDeduplicationMetadataUploadBug576=== RUN TestMetricsInventory577=== PAUSE TestMetricsInventory578=== RUN TestMetricsCommit579=== PAUSE TestMetricsCommit580=== RUN TestService_NativeMTLS581=== PAUSE TestService_NativeMTLS582=== RUN TestServerTLSConfig583=== PAUSE TestServerTLSConfig584=== RUN TestMultipartCleanup585=== PAUSE TestMultipartCleanup586=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded587=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded588=== RUN TestPendingCleanupUsesOneCutoff589=== PAUSE TestPendingCleanupUsesOneCutoff590=== RUN TestObjectStatsTrigger591=== PAUSE TestObjectStatsTrigger592=== RUN TestObjectStatsLargeCommit593=== PAUSE TestObjectStatsLargeCommit594=== RUN TestOrphanedObjectsGC595=== PAUSE TestOrphanedObjectsGC596=== RUN TestOrphanedObjectsGCStressTest597=== PAUSE TestOrphanedObjectsGCStressTest598=== RUN TestCreatePin_ReservedPins599=== PAUSE TestCreatePin_ReservedPins600=== RUN TestPresentReportsOnlyClosureRoots601=== PAUSE TestPresentReportsOnlyClosureRoots602=== RUN TestPresentRefreshesOnlyStaleClosures603=== PAUSE TestPresentRefreshesOnlyStaleClosures604=== RUN TestPresentNotReportedWhileGCDeletesClosure605=== PAUSE TestPresentNotReportedWhileGCDeletesClosure606=== RUN TestParseSingleRange607=== PAUSE TestParseSingleRange608=== RUN TestProxyHeadersOnlyTrustedOnSocket6092026/10/07 07:42:46 INFO Starting HTTP server address=127.0.0.1:568356102026/10/07 07:42:46 INFO Starting HTTP server address=proxy.sock6112026/10/07 07:42:46 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6122026/10/07 07:42:46 INFO Shutdown signal received, draining in-flight requests timeout=10s613--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)614=== RUN TestIsValidCachePath615=== PAUSE TestIsValidCachePath616=== RUN TestReadProxyNarinfo617=== PAUSE TestReadProxyNarinfo618=== RUN TestReadProxyNarinfoAlreadyDecompressed619=== PAUSE TestReadProxyNarinfoAlreadyDecompressed620=== RUN TestReadProxyContentNegotiation621=== PAUSE TestReadProxyContentNegotiation622=== RUN TestReadProxyNarStreaming623=== PAUSE TestReadProxyNarStreaming624=== RUN TestReadProxy404625=== PAUSE TestReadProxy404626=== RUN TestReadProxyInvalidPath627=== PAUSE TestReadProxyInvalidPath628=== RUN TestReadProxyHead629=== PAUSE TestReadProxyHead630=== RUN TestReadProxyOutlastsServerWriteTimeout631=== PAUSE TestReadProxyOutlastsServerWriteTimeout632=== RUN TestReadProxyConditionalGet633=== PAUSE TestReadProxyConditionalGet634=== RUN TestReadProxyRootRedirectsToIndexHTML635=== PAUSE TestReadProxyRootRedirectsToIndexHTML636=== RUN TestReadProxyDisabled637=== PAUSE TestReadProxyDisabled638=== RUN TestReadRedirectNar639=== PAUSE TestReadRedirectNar640=== RUN TestReadRedirectKeepsNarinfoProxied641=== PAUSE TestReadRedirectKeepsNarinfoProxied642=== RUN TestReadProxyRangeRequest643=== PAUSE TestReadProxyRangeRequest644=== RUN TestReadRedirectUsesPublicS3URL645=== PAUSE TestReadRedirectUsesPublicS3URL646=== RUN TestPush_OverlappingRootsStoreOneRowPerKey647=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey648=== RUN TestPush_CompleteCommitsEveryRoot649=== PAUSE TestPush_CompleteCommitsEveryRoot650=== RUN TestPush_RepeatedRootCommitsOnce651=== PAUSE TestPush_RepeatedRootCommitsOnce652=== RUN TestPush_CompleteWaitsForCleanupOfThePush653=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush654=== RUN TestPush_RootsAreLockedInByteOrder655=== PAUSE TestPush_RootsAreLockedInByteOrder656=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit657=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit658=== RUN TestPush_RejectsBadRequests659=== PAUSE TestPush_RejectsBadRequests660=== RUN TestPush_SignsNarinfosOfItsPendingObjects661=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects662=== RUN TestRedundantMultipartUpload663=== PAUSE TestRedundantMultipartUpload664=== RUN TestCompleteMultipartUpload_ErrorButObjectExists665=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists666=== RUN TestCompletedNarNotReofferedAcrossClosures667=== PAUSE TestCompletedNarNotReofferedAcrossClosures668=== RUN TestPresignedUploadRegisteredBeforeCommit669=== PAUSE TestPresignedUploadRegisteredBeforeCommit670=== RUN TestService_Rustfstest671=== PAUSE TestService_Rustfstest672=== RUN TestParseSize673=== PAUSE TestParseSize674=== RUN TestSkippedUploadsHandler675=== PAUSE TestSkippedUploadsHandler676=== RUN TestSystemdListenerNotActivated677--- PASS: TestSystemdListenerNotActivated (0.00s)678=== RUN TestWatchdogBeatsWhenHealthy679--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)680=== RUN TestWatchdogSkipsWhenUnhealthy6812026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6872026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6882026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6892026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6902026/10/07 07:42:46 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"691--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)692=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle693=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle694=== RUN TestProxyWriteTimeout695=== PAUSE TestProxyWriteTimeout696=== RUN TestPendingClosureWriteTimeout697=== PAUSE TestPendingClosureWriteTimeout698=== RUN TestIsValidUploadKey699=== PAUSE TestIsValidUploadKey700=== RUN TestUploadHandlersRejectInvalidKeys701=== PAUSE TestUploadHandlersRejectInvalidKeys702=== RUN TestUploadHandlersRejectOversizedBody703=== PAUSE TestUploadHandlersRejectOversizedBody704=== RUN TestService_cleanupPendingClosuresHandler705=== PAUSE TestService_cleanupPendingClosuresHandler706=== RUN TestService_createPendingClosureHandler707=== PAUSE TestService_createPendingClosureHandler708=== RUN TestService_verifyS3Integrity709=== PAUSE TestService_verifyS3Integrity710=== RUN TestCompleteMultipartUnregistered711=== PAUSE TestCompleteMultipartUnregistered712=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT713=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT714=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT715=== CONT TestPresentNotReportedWhileGCDeletesClosure716=== CONT TestOrphanedObjectsGCStressTest717=== CONT TestParseSize718=== CONT TestForceGCDuringPushOffersSweptObject719--- PASS: TestParseSize (0.00s)720=== CONT TestPush_OverlappingRootsStoreOneRowPerKey721=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows722=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale723=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale724=== CONT TestPush_RootsAreLockedInByteOrder725=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh726=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh727=== CONT TestPresentRefreshesOnlyStaleClosures728=== CONT TestPresentReportsOnlyClosureRoots729=== CONT TestCreatePin_ReservedPins730=== CONT TestCompleteMultipartUnregistered731=== CONT TestService_verifyS3Integrity732=== CONT TestService_createPendingClosureHandler733=== CONT TestService_cleanupPendingClosuresHandler734=== CONT TestUploadHandlersRejectOversizedBody735=== CONT TestUploadHandlersRejectInvalidKeys736=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info737=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info738=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal739=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal740=== CONT TestIsValidUploadKey741=== CONT TestPendingClosureWriteTimeout742=== CONT TestProxyWriteTimeout743=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle744=== CONT TestSkippedUploadsHandler745=== CONT TestService_AuthMiddleware746=== CONT TestPush_CompleteWaitsForCleanupOfThePush747=== CONT TestPush_RepeatedRootCommitsOnce748=== CONT TestPush_CompleteCommitsEveryRoot749=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows750=== CONT TestReadRedirectUsesPublicS3URL751=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check752=== RUN TestPendingClosureWriteTimeout/empty753=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key754=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key755=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key756=== PAUSE TestPendingClosureWriteTimeout/empty757=== RUN TestPendingClosureWriteTimeout/400_objects758=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key759=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check760=== RUN TestIsValidUploadKey/narinfo7612026/10/07 07:42:46 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000762=== PAUSE TestPendingClosureWriteTimeout/400_objects763=== CONT TestReadRedirectKeepsNarinfoProxied764=== CONT TestReadProxyRangeRequest765=== RUN TestPendingClosureWriteTimeout/670k_objects766=== RUN TestProxyWriteTimeout/narinfo767=== PAUSE TestProxyWriteTimeout/narinfo768=== RUN TestProxyWriteTimeout/1_GiB_nar769=== PAUSE TestProxyWriteTimeout/1_GiB_nar770=== RUN TestProxyWriteTimeout/10_GiB_nar771=== PAUSE TestProxyWriteTimeout/10_GiB_nar772=== RUN TestProxyWriteTimeout/unknown_size773=== PAUSE TestProxyWriteTimeout/unknown_size774=== PAUSE TestIsValidUploadKey/narinfo775=== RUN TestIsValidUploadKey/nar_zst776=== PAUSE TestIsValidUploadKey/nar_zst777=== RUN TestIsValidUploadKey/nar_xz778=== PAUSE TestIsValidUploadKey/nar_xz779=== RUN TestIsValidUploadKey/nar_plain780=== PAUSE TestIsValidUploadKey/nar_plain781=== RUN TestIsValidUploadKey/listing782=== PAUSE TestIsValidUploadKey/listing783=== RUN TestIsValidUploadKey/build_log784=== PAUSE TestIsValidUploadKey/build_log785=== RUN TestIsValidUploadKey/build_log_home-manager_file786=== PAUSE TestIsValidUploadKey/build_log_home-manager_file787=== RUN TestIsValidUploadKey/build_log_plus_in_name788=== PAUSE TestIsValidUploadKey/build_log_plus_in_name789=== RUN TestIsValidUploadKey/build_log_question_mark790=== PAUSE TestIsValidUploadKey/build_log_question_mark791=== RUN TestIsValidUploadKey/build_log_equals792=== PAUSE TestIsValidUploadKey/build_log_equals793=== RUN TestIsValidUploadKey/realisation794=== PAUSE TestIsValidUploadKey/realisation795=== RUN TestIsValidUploadKey/realisation_plus_in_output796=== PAUSE TestIsValidUploadKey/realisation_plus_in_output797=== RUN TestIsValidUploadKey/nix-cache-info798=== PAUSE TestIsValidUploadKey/nix-cache-info799=== RUN TestIsValidUploadKey/index.html800=== PAUSE TestIsValidUploadKey/index.html801=== RUN TestIsValidUploadKey/narinfo_key,_nar_type802=== CONT TestReadRedirectNar803=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type804=== RUN TestIsValidUploadKey/nar_key,_narinfo_type805=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type806=== RUN TestIsValidUploadKey/listing_key,_narinfo_type807=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type808=== RUN TestIsValidUploadKey/traversal809=== PAUSE TestIsValidUploadKey/traversal810=== RUN TestIsValidUploadKey/traversal_nar811=== PAUSE TestIsValidUploadKey/traversal_nar812=== RUN TestIsValidUploadKey/absolute813=== PAUSE TestIsValidUploadKey/absolute814=== RUN TestIsValidUploadKey/empty_key815=== PAUSE TestIsValidUploadKey/empty_key816=== RUN TestIsValidUploadKey/unknown_type817=== PAUSE TestIsValidUploadKey/unknown_type818=== CONT TestReadProxyDisabled819=== PAUSE TestPendingClosureWriteTimeout/670k_objects820=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline821=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline822=== CONT TestReadProxyRootRedirectsToIndexHTML823--- PASS: TestSkippedUploadsHandler (0.07s)824=== CONT TestReadProxyConditionalGet825=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure826=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure827=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart828=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart829=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts830=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts831=== CONT TestReadProxyOutlastsServerWriteTimeout8322026/10/07 07:42:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56838/oidc8332026/10/07 07:42:47 INFO Received push request method=POST path=/api/pushes834--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.12s)835=== CONT TestReadProxyHead8362026/10/07 07:42:47 INFO Received push request method=POST path=/api/pushes8372026-10-07 07:42:48.310 UTC [42870] ERROR: could not obtain lock on row in relation "closures"8382026-10-07 07:42:48.310 UTC [42870] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8392026-10-07 07:42:48.316 UTC [42870] ERROR: could not obtain lock on row in relation "closures"8402026-10-07 07:42:48.316 UTC [42870] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8412026-10-07 07:42:48.320 UTC [42870] ERROR: could not obtain lock on row in relation "closures"8422026-10-07 07:42:48.320 UTC [42870] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8432026-10-07 07:42:48.326 UTC [42870] ERROR: could not obtain lock on row in relation "closures"8442026-10-07 07:42:48.326 UTC [42870] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT8452026-10-07 07:42:48.327 UTC [42870] ERROR: could not obtain lock on row in relation "closures"8462026-10-07 07:42:48.327 UTC [42870] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT847--- PASS: TestPush_RootsAreLockedInByteOrder (1.82s)848=== CONT TestReadProxyInvalidPath8492026/10/07 07:42:48 INFO Received uploads request method=POST path=/api/pending_closures8502026/10/07 07:42:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete851--- PASS: TestReadRedirectUsesPublicS3URL (2.56s)852=== CONT TestReadProxy404853--- PASS: TestPresentReportsOnlyClosureRoots (3.00s)854=== CONT TestReadProxyNarStreaming855--- PASS: TestPresentRefreshesOnlyStaleClosures (3.86s)856=== CONT TestReadProxyContentNegotiation8572026/10/07 07:42:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8582026/10/07 07:42:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst859--- PASS: TestCompleteMultipartUnregistered (4.26s)860=== CONT TestReadProxyNarinfoAlreadyDecompressed8612026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/07 07:42:51 INFO Received cleanup request method=DELETE path=/api/pending_closures8632026/10/07 07:42:51 INFO Aborted multipart uploads count=0 kept=08642026/10/07 07:42:51 INFO Received uploads request method=POST path=/api/pending_closures8652026/10/07 07:42:51 INFO Received cleanup request method=DELETE path=/api/pending_closures8662026/10/07 07:42:51 INFO Aborted multipart uploads count=1 kept=08672026/10/07 07:42:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8682026-10-07 07:42:51.814 UTC [42876] ERROR: Closure does not exist: id=18692026-10-07 07:42:51.814 UTC [42876] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8702026-10-07 07:42:51.814 UTC [42876] STATEMENT: -- name: CommitPendingClosure :one871 SELECT commit_pending_closure($1::bigint)::bigint872 873--- PASS: TestService_cleanupPendingClosuresHandler (5.28s)874=== CONT TestReadProxyNarinfo8752026/10/07 07:42:52 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"876--- PASS: TestService_AuthMiddleware (5.51s)877=== CONT TestIsValidCachePath878=== RUN TestIsValidCachePath/narinfo879=== PAUSE TestIsValidCachePath/narinfo880=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars881=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars882=== RUN TestIsValidCachePath/nar_zst883=== PAUSE TestIsValidCachePath/nar_zst884=== RUN TestIsValidCachePath/nar_xz885=== PAUSE TestIsValidCachePath/nar_xz886=== RUN TestIsValidCachePath/nar_bz2887=== PAUSE TestIsValidCachePath/nar_bz2888=== RUN TestIsValidCachePath/nar_uncompressed889=== PAUSE TestIsValidCachePath/nar_uncompressed890=== RUN TestIsValidCachePath/ls891=== PAUSE TestIsValidCachePath/ls892=== RUN TestIsValidCachePath/log893=== PAUSE TestIsValidCachePath/log894=== RUN TestIsValidCachePath/realisation895=== PAUSE TestIsValidCachePath/realisation896=== RUN TestIsValidCachePath/nix-cache-info897=== PAUSE TestIsValidCachePath/nix-cache-info898=== RUN TestIsValidCachePath/index.html899=== PAUSE TestIsValidCachePath/index.html900=== RUN TestIsValidCachePath/traversal_parent901=== PAUSE TestIsValidCachePath/traversal_parent902=== RUN TestIsValidCachePath/traversal_in_middle903=== PAUSE TestIsValidCachePath/traversal_in_middle904=== RUN TestIsValidCachePath/invalid_char_e905=== PAUSE TestIsValidCachePath/invalid_char_e906=== RUN TestIsValidCachePath/invalid_char_u907=== PAUSE TestIsValidCachePath/invalid_char_u908=== RUN TestIsValidCachePath/random_path909=== PAUSE TestIsValidCachePath/random_path910=== RUN TestIsValidCachePath/empty911=== PAUSE TestIsValidCachePath/empty912=== RUN TestIsValidCachePath/leading_slash913=== PAUSE TestIsValidCachePath/leading_slash914=== RUN TestIsValidCachePath/wrong_extension915=== PAUSE TestIsValidCachePath/wrong_extension916=== RUN TestIsValidCachePath/short_hash917=== PAUSE TestIsValidCachePath/short_hash918=== CONT TestParseSingleRange919=== RUN TestParseSingleRange/none920=== PAUSE TestParseSingleRange/none921=== RUN TestParseSingleRange/unknown_unit922=== PAUSE TestParseSingleRange/unknown_unit923=== RUN TestParseSingleRange/multi-range_ignored924=== PAUSE TestParseSingleRange/multi-range_ignored925=== RUN TestParseSingleRange/malformed_no_dash926=== PAUSE TestParseSingleRange/malformed_no_dash927=== RUN TestParseSingleRange/malformed_both_empty928=== PAUSE TestParseSingleRange/malformed_both_empty929=== RUN TestParseSingleRange/malformed_end_before_start930=== PAUSE TestParseSingleRange/malformed_end_before_start931=== RUN TestParseSingleRange/closed932=== PAUSE TestParseSingleRange/closed933=== RUN TestParseSingleRange/open-ended934=== PAUSE TestParseSingleRange/open-ended935=== RUN TestParseSingleRange/end_clamped_to_size936=== PAUSE TestParseSingleRange/end_clamped_to_size937=== RUN TestParseSingleRange/suffix938=== PAUSE TestParseSingleRange/suffix939=== RUN TestParseSingleRange/suffix_exceeds_size940=== PAUSE TestParseSingleRange/suffix_exceeds_size941=== RUN TestParseSingleRange/single_byte942=== PAUSE TestParseSingleRange/single_byte943=== RUN TestParseSingleRange/start_past_EOF944=== PAUSE TestParseSingleRange/start_past_EOF945=== RUN TestParseSingleRange/start_far_past_EOF946=== PAUSE TestParseSingleRange/start_far_past_EOF947=== CONT TestGracefulShutdownDrainsInflight9482026/10/07 07:42:52 INFO Starting HTTP server address=127.0.0.1:568859492026/10/07 07:42:52 INFO Shutdown signal received, draining in-flight requests timeout=10s950--- PASS: TestGracefulShutdownDrainsInflight (0.07s)951=== CONT TestOrphanedObjectsGC9522026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures9542026/10/07 07:42:52 INFO Received uploads request method=POST path=/api/pending_closures9552026/10/07 07:42:52 WARN Rate limiter enabled after throttle name=s3-test rate=59562026/10/07 07:42:52 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."957=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle958 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=10959 throttle_test.go:215: Rate limiter: enabled=true, rate=5.00960--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.38s)961=== CONT TestObjectStatsLargeCommit962--- PASS: TestReadRedirectKeepsNarinfoProxied (6.40s)963=== CONT TestGCTaskStore_StartNew964--- PASS: TestGCTaskStore_StartNew (0.00s)965=== CONT TestGCTaskStore_Fail966--- PASS: TestGCTaskStore_Fail (0.00s)967=== CONT TestObjectStatsTrigger9682026/10/07 07:42:53 INFO Received push request method=POST path=/api/pushes9692026/10/07 07:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/10/07 07:42:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLjQwMmRjNTE2LWVlNWQtNGJkOC1hZGIxLTc2Mjk0ZTVhOWYxNHgxNzkxMzU4OTcxMjQzOTAxMDAw parts=109712026/10/07 07:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9722026/10/07 07:42:53 INFO Completed upload id=1 objects=2 duration=28.206125ms9732026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures9742026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/07 07:42:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9762026/10/07 07:42:53 WARN Found objects in DB but missing from S3, will re-upload count=1977--- PASS: TestService_verifyS3Integrity (7.10s)978=== CONT TestPendingCleanupUsesOneCutoff9792026/10/07 07:42:53 INFO Received uploads request method=POST path=/api/pending_closures9802026-10-07 07:42:53.862 UTC [42917] ERROR: Push does not exist: id=19812026-10-07 07:42:53.862 UTC [42917] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9822026-10-07 07:42:53.862 UTC [42917] STATEMENT: SELECT commit_push($1)983--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (7.32s)984=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded985--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (7.44s)986=== CONT TestMultipartCleanup9872026/10/07 07:42:54 INFO Received push request method=POST path=/api/pushes9882026/10/07 07:42:54 INFO Received complete push request method=POST path=/api/pushes/1/complete9892026/10/07 07:42:54 INFO Completed push id=1 objects=6 duration=72.595916ms990--- PASS: TestPush_CompleteCommitsEveryRoot (8.04s)991=== CONT TestGCTaskStore_PhaseUpdates992--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)993=== CONT TestGCTaskStore_CompletedAllowsNewTask994--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)995=== CONT TestGCTaskStore_GetReturnsLatest996--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)997=== CONT TestGCTaskStore_GetEmpty998--- PASS: TestGCTaskStore_GetEmpty (0.00s)999=== CONT TestServerTLSConfig1000=== RUN TestServerTLSConfig/no_client_CA1001=== PAUSE TestServerTLSConfig/no_client_CA1002=== RUN TestServerTLSConfig/missing_CA_file1003=== PAUSE TestServerTLSConfig/missing_CA_file1004=== RUN TestServerTLSConfig/not_a_PEM_file1005=== PAUSE TestServerTLSConfig/not_a_PEM_file1006=== CONT TestGCTaskStore_ConflictDifferentParams1007--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1008=== CONT TestService_NativeMTLS10092026/10/07 07:42:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10102026/10/07 07:42:54 INFO Received push request method=POST path=/api/pushes10112026/10/07 07:42:54 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLmRlNWQwNGIyLTJkYTctNDJmOC1hYjcxLTE0NDE0MzA0MzVmM3gxNzkxMzU4OTcyNTM1Nzc1MDAw parts=1010122026/10/07 07:42:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10132026/10/07 07:42:54 INFO Completed upload id=1 objects=2 duration=22.209083ms10142026/10/07 07:42:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010152026/10/07 07:42:54 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/07 07:42:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures10172026/10/07 07:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete10182026/10/07 07:42:55 INFO Aborted multipart uploads count=0 kept=010192026/10/07 07:42:55 INFO Completed push id=1 objects=4 duration=36.332625ms1020--- PASS: TestPush_RepeatedRootCommitsOnce (8.45s)10212026/10/07 07:42:55 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=01022=== CONT TestGCTaskStore_DeduplicateSameParams1023--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1024=== CONT TestMetricsCommit10252026/10/07 07:42:55 INFO Vacuumed table table=pending_closures10262026/10/07 07:42:55 INFO Vacuumed table table=pending_objects10272026/10/07 07:42:55 INFO Vacuumed table table=multipart_uploads10282026/10/07 07:42:55 INFO Vacuumed table table=closures10292026/10/07 07:42:55 INFO Vacuumed table table=objects1030--- PASS: TestReadProxyRangeRequest (8.75s)1031=== CONT TestMetricsInventory10322026/10/07 07:42:55 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001033--- PASS: TestService_createPendingClosureHandler (8.83s)1034=== CONT TestCacheConfigHandlerMaxNarSize1035--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1036=== CONT TestGenerateLandingPage1037--- PASS: TestGenerateLandingPage (0.00s)1038=== CONT TestNARDeduplicationMetadataUploadBug1039--- PASS: TestReadProxyConditionalGet (9.18s)1040=== CONT TestService_readinessHandler10412026/10/07 07:42:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10422026/10/07 07:42:56 WARN Refused reserved pin name=worker-x86_64-linux10432026/10/07 07:42:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10442026/10/07 07:42:56 INFO Received create pin request method=POST path=/api/pins/my-app10452026/10/07 07:42:56 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1046--- PASS: TestCreatePin_ReservedPins (10.41s)1047=== CONT TestCreatePendingClosureRejectsOversizedNAR10482026/10/07 07:42:56 INFO Received uploads request method=POST path=/api/pending_closures1049--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1050=== CONT TestService_healthCheckHandler1051--- PASS: TestReadRedirectNar (10.99s)1052=== CONT TestRedundantMultipartUpload1053--- PASS: TestReadProxyDisabled (11.53s)1054=== CONT TestPresignedUploadRegisteredBeforeCommit1055--- PASS: TestReadProxyRootRedirectsToIndexHTML (12.17s)1056=== CONT TestCompletedNarNotReofferedAcrossClosures1057--- PASS: TestReadProxyInvalidPath (10.97s)1058=== CONT TestService_Rustfstest1059--- PASS: TestReadProxyHead (12.26s)1060=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1061--- PASS: TestReadProxy404 (11.46s)1062=== CONT TestPush_RejectsBadRequests1063--- PASS: TestReadProxyOutlastsServerWriteTimeout (13.99s)1064=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1065=== NAME TestOrphanedObjectsGCStressTest1066 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1067 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1068--- PASS: TestReadProxyNarStreaming (11.29s)1069=== CONT TestPush_SignsNarinfosOfItsPendingObjects1070--- PASS: TestReadProxyContentNegotiation (11.02s)1071=== CONT TestRegisterCompletedObjectNeedsPendingRow1072--- PASS: TestReadProxyNarinfoAlreadyDecompressed (10.97s)1073=== CONT TestSweepRechecksPendingAfterLocking10742026/10/07 07:43:02 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1075--- PASS: TestReadProxyNarinfo (10.52s)1076=== CONT TestGetExistingObjectsLocksRows1077--- PASS: TestObjectStatsTrigger (10.83s)1078=== CONT TestGCEndsOnShutdown1079=== RUN TestGCEndsOnShutdown/before_the_run1080=== PAUSE TestGCEndsOnShutdown/before_the_run1081=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1082=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1083=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1084=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1085=== CONT TestCommitRacingPendingCleanupKeepsObjects1086=== NAME TestOrphanedObjectsGC1087 orphaned_objects_gc_test.go:287: GC Test Summary:1088 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1089 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1090 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1091 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1092 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1093--- PASS: TestOrphanedObjectsGC (11.70s)1094=== CONT TestPushWaitsForSweepHoldingRow10952026/10/07 07:43:04 INFO Received uploads request method=POST path=/api/pending_closures10962026/10/07 07:43:04 INFO Received uploads request method=POST path=/api/pending_closures10972026/10/07 07:43:04 INFO Received cleanup request method=DELETE path=/api/pending_closures10982026/10/07 07:43:04 INFO Received uploads request method=POST path=/api/pending_closures10992026/10/07 07:43:04 INFO Received cleanup request method=DELETE path=/api/pending_closures11002026/10/07 07:43:04 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11012026/10/07 07:43:04 INFO Aborted multipart uploads count=0 kept=111022026/10/07 07:43:04 INFO Received cleanup request method=DELETE path=/api/pending_closures11032026/10/07 07:43:04 INFO Aborted multipart uploads count=1 kept=01104--- PASS: TestMultipartCleanup (11.01s)1105=== CONT TestClientCADerivations11062026/10/07 07:43:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11072026/10/07 07:43:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1108--- PASS: TestService_NativeMTLS (10.53s)1109=== CONT TestClientFallsBackToClosures11102026/10/07 07:43:05 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (11.88s)1112=== CONT TestClientPushesUseOnePush11132026/10/07 07:43:06 INFO Received push request method=POST path=/api/pushes11142026/10/07 07:43:06 INFO Received complete push request method=POST path=/api/pushes/1/complete11152026/10/07 07:43:06 INFO Completed push id=1 objects=4 duration=80.066833ms11162026/10/07 07:43:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11172026/10/07 07:43:06 INFO Completed upload id=2 objects=2 duration=2.654084ms1118--- PASS: TestMetricsCommit (11.25s)1119=== CONT TestPinProtectsFromGC1120=== NAME TestOrphanedObjectsGCStressTest1121 orphaned_objects_gc_test.go:503: Stress test completed successfully:1122 orphaned_objects_gc_test.go:504: - Active objects preserved: 201123 orphaned_objects_gc_test.go:505: - Objects deleted: 2101124 orphaned_objects_gc_test.go:506: - Total GC'd: 2101125--- PASS: TestOrphanedObjectsGCStressTest (20.34s)1126=== CONT TestClientSharedPathCommittedMidPush1127--- PASS: TestMetricsInventory (11.78s)1128=== CONT TestClientWithDependencies1129=== NAME TestNARDeduplicationMetadataUploadBug1130 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestNARDeduplicationMetadataUploadBug2392086945/001/store/jhq1lnr51nw7wrflnab36lqjwqchrsb4-file1.txt11312026/10/07 07:43:07 INFO Received push request method=POST path=/api/pushes11322026/10/07 07:43:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11332026/10/07 07:43:07 INFO Uploading jhq1lnr51nw7wrflnab36lqjwqchrsb4-file1.txt (160B)11342026/10/07 07:43:07 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11352026/10/07 07:43:07 WARN Failed to register uploaded object key=jhq1lnr51nw7wrflnab36lqjwqchrsb4.ls error="server returned 404: 404 page not found\n"11362026/10/07 07:43:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11372026/10/07 07:43:07 INFO Signed narinfos id=1 count=111382026/10/07 07:43:07 INFO Uploading 1 narinfos11392026/10/07 07:43:07 INFO Received complete push request method=POST path=/api/pushes/1/complete11402026/10/07 07:43:07 WARN Failed to register uploaded object key=jhq1lnr51nw7wrflnab36lqjwqchrsb4.narinfo error="server returned 404: 404 page not found\n"11412026/10/07 07:43:07 INFO Completed push id=1 objects=3 duration=35.643ms11422026/10/07 07:43:07 INFO Upload complete. (240ms)1143 metadata_upload_test.go:54: Retrieved narinfo from S3:11442026/10/07 07:43:07 WARN readiness check failed error="closed pool"1145 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestNARDeduplicationMetadataUploadBug2392086945/001/store/jhq1lnr51nw7wrflnab36lqjwqchrsb4-file1.txt1146 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1147 Compression: zstd1148 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1149 NarSize: 1601150 References: 1151 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1152=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1153--- PASS: TestService_readinessHandler (11.68s)1154=== NAME TestNARDeduplicationMetadataUploadBug1155 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1156 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1157 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1158 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestNARDeduplicationMetadataUploadBug2392086945/001/store/gffqw45wmmb8bczwjvdayjph92rvryb4-file2.txt11592026/10/07 07:43:07 INFO Received push request method=POST path=/api/pushes11602026/10/07 07:43:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11612026/10/07 07:43:07 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11622026/10/07 07:43:07 WARN Failed to register uploaded object key=gffqw45wmmb8bczwjvdayjph92rvryb4.ls error="server returned 404: 404 page not found\n"11632026/10/07 07:43:07 INFO Signed narinfos id=2 count=111642026/10/07 07:43:07 INFO Uploading 1 narinfos11652026/10/07 07:43:07 INFO Received complete push request method=POST path=/api/pushes/2/complete11662026/10/07 07:43:07 WARN Failed to register uploaded object key=gffqw45wmmb8bczwjvdayjph92rvryb4.narinfo error="server returned 404: 404 page not found\n"1167--- PASS: TestService_healthCheckHandler (10.88s)1168=== CONT TestGCSweepDeliversEachKeyOnce11692026/10/07 07:43:07 INFO Completed push id=2 objects=3 duration=76.00525ms11702026/10/07 07:43:07 INFO Upload complete. (223ms)1171=== NAME TestNARDeduplicationMetadataUploadBug1172 metadata_upload_test.go:76: Retrieved narinfo from S3:1173 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestNARDeduplicationMetadataUploadBug2392086945/001/store/gffqw45wmmb8bczwjvdayjph92rvryb4-file2.txt1174 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1175 Compression: zstd1176 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1177 NarSize: 1601178 References: 1179 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1180 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1181 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1182 {"version":1,"root":{"type":"regular","size":44}}1183--- PASS: TestNARDeduplicationMetadataUploadBug (12.70s)1184=== CONT TestTombstonedObjectOfferedWithoutWaiting11852026/10/07 07:43:08 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/07 07:43:08 INFO Received uploads request method=POST path=/api/pending_closures11872026/10/07 07:43:08 INFO Received uploads request method=POST path=/api/pending_closures11882026/10/07 07:43:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11892026/10/07 07:43:09 INFO Received uploads request method=POST path=/api/pending_closures1190--- PASS: TestPresignedUploadRegisteredBeforeCommit (10.91s)1191=== CONT TestClientMultipleUploads1192--- PASS: TestService_Rustfstest (10.06s)1193=== CONT TestGCSweepSkipsPendingObjects11942026/10/07 07:43:09 INFO Received uploads request method=POST path=/api/pending_closures11952026/10/07 07:43:10 INFO Received uploads request method=POST path=/api/pending_closures11962026/10/07 07:43:10 INFO Aborted multipart uploads count=1 kept=011972026/10/07 07:43:10 INFO Received cleanup request method=DELETE path=/api/pending_closures11982026/10/07 07:43:10 INFO Aborted multipart uploads count=1 kept=01199--- PASS: TestPendingCleanupUsesOneCutoff (16.92s)1200=== CONT TestClientIntegration12012026/10/07 07:43:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12022026/10/07 07:43:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLmUxODM0MWVjLTc5OTMtNDRmYy05NjllLTRkYTU3Mjg5OTZmNngxNzkxMzU4OTkwNTI5ODY0MDAw12032026/10/07 07:43:11 INFO Received push request method=POST path=/api/pushes12042026/10/07 07:43:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLmUxODM0MWVjLTc5OTMtNDRmYy05NjllLTRkYTU3Mjg5OTZmNngxNzkxMzU4OTkwNTI5ODY0MDAw parts=11205--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (11.18s)1206=== CONT TestClientErrorHandling1207=== RUN TestClientErrorHandling/InvalidStorePath1208=== PAUSE TestClientErrorHandling/InvalidStorePath1209=== RUN TestClientErrorHandling/InvalidAuthToken1210=== PAUSE TestClientErrorHandling/InvalidAuthToken1211=== RUN TestClientErrorHandling/ServerNotAvailable1212=== PAUSE TestClientErrorHandling/ServerNotAvailable1213=== CONT TestLeadIncumbentAnnouncesAtOnce12142026/10/07 07:43:11 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/10/07 07:43:11 INFO Completed push id=1 objects=4 duration=82.130833ms12162026/10/07 07:43:11 INFO Received push request method=POST path=/api/pushes12172026/10/07 07:43:11 INFO Aborted multipart uploads count=0 kept=012182026/10/07 07:43:11 WARN Force mode enabled - objects will be deleted immediately without grace period12192026/10/07 07:43:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12202026/10/07 07:43:11 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=01221=== RUN TestPush_RejectsBadRequests/no_roots1222=== PAUSE TestPush_RejectsBadRequests/no_roots1223=== RUN TestPush_RejectsBadRequests/no_objects1224=== PAUSE TestPush_RejectsBadRequests/no_objects1225=== RUN TestPush_RejectsBadRequests/bad_root1226=== PAUSE TestPush_RejectsBadRequests/bad_root1227=== RUN TestPush_RejectsBadRequests/root_not_in_objects1228=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1229=== CONT TestPushDedupSurvivesConcurrentGC12302026/10/07 07:43:11 INFO Vacuumed table table=pending_closures12312026/10/07 07:43:11 INFO Vacuumed table table=pending_objects12322026/10/07 07:43:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLjFkMjM2OGQ5LWM3ODgtNGNkYy05YmM5LTA4N2I4NjViOGE2MHgxNzkxMzU4OTg4NDIwNDgzMDAw parts=1212332026/10/07 07:43:11 INFO Received uploads request method=POST path=/api/pending_closures12342026/10/07 07:43:11 INFO Vacuumed table table=multipart_uploads12352026/10/07 07:43:11 INFO Received uploads request method=POST path=/api/pending_closures12362026/10/07 07:43:11 INFO Vacuumed table table=closures12372026/10/07 07:43:11 INFO Vacuumed table table=objects12382026/10/07 07:43:11 INFO Received complete push request method=POST path=/api/pushes/2/complete12392026/10/07 07:43:11 INFO Completed push id=2 objects=4 duration=10.191542ms1240--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (11.33s)1241=== CONT TestDeduplicatedObjectsRecordedAsPending12422026/10/07 07:43:12 INFO Received push request method=POST path=/api/pushes12432026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12442026/10/07 07:43:12 INFO Signed narinfos id=1 count=112452026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12462026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12472026/10/07 07:43:12 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12482026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12492026/10/07 07:43:12 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12502026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12512026/10/07 07:43:12 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112522026/10/07 07:43:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12532026/10/07 07:43:12 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1254--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (11.56s)1255=== CONT TestGCMetrics1256--- PASS: TestRegisterCompletedObjectNeedsPendingRow (11.38s)1257=== CONT TestLeadElectsOneAndHandsOver12582026/10/07 07:43:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12592026/10/07 07:43:13 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLjJmN2I5Zjc4LWQ0NDYtNDhjZS1hZDE2LTQyODMzZGI3OGQ3M3gxNzkxMzU4OTg5OTM2MzQzMDAw parts=1212602026/10/07 07:43:13 INFO Received uploads request method=POST path=/api/pending_closures1261--- PASS: TestCompletedNarNotReofferedAcrossClosures (14.45s)1262=== CONT TestGCBugBareHashReferences12632026/10/07 07:43:13 INFO Aborted multipart uploads count=0 kept=012642026/10/07 07:43:13 WARN Force mode enabled - objects will be deleted immediately without grace period12652026/10/07 07:43:13 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=012662026/10/07 07:43:13 INFO Vacuumed table table=pending_closures12672026/10/07 07:43:13 INFO Vacuumed table table=pending_objects12682026/10/07 07:43:13 INFO Vacuumed table table=multipart_uploads12692026/10/07 07:43:13 INFO Vacuumed table table=closures12702026/10/07 07:43:13 INFO Vacuumed table table=objects1271--- PASS: TestSweepRechecksPendingAfterLocking (11.98s)1272=== CONT TestConnectWaitsForAPeerMigration1273--- PASS: TestGetExistingObjectsLocksRows (11.61s)1274=== CONT TestGCAdvisoryLockBlocksConcurrentRun12752026/10/07 07:43:14 INFO Aborted multipart uploads count=0 kept=012762026/10/07 07:43:14 WARN Force mode enabled - objects will be deleted immediately without grace period12772026/10/07 07:43:14 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=012782026/10/07 07:43:14 INFO Vacuumed table table=pending_closures12792026/10/07 07:43:14 INFO Vacuumed table table=pending_objects12802026/10/07 07:43:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12812026/10/07 07:43:14 INFO Vacuumed table table=multipart_uploads12822026/10/07 07:43:14 INFO Vacuumed table table=closures12832026/10/07 07:43:14 INFO Vacuumed table table=objects12842026/10/07 07:43:14 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLjE0ZDBjNTBjLThkZmMtNGZiNC04ODE3LThmMDdiMzRmMmY1Y3gxNzkxMzU4OTkxODI0MTE0MDAw error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12852026/10/07 07:43:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZWQ4MmE4Y2QtOWE1ZS00NWQ5LWFlMjgtYTFkN2E5ZDgxODRiLmIzMzY5NWY3LWE0NmMtNDY2OC1iYWFiLTI2NThiMjVjYzcwMXgxNzkxMzU4OTkxNzYwNTA4MDAw parts=1212862026/10/07 07:43:14 INFO Received cleanup request method=DELETE path=/api/pending_closures1287--- PASS: TestCommitRacingPendingCleanupKeepsObjects (11.03s)1288=== CONT TestResolveDBConnectionString12892026/10/07 07:43:14 INFO Aborted multipart uploads count=1 kept=01290=== RUN TestResolveDBConnectionString/flag_wins1291=== PAUSE TestResolveDBConnectionString/flag_wins1292=== RUN TestResolveDBConnectionString/file_when_flag_empty1293=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1294=== RUN TestResolveDBConnectionString/missing_file_is_an_error1295=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1296=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1297=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1298=== RUN TestResolveDBConnectionString/nothing_configured1299=== PAUSE TestResolveDBConnectionString/nothing_configured1300=== CONT TestLeadEndsOnShutdown1301--- PASS: TestRedundantMultipartUpload (17.32s)1302=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13032026/10/07 07:43:14 INFO Received uploads request method=POST path=/api/pending_closures1304--- PASS: TestPushWaitsForSweepHoldingRow (11.55s)1305=== CONT TestDeleteClosuresRacingPins13062026/10/07 07:43:15 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/07 07:43:15 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/07 07:43:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13092026/10/07 07:43:15 INFO Uploading qdb2nj0aanky56bj45j4sqljvqhbiw9l-a (256B)13102026/10/07 07:43:15 INFO Uploading 4jpjhw3qnbmj64pln8qfz78mkj4hh93a-shared-dep (136B)13112026/10/07 07:43:15 WARN Failed to register uploaded object key=qdb2nj0aanky56bj45j4sqljvqhbiw9l.ls error="server returned 404: 404 page not found\n"13122026/10/07 07:43:15 WARN Failed to register uploaded object key=35mwhwd42vkb7syy9bbl8b35s31gwnjm.ls error="server returned 404: 404 page not found\n"13132026/10/07 07:43:15 WARN Failed to register uploaded object key=4jpjhw3qnbmj64pln8qfz78mkj4hh93a.ls error="server returned 404: 404 page not found\n"13142026/10/07 07:43:15 WARN Failed to register uploaded object key=nar/0vg3mgs8yiflfgnivb9rz4ia9h275p6qghvj9bq6ymx93jd4r4x4.nar.zst error="server returned 404: 404 page not found\n"13152026/10/07 07:43:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13162026/10/07 07:43:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13172026/10/07 07:43:15 INFO Signed narinfos id=1 count=213182026/10/07 07:43:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13192026/10/07 07:43:15 INFO Signed narinfos id=2 count=213202026/10/07 07:43:15 INFO Uploading 4 narinfos13212026/10/07 07:43:15 WARN Failed to register uploaded object key=qdb2nj0aanky56bj45j4sqljvqhbiw9l.narinfo error="server returned 404: 404 page not found\n"13222026/10/07 07:43:15 WARN Failed to register uploaded object key=35mwhwd42vkb7syy9bbl8b35s31gwnjm.narinfo error="server returned 404: 404 page not found\n"13232026/10/07 07:43:15 WARN Failed to register uploaded object key=4jpjhw3qnbmj64pln8qfz78mkj4hh93a.narinfo error="server returned 404: 404 page not found\n"13242026/10/07 07:43:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13252026/10/07 07:43:15 WARN Failed to register uploaded object key=4jpjhw3qnbmj64pln8qfz78mkj4hh93a.narinfo error="server returned 404: 404 page not found\n"13262026/10/07 07:43:16 INFO Completed upload id=1 objects=6 duration=42.059292ms13272026/10/07 07:43:16 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13282026/10/07 07:43:16 INFO Completed upload id=2 objects=6 duration=1.872333ms13292026/10/07 07:43:16 INFO Upload complete. (329ms)1330=== NAME TestClientFallsBackToClosures1331 client_pushes_test.go:112: Retrieved narinfo from S3:1332 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientFallsBackToClosures1359157161/001/store/4jpjhw3qnbmj64pln8qfz78mkj4hh93a-shared-dep1333 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1334 Compression: zstd1335 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821336 NarSize: 1361337 References: 1338 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1339 client_pushes_test.go:112: Retrieved narinfo from S3:1340 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientFallsBackToClosures1359157161/001/store/qdb2nj0aanky56bj45j4sqljvqhbiw9l-a1341 URL: nar/0vg3mgs8yiflfgnivb9rz4ia9h275p6qghvj9bq6ymx93jd4r4x4.nar.zst1342 Compression: zstd1343 NarHash: sha256:0vg3mgs8yiflfgnivb9rz4ia9h275p6qghvj9bq6ymx93jd4r4x41344 NarSize: 2561345 References: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientFallsBackToClosures1359157161/001/store/4jpjhw3qnbmj64pln8qfz78mkj4hh93a-shared-dep1346 CA: text:sha256:1a8j3w8xhysaynbz83hx40cwgv76nlfsgsv29s5pp4122wg72j1r1347 client_pushes_test.go:112: Retrieved narinfo from S3:1348 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientFallsBackToClosures1359157161/001/store/35mwhwd42vkb7syy9bbl8b35s31gwnjm-b1349 URL: nar/0vg3mgs8yiflfgnivb9rz4ia9h275p6qghvj9bq6ymx93jd4r4x4.nar.zst1350 Compression: zstd1351 NarHash: sha256:0vg3mgs8yiflfgnivb9rz4ia9h275p6qghvj9bq6ymx93jd4r4x41352 NarSize: 2561353 References: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientFallsBackToClosures1359157161/001/store/4jpjhw3qnbmj64pln8qfz78mkj4hh93a-shared-dep1354 CA: text:sha256:1a8j3w8xhysaynbz83hx40cwgv76nlfsgsv29s5pp4122wg72j1r1355--- PASS: TestClientFallsBackToClosures (11.00s)1356=== CONT TestService_RequireScope_OIDC1357=== NAME TestClientCADerivations1358 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientCADerivations4202174531/001/store/kf4iigr2s5pb72az7a1p8x0jkfg01xnj-ca-test13592026/10/07 07:43:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57078/oidc1360 client_ca_test.go:139: Found 1 dependencies (including self)13612026/10/07 07:43:16 INFO Received push request method=POST path=/api/pushes13622026/10/07 07:43:16 INFO Received push request method=POST path=/api/pushes13632026/10/07 07:43:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13642026/10/07 07:43:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13652026/10/07 07:43:16 INFO Uploading kf4iigr2s5pb72az7a1p8x0jkfg01xnj-ca-test (144B)13662026/10/07 07:43:16 INFO Uploading d538cd90v5cjp832iazlhkhr9rpmysg3-a (256B)13672026/10/07 07:43:16 INFO Uploading 0zl66avhz04lxgrpznajvvcd42y7r00w-shared-dep (136B)13682026/10/07 07:43:16 WARN Failed to register uploaded object key=kf4iigr2s5pb72az7a1p8x0jkfg01xnj.ls error="server returned 404: 404 page not found\n"13692026/10/07 07:43:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13702026/10/07 07:43:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13712026/10/07 07:43:16 WARN Failed to register uploaded object key=log/yzzjsv1b2535cgv7cnx01y0hijfkn8d9-ca-test.drv error="server returned 404: 404 page not found\n"13722026/10/07 07:43:16 WARN Failed to register uploaded object key=cqb60zcc8jjpjkdybkg0nqmg7lmgwx5p.ls error="server returned 404: 404 page not found\n"13732026/10/07 07:43:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13742026/10/07 07:43:16 WARN Failed to register uploaded object key=0zl66avhz04lxgrpznajvvcd42y7r00w.ls error="server returned 404: 404 page not found\n"13752026/10/07 07:43:16 INFO Signed narinfos id=1 count=113762026/10/07 07:43:16 WARN Failed to register uploaded object key=d538cd90v5cjp832iazlhkhr9rpmysg3.ls error="server returned 404: 404 page not found\n"13772026/10/07 07:43:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13782026/10/07 07:43:16 WARN Failed to register uploaded object key=nar/1ds2gilbd9izk30mkhjrsckkdsyh5kl6f6lf3aijy93ahl67fw0w.nar.zst error="server returned 404: 404 page not found\n"13792026/10/07 07:43:16 INFO Uploading 1 narinfos13802026/10/07 07:43:16 INFO Signed narinfos id=1 count=313812026/10/07 07:43:16 INFO Uploading 3 narinfos13822026/10/07 07:43:16 INFO Received complete push request method=POST path=/api/pushes/1/complete13832026/10/07 07:43:16 WARN Failed to register uploaded object key=kf4iigr2s5pb72az7a1p8x0jkfg01xnj.narinfo error="server returned 404: 404 page not found\n"13842026/10/07 07:43:16 WARN Failed to register uploaded object key=0zl66avhz04lxgrpznajvvcd42y7r00w.narinfo error="server returned 404: 404 page not found\n"13852026/10/07 07:43:16 WARN Failed to register uploaded object key=d538cd90v5cjp832iazlhkhr9rpmysg3.narinfo error="server returned 404: 404 page not found\n"13862026/10/07 07:43:16 INFO Received complete push request method=POST path=/api/pushes/1/complete13872026/10/07 07:43:16 WARN Failed to register uploaded object key=cqb60zcc8jjpjkdybkg0nqmg7lmgwx5p.narinfo error="server returned 404: 404 page not found\n"13882026/10/07 07:43:16 INFO Completed push id=1 objects=4 duration=22.325959ms13892026/10/07 07:43:16 INFO Upload complete. (291ms)1390 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientCADerivations4202174531/001/store/kf4iigr2s5pb72az7a1p8x0jkfg01xnj-ca-test1391 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1392 Compression: zstd1393 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1394 NarSize: 1441395 References: 1396 Deriver: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientCADerivations4202174531/001/store/yzzjsv1b2535cgv7cnx01y0hijfkn8d9-ca-test.drv1397 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1398 client_ca_test.go:185: Checking for realisation files in S3...1399 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1400 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14012026/10/07 07:43:16 INFO Completed push id=1 objects=8 duration=27.106084ms14022026/10/07 07:43:16 INFO Upload complete. (239ms)1403=== NAME TestClientPushesUseOnePush1404 client_pushes_test.go:97: Retrieved narinfo from S3:1405 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientPushesUseOnePush14974449/001/store/0zl66avhz04lxgrpznajvvcd42y7r00w-shared-dep1406 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1407 Compression: zstd1408 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821409 NarSize: 1361410 References: 1411 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1412 client_pushes_test.go:97: Retrieved narinfo from S3:1413 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientPushesUseOnePush14974449/001/store/d538cd90v5cjp832iazlhkhr9rpmysg3-a1414 URL: nar/1ds2gilbd9izk30mkhjrsckkdsyh5kl6f6lf3aijy93ahl67fw0w.nar.zst1415 Compression: zstd1416 NarHash: sha256:1ds2gilbd9izk30mkhjrsckkdsyh5kl6f6lf3aijy93ahl67fw0w1417 NarSize: 2561418 References: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientPushesUseOnePush14974449/001/store/0zl66avhz04lxgrpznajvvcd42y7r00w-shared-dep1419 CA: text:sha256:1i36c449g374n4wb7mh8v3vpyxhm2g7y76v5s0iwnix5yny4jq3d1420 client_pushes_test.go:97: Retrieved narinfo from S3:1421 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientPushesUseOnePush14974449/001/store/cqb60zcc8jjpjkdybkg0nqmg7lmgwx5p-b1422 URL: nar/1ds2gilbd9izk30mkhjrsckkdsyh5kl6f6lf3aijy93ahl67fw0w.nar.zst1423 Compression: zstd1424 NarHash: sha256:1ds2gilbd9izk30mkhjrsckkdsyh5kl6f6lf3aijy93ahl67fw0w1425 NarSize: 2561426 References: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientPushesUseOnePush14974449/001/store/0zl66avhz04lxgrpznajvvcd42y7r00w-shared-dep1427 CA: text:sha256:1i36c449g374n4wb7mh8v3vpyxhm2g7y76v5s0iwnix5yny4jq3d1428=== NAME TestPinProtectsFromGC1429 client_integration_test.go:731: Pinned store path: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestPinProtectsFromGC2250007337/001/store/wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf-pinned-file.txt1430 client_integration_test.go:732: Unpinned store path: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestPinProtectsFromGC2250007337/001/store/5rmm9yvbwsz9sqnv2sns1c80f92k7bdk-unpinned-file.txt1431--- PASS: TestClientPushesUseOnePush (10.87s)1432=== CONT TestCacheConfigHandler1433=== RUN TestCacheConfigHandler/full_config,_no_issuer1434=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1435=== RUN TestCacheConfigHandler/no_cache_url_configured1436=== PAUSE TestCacheConfigHandler/no_cache_url_configured1437=== RUN TestCacheConfigHandler/no_signing_keys1438=== PAUSE TestCacheConfigHandler/no_signing_keys1439=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1440=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1441=== CONT TestCacheStatsHandler1442=== NAME TestClientCADerivations1443 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket61?endpoint=http://localhost:56810®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientCADerivations4202174531/001/store'1444 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11445--- PASS: TestClientCADerivations (11.76s)1446=== CONT TestService_ReadScope_PublicByDefault14472026/10/07 07:43:16 INFO Received push request method=POST path=/api/pushes14482026/10/07 07:43:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14492026/10/07 07:43:16 INFO Uploading wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf-pinned-file.txt (128B)14502026/10/07 07:43:16 WARN Failed to register uploaded object key=wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf.ls error="server returned 404: 404 page not found\n"14512026/10/07 07:43:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/10/07 07:43:16 INFO Signed narinfos id=1 count=114532026/10/07 07:43:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14542026/10/07 07:43:16 INFO Uploading 1 narinfos14552026/10/07 07:43:16 INFO Received complete push request method=POST path=/api/pushes/1/complete14562026/10/07 07:43:16 WARN Failed to register uploaded object key=wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf.narinfo error="server returned 404: 404 page not found\n"1457--- PASS: TestObjectStatsLargeCommit (23.99s)1458=== CONT TestFailedS3DeleteKeepsTombstone14592026/10/07 07:43:16 INFO Completed push id=1 objects=3 duration=68.112959ms14602026/10/07 07:43:16 INFO Upload complete. (253ms)14612026/10/07 07:43:17 INFO Received push request method=POST path=/api/pushes14622026/10/07 07:43:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14632026/10/07 07:43:17 INFO Uploading 5rmm9yvbwsz9sqnv2sns1c80f92k7bdk-unpinned-file.txt (128B)14642026/10/07 07:43:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14652026/10/07 07:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14662026/10/07 07:43:17 WARN Failed to register uploaded object key=5rmm9yvbwsz9sqnv2sns1c80f92k7bdk.ls error="server returned 404: 404 page not found\n"14672026/10/07 07:43:17 INFO Signed narinfos id=2 count=114682026/10/07 07:43:17 INFO Uploading 1 narinfos14692026/10/07 07:43:17 INFO Received complete push request method=POST path=/api/pushes/2/complete14702026/10/07 07:43:17 WARN Failed to register uploaded object key=5rmm9yvbwsz9sqnv2sns1c80f92k7bdk.narinfo error="server returned 404: 404 page not found\n"14712026/10/07 07:43:17 INFO Completed push id=2 objects=3 duration=1.044541ms14722026/10/07 07:43:17 INFO Received push request method=POST path=/api/pushes14732026/10/07 07:43:17 INFO Upload complete. (116ms)14742026/10/07 07:43:17 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14752026/10/07 07:43:17 INFO Uploading 0kipbgn4jg0hpjwngk6kyb36vja2pplf-top (264B)14762026/10/07 07:43:17 INFO Uploading pc6xrcsg1mgzv32mhipz0wr1jcqln506-shared-dep (136B)14772026/10/07 07:43:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures14782026/10/07 07:43:17 INFO Garbage collection started14792026/10/07 07:43:17 WARN Failed to register uploaded object key=0kipbgn4jg0hpjwngk6kyb36vja2pplf.ls error="server returned 404: 404 page not found\n"14802026/10/07 07:43:17 WARN Failed to register uploaded object key=nar/0q63a7iaijsayyshfs0yhjkd477h2cqi2wzm4jsnm8a0vw2l3pmg.nar.zst error="server returned 404: 404 page not found\n"14812026/10/07 07:43:17 INFO Aborted multipart uploads count=0 kept=014822026/10/07 07:43:17 WARN Failed to register uploaded object key=pc6xrcsg1mgzv32mhipz0wr1jcqln506.ls error="server returned 404: 404 page not found\n"14832026/10/07 07:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14842026/10/07 07:43:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14852026/10/07 07:43:17 INFO Signed narinfos id=1 count=214862026/10/07 07:43:17 INFO Uploading 2 narinfos14872026/10/07 07:43:17 WARN Force mode enabled - objects will be deleted immediately without grace period14882026/10/07 07:43:17 WARN Failed to register uploaded object key=pc6xrcsg1mgzv32mhipz0wr1jcqln506.narinfo error="server returned 404: 404 page not found\n"14892026/10/07 07:43:17 INFO Received complete push request method=POST path=/api/pushes/1/complete14902026/10/07 07:43:17 WARN Failed to register uploaded object key=0kipbgn4jg0hpjwngk6kyb36vja2pplf.narinfo error="server returned 404: 404 page not found\n"14912026/10/07 07:43:17 INFO Completed push id=1 objects=6 duration=24.929792ms14922026/10/07 07:43:17 INFO Upload complete. (257ms)1493=== NAME TestClientSharedPathCommittedMidPush1494 client_integration_test.go:680: Retrieved narinfo from S3:1495 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientSharedPathCommittedMidPush2180278703/001/store/pc6xrcsg1mgzv32mhipz0wr1jcqln506-shared-dep1496 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1497 Compression: zstd1498 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821499 NarSize: 1361500 References: 1501 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1502 client_integration_test.go:680: Retrieved narinfo from S3:1503 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientSharedPathCommittedMidPush2180278703/001/store/0kipbgn4jg0hpjwngk6kyb36vja2pplf-top1504 URL: nar/0q63a7iaijsayyshfs0yhjkd477h2cqi2wzm4jsnm8a0vw2l3pmg.nar.zst1505 Compression: zstd1506 NarHash: sha256:0q63a7iaijsayyshfs0yhjkd477h2cqi2wzm4jsnm8a0vw2l3pmg1507 NarSize: 2641508 References: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientSharedPathCommittedMidPush2180278703/001/store/pc6xrcsg1mgzv32mhipz0wr1jcqln506-shared-dep1509 CA: text:sha256:0x67fa8l1vjvpnxig4a895cjgyam9swhh3mvmh2pxsjpj3jqpmc615102026/10/07 07:43:17 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=015112026/10/07 07:43:17 INFO Vacuumed table table=pending_closures15122026/10/07 07:43:17 INFO Received uploads request method=POST path=/api/pending_closures15132026/10/07 07:43:17 INFO Vacuumed table table=pending_objects15142026/10/07 07:43:17 INFO Vacuumed table table=multipart_uploads1515--- PASS: TestClientSharedPathCommittedMidPush (10.50s)1516=== CONT TestSweepSkipsRowsLockedByPush15172026/10/07 07:43:17 INFO Vacuumed table table=closures15182026/10/07 07:43:17 INFO Vacuumed table table=objects1519=== NAME TestClientWithDependencies1520 client_integration_test.go:613: Built derivation: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientWithDependencies3877534350/001/store/lrda6j18xxks13kzvanbxxqhr0dnm3xs-test-script1521 client_integration_test.go:615: Found 1 dependencies (including self)15222026/10/07 07:43:17 INFO Received uploads request method=POST path=/api/pending_closures1523--- PASS: TestTombstonedObjectOfferedWithoutWaiting (9.52s)1524=== CONT TestService_ReadAuthMiddleware1525--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (10.11s)1526=== CONT TestService_AuthMiddleware_OIDC15272026/10/07 07:43:17 INFO Received push request method=POST path=/api/pushes15282026/10/07 07:43:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15292026/10/07 07:43:17 INFO Uploading lrda6j18xxks13kzvanbxxqhr0dnm3xs-test-script (136B)15302026/10/07 07:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57146/oidc15312026/10/07 07:43:17 WARN Failed to register uploaded object key=lrda6j18xxks13kzvanbxxqhr0dnm3xs.ls error="server returned 404: 404 page not found\n"15322026/10/07 07:43:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15332026/10/07 07:43:17 WARN Failed to register uploaded object key=log/0adqp5ynp89095wz3rscqr87qlpnyn9s-test-script.drv error="server returned 404: 404 page not found\n"15342026/10/07 07:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15352026/10/07 07:43:17 INFO Signed narinfos id=1 count=115362026/10/07 07:43:17 INFO Uploading 1 narinfos15372026/10/07 07:43:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15382026/10/07 07:43:17 WARN Failed to register uploaded object key=lrda6j18xxks13kzvanbxxqhr0dnm3xs.narinfo error="server returned 404: 404 page not found\n"15392026/10/07 07:43:17 INFO Completed push id=1 objects=4 duration=30.22025ms15402026/10/07 07:43:17 INFO Upload complete. (165ms)1541=== NAME TestClientWithDependencies1542 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientWithDependencies3877534350/001/store) requires matching store prefix1543--- PASS: TestClientWithDependencies (10.67s)1544=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15452026/10/07 07:43:17 INFO Aborted multipart uploads count=0 kept=015462026/10/07 07:43:17 WARN Force mode enabled - objects will be deleted immediately without grace period15472026/10/07 07:43:18 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=015482026/10/07 07:43:18 INFO Vacuumed table table=pending_closures15492026/10/07 07:43:18 INFO Vacuumed table table=pending_objects15502026/10/07 07:43:18 INFO Vacuumed table table=multipart_uploads15512026/10/07 07:43:18 INFO Vacuumed table table=closures15522026/10/07 07:43:18 INFO Vacuumed table table=objects1553--- PASS: TestGCSweepDeliversEachKeyOnce (10.31s)1554=== CONT TestService_AuthMiddleware_MTLSProxyHeader1555=== NAME TestClientMultipleUploads1556 client_integration_test.go:358: Created store path 0: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientMultipleUploads1353455394/001/store/k5lygb0sn0n3j2jijhaa2nnbmv631fdd-test-file-0.txt1557 client_integration_test.go:358: Created store path 1: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientMultipleUploads1353455394/001/store/y95bvpdxg8kf6fbhcaf678z04h43n2y4-test-file-1.txt15582026/10/07 07:43:18 INFO Received uploads request method=POST path=/api/pending_closures1559 client_integration_test.go:358: Created store path 2: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientMultipleUploads1353455394/001/store/51v4g806kykm8lk80mwp0xl2l8bzlnsl-test-file-2.txt15602026/10/07 07:43:18 INFO Aborted multipart uploads count=0 kept=015612026/10/07 07:43:18 WARN Force mode enabled - objects will be deleted immediately without grace period15622026/10/07 07:43:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015632026/10/07 07:43:18 INFO Vacuumed table table=pending_closures15642026/10/07 07:43:18 INFO Vacuumed table table=pending_objects15652026/10/07 07:43:18 INFO Vacuumed table table=multipart_uploads15662026/10/07 07:43:18 INFO Received push request method=POST path=/api/pushes15672026/10/07 07:43:18 INFO Vacuumed table table=closures15682026/10/07 07:43:18 INFO Vacuumed table table=objects15692026/10/07 07:43:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15702026/10/07 07:43:18 INFO Uploading k5lygb0sn0n3j2jijhaa2nnbmv631fdd-test-file-0.txt (160B)15712026/10/07 07:43:18 INFO Uploading y95bvpdxg8kf6fbhcaf678z04h43n2y4-test-file-1.txt (160B)15722026/10/07 07:43:18 INFO Uploading 51v4g806kykm8lk80mwp0xl2l8bzlnsl-test-file-2.txt (160B)1573--- PASS: TestGCSweepSkipsPendingObjects (9.26s)1574=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15752026/10/07 07:43:18 WARN Failed to register uploaded object key=k5lygb0sn0n3j2jijhaa2nnbmv631fdd.ls error="server returned 404: 404 page not found\n"15762026/10/07 07:43:18 WARN Failed to register uploaded object key=51v4g806kykm8lk80mwp0xl2l8bzlnsl.ls error="server returned 404: 404 page not found\n"15772026/10/07 07:43:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15782026/10/07 07:43:18 WARN Failed to register uploaded object key=y95bvpdxg8kf6fbhcaf678z04h43n2y4.ls error="server returned 404: 404 page not found\n"15792026/10/07 07:43:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15802026/10/07 07:43:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15812026/10/07 07:43:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15822026/10/07 07:43:18 INFO Signed narinfos id=1 count=315832026/10/07 07:43:18 INFO Uploading 3 narinfos15842026/10/07 07:43:18 WARN Failed to register uploaded object key=k5lygb0sn0n3j2jijhaa2nnbmv631fdd.narinfo error="server returned 404: 404 page not found\n"15852026/10/07 07:43:18 WARN Failed to register uploaded object key=y95bvpdxg8kf6fbhcaf678z04h43n2y4.narinfo error="server returned 404: 404 page not found\n"15862026/10/07 07:43:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15872026/10/07 07:43:18 WARN Failed to register uploaded object key=51v4g806kykm8lk80mwp0xl2l8bzlnsl.narinfo error="server returned 404: 404 page not found\n"15882026/10/07 07:43:18 INFO Completed push id=1 objects=9 duration=20.838875ms15892026/10/07 07:43:18 INFO Upload complete. (196ms)1590=== NAME TestClientMultipleUploads1591 client_integration_test.go:369: Uploaded 3 paths in 229.656917ms1592=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1593--- PASS: TestClientMultipleUploads (9.88s)1594=== NAME TestClientIntegration1595 client_integration_test.go:286: Created store path: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientIntegration1298897642/002/store/rrkd5dyrhz9vlvpz81l3d46cp3908r6w-test-file.txt15962026/10/07 07:43:19 INFO lead: acquired remote=192.0.2.1:123415972026/10/07 07:43:19 INFO lead: released remote=192.0.2.1:12341598--- PASS: TestLeadIncumbentAnnouncesAtOnce (8.02s)1599=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16002026/10/07 07:43:19 INFO Received uploads request method=POST path=/1601=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16022026/10/07 07:43:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016032026/10/07 07:43:19 INFO Received create pin request method=POST path=/api/pins/myapp16042026/10/07 07:43:19 INFO Received push request method=POST path=/api/pushes16052026/10/07 07:43:19 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestPinProtectsFromGC2250007337/001/store/wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf-pinned-file.txt narinfo_key=wj7jx3inxrdd8pdl0jg2n3f66dyiv8lf.narinfo16062026/10/07 07:43:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures16072026/10/07 07:43:19 INFO Garbage collection started16082026/10/07 07:43:19 INFO Aborted multipart uploads count=0 kept=016092026/10/07 07:43:19 WARN Force mode enabled - objects will be deleted immediately without grace period16102026/10/07 07:43:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016112026/10/07 07:43:19 INFO Vacuumed table table=pending_closures16122026/10/07 07:43:19 INFO Vacuumed table table=pending_objects16132026/10/07 07:43:19 INFO Vacuumed table table=multipart_uploads16142026/10/07 07:43:19 INFO Vacuumed table table=closures16152026/10/07 07:43:19 INFO Vacuumed table table=objects16162026/10/07 07:43:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16172026/10/07 07:43:19 INFO Uploading rrkd5dyrhz9vlvpz81l3d46cp3908r6w-test-file.txt (152B)16182026/10/07 07:43:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16192026/10/07 07:43:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16202026/10/07 07:43:19 WARN Failed to register uploaded object key=rrkd5dyrhz9vlvpz81l3d46cp3908r6w.ls error="server returned 404: 404 page not found\n"16212026/10/07 07:43:19 INFO Signed narinfos id=1 count=116222026/10/07 07:43:19 INFO Uploading 1 narinfos16232026/10/07 07:43:19 INFO Received complete push request method=POST path=/api/pushes/1/complete16242026/10/07 07:43:19 WARN Failed to register uploaded object key=rrkd5dyrhz9vlvpz81l3d46cp3908r6w.narinfo error="server returned 404: 404 page not found\n"16252026/10/07 07:43:19 INFO Completed push id=1 objects=3 duration=26.814083ms16262026/10/07 07:43:19 INFO Upload complete. (260ms)16272026/10/07 07:43:19 INFO All 1 paths already cached1628=== NAME TestClientIntegration1629 client_integration_test.go:312: Retrieved narinfo from S3:1630 StorePath: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestClientIntegration1298897642/002/store/rrkd5dyrhz9vlvpz81l3d46cp3908r6w-test-file.txt1631 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1632 Compression: zstd1633 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11634 NarSize: 1521635 References: 1636 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11637 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1638 client_integration_test.go:313: Decompressed .ls content (64 bytes):1639 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1640 client_integration_test.go:316: Testing garbage collection...16412026/10/07 07:43:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures16422026/10/07 07:43:19 INFO Garbage collection started16432026/10/07 07:43:19 INFO Aborted multipart uploads count=0 kept=016442026/10/07 07:43:19 WARN Force mode enabled - objects will be deleted immediately without grace period16452026/10/07 07:43:19 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=016462026/10/07 07:43:19 INFO Received uploads request method=POST path=/api/pending_closures16472026/10/07 07:43:19 INFO Vacuumed table table=pending_closures16482026/10/07 07:43:19 INFO Vacuumed table table=pending_objects16492026/10/07 07:43:19 INFO Vacuumed table table=multipart_uploads16502026/10/07 07:43:19 INFO Vacuumed table table=closures16512026/10/07 07:43:19 INFO Aborted multipart uploads count=0 kept=016522026/10/07 07:43:19 INFO Vacuumed table table=objects16532026/10/07 07:43: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=016542026/10/07 07:43:19 INFO Vacuumed table table=pending_closures16552026/10/07 07:43:19 INFO Received uploads request method=POST path=/api/pending_closures16562026/10/07 07:43:19 INFO Vacuumed table table=pending_objects16572026/10/07 07:43:19 INFO Vacuumed table table=multipart_uploads1658--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.04s)1659=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16602026/10/07 07:43:20 INFO Received request for more parts method=POST path=/1661=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16622026/10/07 07:43:20 INFO Received complete multipart upload request method=POST path=/1663=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16642026/10/07 07:43:20 INFO Received uploads request method=POST path=/1665--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1666 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1667 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1668 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1669 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1670=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16712026/10/07 07:43:20 INFO Vacuumed table table=closures16722026/10/07 07:43:20 INFO Vacuumed table table=objects16732026/10/07 07:43:20 INFO Aborted multipart uploads count=0 kept=016742026/10/07 07:43:20 WARN Force mode enabled - objects will be deleted immediately without grace period16752026/10/07 07:43:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016762026/10/07 07:43:20 INFO Vacuumed table table=pending_closures16772026/10/07 07:43:20 INFO Vacuumed table table=pending_objects16782026/10/07 07:43:20 INFO Vacuumed table table=multipart_uploads16792026/10/07 07:43:20 INFO Vacuumed table table=closures16802026/10/07 07:43:20 INFO Vacuumed table table=objects1681--- PASS: TestPushDedupSurvivesConcurrentGC (8.45s)1682=== CONT TestProxyWriteTimeout/narinfo1683=== CONT TestProxyWriteTimeout/10_GiB_nar1684=== CONT TestProxyWriteTimeout/unknown_size1685=== CONT TestProxyWriteTimeout/1_GiB_nar1686--- PASS: TestProxyWriteTimeout (0.00s)1687 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1688 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1689 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1690 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1691=== CONT TestIsValidUploadKey/narinfo1692=== CONT TestIsValidUploadKey/realisation_plus_in_output1693=== CONT TestIsValidUploadKey/unknown_type1694=== CONT TestIsValidUploadKey/empty_key1695=== CONT TestIsValidUploadKey/absolute1696=== CONT TestIsValidUploadKey/traversal_nar1697=== CONT TestIsValidUploadKey/traversal1698=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1699=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1700=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1701=== CONT TestIsValidUploadKey/index.html1702=== CONT TestIsValidUploadKey/nix-cache-info1703=== CONT TestIsValidUploadKey/build_log_home-manager_file1704=== CONT TestIsValidUploadKey/realisation1705=== CONT TestIsValidUploadKey/build_log_equals1706=== CONT TestIsValidUploadKey/build_log_question_mark1707=== CONT TestIsValidUploadKey/build_log_plus_in_name1708=== CONT TestIsValidUploadKey/nar_plain1709=== CONT TestIsValidUploadKey/build_log1710=== CONT TestIsValidUploadKey/listing1711=== CONT TestIsValidUploadKey/nar_xz1712=== CONT TestIsValidUploadKey/nar_zst1713--- PASS: TestIsValidUploadKey (0.05s)1714 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1715 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1716 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1717 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1718 --- PASS: TestIsValidUploadKey/absolute (0.00s)1719 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1720 --- PASS: TestIsValidUploadKey/traversal (0.00s)1721 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1722 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1723 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1724 --- PASS: TestIsValidUploadKey/index.html (0.00s)1725 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1726 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1727 --- PASS: TestIsValidUploadKey/realisation (0.00s)1728 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1729 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1730 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1731 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log (0.00s)1733 --- PASS: TestIsValidUploadKey/listing (0.00s)1734 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1735 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1736=== CONT TestPendingClosureWriteTimeout/empty1737=== CONT TestPendingClosureWriteTimeout/400_objects1738=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17392026/10/07 07:43:20 INFO Aborted multipart uploads count=0 kept=017402026/10/07 07:43:20 WARN Force mode enabled - objects will be deleted immediately without grace period17412026/10/07 07:43:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017422026/10/07 07:43:20 INFO Vacuumed table table=pending_closures17432026/10/07 07:43:20 INFO Vacuumed table table=pending_objects17442026/10/07 07:43:20 INFO Vacuumed table table=multipart_uploads17452026/10/07 07:43:20 INFO Vacuumed table table=closures17462026/10/07 07:43:20 INFO Vacuumed table table=objects1747--- PASS: TestGCMetrics (7.98s)1748=== CONT TestPendingClosureWriteTimeout/670k_objects1749=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17502026/10/07 07:43:20 INFO Received uploads request method=POST path=/17512026/10/07 07:43:20 INFO lead: acquired remote=192.0.2.1:12341752=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17532026/10/07 07:43:20 INFO Received request for more parts method=POST path=/1754=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17552026/10/07 07:43:20 INFO Received complete multipart upload request method=POST path=/1756--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)1757 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1758 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1759 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1760=== CONT TestIsValidCachePath/narinfo1761=== CONT TestIsValidCachePath/index.html1762=== CONT TestIsValidCachePath/short_hash1763=== CONT TestIsValidCachePath/wrong_extension1764=== CONT TestIsValidCachePath/leading_slash1765=== CONT TestIsValidCachePath/empty1766=== CONT TestIsValidCachePath/random_path1767=== CONT TestIsValidCachePath/invalid_char_u1768=== CONT TestIsValidCachePath/invalid_char_e1769=== CONT TestIsValidCachePath/traversal_in_middle1770=== CONT TestIsValidCachePath/traversal_parent1771=== CONT TestIsValidCachePath/nar_uncompressed1772=== CONT TestIsValidCachePath/nix-cache-info1773=== CONT TestIsValidCachePath/realisation1774=== CONT TestIsValidCachePath/log1775=== CONT TestIsValidCachePath/ls1776=== CONT TestIsValidCachePath/nar_xz1777=== CONT TestIsValidCachePath/nar_bz21778=== CONT TestIsValidCachePath/nar_zst1779=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1780--- PASS: TestIsValidCachePath (0.03s)1781 --- PASS: TestIsValidCachePath/narinfo (0.00s)1782 --- PASS: TestIsValidCachePath/index.html (0.00s)1783 --- PASS: TestIsValidCachePath/short_hash (0.00s)1784 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1785 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1786 --- PASS: TestIsValidCachePath/empty (0.00s)1787 --- PASS: TestIsValidCachePath/random_path (0.00s)1788 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1789 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1790 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1791 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1792 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1793 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1794 --- PASS: TestIsValidCachePath/realisation (0.00s)1795 --- PASS: TestIsValidCachePath/log (0.00s)1796 --- PASS: TestIsValidCachePath/ls (0.00s)1797 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1798 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1799 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1800 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1801=== CONT TestParseSingleRange/none1802=== CONT TestParseSingleRange/start_far_past_EOF1803=== CONT TestParseSingleRange/start_past_EOF1804=== CONT TestParseSingleRange/single_byte1805=== CONT TestParseSingleRange/suffix_exceeds_size1806=== CONT TestParseSingleRange/suffix1807=== CONT TestParseSingleRange/end_clamped_to_size1808=== CONT TestParseSingleRange/open-ended1809=== CONT TestParseSingleRange/closed1810=== CONT TestParseSingleRange/malformed_end_before_start1811=== CONT TestParseSingleRange/malformed_both_empty1812=== CONT TestParseSingleRange/malformed_no_dash1813=== CONT TestParseSingleRange/multi-range_ignored1814=== CONT TestParseSingleRange/unknown_unit1815--- PASS: TestParseSingleRange (0.03s)1816 --- PASS: TestParseSingleRange/none (0.00s)1817 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1818 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1819 --- PASS: TestParseSingleRange/single_byte (0.00s)1820 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1821 --- PASS: TestParseSingleRange/suffix (0.00s)1822 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1823 --- PASS: TestParseSingleRange/open-ended (0.00s)1824 --- PASS: TestParseSingleRange/closed (0.00s)1825 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1826 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1827 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1828 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1829 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1830=== CONT TestServerTLSConfig/no_client_CA1831=== CONT TestServerTLSConfig/missing_CA_file1832=== CONT TestServerTLSConfig/not_a_PEM_file1833--- PASS: TestServerTLSConfig (0.01s)1834 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1835 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1836 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1837=== CONT TestGCEndsOnShutdown/before_the_run1838--- PASS: TestGCBugBareHashReferences (7.97s)1839=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1840=== NAME TestPinProtectsFromGC1841 client_integration_test.go:840: Pin successfully protected closure from garbage collection18422026/10/07 07:43:21 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1843--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.32s)1844=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1845--- PASS: TestPinProtectsFromGC (15.02s)1846=== CONT TestClientErrorHandling/InvalidStorePath18472026/10/07 07:43:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01848=== NAME TestClientIntegration1849 client_integration_test.go:323: Objects in database after GC:1850 client_integration_test.go:323: Successfully deleted all objects with GC --force18512026/10/07 07:43:21 INFO lead: acquired remote=192.0.2.1:12341852--- PASS: TestClientIntegration (11.15s)1853=== CONT TestClientErrorHandling/ServerNotAvailable18542026/10/07 07:43:21 INFO lead: released remote=192.0.2.1:123418552026/10/07 07:43:21 INFO lead: acquired remote=192.0.2.1:12341856--- PASS: TestConnectWaitsForAPeerMigration (8.38s)1857=== CONT TestClientErrorHandling/InvalidAuthToken18582026/10/07 07:43:22 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18592026/10/07 07:43:22 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.393923ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18602026/10/07 07:43:22 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=377.923237ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1861=== RUN TestService_RequireScope_OIDC/builder_may_write1862=== PAUSE TestService_RequireScope_OIDC/builder_may_write1863=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1864=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1865=== RUN TestService_RequireScope_OIDC/ops_may_admin1866=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1867=== RUN TestService_RequireScope_OIDC/ops_may_not_write1868=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1869=== RUN TestService_RequireScope_OIDC/reader_may_not_write1870=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1871=== RUN TestService_RequireScope_OIDC/static_token_may_admin1872=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1873=== RUN TestService_RequireScope_OIDC/static_token_may_write1874=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1875=== RUN TestService_RequireScope_OIDC/reader_may_read1876=== PAUSE TestService_RequireScope_OIDC/reader_may_read1877=== RUN TestService_RequireScope_OIDC/writer_implies_read1878=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1879=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1880=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read18812026/10/07 07:43:22 INFO lead: released remote=192.0.2.1:12341882=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1883--- PASS: TestLeadEndsOnShutdown (7.80s)1884=== CONT TestPush_RejectsBadRequests/no_roots1885=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc18862026/10/07 07:43:22 INFO Received push request method=POST path=/api/pushes1887=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1888=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1889=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1890=== CONT TestPush_RejectsBadRequests/bad_root1891=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18922026/10/07 07:43:22 INFO Received push request method=POST path=/api/pushes1893=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1894=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1895=== CONT TestPush_RejectsBadRequests/root_not_in_objects18962026/10/07 07:43:22 INFO Received push request method=POST path=/api/pushes1897=== CONT TestResolveDBConnectionString/flag_wins1898=== CONT TestPush_RejectsBadRequests/no_objects18992026/10/07 07:43:22 INFO Received push request method=POST path=/api/pushes1900=== CONT TestResolveDBConnectionString/nothing_configured1901=== CONT TestResolveDBConnectionString/missing_file_is_an_error1902--- PASS: TestPush_RejectsBadRequests (11.07s)1903 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1904 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)1905 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1906 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1907=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1908=== CONT TestResolveDBConnectionString/file_when_flag_empty1909--- PASS: TestResolveDBConnectionString (0.02s)1910 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1911 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1912 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1913 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1914 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1915=== CONT TestCacheConfigHandler/full_config,_no_issuer1916=== CONT TestCacheConfigHandler/no_signing_keys1917=== CONT TestCacheConfigHandler/no_cache_url_configured1918=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1919--- PASS: TestCacheConfigHandler (0.00s)1920 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1921 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1922 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1923 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1924=== CONT TestService_RequireScope_OIDC/builder_may_write1925=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1926=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19272026/10/07 07:43:22 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]1928=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1929=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1930=== CONT TestService_RequireScope_OIDC/writer_implies_read1931=== CONT TestService_RequireScope_OIDC/reader_may_read1932=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1933=== CONT TestService_RequireScope_OIDC/static_token_may_write1934=== CONT TestService_RequireScope_OIDC/static_token_may_admin1935=== CONT TestService_RequireScope_OIDC/ops_may_not_write1936=== CONT TestService_RequireScope_OIDC/reader_may_not_write1937=== CONT TestService_RequireScope_OIDC/ops_may_admin1938=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1939--- PASS: TestService_RequireScope_OIDC (6.62s)1940 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19542026/10/07 07:43:22 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.683001ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19552026/10/07 07:43:22 INFO lead: released remote=192.0.2.1:12341956--- PASS: TestLeadElectsOneAndHandsOver (10.13s)1957--- PASS: TestCacheStatsHandler (6.48s)1958--- PASS: TestService_ReadScope_PublicByDefault (6.68s)1959--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.60s)19602026/10/07 07:43:23 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.679896905s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19612026/10/07 07:43:23 INFO Received uploads request method=POST path=/api/pending_closures19622026/10/07 07:43:24 INFO Aborted multipart uploads count=0 kept=019632026/10/07 07:43:24 WARN Force mode enabled - objects will be deleted immediately without grace period19642026/10/07 07:43:24 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19652026/10/07 07:43:24 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1966--- PASS: TestFailedS3DeleteKeepsTombstone (7.24s)19672026/10/07 07:43:24 INFO Aborted multipart uploads count=0 kept=019682026/10/07 07:43:24 WARN Force mode enabled - objects will be deleted immediately without grace period19692026/10/07 07:43: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=019702026/10/07 07:43:24 INFO Vacuumed table table=pending_closures19712026/10/07 07:43:24 INFO Vacuumed table table=pending_objects19722026/10/07 07:43:24 INFO Vacuumed table table=multipart_uploads19732026/10/07 07:43:24 INFO Vacuumed table table=closures19742026/10/07 07:43:24 INFO Vacuumed table table=objects19752026/10/07 07:43:24 INFO Aborted multipart uploads count=0 kept=019762026/10/07 07:43:24 WARN Force mode enabled - objects will be deleted immediately without grace period19772026/10/07 07:43:24 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=019782026/10/07 07:43:24 INFO Vacuumed table table=pending_closures19792026/10/07 07:43:24 INFO Vacuumed table table=pending_objects19802026/10/07 07:43:24 INFO Vacuumed table table=multipart_uploads19812026/10/07 07:43:24 INFO Vacuumed table table=closures19822026/10/07 07:43:24 INFO Vacuumed table table=objects1983--- PASS: TestSweepSkipsRowsLockedByPush (7.04s)1984--- PASS: TestService_ReadAuthMiddleware (6.99s)1985=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1986=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1987=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1988=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1989=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1990=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1991=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1992=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1993=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1994=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19952026/10/07 07:43:24 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]1996=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1997=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19982026/10/07 07:43:24 WARN Authentication failed token_preview=eyJhbGciOi...9mbA3w9JFA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1999--- PASS: TestService_AuthMiddleware_OIDC (7.37s)2000 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2001 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2002 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2003 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20042026/10/07 07:43:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20052026/10/07 07:43:25 WARN mTLS auth: bound subjects configured but subject DN unavailable20062026/10/07 07:43:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2007--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.34s)2008--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.20s)20092026/10/07 07:43:25 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20102026/10/07 07:43:25 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.852647ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20112026-10-07 07:43:25.569 UTC [42727] LOG: checkpoint starting: wal20122026/10/07 07:43:25 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=373.256669ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/07 07:43:26 INFO Received uploads request method=POST path=/api/pending_closures20142026/10/07 07:43:26 INFO Aborted multipart uploads count=0 kept=020152026/10/07 07:43:26 WARN Force mode enabled - objects will be deleted immediately without grace period20162026/10/07 07:43:26 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=020172026/10/07 07:43:26 INFO Vacuumed table table=pending_closures20182026/10/07 07:43:26 INFO Vacuumed table table=pending_objects20192026/10/07 07:43:26 INFO Vacuumed table table=multipart_uploads20202026/10/07 07:43:26 INFO Vacuumed table table=closures20212026/10/07 07:43:26 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.764136ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20222026/10/07 07:43:26 INFO Vacuumed table table=objects2023--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2024 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (7.47s)2025 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (7.34s)2026--- PASS: TestDeleteClosuresRacingPins (10.85s)20272026/10/07 07:43:26 INFO Received uploads request method=POST path=/api/pending_closures20282026/10/07 07:43:26 INFO Aborted multipart uploads count=0 kept=020292026/10/07 07:43:26 WARN Force mode enabled - objects will be deleted immediately without grace period20302026/10/07 07:43: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=020312026/10/07 07:43:26 INFO Vacuumed table table=pending_closures20322026/10/07 07:43:26 INFO Vacuumed table table=pending_objects20332026/10/07 07:43:26 INFO Vacuumed table table=multipart_uploads20342026/10/07 07:43:26 INFO Vacuumed table table=closures20352026/10/07 07:43:26 INFO Vacuumed table table=objects2036--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2037 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (7.07s)2038 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.43s)20392026/10/07 07:43:26 INFO Received uploads request method=POST path=/api/pending_closures20402026/10/07 07:43:26 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.587601948s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20412026/10/07 07:43:26 INFO Aborted multipart uploads count=0 kept=020422026/10/07 07:43:26 WARN Force mode enabled - objects will be deleted immediately without grace period20432026-10-07 07:43:26.976 UTC [43298] ERROR: canceling statement due to user request20442026-10-07 07:43:26.976 UTC [43298] STATEMENT: -- name: MarkStaleObjects :execrows2045 WITH RECURSIVE ct AS (2046 SELECT timezone('UTC', now()) AS now2047 ),2048 closure_reach AS (2049 -- Start with all closure keys2050 SELECT o.key, o.refs2051 FROM objects o2052 INNER JOIN closures c ON o.key = c.key2053 UNION2054 -- Recursively add all referenced objects2055 SELECT o.key, o.refs2056 FROM objects o2057 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2058 ),2059 reachable_objects AS (2060 SELECT DISTINCT key FROM closure_reach2061 ),2062 stale_objects AS (2063 SELECT o.key2064 FROM objects AS o, ct2065 WHERE2066 NOT EXISTS (2067 SELECT 12068 FROM reachable_objects ro2069 WHERE ro.key = o.key2070 )2071 AND NOT EXISTS (2072 SELECT 12073 FROM pending_objects AS po2074 WHERE po.key = o.key2075 )2076 AND o.deleted_at IS NULL -- Only mark fresh objects2077 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2078 FOR UPDATE2079 )2080 UPDATE objects2081 SET2082 deleted_at = ct.now,2083 first_deleted_at = COALESCE(first_deleted_at, ct.now)2084 FROM stale_objects, ct2085 WHERE objects.key = stale_objects.key2086 20872026/10/07 07:43:27 INFO Aborted multipart uploads count=0 kept=020882026/10/07 07:43:27 WARN Force mode enabled - objects will be deleted immediately without grace period20892026/10/07 07:43:27 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:56810/bucket99/?delete=\": context canceled"2090--- PASS: TestGCEndsOnShutdown (0.00s)2091 --- PASS: TestGCEndsOnShutdown/before_the_run (5.93s)2092 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.77s)2093 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.05s)2094--- PASS: TestPendingClosureWriteTimeout (0.06s)2095 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2096 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2097 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2098 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (7.19s)20992026/10/07 07:43:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21002026/10/07 07:43:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21012026/10/07 07:43:28 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"21022026/10/07 07:43:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21032026/10/07 07:43:28 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.189893ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21042026/10/07 07:43:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.684721ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21052026/10/07 07:43:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=825.564608ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21062026/10/07 07:43:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.74208748s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21072026/10/07 07:43:31 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21082026/10/07 07:43:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=192.671023ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21092026/10/07 07:43:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=396.891764ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21102026/10/07 07:43:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=848.468358ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21112026/10/07 07:43:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.759216526s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2112--- PASS: TestClientErrorHandling (0.01s)2113 --- PASS: TestClientErrorHandling/InvalidStorePath (5.86s)2114 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.60s)2115 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.35s)2116PASS2117{"timestamp":"2026-10-07T07:43:35.056921Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56904","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}21182026-10-07 07:43:35.215 UTC [42722] LOG: received smart shutdown request21192026-10-07 07:43:35.216 UTC [42722] LOG: background worker "logical replication launcher" (PID 42733) exited with exit code 121202026-10-07 07:43:36.516 UTC [42727] LOG: checkpoint complete: wrote 11260 buffers (68.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=10.143 s, sync=0.667 s, total=10.948 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=533525 kB, estimate=533525 kB; lsn=0/22773C08, redo lsn=0/220923C021212026-10-07 07:43:36.517 UTC [42727] LOG: shutting down21222026-10-07 07:43:36.517 UTC [42727] LOG: checkpoint starting: shutdown immediate21232026-10-07 07:43:36.520 UTC [42727] LOG: checkpoint complete: wrote 94 buffers (0.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.002 s, total=0.004 s; sync files=54, longest=0.001 s, average=0.001 s; distance=7046 kB, estimate=480877 kB; lsn=0/22773C80, redo lsn=0/22773C8021242026-10-07 07:43:36.527 UTC [42722] LOG: database system is shut down2125Running OIDC tests...2126=== RUN TestAudienceForIssuer2127=== PAUSE TestAudienceForIssuer2128=== RUN TestGlobMatch2129=== PAUSE TestGlobMatch2130=== RUN TestValidateToken_ValidToken2131=== PAUSE TestValidateToken_ValidToken2132=== RUN TestValidateToken_WrongAudience2133=== PAUSE TestValidateToken_WrongAudience2134=== RUN TestValidateToken_Expired2135=== PAUSE TestValidateToken_Expired2136=== RUN TestValidateToken_BoundClaimsMismatch2137=== PAUSE TestValidateToken_BoundClaimsMismatch2138=== RUN TestValidateToken_BoundSubjectMismatch2139=== PAUSE TestValidateToken_BoundSubjectMismatch2140=== RUN TestValidateToken_MultipleProviders2141=== PAUSE TestValidateToken_MultipleProviders2142=== RUN TestValidateToken_NoMatchingProvider2143=== PAUSE TestValidateToken_NoMatchingProvider2144=== RUN TestValidateToken_KubernetesServiceAccount2145=== PAUSE TestValidateToken_KubernetesServiceAccount2146=== RUN TestNewValidator_KubernetesRequiresCA2147=== PAUSE TestNewValidator_KubernetesRequiresCA2148=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2149=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2150=== RUN TestPins_ReservedForMatchingRule2151=== PAUSE TestPins_ReservedForMatchingRule2152=== RUN TestPins_TopLevelShorthand2153=== PAUSE TestPins_TopLevelShorthand2154=== RUN TestPins_ConfigValidation2155=== PAUSE TestPins_ConfigValidation2156=== RUN TestScopes_LegacyProviderDefaultsToWrite2157=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2158=== RUN TestScopes_Rules2159=== PAUSE TestScopes_Rules2160=== RUN TestScopes_ConfigValidation2161=== PAUSE TestScopes_ConfigValidation2162=== CONT TestAudienceForIssuer2163--- PASS: TestAudienceForIssuer (0.00s)2164=== CONT TestValidateToken_BoundClaimsMismatch2165=== CONT TestValidateToken_MultipleProviders2166=== CONT TestValidateToken_Expired2167=== CONT TestValidateToken_WrongAudience2168=== CONT TestValidateToken_ValidToken2169=== CONT TestGlobMatch2170=== RUN TestGlobMatch/foo_foo2171=== PAUSE TestGlobMatch/foo_foo2172=== RUN TestGlobMatch/foo_bar2173=== PAUSE TestGlobMatch/foo_bar2174=== RUN TestGlobMatch/*_2175=== PAUSE TestGlobMatch/*_2176=== RUN TestGlobMatch/*_anything2177=== PAUSE TestGlobMatch/*_anything2178=== RUN TestGlobMatch/foo*_foo2179=== PAUSE TestGlobMatch/foo*_foo2180=== RUN TestGlobMatch/foo*_foobar2181=== PAUSE TestGlobMatch/foo*_foobar2182=== RUN TestGlobMatch/foo*_bar2183=== PAUSE TestGlobMatch/foo*_bar2184=== RUN TestGlobMatch/*bar_bar2185=== PAUSE TestGlobMatch/*bar_bar2186=== RUN TestGlobMatch/*bar_foobar2187=== PAUSE TestGlobMatch/*bar_foobar2188=== RUN TestGlobMatch/*bar_foo2189=== PAUSE TestGlobMatch/*bar_foo2190=== RUN TestGlobMatch/foo*bar_foobar2191=== PAUSE TestGlobMatch/foo*bar_foobar2192=== RUN TestGlobMatch/foo*bar_foo123bar2193=== PAUSE TestGlobMatch/foo*bar_foo123bar2194=== RUN TestGlobMatch/foo*bar_foobarbaz2195=== PAUSE TestGlobMatch/foo*bar_foobarbaz2196=== RUN TestGlobMatch/*/*_foo/bar2197=== PAUSE TestGlobMatch/*/*_foo/bar2198=== RUN TestGlobMatch/*/*_foo2199=== PAUSE TestGlobMatch/*/*_foo2200=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2201=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2202=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02203=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02204=== RUN TestGlobMatch/refs/*/main_refs/heads/main2205=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2206=== RUN TestGlobMatch/fo?_foo2207=== PAUSE TestGlobMatch/fo?_foo2208=== RUN TestGlobMatch/fo?_fo2209=== PAUSE TestGlobMatch/fo?_fo2210=== RUN TestGlobMatch/fo?_fooo2211=== PAUSE TestGlobMatch/fo?_fooo2212=== RUN TestGlobMatch/?oo_foo2213=== PAUSE TestGlobMatch/?oo_foo2214=== RUN TestGlobMatch/?oo_boo2215=== PAUSE TestGlobMatch/?oo_boo2216=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2217=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2218=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2219=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2220=== CONT TestGlobMatch/foo_foo2221=== CONT TestValidateToken_BoundSubjectMismatch2222=== CONT TestGlobMatch/*/*_foo/bar2223=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2224=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2225=== CONT TestGlobMatch/?oo_boo2226=== CONT TestGlobMatch/?oo_foo2227=== CONT TestGlobMatch/fo?_fooo2228=== CONT TestGlobMatch/fo?_fo2229=== CONT TestGlobMatch/fo?_foo2230=== CONT TestGlobMatch/refs/*/main_refs/heads/main2231=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02232=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2233=== CONT TestGlobMatch/*/*_foo2234=== CONT TestGlobMatch/*bar_bar2235=== CONT TestGlobMatch/foo*bar_foobarbaz2236=== CONT TestGlobMatch/foo*bar_foo123bar2237=== CONT TestGlobMatch/foo*bar_foobar2238=== CONT TestGlobMatch/*bar_foo2239=== CONT TestGlobMatch/*bar_foobar2240=== CONT TestGlobMatch/foo*_foo2241=== CONT TestGlobMatch/foo*_bar2242=== CONT TestGlobMatch/foo*_foobar2243=== CONT TestGlobMatch/*_2244=== CONT TestGlobMatch/*_anything2245=== CONT TestGlobMatch/foo_bar2246--- PASS: TestGlobMatch (0.00s)2247 --- PASS: TestGlobMatch/foo_foo (0.00s)2248 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2249 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2250 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2251 --- PASS: TestGlobMatch/?oo_boo (0.00s)2252 --- PASS: TestGlobMatch/?oo_foo (0.00s)2253 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2254 --- PASS: TestGlobMatch/fo?_fo (0.00s)2255 --- PASS: TestGlobMatch/fo?_foo (0.00s)2256 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2257 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2258 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2259 --- PASS: TestGlobMatch/*/*_foo (0.00s)2260 --- PASS: TestGlobMatch/*bar_bar (0.00s)2261 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2262 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2263 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2264 --- PASS: TestGlobMatch/*bar_foo (0.00s)2265 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2266 --- PASS: TestGlobMatch/foo*_foo (0.00s)2267 --- PASS: TestGlobMatch/foo*_bar (0.00s)2268 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2269 --- PASS: TestGlobMatch/*_ (0.00s)2270 --- PASS: TestGlobMatch/*_anything (0.00s)2271 --- PASS: TestGlobMatch/foo_bar (0.00s)2272=== CONT TestPins_ConfigValidation2273=== CONT TestScopes_ConfigValidation2274=== CONT TestScopes_Rules2275=== CONT TestScopes_LegacyProviderDefaultsToWrite2276=== CONT TestValidateToken_NoMatchingProvider2277--- PASS: TestPins_ConfigValidation (0.00s)2278=== CONT TestPins_ReservedForMatchingRule2279--- PASS: TestScopes_ConfigValidation (0.01s)2280=== CONT TestPins_TopLevelShorthand2281=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2282=== CONT TestNewValidator_KubernetesRequiresCA2283=== CONT TestValidateToken_KubernetesServiceAccount22842026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57302/oidc2285--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22862026/10/07 07:43:38 http: TLS handshake error from 127.0.0.1:57306: read tcp 127.0.0.1:57305->127.0.0.1:57306: use of closed network connection2287--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)22882026/10/07 07:43:38 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5730422892026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57308/oidc22902026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57309/oidc2291--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)2292--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)2293--- PASS: TestScopes_Rules (0.10s)22942026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57313/oidc2295--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)22962026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57315/oidc2297--- PASS: TestValidateToken_Expired (0.12s)22982026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57317/oidc2299--- PASS: TestValidateToken_ValidToken (0.12s)23002026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57320/oidc2301--- PASS: TestValidateToken_WrongAudience (0.13s)23022026/10/07 07:43:38 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232303--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)23042026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57324/oidc2305--- PASS: TestPins_ReservedForMatchingRule (0.14s)23062026/10/07 07:43:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57319/oidc2307--- PASS: TestValidateToken_NoMatchingProvider (0.14s)23082026/10/07 07:43:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57328/oidc2309--- PASS: TestPins_TopLevelShorthand (0.15s)23102026/10/07 07:43:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57312/oidc23112026/10/07 07:43:38 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57330/oidc2312--- PASS: TestValidateToken_MultipleProviders (0.19s)2313PASS2314Running hook tests...2315=== RUN TestSendPathsEmpty2316=== PAUSE TestSendPathsEmpty2317=== RUN TestQueueEnqueueAndFetch2318=== PAUSE TestQueueEnqueueAndFetch2319=== RUN TestQueueDeduplication2320=== PAUSE TestQueueDeduplication2321=== RUN TestQueueRemove2322=== PAUSE TestQueueRemove2323=== RUN TestQueueFetchBatchLimit2324=== PAUSE TestQueueFetchBatchLimit2325=== RUN TestQueueRetryMovesToBack2326=== PAUSE TestQueueRetryMovesToBack2327=== RUN TestQueueFetchRemoveLifecycle2328=== PAUSE TestQueueFetchRemoveLifecycle2329=== RUN TestQueueConcurrentWriters2330=== PAUSE TestQueueConcurrentWriters2331=== RUN TestQueueRemoveLargeClosure2332=== PAUSE TestQueueRemoveLargeClosure2333=== RUN TestServerClientIntegration2334--- PASS: TestServerClientIntegration (0.00s)2335=== RUN TestServerQueueError23362026/10/07 07:43:38 ERROR Failed to queue paths error="permission denied" count=12337--- PASS: TestServerQueueError (0.00s)2338=== RUN TestGetListenerSocketActivation2339 server_test.go:146: systemd socket activation does not exist on darwin2340--- SKIP: TestGetListenerSocketActivation (0.00s)2341=== RUN TestDrainIsolatesPoisonPath2342=== PAUSE TestDrainIsolatesPoisonPath2343=== RUN TestRunNotBlockedByPoisonHead2344=== PAUSE TestRunNotBlockedByPoisonHead2345=== RUN TestDrainGivesUpWhenServerDown2346=== PAUSE TestDrainGivesUpWhenServerDown2347=== RUN TestFailedPathPrunedByLaterClosure2348=== PAUSE TestFailedPathPrunedByLaterClosure2349=== RUN TestWorkerUploadsAndRemoves2350=== PAUSE TestWorkerUploadsAndRemoves2351=== RUN TestWorkerSkipsGCdPaths2352=== PAUSE TestWorkerSkipsGCdPaths2353=== RUN TestWorkerPrunesClosureDeps2354=== PAUSE TestWorkerPrunesClosureDeps2355=== RUN TestDrainTimeout2356=== PAUSE TestDrainTimeout2357=== CONT TestSendPathsEmpty2358=== CONT TestDrainIsolatesPoisonPath2359--- PASS: TestSendPathsEmpty (0.00s)2360=== CONT TestQueueRemoveLargeClosure2361=== CONT TestQueueConcurrentWriters2362=== CONT TestQueueFetchRemoveLifecycle2363=== CONT TestQueueRetryMovesToBack2364=== CONT TestQueueFetchBatchLimit2365=== CONT TestQueueRemove2366=== CONT TestQueueDeduplication2367=== CONT TestWorkerUploadsAndRemoves2368=== CONT TestDrainTimeout2369=== CONT TestWorkerPrunesClosureDeps2370=== CONT TestWorkerSkipsGCdPaths2371=== CONT TestQueueEnqueueAndFetch2372=== CONT TestDrainGivesUpWhenServerDown2373=== CONT TestFailedPathPrunedByLaterClosure2374=== CONT TestRunNotBlockedByPoisonHead2375--- PASS: TestQueueRemove (0.01s)23762026/10/07 07:43:38 INFO Uploading batch count=423772026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=42378--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23792026/10/07 07:43:38 INFO Uploading batch count=223802026/10/07 07:43:38 INFO Upload queue status pending=223812026/10/07 07:43:38 INFO Uploading batch count=123822026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=123832026/10/07 07:43:38 INFO Upload queue status pending=223842026/10/07 07:43:38 INFO Uploading batch count=223852026/10/07 07:43:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestWorkerSkipsGCdPaths4082868436/002/nonexistent23862026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainIsolatesPoisonPath2666669624/002/bbb23872026/10/07 07:43:38 INFO Upload queue status pending=223882026/10/07 07:43:38 INFO Uploading batch count=123892026/10/07 07:43:38 INFO Upload queue status pending=32390--- PASS: TestQueueRetryMovesToBack (0.02s)23912026/10/07 07:43:38 INFO Uploading batch count=123922026/10/07 07:43:38 INFO Uploading batch count=123932026/10/07 07:43:38 INFO Uploading batch count=123942026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=12395--- PASS: TestQueueDeduplication (0.02s)23962026/10/07 07:43:38 INFO Uploading batch count=223972026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=223982026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/a23992026/10/07 07:43:38 INFO Uploading batch count=124002026/10/07 07:43:38 INFO Uploading batch count=124012026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=124022026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/b24032026/10/07 07:43:38 INFO Uploading batch count=124042026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=12405--- PASS: TestQueueEnqueueAndFetch (0.02s)24062026/10/07 07:43:38 INFO Uploading batch count=224072026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=224082026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/c2409--- PASS: TestQueueFetchBatchLimit (0.02s)24102026/10/07 07:43:38 INFO Uploading batch count=124112026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=124122026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/d24132026/10/07 07:43:38 ERROR Drain finished with paths left in queue remaining=124142026/10/07 07:43:38 INFO Uploading batch count=224152026/10/07 07:43:38 ERROR Upload failed error="upload failed" count=224162026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/e24172026/10/07 07:43:38 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestDrainGivesUpWhenServerDown3817363693/002/f24182026/10/07 07:43:38 ERROR Drain finished with paths left in queue remaining=102419--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2420--- PASS: TestDrainIsolatesPoisonPath (0.02s)2421--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2422--- PASS: TestWorkerSkipsGCdPaths (0.03s)2423--- PASS: TestWorkerPrunesClosureDeps (0.03s)2424--- PASS: TestWorkerUploadsAndRemoves (0.03s)2425--- PASS: TestQueueRemoveLargeClosure (0.05s)2426--- PASS: TestQueueConcurrentWriters (0.13s)24272026/10/07 07:43:39 ERROR Upload failed error="context deadline exceeded" count=224282026/10/07 07:43:39 ERROR Drain finished with paths left in queue remaining=42429--- PASS: TestDrainTimeout (0.22s)24302026/10/07 07:43:39 INFO Uploading batch count=124312026/10/07 07:43:39 INFO Uploading batch count=124322026/10/07 07:43:39 INFO Uploading batch count=124332026/10/07 07:43:39 ERROR Upload failed error="upload failed" count=124342026/10/07 07:43:39 INFO Uploading batch count=124352026/10/07 07:43:39 ERROR Upload failed error="upload failed" count=124362026/10/07 07:43:39 INFO Uploading batch count=124372026/10/07 07:43:39 ERROR Upload failed error="upload failed" count=124382026/10/07 07:43:39 INFO Uploading batch count=124392026/10/07 07:43:39 ERROR Upload failed error="upload failed" count=124402026/10/07 07:43:39 ERROR Drain finished with paths left in queue remaining=12441--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2442PASS2443Running signing tests...2444=== RUN TestExternalSigner2445=== PAUSE TestExternalSigner2446=== RUN TestExternalSignerWrongPublicKey2447=== PAUSE TestExternalSignerWrongPublicKey2448=== RUN TestExternalSignerErrors2449=== PAUSE TestExternalSignerErrors2450=== RUN TestExternalSignerRestartsAfterCrash2451=== PAUSE TestExternalSignerRestartsAfterCrash2452=== RUN TestExternalSignerProgramErrorKeepsProcess2453=== PAUSE TestExternalSignerProgramErrorKeepsProcess2454=== RUN TestExternalSignerClose2455=== PAUSE TestExternalSignerClose2456=== RUN TestExternalSignerRejectsInvalidPublicKey2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey2458=== RUN TestExternalSignerCancellation2459=== PAUSE TestExternalSignerCancellation2460=== RUN TestGenerateFingerprint2461=== PAUSE TestGenerateFingerprint2462=== RUN TestParseSigningKey2463=== PAUSE TestParseSigningKey2464=== RUN TestSign2465=== PAUSE TestSign2466=== RUN TestSignBatch2467=== PAUSE TestSignBatch2468=== RUN TestNilKeyPublicKey2469=== PAUSE TestNilKeyPublicKey2470=== RUN TestSignErrors2471=== PAUSE TestSignErrors2472=== CONT TestExternalSigner2473=== CONT TestExternalSignerCancellation2474=== CONT TestExternalSignerErrors2475=== CONT TestExternalSignerProgramErrorKeepsProcess2476=== CONT TestExternalSignerRejectsInvalidPublicKey2477=== RUN TestExternalSignerRejectsInvalidPublicKey/#002478=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002479=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2480=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2481=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2482=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2483=== CONT TestExternalSignerClose2484=== CONT TestExternalSignerRestartsAfterCrash2485=== CONT TestSignBatch2486=== CONT TestSignErrors2487=== CONT TestNilKeyPublicKey2488--- PASS: TestNilKeyPublicKey (0.00s)2489=== CONT TestExternalSignerWrongPublicKey2490=== CONT TestParseSigningKey2491=== RUN TestParseSigningKey/valid_32-byte_key2492=== CONT TestSign2493=== CONT TestGenerateFingerprint2494=== RUN TestExternalSignerErrors/exit_at_startup2495=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2496=== RUN TestGenerateFingerprint/basic_with_references2497=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2498=== PAUSE TestGenerateFingerprint/basic_with_references2499=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2500=== RUN TestGenerateFingerprint/no_references2501=== PAUSE TestExternalSignerErrors/exit_at_startup2502=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2503=== CONT TestExternalSignerRejectsInvalidPublicKey/#002504=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2505=== PAUSE TestGenerateFingerprint/no_references2506=== RUN TestExternalSignerErrors/exit_on_request2507=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2508=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2509=== PAUSE TestParseSigningKey/valid_32-byte_key2510=== PAUSE TestExternalSignerErrors/exit_on_request2511=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2512=== RUN TestExternalSignerErrors/invalid_JSON2513=== PAUSE TestExternalSignerErrors/invalid_JSON2514=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2515=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2516=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2517--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2518 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2523=== RUN TestExternalSignerErrors/missing_signature_name2524=== PAUSE TestExternalSignerErrors/missing_signature_name2525=== RUN TestExternalSignerErrors/program_error2526=== PAUSE TestExternalSignerErrors/program_error2527=== RUN TestExternalSignerErrors/wrong_shape2528=== PAUSE TestExternalSignerErrors/wrong_shape2529=== RUN TestExternalSignerErrors/wrong_id2530=== PAUSE TestExternalSignerErrors/wrong_id2531=== RUN TestExternalSignerErrors/missing_signatures2532=== PAUSE TestExternalSignerErrors/missing_signatures2533=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2534=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2535=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2536=== RUN TestExternalSignerErrors/wrong_signatures_shape2537=== RUN TestParseSigningKey/no_colon2538=== RUN TestGenerateFingerprint/invalid_nar_hash_length2539=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2540=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2541=== PAUSE TestParseSigningKey/no_colon2542=== RUN TestGenerateFingerprint/invalid_store_path_prefix2543=== RUN TestExternalSignerErrors/too_few_signatures2544=== PAUSE TestExternalSignerErrors/too_few_signatures2545=== RUN TestParseSigningKey/empty_name2546=== RUN TestExternalSignerErrors/unrequested_key2547=== PAUSE TestParseSigningKey/empty_name2548=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2549=== PAUSE TestExternalSignerErrors/unrequested_key2550=== RUN TestGenerateFingerprint/invalid_reference_prefix2551=== RUN TestParseSigningKey/invalid_base642552=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2553=== RUN TestExternalSignerErrors/invalid_signature_base642554=== CONT TestGenerateFingerprint/basic_with_references2555=== PAUSE TestParseSigningKey/invalid_base642556=== RUN TestParseSigningKey/wrong_length2557=== CONT TestGenerateFingerprint/invalid_nar_hash_length2558=== PAUSE TestParseSigningKey/wrong_length2559=== CONT TestGenerateFingerprint/no_references2560=== CONT TestParseSigningKey/valid_32-byte_key2561=== CONT TestParseSigningKey/no_colon2562=== CONT TestParseSigningKey/empty_name2563=== CONT TestGenerateFingerprint/invalid_reference_prefix2564=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2565=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2566=== CONT TestParseSigningKey/invalid_base642567=== PAUSE TestExternalSignerErrors/invalid_signature_base642568=== RUN TestExternalSignerErrors/null2569=== PAUSE TestExternalSignerErrors/null2570=== RUN TestExternalSignerErrors/null_signatures2571=== PAUSE TestExternalSignerErrors/null_signatures2572=== RUN TestExternalSignerErrors/wrong_signature_name2573=== RUN TestSignErrors/nil_key2574=== PAUSE TestSignErrors/nil_key2575=== CONT TestParseSigningKey/wrong_length2576--- PASS: TestSign (0.00s)2577=== PAUSE TestExternalSignerErrors/wrong_signature_name2578=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2579--- PASS: TestParseSigningKey (0.00s)2580 --- PASS: TestParseSigningKey/no_colon (0.00s)2581 --- PASS: TestParseSigningKey/empty_name (0.00s)2582 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2583 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2584 --- PASS: TestParseSigningKey/wrong_length (0.00s)2585 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2586=== CONT TestGenerateFingerprint/invalid_store_path_prefix2587--- PASS: TestGenerateFingerprint (0.00s)2588 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2589 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2590 --- PASS: TestGenerateFingerprint/no_references (0.00s)2591 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2592 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2593 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2594 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2595=== RUN TestSignErrors/nil_narinfo2596=== PAUSE TestSignErrors/nil_narinfo2597=== RUN TestExternalSignerErrors/wrong_signature_length2598=== RUN TestSignErrors/invalid_narinfo2599=== PAUSE TestSignErrors/invalid_narinfo2600=== PAUSE TestExternalSignerErrors/wrong_signature_length2601=== RUN TestSignErrors/canceled2602=== CONT TestExternalSignerErrors/unrequested_key2603=== CONT TestExternalSignerErrors/wrong_shape2604=== CONT TestExternalSignerErrors/missing_signature_name2605=== CONT TestExternalSignerErrors/program_error2606=== CONT TestExternalSignerErrors/invalid_JSON2607=== PAUSE TestSignErrors/canceled2608=== CONT TestSignErrors/nil_key2609--- PASS: TestSignBatch (0.00s)2610=== CONT TestSignErrors/canceled2611=== CONT TestSignErrors/nil_narinfo2612=== CONT TestSignErrors/invalid_narinfo2613=== CONT TestExternalSignerErrors/wrong_signature_length2614--- PASS: TestSignErrors (0.00s)2615 --- PASS: TestSignErrors/nil_key (0.00s)2616 --- PASS: TestSignErrors/canceled (0.00s)2617 --- PASS: TestSignErrors/nil_narinfo (0.00s)2618 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2619=== CONT TestExternalSignerErrors/wrong_signature_name2620=== CONT TestExternalSignerErrors/null_signatures2621=== CONT TestExternalSignerErrors/null2622=== CONT TestExternalSignerErrors/invalid_signature_base642623=== CONT TestExternalSignerErrors/exit_at_startup2624=== CONT TestExternalSignerErrors/wrong_signatures_shape2625=== CONT TestExternalSignerErrors/too_few_signatures2626=== CONT TestExternalSignerErrors/exit_on_request2627=== CONT TestExternalSignerErrors/wrong_id2628=== CONT TestExternalSignerErrors/missing_signatures2629--- PASS: TestExternalSignerCancellation (0.23s)2630--- PASS: TestExternalSigner (0.42s)2631--- PASS: TestExternalSignerWrongPublicKey (0.59s)2632--- PASS: TestExternalSignerClose (0.78s)2633--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.97s)2634--- PASS: TestExternalSignerRestartsAfterCrash (1.19s)2635/private/var/tb/8/scratch/75ba4e933cbdf169/build/TestExternalSignerRestartsAfterCrash3781664523/001/sign program: line 7: /private/var/tb/8/scratch/75ba4e933cbdf169/build/TestExternalSignerRestartsAfterCrash3781664523/001/sign program.starts: No such file or directory2636--- PASS: TestExternalSignerErrors (0.01s)2637 --- PASS: TestExternalSignerErrors/exit_on_request (1.35s)2638 --- PASS: TestExternalSignerErrors/missing_signatures (1.53s)2639 --- PASS: TestExternalSignerErrors/wrong_id (1.72s)2640 --- PASS: TestExternalSignerErrors/invalid_JSON (1.91s)2641 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.09s)2642 --- PASS: TestExternalSignerErrors/null (2.28s)2643 --- PASS: TestExternalSignerErrors/exit_at_startup (2.47s)2644 --- PASS: TestExternalSignerErrors/wrong_shape (2.66s)2645 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.84s)2646 --- PASS: TestExternalSignerErrors/too_few_signatures (3.03s)2647 --- PASS: TestExternalSignerErrors/null_signatures (3.21s)2648 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.40s)2649 --- PASS: TestExternalSignerErrors/unrequested_key (3.58s)2650 --- PASS: TestExternalSignerErrors/missing_signature_name (3.79s)2651 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.99s)2652 --- PASS: TestExternalSignerErrors/program_error (4.15s)2653PASS2654Running OpenBao signer tests...2655=== RUN TestSign2656=== PAUSE TestSign2657=== RUN TestSignErrors2658=== PAUSE TestSignErrors2659=== RUN TestServe2660=== PAUSE TestServe2661=== RUN TestServeRejectsGarbage2662=== PAUSE TestServeRejectsGarbage2663=== CONT TestSign2664=== CONT TestSignErrors2665=== RUN TestSignErrors/http_error2666=== PAUSE TestSignErrors/http_error2667=== CONT TestServeRejectsGarbage2668=== RUN TestSignErrors/invalid_json2669=== PAUSE TestSignErrors/invalid_json2670=== CONT TestServe2671=== RUN TestSignErrors/no_prefix2672=== PAUSE TestSignErrors/no_prefix2673=== RUN TestSignErrors/invalid_base642674--- PASS: TestServeRejectsGarbage (0.00s)2675=== PAUSE TestSignErrors/invalid_base642676=== CONT TestSignErrors/http_error2677=== CONT TestSignErrors/no_prefix2678=== CONT TestSignErrors/invalid_json2679=== CONT TestSignErrors/invalid_base642680--- PASS: TestServe (0.00s)2681--- PASS: TestSignErrors (0.00s)2682 --- PASS: TestSignErrors/invalid_base64 (0.00s)2683 --- PASS: TestSignErrors/no_prefix (0.00s)2684 --- PASS: TestSignErrors/http_error (0.00s)2685 --- PASS: TestSignErrors/invalid_json (0.00s)2686--- PASS: TestSign (0.00s)2687PASS