niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #397
· 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.24s)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 TestStreamPushStopsWhenCanceled74=== PAUSE TestStreamPushStopsWhenCanceled75=== RUN TestSetClientTLS76=== PAUSE TestSetClientTLS77=== RUN TestSetClientTLSDoesNotMutateDefaultTransport78=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport79=== RUN TestSetClientTLSErrors80=== PAUSE TestSetClientTLSErrors81=== RUN TestStaticToken82=== PAUSE TestStaticToken83=== RUN TestFileTokenReadsAndCaches84=== PAUSE TestFileTokenReadsAndCaches85=== RUN TestFileTokenMissing86=== PAUSE TestFileTokenMissing87=== RUN TestFileTokenEmpty88=== PAUSE TestFileTokenEmpty89=== RUN TestScriptTokenNoExpiryRerunsEveryCall90=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall91=== RUN TestScriptTokenCachesUntilRefresh92=== PAUSE TestScriptTokenCachesUntilRefresh93=== RUN TestScriptTokenEmptyToken94=== PAUSE TestScriptTokenEmptyToken95=== RUN TestScriptTokenBadJSON96=== PAUSE TestScriptTokenBadJSON97=== RUN TestScriptTokenScriptFails98=== PAUSE TestScriptTokenScriptFails99=== RUN TestScriptTokenEmptyCommand100=== PAUSE TestScriptTokenEmptyCommand101=== CONT TestDoServerRequestAttachesToken102=== CONT TestScriptTokenEmptyCommand103--- PASS: TestScriptTokenEmptyCommand (0.00s)104=== CONT TestStreamPushReportsEveryPath105=== CONT TestDoWithRetry_BodyReplayedViaGetBody106=== CONT TestScriptTokenScriptFails107=== CONT TestScriptTokenBadJSON108=== CONT TestScriptTokenEmptyToken109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestScriptTokenNoExpiryRerunsEveryCall111--- PASS: TestStreamPushReportsEveryPath (0.00s)112=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess113=== CONT TestFileTokenEmpty114--- PASS: TestFileTokenEmpty (0.00s)115=== CONT TestShellSplitErrors116--- PASS: TestShellSplitErrors (0.00s)117=== CONT TestRateLimiterFeedback118=== CONT TestFileTokenMissing119=== CONT TestFileTokenReadsAndCaches120=== CONT TestStaticToken121--- PASS: TestStaticToken (0.00s)122=== CONT TestShellSplit123--- PASS: TestShellSplit (0.00s)124=== CONT TestPathInfoCACompatibility125=== CONT TestSetClientTLSErrors126=== RUN TestRateLimiterFeedback/429_enables_limiter127=== RUN TestPathInfoCACompatibility/null_ca_field128=== PAUSE TestRateLimiterFeedback/429_enables_limiter129=== RUN TestRateLimiterFeedback/503_enables_limiter130=== PAUSE TestRateLimiterFeedback/503_enables_limiter131=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter132=== CONT TestSetClientTLSDoesNotMutateDefaultTransport1332026/10/08 12:57:47 WARN Rate limiter enabled after throttle name=server-test rate=5134=== CONT TestSetClientTLS135=== CONT TestParsePathInfoJSON136=== RUN TestParsePathInfoJSON/Nix_format137=== PAUSE TestParsePathInfoJSON/Nix_format138=== RUN TestParsePathInfoJSON/Lix_format139=== PAUSE TestParsePathInfoJSON/Lix_format140=== RUN TestParsePathInfoJSON/empty_input141=== PAUSE TestParsePathInfoJSON/empty_input142=== RUN TestParsePathInfoJSON/whitespace_only143=== PAUSE TestParsePathInfoJSON/whitespace_only144=== RUN TestParsePathInfoJSON/invalid_JSON145=== PAUSE TestParsePathInfoJSON/invalid_JSON146=== CONT TestPathInfoHashCompatibility147=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon150=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon151=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512154=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== CONT TestGetStorePathHash156=== RUN TestGetStorePathHash/valid_store_path157=== PAUSE TestGetStorePathHash/valid_store_path158=== RUN TestSetClientTLSErrors/missing_cert_file159=== PAUSE TestSetClientTLSErrors/missing_cert_file160=== RUN TestSetClientTLSErrors/missing_key_file161=== PAUSE TestSetClientTLSErrors/missing_key_file162=== RUN TestSetClientTLSErrors/missing_ca_file163=== PAUSE TestSetClientTLSErrors/missing_ca_file164=== CONT TestStreamPushStopsWhenCanceled165=== CONT TestClientSignaturesByStorePath166=== CONT TestDumpPathMatchesNix167=== CONT TestStreamPushReportsSignatures168=== CONT TestStreamPushRequestLine169=== CONT TestEncodeNixBase32170=== CONT TestStreamPushGivesUpOnDeadServer171=== CONT TestStreamPushIsolatesFailures172=== CONT TestResolveStorePath173=== CONT TestStreamPushBatchesUnderLoad1742026/10/08 12:57:47 WARN Rate limiter enabled after throttle name=server-test rate=51752026/10/08 12:57:47 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:519501762026/10/08 12:57:47 ERROR Upload failed error="connection refused" count=201772026/10/08 12:57:47 ERROR Server seems unavailable, giving up on batch untried=171782026/10/08 12:57:47 ERROR Upload failed error=boom count=11792026/10/08 12:57:47 ERROR Upload failed error="bad path" count=31802026/10/08 12:57:47 ERROR Upload failed error=boom count=1181=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter182=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter183=== PAUSE TestPathInfoCACompatibility/null_ca_field184--- PASS: TestFileTokenMissing (0.01s)185=== CONT TestParsePathInfoJSONMultiplePaths186=== RUN TestGetStorePathHash/basename_without_hyphen_should_error187=== RUN TestSetClientTLSErrors/invalid_ca_file188=== CONT TestConvertHashToNix32189=== CONT TestEncodeNixBase32WithRealHash190=== RUN TestEncodeNixBase32/test_string_hash191=== PAUSE TestEncodeNixBase32/test_string_hash192=== RUN TestEncodeNixBase32/empty_input193=== PAUSE TestEncodeNixBase32/empty_input194=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter195=== RUN TestPathInfoCACompatibility/old_string_format_-_text196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text197=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive198=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== RUN TestPathInfoCACompatibility/new_structured_format_-_text200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text201=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method202--- PASS: TestFileTokenReadsAndCaches (0.01s)203--- PASS: TestStreamPushStopsWhenCanceled (0.00s)204--- PASS: TestScriptTokenScriptFails (0.01s)205--- PASS: TestClientSignaturesByStorePath (0.00s)206--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)207--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)208=== CONT TestFilterOversizedClosures209=== RUN TestFilterOversizedClosures/no_limit_keeps_everything210=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything211=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== RUN TestFilterOversizedClosures/all_closures_skipped214=== PAUSE TestFilterOversizedClosures/all_closures_skipped215=== RUN TestConvertHashToNix32/SRI_format_to_Nix32216=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32217=== RUN TestConvertHashToNix32/already_Nix32_format218=== PAUSE TestConvertHashToNix32/already_Nix32_format219=== RUN TestConvertHashToNix32/invalid_format220=== PAUSE TestConvertHashToNix32/invalid_format221=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun222=== CONT TestRegisterUploadedObjectReusesConnections223=== CONT TestCaseHackSuffix224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method225=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths226=== PAUSE TestSetClientTLSErrors/invalid_ca_file227=== CONT TestDumpPathWriterError228=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error229=== CONT TestUploadMultipart_PartsInParallel230=== CONT TestDumpPathSingleFile231=== CONT TestUploadMultipart_SupersededByPeer232=== CONT TestPartSizeForNAR233=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica234--- PASS: TestStreamPushIsolatesFailures (0.00s)235--- PASS: TestStreamPushReportsSignatures (0.00s)236--- PASS: TestEncodeNixBase32WithRealHash (0.00s)237--- PASS: TestDoServerRequestAttachesToken (0.01s)238=== RUN TestSetClientTLS/rejects_connection_without_client_cert2392026/10/08 12:57:47 WARN Rate limiter backed off name=server-test rate=5240=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert241=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA242=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA243=== RUN TestSetClientTLS/preserves_debug_logging_transport244=== PAUSE TestSetClientTLS/preserves_debug_logging_transport245=== CONT TestParsePathInfoJSON/invalid_JSON246=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)247--- PASS: TestResolveStorePath (0.00s)248=== CONT TestParsePathInfoJSON/empty_input249=== CONT TestParsePathInfoJSON/Lix_format250=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI251=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512252=== CONT TestEncodeNixBase32/test_string_hash253=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon254--- PASS: TestPathInfoHashCompatibility (0.00s)255 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)256 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)257 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)258 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)259=== CONT TestRateLimiterFeedback/429_enables_limiter260=== CONT TestEncodeNixBase32/empty_input261--- PASS: TestEncodeNixBase32 (0.00s)262 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)263 --- PASS: TestEncodeNixBase32/empty_input (0.00s)264=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths265=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter266=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths267=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths268=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter269=== CONT TestParsePathInfoJSON/Nix_format270=== CONT TestRateLimiterFeedback/503_enables_limiter271=== CONT TestParsePathInfoJSON/whitespace_only272--- PASS: TestScriptTokenBadJSON (0.02s)273=== CONT TestConvertHashToNix32/SRI_format_to_Nix32274=== CONT TestConvertHashToNix32/invalid_format275=== CONT TestConvertHashToNix32/already_Nix32_format276--- PASS: TestConvertHashToNix32 (0.00s)277 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)278 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)279 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)2802026/10/08 12:57:47 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:51950281=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2822026/10/08 12:57:47 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=2000283=== CONT TestPathInfoCACompatibility/null_ca_field284=== CONT TestSetClientTLSErrors/missing_cert_file285=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method2862026/10/08 12:57:47 WARN Rate limiter enabled after throttle name=server-test rate=5287=== CONT TestPathInfoCACompatibility/new_structured_format_-_text2882026/10/08 12:57:47 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:51966289=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive290=== CONT TestPathInfoCACompatibility/old_string_format_-_text291=== CONT TestSetClientTLSErrors/invalid_ca_file292=== CONT TestFilterOversizedClosures/no_limit_keeps_everything293=== CONT TestSetClientTLSErrors/missing_ca_file294=== CONT TestSetClientTLSErrors/missing_key_file295=== CONT TestSetClientTLS/rejects_connection_without_client_cert296--- PASS: TestParsePathInfoJSON (0.00s)297 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)298 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)299 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)300 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)301 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)302--- PASS: TestScriptTokenEmptyToken (0.03s)303=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error304=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error305=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error306=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error307=== RUN TestUploadMultipart_SupersededByPeer/exists308=== PAUSE TestUploadMultipart_SupersededByPeer/exists309=== RUN TestUploadMultipart_SupersededByPeer/missing310=== PAUSE TestUploadMultipart_SupersededByPeer/missing311=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA312=== CONT TestSetClientTLS/preserves_debug_logging_transport313=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths314=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths315=== CONT TestGetStorePathHash/valid_store_path316=== RUN TestPartSizeForNAR/zero_stays_at_minimum317=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum318=== CONT TestFilterOversizedClosures/all_closures_skipped3192026/10/08 12:57:47 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=50320=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error321=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error322=== CONT TestGetStorePathHash/basename_without_hyphen_should_error323=== CONT TestUploadMultipart_SupersededByPeer/exists3242026/10/08 12:57:47 WARN Rate limiter enabled after throttle name=server-test rate=53252026/10/08 12:57:47 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:51999326=== RUN TestPartSizeForNAR/small_stays_at_minimum327=== PAUSE TestPartSizeForNAR/small_stays_at_minimum3282026/10/08 12:57:47 INFO Garbage collection started3292026/10/08 12:57:47 WARN Rate limiter backed off name=server-test rate=53302026/10/08 12:57:47 INFO Garbage collection started331=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum332--- PASS: TestPathInfoCACompatibility (0.01s)333 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)334 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)335 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)338=== CONT TestUploadMultipart_SupersededByPeer/missing339=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum340=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts341=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts342=== RUN TestPartSizeForNAR/1_TiB3432026/10/08 12:57:47 WARN Rate limiter backed off name=server-test rate=5344--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)345 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)346 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)347=== PAUSE TestPartSizeForNAR/1_TiB348=== RUN TestPartSizeForNAR/5_TiB_S3_max_object349--- PASS: TestFilterOversizedClosures (0.00s)350 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)351 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)352 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)353=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object354=== RUN TestPartSizeForNAR/capped_at_5_GiB355=== PAUSE TestPartSizeForNAR/capped_at_5_GiB356--- PASS: TestGetStorePathHash (0.02s)357 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)358 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)359 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)360 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)361=== CONT TestPartSizeForNAR/zero_stays_at_minimum362=== CONT TestPartSizeForNAR/capped_at_5_GiB363=== CONT TestPartSizeForNAR/5_TiB_S3_max_object364=== CONT TestPartSizeForNAR/1_TiB365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts366=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum367=== CONT TestPartSizeForNAR/small_stays_at_minimum368--- PASS: TestPartSizeForNAR (0.01s)369 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)3772026/10/08 12:57:47 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=0378--- PASS: TestRateLimiterFeedback (0.01s)379 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)380 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)381 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)382 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.02s)383--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)384--- PASS: TestSetClientTLSErrors (0.02s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)387 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)389--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)390 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)391 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3922026/10/08 12:57:47 WARN Garbage collection finished on another replica. Its statistics are not available here393--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)394--- PASS: TestStreamPushRequestLine (0.03s)395--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)396--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)397--- PASS: TestDumpPathWriterError (0.06s)3982026/10/08 12:57:47 http: TLS handshake error from 127.0.0.1:52034: read tcp 127.0.0.1:51956->127.0.0.1:52034: use of closed network connection399--- PASS: TestSetClientTLS (0.00s)400 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)401 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)402 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)403--- PASS: TestStreamPushBatchesUnderLoad (0.11s)404--- PASS: TestScriptTokenCachesUntilRefresh (0.14s)405--- PASS: TestDumpPathSingleFile (0.16s)406--- PASS: TestCaseHackSuffix (0.19s)407--- PASS: TestDumpPathMatchesNix (0.32s)408--- PASS: TestUploadMultipart_PartsInParallel (0.66s)409--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)410PASS411Running server tests...412The files belonging to this database system will be owned by user "_tribuchetbld4".413This user must also own the server process.414415The database cluster will be initialized with locale "C".416The default database encoding has accordingly been set to "SQL_ASCII".417The default text search configuration will be set to "english".418419Data page checksums are enabled.420421creating directory /private/var/tb/4/scratch/b802c6ef575c14ab/build/postgres626905297/data ... ok422creating subdirectories ... ok423selecting dynamic shared memory implementation ... posix424selecting default "max_connections" ... 100425selecting default "shared_buffers" ... 128MB426selecting default time zone ... UTC427creating configuration files ... ok428running bootstrap script ... ok429performing post-bootstrap initialization ... ok430syncing data to disk ... ok431432initdb: warning: enabling "trust" authentication for local connections433initdb: 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.434435Success. You can now start the database server using:436437 pg_ctl -D /private/var/tb/4/scratch/b802c6ef575c14ab/build/postgres626905297/data -l logfile start4384392026-10-08 12:57:51.171 UTC [42660] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4402026-10-08 12:57:51.171 UTC [42660] LOG: listening on Unix socket "/private/var/tb/4/scratch/b802c6ef575c14ab/build/postgres626905297/.s.PGSQL.5432"4412026-10-08 12:57:51.177 UTC [42670] LOG: database system was shut down at 2026-10-08 12:57:51 UTC4422026-10-08 12:57:51.180 UTC [42660] LOG: database system is ready to accept connections443/private/var/tb/4/scratch/b802c6ef575c14ab/build/postgres626905297:5432 - accepting connections444{"timestamp":"2026-10-08T12:57:53.743442Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3db42064-fd14-4646-bf62-50c7bee29c0d","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(4)"}445{"timestamp":"2026-10-08T12:57:53.84735Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2f334737-8ad4-43a7-b808-48d2839d5608","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(4)"}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/08 12:57:54 INFO lead: acquired remote=192.0.2.1:12344942026/10/08 12:57:55 INFO lead: released remote=192.0.2.1:12344952026/10/08 12:57:55 INFO lead: acquired remote=192.0.2.1:12344962026/10/08 12:57:56 INFO lead: released remote=192.0.2.1:1234497--- PASS: TestLeadIncumbentWinsAfterRestart (2.42s)498=== RUN TestLeadIncumbentAnnouncesAtOnce499=== PAUSE TestLeadIncumbentAnnouncesAtOnce500=== RUN TestLeadEndsOnShutdown501=== PAUSE TestLeadEndsOnShutdown502=== RUN TestLeadEndsWhenItsConnectionHangs5032026/10/08 12:57:56 INFO lead: acquired remote=192.0.2.1:12345042026-10-08 12:57:58.013 UTC [43313] FATAL: terminating connection due to administrator command5052026/10/08 12:57:58 INFO lead: acquired remote=192.0.2.1:12345062026/10/08 12:57:59 WARN lead: lock connection lost error="timeout: context deadline exceeded"5072026/10/08 12:57:59 INFO lead: released remote=192.0.2.1:12345082026/10/08 12:57:59 INFO lead: released remote=192.0.2.1:1234509--- PASS: TestLeadEndsWhenItsConnectionHangs (3.04s)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/08 12:57:59 INFO Starting HTTP server address=127.0.0.1:521126102026/10/08 12:57:59 INFO Starting HTTP server address=proxy.sock6112026/10/08 12:57:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6122026/10/08 12:57:59 INFO Shutdown signal received, draining in-flight requests timeout=10s613--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.26s)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/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6822026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6832026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6842026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6852026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6862026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6872026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6882026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6892026/10/08 12:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6902026/10/08 12:57:59 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 TestService_AuthMiddleware715=== CONT TestMetricsInventory716=== CONT TestDeduplicatedObjectsRecordedAsPending717=== CONT TestPinProtectsFromGC718=== CONT TestLeadElectsOneAndHandsOver719=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT720=== CONT TestClientSharedPathCommittedMidPush721=== CONT TestConnectWaitsForAPeerMigration722=== CONT TestRegisterCompletedObjectNeedsPendingRow723=== CONT TestCompleteMultipartUnregistered724=== CONT TestClientWithDependencies725=== CONT TestPushDedupSurvivesConcurrentGC726=== CONT TestClientFallsBackToClosures727=== CONT TestGCMetrics728=== CONT TestClientPushesUseOnePush729=== CONT TestGCBugBareHashReferences730=== CONT TestReadRedirectNar731=== CONT TestGCAdvisoryLockBlocksConcurrentRun732=== CONT TestService_verifyS3Integrity733=== CONT TestLeadEndsOnShutdown734=== CONT TestService_createPendingClosureHandler735=== CONT TestLeadIncumbentAnnouncesAtOnce736=== CONT TestService_cleanupPendingClosuresHandler737=== CONT TestGCTaskStore_DeduplicateSameParams738--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)739=== CONT TestResolveDBConnectionString740=== RUN TestResolveDBConnectionString/flag_wins741=== PAUSE TestResolveDBConnectionString/flag_wins742=== RUN TestResolveDBConnectionString/file_when_flag_empty743=== PAUSE TestResolveDBConnectionString/file_when_flag_empty744=== RUN TestResolveDBConnectionString/missing_file_is_an_error745=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error746=== RUN TestResolveDBConnectionString/PGHOST_allows_empty747=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty748=== RUN TestResolveDBConnectionString/nothing_configured749=== PAUSE TestResolveDBConnectionString/nothing_configured750=== CONT TestUploadHandlersRejectOversizedBody751=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure752=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure753=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart754=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart755=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts756=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts757=== CONT TestUploadHandlersRejectInvalidKeys758=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info759=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info760=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal761=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal762=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key763=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key764=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key765=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key766=== CONT TestIsValidUploadKey767=== RUN TestIsValidUploadKey/narinfo768=== PAUSE TestIsValidUploadKey/narinfo769=== RUN TestIsValidUploadKey/nar_zst770=== PAUSE TestIsValidUploadKey/nar_zst771=== RUN TestIsValidUploadKey/nar_xz772=== PAUSE TestIsValidUploadKey/nar_xz773=== RUN TestIsValidUploadKey/nar_plain774=== PAUSE TestIsValidUploadKey/nar_plain775=== RUN TestIsValidUploadKey/listing776=== PAUSE TestIsValidUploadKey/listing777=== RUN TestIsValidUploadKey/build_log778=== PAUSE TestIsValidUploadKey/build_log779=== RUN TestIsValidUploadKey/build_log_home-manager_file780=== PAUSE TestIsValidUploadKey/build_log_home-manager_file781=== RUN TestIsValidUploadKey/build_log_plus_in_name782=== PAUSE TestIsValidUploadKey/build_log_plus_in_name783=== RUN TestIsValidUploadKey/build_log_question_mark784=== PAUSE TestIsValidUploadKey/build_log_question_mark785=== RUN TestIsValidUploadKey/build_log_equals786=== PAUSE TestIsValidUploadKey/build_log_equals787=== RUN TestIsValidUploadKey/realisation788=== PAUSE TestIsValidUploadKey/realisation789=== RUN TestIsValidUploadKey/realisation_plus_in_output790=== PAUSE TestIsValidUploadKey/realisation_plus_in_output791=== RUN TestIsValidUploadKey/nix-cache-info792=== PAUSE TestIsValidUploadKey/nix-cache-info793=== RUN TestIsValidUploadKey/index.html794=== PAUSE TestIsValidUploadKey/index.html795=== RUN TestIsValidUploadKey/narinfo_key,_nar_type796=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type797=== RUN TestIsValidUploadKey/nar_key,_narinfo_type798=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type799=== RUN TestIsValidUploadKey/listing_key,_narinfo_type800=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type801=== RUN TestIsValidUploadKey/traversal802=== PAUSE TestIsValidUploadKey/traversal803=== RUN TestIsValidUploadKey/traversal_nar804=== PAUSE TestIsValidUploadKey/traversal_nar805=== RUN TestIsValidUploadKey/absolute806=== PAUSE TestIsValidUploadKey/absolute807=== RUN TestIsValidUploadKey/empty_key808=== PAUSE TestIsValidUploadKey/empty_key809=== RUN TestIsValidUploadKey/unknown_type810=== PAUSE TestIsValidUploadKey/unknown_type811=== CONT TestPendingClosureWriteTimeout812=== RUN TestPendingClosureWriteTimeout/empty813=== PAUSE TestPendingClosureWriteTimeout/empty814=== RUN TestPendingClosureWriteTimeout/400_objects815=== PAUSE TestPendingClosureWriteTimeout/400_objects816=== RUN TestPendingClosureWriteTimeout/670k_objects817=== PAUSE TestPendingClosureWriteTimeout/670k_objects818=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline819=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline820=== CONT TestProxyWriteTimeout821=== RUN TestProxyWriteTimeout/narinfo822=== PAUSE TestProxyWriteTimeout/narinfo823=== RUN TestProxyWriteTimeout/1_GiB_nar824=== PAUSE TestProxyWriteTimeout/1_GiB_nar825=== RUN TestProxyWriteTimeout/10_GiB_nar826=== PAUSE TestProxyWriteTimeout/10_GiB_nar827=== RUN TestProxyWriteTimeout/unknown_size828=== PAUSE TestProxyWriteTimeout/unknown_size829=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8302026/10/08 12:58:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"831--- PASS: TestService_AuthMiddleware (0.73s)832=== CONT TestSkippedUploadsHandler8332026/10/08 12:58:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000834--- PASS: TestSkippedUploadsHandler (0.00s)835=== CONT TestParseSize836--- PASS: TestParseSize (0.00s)837=== CONT TestService_Rustfstest838--- PASS: TestMetricsInventory (1.22s)839=== CONT TestPresignedUploadRegisteredBeforeCommit8402026/10/08 12:58:01 INFO Received uploads request method=POST path=/api/pending_closures841--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.71s)842=== CONT TestCompletedNarNotReofferedAcrossClosures843=== NAME TestPinProtectsFromGC844 client_integration_test.go:731: Pinned store path: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestPinProtectsFromGC101346647/001/store/24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq-pinned-file.txt845 client_integration_test.go:732: Unpinned store path: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestPinProtectsFromGC101346647/001/store/9b0ckv97clgkwp1vxn541rgn3m2kc23q-unpinned-file.txt8462026/10/08 12:58:02 INFO Aborted multipart uploads count=0 kept=08472026/10/08 12:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period8482026/10/08 12:58:02 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=08492026/10/08 12:58:02 INFO Vacuumed table table=pending_closures8502026/10/08 12:58:02 INFO Vacuumed table table=pending_objects8512026/10/08 12:58:02 INFO Vacuumed table table=multipart_uploads8522026/10/08 12:58:02 INFO Vacuumed table table=closures8532026/10/08 12:58:02 INFO Vacuumed table table=objects854--- PASS: TestGCMetrics (2.42s)855=== CONT TestCompleteMultipartUpload_ErrorButObjectExists8562026/10/08 12:58:02 INFO Received push request method=POST path=/api/pushes8572026/10/08 12:58:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8582026/10/08 12:58:02 INFO Uploading 24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq-pinned-file.txt (128B)8592026/10/08 12:58:02 WARN Failed to register uploaded object key=24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq.ls error="server returned 404: 404 page not found\n"8602026/10/08 12:58:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"8612026/10/08 12:58:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8622026/10/08 12:58:02 INFO Signed narinfos id=1 count=18632026/10/08 12:58:02 INFO Uploading 1 narinfos8642026/10/08 12:58:02 INFO Received complete push request method=POST path=/api/pushes/1/complete8652026/10/08 12:58:02 WARN Failed to register uploaded object key=24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq.narinfo error="server returned 404: 404 page not found\n"8662026/10/08 12:58:02 INFO Completed push id=1 objects=3 duration=36.451125ms8672026/10/08 12:58:02 INFO Upload complete. (228ms)8682026/10/08 12:58:02 INFO Received push request method=POST path=/api/pushes8692026/10/08 12:58:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8702026/10/08 12:58:02 INFO Uploading 9b0ckv97clgkwp1vxn541rgn3m2kc23q-unpinned-file.txt (128B)8712026/10/08 12:58:02 WARN Failed to register uploaded object key=9b0ckv97clgkwp1vxn541rgn3m2kc23q.ls error="server returned 404: 404 page not found\n"8722026/10/08 12:58:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8732026/10/08 12:58:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"8742026/10/08 12:58:02 INFO Signed narinfos id=2 count=18752026/10/08 12:58:02 INFO Uploading 1 narinfos8762026/10/08 12:58:02 INFO Received complete push request method=POST path=/api/pushes/2/complete8772026/10/08 12:58:02 WARN Failed to register uploaded object key=9b0ckv97clgkwp1vxn541rgn3m2kc23q.narinfo error="server returned 404: 404 page not found\n"8782026/10/08 12:58:02 INFO Completed push id=2 objects=3 duration=810.083µs8792026/10/08 12:58:02 INFO Upload complete. (186ms)8802026/10/08 12:58:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures8812026/10/08 12:58:02 INFO Garbage collection started8822026/10/08 12:58:02 INFO Aborted multipart uploads count=0 kept=08832026/10/08 12:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period8842026/10/08 12:58:03 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=08852026/10/08 12:58:03 INFO Vacuumed table table=pending_closures8862026/10/08 12:58:03 INFO Vacuumed table table=pending_objects8872026/10/08 12:58:03 INFO Vacuumed table table=multipart_uploads8882026/10/08 12:58:03 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/08 12:58:03 INFO Vacuumed table table=closures8902026/10/08 12:58:03 INFO Vacuumed table table=objects891--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.31s)892=== CONT TestRedundantMultipartUpload893=== NAME TestClientWithDependencies894 client_integration_test.go:613: Built derivation: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientWithDependencies3993861479/001/store/kizfxldz4vnza3hxc4an463zi936nz9q-test-script895 client_integration_test.go:615: Found 1 dependencies (including self)8962026/10/08 12:58:03 INFO Received push request method=POST path=/api/pushes897--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.51s)898=== CONT TestPush_SignsNarinfosOfItsPendingObjects8992026/10/08 12:58:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9002026/10/08 12:58:03 INFO Uploading kizfxldz4vnza3hxc4an463zi936nz9q-test-script (136B)9012026/10/08 12:58:03 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9022026/10/08 12:58:03 WARN Failed to register uploaded object key=kizfxldz4vnza3hxc4an463zi936nz9q.ls error="server returned 404: 404 page not found\n"9032026/10/08 12:58:03 WARN Failed to register uploaded object key=log/m5na9c317zfvcvlfpc61p3hnydmmx1xv-test-script.drv error="server returned 404: 404 page not found\n"9042026/10/08 12:58:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9052026/10/08 12:58:03 INFO Signed narinfos id=1 count=19062026/10/08 12:58:03 INFO Uploading 1 narinfos9072026/10/08 12:58:03 INFO Received complete push request method=POST path=/api/pushes/1/complete9082026/10/08 12:58:03 WARN Failed to register uploaded object key=kizfxldz4vnza3hxc4an463zi936nz9q.narinfo error="server returned 404: 404 page not found\n"9092026/10/08 12:58:03 INFO Completed push id=1 objects=4 duration=5.808708ms9102026/10/08 12:58:03 INFO Upload complete. (214ms)911=== NAME TestClientWithDependencies912 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientWithDependencies3993861479/001/store) requires matching store prefix913--- PASS: TestClientWithDependencies (3.76s)914=== CONT TestPush_RejectsBadRequests915--- PASS: TestReadRedirectNar (4.15s)916=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9172026/10/08 12:58:04 INFO Received push request method=POST path=/api/pushes9182026/10/08 12:58:04 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9192026/10/08 12:58:04 INFO Uploading 9ybfr7c6p0l9rc1rk1dqrqcp84c3vh59-shared-dep (136B)9202026/10/08 12:58:04 INFO Uploading spjkpgazl16762r3lf75bvn4066xpxzs-top (264B)9212026/10/08 12:58:04 WARN Failed to register uploaded object key=9ybfr7c6p0l9rc1rk1dqrqcp84c3vh59.ls error="server returned 404: 404 page not found\n"9222026/10/08 12:58:04 WARN Failed to register uploaded object key=nar/08rdi3q2ils8lvm0xpvdqp7ak5h25rdj6wgv39kikhq8hfjygwvh.nar.zst error="server returned 404: 404 page not found\n"9232026/10/08 12:58:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9242026/10/08 12:58:04 WARN Failed to register uploaded object key=spjkpgazl16762r3lf75bvn4066xpxzs.ls error="server returned 404: 404 page not found\n"9252026/10/08 12:58:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9262026/10/08 12:58:04 INFO Signed narinfos id=1 count=29272026/10/08 12:58:04 INFO Uploading 2 narinfos9282026/10/08 12:58:04 WARN Failed to register uploaded object key=9ybfr7c6p0l9rc1rk1dqrqcp84c3vh59.narinfo error="server returned 404: 404 page not found\n"9292026/10/08 12:58:04 INFO Received complete push request method=POST path=/api/pushes/1/complete9302026/10/08 12:58:04 WARN Failed to register uploaded object key=spjkpgazl16762r3lf75bvn4066xpxzs.narinfo error="server returned 404: 404 page not found\n"9312026/10/08 12:58:04 INFO Completed push id=1 objects=6 duration=33.49825ms9322026/10/08 12:58:04 INFO Upload complete. (251ms)933=== NAME TestClientSharedPathCommittedMidPush934 client_integration_test.go:680: Retrieved narinfo from S3:935 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientSharedPathCommittedMidPush2945458706/001/store/9ybfr7c6p0l9rc1rk1dqrqcp84c3vh59-shared-dep936 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst937 Compression: zstd938 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82939 NarSize: 136940 References: 941 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n942 client_integration_test.go:680: Retrieved narinfo from S3:943 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientSharedPathCommittedMidPush2945458706/001/store/spjkpgazl16762r3lf75bvn4066xpxzs-top944 URL: nar/08rdi3q2ils8lvm0xpvdqp7ak5h25rdj6wgv39kikhq8hfjygwvh.nar.zst945 Compression: zstd946 NarHash: sha256:08rdi3q2ils8lvm0xpvdqp7ak5h25rdj6wgv39kikhq8hfjygwvh947 NarSize: 264948 References: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientSharedPathCommittedMidPush2945458706/001/store/9ybfr7c6p0l9rc1rk1dqrqcp84c3vh59-shared-dep949 CA: text:sha256:0xj07bjyy5pl98bsdw59kijzs59s23mpxf3951j8qjp5m4z2gcw2950--- PASS: TestClientSharedPathCommittedMidPush (4.47s)951=== CONT TestPush_RootsAreLockedInByteOrder9522026/10/08 12:58:04 INFO lead: acquired remote=192.0.2.1:12349532026/10/08 12:58:04 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld4 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"954--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (4.77s)955=== CONT TestPush_CompleteWaitsForCleanupOfThePush9562026/10/08 12:58:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=09572026/10/08 12:58:04 INFO Received create pin request method=POST path=/api/pins/myapp9582026/10/08 12:58:04 INFO Created/updated pin name=myapp store_path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestPinProtectsFromGC101346647/001/store/24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq-pinned-file.txt narinfo_key=24n3bzjdibqdfy5aqyfpcbvhqvkgdgwq.narinfo9592026/10/08 12:58:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures9602026/10/08 12:58:04 INFO Garbage collection started9612026/10/08 12:58:04 INFO Aborted multipart uploads count=0 kept=09622026/10/08 12:58:04 WARN Force mode enabled - objects will be deleted immediately without grace period9632026/10/08 12:58:04 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=09642026/10/08 12:58:04 INFO Vacuumed table table=pending_closures9652026/10/08 12:58:04 INFO Vacuumed table table=pending_objects9662026/10/08 12:58:04 INFO Vacuumed table table=multipart_uploads9672026/10/08 12:58:04 INFO Vacuumed table table=closures9682026/10/08 12:58:04 INFO Vacuumed table table=objects9692026/10/08 12:58:05 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/08 12:58:05 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/08 12:58:05 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/08 12:58:05 INFO Received push request method=POST path=/api/pushes9732026/10/08 12:58:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9742026/10/08 12:58:05 INFO Uploading xi6vphl04z5jxiavahq14i71ck0dybcc-a (256B)9752026/10/08 12:58:05 INFO Uploading 9zcm7knwmgg2lp6drc3yqpng0h7w1wfw-shared-dep (136B)9762026/10/08 12:58:05 WARN Failed to register uploaded object key=xi6vphl04z5jxiavahq14i71ck0dybcc.ls error="server returned 404: 404 page not found\n"9772026/10/08 12:58:05 WARN Failed to register uploaded object key=5jvpvjbwj7nc7p13bx56j180m25g5m97.ls error="server returned 404: 404 page not found\n"9782026/10/08 12:58:05 WARN Failed to register uploaded object key=nar/0cfzz8p684ivgyknspvsfn03l6913vm611y9a3n9fyvkva8ql3rf.nar.zst error="server returned 404: 404 page not found\n"9792026/10/08 12:58:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9802026/10/08 12:58:05 WARN Failed to register uploaded object key=9zcm7knwmgg2lp6drc3yqpng0h7w1wfw.ls error="server returned 404: 404 page not found\n"9812026/10/08 12:58:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9822026/10/08 12:58:05 INFO Signed narinfos id=1 count=39832026/10/08 12:58:05 INFO Uploading 3 narinfos9842026/10/08 12:58:05 WARN Failed to register uploaded object key=5jvpvjbwj7nc7p13bx56j180m25g5m97.narinfo error="server returned 404: 404 page not found\n"9852026/10/08 12:58:05 WARN Failed to register uploaded object key=9zcm7knwmgg2lp6drc3yqpng0h7w1wfw.narinfo error="server returned 404: 404 page not found\n"9862026/10/08 12:58:05 INFO Received complete push request method=POST path=/api/pushes/1/complete9872026/10/08 12:58:05 WARN Failed to register uploaded object key=xi6vphl04z5jxiavahq14i71ck0dybcc.narinfo error="server returned 404: 404 page not found\n"9882026/10/08 12:58:05 INFO Completed push id=1 objects=8 duration=22.574083ms9892026/10/08 12:58:05 INFO Upload complete. (207ms)990=== NAME TestClientPushesUseOnePush991 client_pushes_test.go:97: Retrieved narinfo from S3:992 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientPushesUseOnePush1052564445/001/store/9zcm7knwmgg2lp6drc3yqpng0h7w1wfw-shared-dep993 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst994 Compression: zstd995 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82996 NarSize: 136997 References: 998 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n999 client_pushes_test.go:97: Retrieved narinfo from S3:1000 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientPushesUseOnePush1052564445/001/store/xi6vphl04z5jxiavahq14i71ck0dybcc-a1001 URL: nar/0cfzz8p684ivgyknspvsfn03l6913vm611y9a3n9fyvkva8ql3rf.nar.zst1002 Compression: zstd1003 NarHash: sha256:0cfzz8p684ivgyknspvsfn03l6913vm611y9a3n9fyvkva8ql3rf1004 NarSize: 2561005 References: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientPushesUseOnePush1052564445/001/store/9zcm7knwmgg2lp6drc3yqpng0h7w1wfw-shared-dep1006 CA: text:sha256:1mqcfyb3qn0khbyfr2xkgsmvd0330slnvkn1q3qyvkvx43l1968n1007 client_pushes_test.go:97: Retrieved narinfo from S3:1008 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientPushesUseOnePush1052564445/001/store/5jvpvjbwj7nc7p13bx56j180m25g5m97-b1009 URL: nar/0cfzz8p684ivgyknspvsfn03l6913vm611y9a3n9fyvkva8ql3rf.nar.zst1010 Compression: zstd1011 NarHash: sha256:0cfzz8p684ivgyknspvsfn03l6913vm611y9a3n9fyvkva8ql3rf1012 NarSize: 2561013 References: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientPushesUseOnePush1052564445/001/store/9zcm7knwmgg2lp6drc3yqpng0h7w1wfw-shared-dep1014 CA: text:sha256:1mqcfyb3qn0khbyfr2xkgsmvd0330slnvkn1q3qyvkvx43l1968n10152026/10/08 12:58:05 INFO lead: released remote=192.0.2.1:12341016--- PASS: TestClientPushesUseOnePush (5.72s)1017=== CONT TestPush_RepeatedRootCommitsOnce10182026/10/08 12:58:05 INFO lead: acquired remote=192.0.2.1:123410192026/10/08 12:58:05 INFO Received uploads request method=POST path=/api/pending_closures10202026/10/08 12:58:06 INFO Aborted multipart uploads count=0 kept=010212026/10/08 12:58:06 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=010222026/10/08 12:58:06 INFO Vacuumed table table=pending_closures10232026/10/08 12:58:06 INFO Vacuumed table table=pending_objects10242026/10/08 12:58:06 INFO Vacuumed table table=multipart_uploads10252026/10/08 12:58:06 INFO Received uploads request method=POST path=/api/pending_closures10262026/10/08 12:58:06 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/08 12:58:06 INFO Vacuumed table table=closures10282026/10/08 12:58:06 INFO Vacuumed table table=objects10292026/10/08 12:58:06 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/08 12:58:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10312026/10/08 12:58:06 INFO Aborted multipart uploads count=0 kept=010322026/10/08 12:58:06 INFO Uploading shc96c8xnbwb92hwl94cma3xa20z6j7x-b (256B)10332026/10/08 12:58:06 INFO Uploading 39489b3n9k345vqcqqi0j2y1s6fk4l5s-shared-dep (136B)10342026/10/08 12:58:06 WARN Force mode enabled - objects will be deleted immediately without grace period10352026/10/08 12:58:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010362026/10/08 12:58:06 INFO Vacuumed table table=pending_closures10372026/10/08 12:58:06 WARN Failed to register uploaded object key=q6y7isz376191600mzmf12p4kf7w6arl.ls error="server returned 404: 404 page not found\n"10382026/10/08 12:58:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10392026/10/08 12:58:06 WARN Failed to register uploaded object key=shc96c8xnbwb92hwl94cma3xa20z6j7x.ls error="server returned 404: 404 page not found\n"10402026/10/08 12:58:06 WARN Failed to register uploaded object key=39489b3n9k345vqcqqi0j2y1s6fk4l5s.ls error="server returned 404: 404 page not found\n"10412026/10/08 12:58:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10422026/10/08 12:58:06 WARN Failed to register uploaded object key=nar/1dfrvhm82321pdzwb5j6qgf3zfgk1qdgw490zndqnbhvn3wq09v9.nar.zst error="server returned 404: 404 page not found\n"10432026/10/08 12:58:06 INFO Signed narinfos id=1 count=210442026/10/08 12:58:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10452026/10/08 12:58:06 INFO Signed narinfos id=2 count=210462026/10/08 12:58:06 INFO Vacuumed table table=pending_objects10472026/10/08 12:58:06 INFO Uploading 4 narinfos10482026/10/08 12:58:06 INFO Vacuumed table table=multipart_uploads10492026/10/08 12:58:06 INFO Vacuumed table table=closures10502026/10/08 12:58:06 INFO Vacuumed table table=objects10512026/10/08 12:58:06 WARN Failed to register uploaded object key=shc96c8xnbwb92hwl94cma3xa20z6j7x.narinfo error="server returned 404: 404 page not found\n"10522026/10/08 12:58:06 WARN Failed to register uploaded object key=39489b3n9k345vqcqqi0j2y1s6fk4l5s.narinfo error="server returned 404: 404 page not found\n"10532026/10/08 12:58:06 WARN Failed to register uploaded object key=q6y7isz376191600mzmf12p4kf7w6arl.narinfo error="server returned 404: 404 page not found\n"1054--- PASS: TestPushDedupSurvivesConcurrentGC (6.48s)1055=== CONT TestPush_CompleteCommitsEveryRoot10562026/10/08 12:58:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10572026/10/08 12:58:06 WARN Failed to register uploaded object key=39489b3n9k345vqcqqi0j2y1s6fk4l5s.narinfo error="server returned 404: 404 page not found\n"10582026/10/08 12:58:06 INFO Completed upload id=1 objects=6 duration=34.211625ms10592026/10/08 12:58:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10602026/10/08 12:58:06 INFO Completed upload id=2 objects=6 duration=646.084µs10612026/10/08 12:58:06 INFO Upload complete. (371ms)1062=== NAME TestClientFallsBackToClosures1063 client_pushes_test.go:112: Retrieved narinfo from S3:1064 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientFallsBackToClosures1366194687/001/store/39489b3n9k345vqcqqi0j2y1s6fk4l5s-shared-dep1065 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1066 Compression: zstd1067 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821068 NarSize: 1361069 References: 1070 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1071 client_pushes_test.go:112: Retrieved narinfo from S3:1072 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientFallsBackToClosures1366194687/001/store/q6y7isz376191600mzmf12p4kf7w6arl-a1073 URL: nar/1dfrvhm82321pdzwb5j6qgf3zfgk1qdgw490zndqnbhvn3wq09v9.nar.zst1074 Compression: zstd1075 NarHash: sha256:1dfrvhm82321pdzwb5j6qgf3zfgk1qdgw490zndqnbhvn3wq09v91076 NarSize: 2561077 References: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientFallsBackToClosures1366194687/001/store/39489b3n9k345vqcqqi0j2y1s6fk4l5s-shared-dep1078 CA: text:sha256:0d4ri0j2f4a6300yaz3x1zyiwc7p58shfwhrz697zxlyk9xd160b1079 client_pushes_test.go:112: Retrieved narinfo from S3:1080 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientFallsBackToClosures1366194687/001/store/shc96c8xnbwb92hwl94cma3xa20z6j7x-b1081 URL: nar/1dfrvhm82321pdzwb5j6qgf3zfgk1qdgw490zndqnbhvn3wq09v9.nar.zst1082 Compression: zstd1083 NarHash: sha256:1dfrvhm82321pdzwb5j6qgf3zfgk1qdgw490zndqnbhvn3wq09v91084 NarSize: 2561085 References: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientFallsBackToClosures1366194687/001/store/39489b3n9k345vqcqqi0j2y1s6fk4l5s-shared-dep1086 CA: text:sha256:0d4ri0j2f4a6300yaz3x1zyiwc7p58shfwhrz697zxlyk9xd160b10872026/10/08 12:58:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10882026/10/08 12:58:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1089--- PASS: TestCompleteMultipartUnregistered (6.69s)1090=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1091--- PASS: TestClientFallsBackToClosures (6.69s)1092=== CONT TestReadRedirectUsesPublicS3URL10932026/10/08 12:58:06 INFO lead: released remote=192.0.2.1:12341094--- PASS: TestLeadElectsOneAndHandsOver (6.89s)1095=== CONT TestReadProxyRangeRequest10962026/10/08 12:58:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1097=== NAME TestPinProtectsFromGC1098 client_integration_test.go:840: Pin successfully protected closure from garbage collection10992026/10/08 12:58:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLmZlYTNjMTQ3LWZmYzktNGU4MC04NzdkLTI2MTg3NDNlYzg0N3gxNzkxNDY0Mjg1MzQ0Mjk4MDAw parts=1011002026/10/08 12:58:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11012026/10/08 12:58:07 INFO Completed upload id=1 objects=2 duration=35.295125ms11022026/10/08 12:58:07 INFO Received cleanup request method=DELETE path=/api/pending_closures11032026/10/08 12:58:07 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011042026/10/08 12:58:07 INFO Aborted multipart uploads count=0 kept=011052026/10/08 12:58:07 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/08 12:58:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures11072026/10/08 12:58:07 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestPinProtectsFromGC (7.19s)1109=== CONT TestReadRedirectKeepsNarinfoProxied11102026/10/08 12:58:07 INFO Aborted multipart uploads count=0 kept=011112026/10/08 12:58:07 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=011122026/10/08 12:58:07 INFO Vacuumed table table=pending_closures11132026/10/08 12:58:07 INFO Received cleanup request method=DELETE path=/api/pending_closures11142026/10/08 12:58:07 INFO Aborted multipart uploads count=1 kept=011152026/10/08 12:58:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11162026/10/08 12:58:07 INFO Vacuumed table table=pending_objects11172026-10-08 12:58:07.327 UTC [43713] ERROR: Closure does not exist: id=111182026-10-08 12:58:07.327 UTC [43713] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11192026-10-08 12:58:07.327 UTC [43713] STATEMENT: -- name: CommitPendingClosure :one1120 SELECT commit_pending_closure($1::bigint)::bigint1121 1122--- PASS: TestService_cleanupPendingClosuresHandler (7.39s)1123=== CONT TestDeleteClosuresRacingPins11242026/10/08 12:58:07 INFO Vacuumed table table=multipart_uploads11252026/10/08 12:58:07 INFO Vacuumed table table=closures11262026/10/08 12:58:07 INFO Vacuumed table table=objects11272026/10/08 12:58:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001128--- PASS: TestService_createPendingClosureHandler (7.57s)1129=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11302026/10/08 12:58:07 INFO lead: acquired remote=192.0.2.1:12341131--- PASS: TestConnectWaitsForAPeerMigration (7.82s)1132=== CONT TestFailedS3DeleteKeepsTombstone11332026/10/08 12:58:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1134--- PASS: TestGCBugBareHashReferences (8.61s)1135=== CONT TestSweepSkipsRowsLockedByPush11362026/10/08 12:58:08 INFO lead: released remote=192.0.2.1:12341137--- PASS: TestLeadEndsOnShutdown (8.71s)1138=== CONT TestCommitRacingPendingCleanupKeepsObjects11392026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures11402026/10/08 12:58:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLjI1ZDQ2MzJkLTcwN2UtNDEwZC1iYTg2LWIyNzc2YjYwYTIwZXgxNzkxNDY0Mjg2MzM0MDYyMDAw parts=1011412026/10/08 12:58:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11422026/10/08 12:58:08 INFO Completed upload id=1 objects=2 duration=44.102125ms11432026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/08 12:58:08 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/08 12:58:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11462026/10/08 12:58:08 WARN Found objects in DB but missing from S3, will re-upload count=11147--- PASS: TestService_verifyS3Integrity (8.90s)1148=== CONT TestGCTaskStore_StartNew1149--- PASS: TestGCTaskStore_StartNew (0.00s)1150=== CONT TestGCEndsOnShutdown1151=== RUN TestGCEndsOnShutdown/before_the_run1152=== PAUSE TestGCEndsOnShutdown/before_the_run1153=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1154=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1155=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1156=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1157=== CONT TestCacheConfigHandler1158=== RUN TestCacheConfigHandler/full_config,_no_issuer1159=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1160=== RUN TestCacheConfigHandler/no_cache_url_configured1161=== PAUSE TestCacheConfigHandler/no_cache_url_configured1162=== RUN TestCacheConfigHandler/no_signing_keys1163=== PAUSE TestCacheConfigHandler/no_signing_keys1164=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1165=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1166=== CONT TestClientMultipleUploads11672026/10/08 12:58:09 INFO lead: acquired remote=192.0.2.1:123411682026/10/08 12:58:09 INFO lead: released remote=192.0.2.1:12341169--- PASS: TestLeadIncumbentAnnouncesAtOnce (9.37s)1170=== CONT TestClientIntegration11712026/10/08 12:58:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1172--- PASS: TestService_Rustfstest (9.16s)1173=== CONT TestClientErrorHandling1174=== RUN TestClientErrorHandling/InvalidStorePath1175=== PAUSE TestClientErrorHandling/InvalidStorePath1176=== RUN TestClientErrorHandling/InvalidAuthToken1177=== PAUSE TestClientErrorHandling/InvalidAuthToken1178=== RUN TestClientErrorHandling/ServerNotAvailable1179=== PAUSE TestClientErrorHandling/ServerNotAvailable1180=== CONT TestClientCADerivations11812026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/08 12:58:10 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11832026/10/08 12:58:10 INFO Received uploads request method=POST path=/api/pending_closures1184--- PASS: TestPresignedUploadRegisteredBeforeCommit (9.47s)1185=== CONT TestCacheStatsHandler11862026/10/08 12:58:11 INFO Received uploads request method=POST path=/api/pending_closures11872026/10/08 12:58:11 INFO Received uploads request method=POST path=/api/pending_closures11882026/10/08 12:58:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11892026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures11902026/10/08 12:58:12 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLmI1MDgxYjQ4LWY2ZWUtNGJiNy1iZDE5LWQ2ZDU3M2M1MDNlZHgxNzkxNDY0MjkxNzk0MjI1MDAw11912026/10/08 12:58:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLmI1MDgxYjQ4LWY2ZWUtNGJiNy1iZDE5LWQ2ZDU3M2M1MDNlZHgxNzkxNDY0MjkxNzk0MjI1MDAw parts=11192--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (10.02s)1193=== CONT TestForceGCDuringPushOffersSweptObject1194=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1195=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1196=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1197=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1198=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11992026/10/08 12:58:12 INFO Received uploads request method=POST path=/api/pending_closures12002026/10/08 12:58:12 INFO Received push request method=POST path=/api/pushes12012026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12022026/10/08 12:58:12 INFO Signed narinfos id=1 count=112032026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12042026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12052026/10/08 12:58:12 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12062026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12072026/10/08 12:58:12 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12082026/10/08 12:58:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12092026/10/08 12:58:13 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112102026/10/08 12:58:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/08 12:58:13 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1212--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (9.56s)1213=== CONT TestService_ReadAuthMiddleware1214=== RUN TestPush_RejectsBadRequests/no_roots1215=== PAUSE TestPush_RejectsBadRequests/no_roots1216=== RUN TestPush_RejectsBadRequests/no_objects1217=== PAUSE TestPush_RejectsBadRequests/no_objects1218=== RUN TestPush_RejectsBadRequests/bad_root1219=== PAUSE TestPush_RejectsBadRequests/bad_root1220=== RUN TestPush_RejectsBadRequests/root_not_in_objects1221=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1222=== CONT TestService_ReadScope_PublicByDefault12232026/10/08 12:58:13 WARN Rate limiter enabled after throttle name=s3-test rate=512242026/10/08 12:58:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1225=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1226 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101227 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001228--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.68s)1229=== CONT TestGracefulShutdownDrainsInflight12302026/10/08 12:58:13 INFO Starting HTTP server address=127.0.0.1:5238612312026/10/08 12:58:13 INFO Shutdown signal received, draining in-flight requests timeout=10s1232--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1233=== CONT TestNARDeduplicationMetadataUploadBug12342026/10/08 12:58:13 INFO Received push request method=POST path=/api/pushes12352026/10/08 12:58:14 INFO Received complete push request method=POST path=/api/pushes/1/complete12362026/10/08 12:58:14 INFO Completed push id=1 objects=4 duration=43.899541ms12372026/10/08 12:58:14 INFO Received push request method=POST path=/api/pushes12382026/10/08 12:58:14 INFO Aborted multipart uploads count=0 kept=012392026/10/08 12:58:14 WARN Force mode enabled - objects will be deleted immediately without grace period12402026/10/08 12:58:14 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=012412026/10/08 12:58:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12422026/10/08 12:58:14 INFO Vacuumed table table=pending_closures12432026/10/08 12:58:14 INFO Received push request method=POST path=/api/pushes12442026/10/08 12:58:14 INFO Vacuumed table table=pending_objects12452026/10/08 12:58:14 INFO Vacuumed table table=multipart_uploads12462026/10/08 12:58:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLjYxNThiNTMwLWQ2YzQtNDkwMi1iNzM4LTYwMjNlZDA4MTg5ZXgxNzkxNDY0MjkxMTYwNjk3MDAw parts=1212472026/10/08 12:58:14 INFO Received uploads request method=POST path=/api/pending_closures1248--- PASS: TestCompletedNarNotReofferedAcrossClosures (12.86s)1249=== CONT TestCreatePendingClosureRejectsOversizedNAR12502026/10/08 12:58:14 INFO Received uploads request method=POST path=/api/pending_closures1251--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1252=== CONT TestCacheConfigHandlerMaxNarSize1253--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1254=== CONT TestGenerateLandingPage1255--- PASS: TestGenerateLandingPage (0.00s)1256=== CONT TestService_readinessHandler12572026/10/08 12:58:14 INFO Vacuumed table table=closures12582026/10/08 12:58:14 INFO Vacuumed table table=objects12592026/10/08 12:58:14 INFO Received complete push request method=POST path=/api/pushes/2/complete12602026/10/08 12:58:14 INFO Completed push id=2 objects=4 duration=19.767583ms1261--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (10.54s)1262=== CONT TestService_healthCheckHandler12632026-10-08 12:58:14.727 UTC [43894] ERROR: could not obtain lock on row in relation "closures"12642026-10-08 12:58:14.727 UTC [43894] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12652026-10-08 12:58:14.730 UTC [43894] ERROR: could not obtain lock on row in relation "closures"12662026-10-08 12:58:14.730 UTC [43894] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12672026-10-08 12:58:14.738 UTC [43894] ERROR: could not obtain lock on row in relation "closures"12682026-10-08 12:58:14.738 UTC [43894] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12692026-10-08 12:58:14.745 UTC [43894] ERROR: could not obtain lock on row in relation "closures"12702026-10-08 12:58:14.745 UTC [43894] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12712026-10-08 12:58:14.747 UTC [43894] ERROR: could not obtain lock on row in relation "closures"12722026-10-08 12:58:14.747 UTC [43894] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1273--- PASS: TestPush_RootsAreLockedInByteOrder (10.36s)1274=== CONT TestService_RequireScope_OIDC12752026/10/08 12:58:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52406/oidc12762026/10/08 12:58:14 INFO Received push request method=POST path=/api/pushes12772026/10/08 12:58:15 INFO Received push request method=POST path=/api/pushes12782026-10-08 12:58:15.392 UTC [44087] ERROR: Push does not exist: id=112792026-10-08 12:58:15.392 UTC [44087] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12802026-10-08 12:58:15.392 UTC [44087] STATEMENT: SELECT commit_push($1)1281--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (10.69s)1282=== CONT TestGCSweepDeliversEachKeyOnce12832026/10/08 12:58:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/10/08 12:58:15 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLmM1OTVhNzBlLTgxNDAtNGI3Zi04NTM4LWVkMzUxNGQ3MTk1Y3gxNzkxNDY0MjkyMzU1MTg5MDAw parts=1212852026/10/08 12:58:15 INFO Received uploads request method=POST path=/api/pending_closures12862026/10/08 12:58:15 INFO Received complete push request method=POST path=/api/pushes/1/complete12872026/10/08 12:58:15 INFO Received uploads request method=POST path=/api/pending_closures12882026/10/08 12:58:15 INFO Completed push id=1 objects=4 duration=87.205417ms1289--- PASS: TestPush_RepeatedRootCommitsOnce (10.09s)1290=== CONT TestGCSweepSkipsPendingObjects12912026/10/08 12:58:15 INFO Received push request method=POST path=/api/pushes1292--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (9.47s)1293=== CONT TestService_AuthMiddleware_MTLSProxyHeader12942026/10/08 12:58:16 INFO Received push request method=POST path=/api/pushes12952026/10/08 12:58:16 INFO Received complete push request method=POST path=/api/pushes/1/complete12962026/10/08 12:58:16 INFO Completed push id=1 objects=6 duration=33.061208ms1297--- PASS: TestPush_CompleteCommitsEveryRoot (10.21s)1298=== CONT TestGCTaskStore_CompletedAllowsNewTask1299--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1300=== CONT TestGCTaskStore_Fail1301--- PASS: TestGCTaskStore_Fail (0.00s)1302=== CONT TestGCTaskStore_PhaseUpdates1303--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1304=== CONT TestPresentNotReportedWhileGCDeletesClosure1305=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1306=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1307=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1308=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1309=== CONT TestReadProxyDisabled1310--- PASS: TestReadProxyRangeRequest (10.17s)1311=== CONT TestReadProxyRootRedirectsToIndexHTML1312--- PASS: TestReadRedirectUsesPublicS3URL (10.83s)1313=== CONT TestReadProxyConditionalGet13142026/10/08 12:58:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13152026/10/08 12:58:18 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLjBiNWYyNWUxLTIyMjYtNGZhZC05YTg4LWJlY2RiYzJiOTA2MHgxNzkxNDY0Mjk1Njg2NTc2MDAw error="Get \"http://127.0.0.1:1/bucket31/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13162026/10/08 12:58:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NTAwMjJhNzAtOTc3MC00MWYyLWI1MzAtZGUyMWY5ZWRjNDVjLmEzZGUzZjU0LTM4NTAtNDE4Mi04MWQ2LTQyMGQyMTZhMWIzOHgxNzkxNDY0Mjk1NjA0ODQzMDAw parts=1213172026/10/08 12:58:18 INFO Received cleanup request method=DELETE path=/api/pending_closures1318--- PASS: TestReadRedirectKeepsNarinfoProxied (11.34s)1319=== CONT TestReadProxyOutlastsServerWriteTimeout13202026/10/08 12:58:18 INFO Aborted multipart uploads count=1 kept=01321--- PASS: TestRedundantMultipartUpload (15.27s)1322=== CONT TestReadProxyHead13232026/10/08 12:58:18 INFO Received uploads request method=POST path=/api/pending_closures13242026/10/08 12:58:19 INFO Aborted multipart uploads count=0 kept=013252026/10/08 12:58:19 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/08 12:58:19 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13272026/10/08 12:58:19 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1328--- PASS: TestFailedS3DeleteKeepsTombstone (11.65s)1329=== CONT TestReadProxyInvalidPath13302026/10/08 12:58:20 INFO Aborted multipart uploads count=0 kept=013312026/10/08 12:58:20 WARN Force mode enabled - objects will be deleted immediately without grace period13322026/10/08 12:58: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=013332026/10/08 12:58:20 INFO Vacuumed table table=pending_closures13342026/10/08 12:58:20 INFO Vacuumed table table=pending_objects13352026/10/08 12:58:20 INFO Vacuumed table table=multipart_uploads13362026/10/08 12:58:20 INFO Vacuumed table table=closures13372026/10/08 12:58:20 INFO Vacuumed table table=objects13382026/10/08 12:58:20 INFO Aborted multipart uploads count=0 kept=013392026/10/08 12:58:20 WARN Force mode enabled - objects will be deleted immediately without grace period13402026/10/08 12:58:20 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=013412026/10/08 12:58:20 INFO Vacuumed table table=pending_closures13422026/10/08 12:58:20 INFO Vacuumed table table=pending_objects13432026/10/08 12:58:20 INFO Vacuumed table table=multipart_uploads13442026/10/08 12:58:20 INFO Vacuumed table table=closures13452026/10/08 12:58:20 INFO Vacuumed table table=objects1346--- PASS: TestSweepSkipsRowsLockedByPush (11.74s)1347=== CONT TestReadProxy4041348=== NAME TestClientMultipleUploads1349 client_integration_test.go:358: Created store path 0: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientMultipleUploads145221129/001/store/9f21isz2yalkh9b2ckan26a8cbmiqyiy-test-file-0.txt1350 client_integration_test.go:358: Created store path 1: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientMultipleUploads145221129/001/store/kv30vaa807nwb9ass7zjx66zgyv9v3wy-test-file-1.txt1351--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (13.51s)1352=== CONT TestReadProxyNarStreaming1353=== NAME TestClientMultipleUploads1354 client_integration_test.go:358: Created store path 2: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientMultipleUploads145221129/001/store/g1gcl89qa6lj5wsslpam1ykbsc7pzmk8-test-file-2.txt13552026/10/08 12:58:21 INFO Aborted multipart uploads count=0 kept=013562026/10/08 12:58:21 WARN Force mode enabled - objects will be deleted immediately without grace period13572026/10/08 12:58:21 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=013582026/10/08 12:58:21 INFO Vacuumed table table=pending_closures13592026/10/08 12:58:21 INFO Vacuumed table table=pending_objects13602026/10/08 12:58:21 INFO Vacuumed table table=multipart_uploads13612026/10/08 12:58:21 INFO Received push request method=POST path=/api/pushes13622026/10/08 12:58:21 INFO Vacuumed table table=closures13632026/10/08 12:58:21 INFO Vacuumed table table=objects13642026/10/08 12:58:21 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13652026/10/08 12:58:21 INFO Uploading 9f21isz2yalkh9b2ckan26a8cbmiqyiy-test-file-0.txt (160B)13662026/10/08 12:58:21 INFO Uploading kv30vaa807nwb9ass7zjx66zgyv9v3wy-test-file-1.txt (160B)13672026/10/08 12:58:21 INFO Uploading g1gcl89qa6lj5wsslpam1ykbsc7pzmk8-test-file-2.txt (160B)1368--- PASS: TestCommitRacingPendingCleanupKeepsObjects (12.61s)1369=== CONT TestReadProxyContentNegotiation13702026/10/08 12:58:21 WARN Failed to register uploaded object key=9f21isz2yalkh9b2ckan26a8cbmiqyiy.ls error="server returned 404: 404 page not found\n"13712026/10/08 12:58:21 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13722026/10/08 12:58:21 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13732026/10/08 12:58:21 WARN Failed to register uploaded object key=kv30vaa807nwb9ass7zjx66zgyv9v3wy.ls error="server returned 404: 404 page not found\n"13742026/10/08 12:58:21 WARN Failed to register uploaded object key=g1gcl89qa6lj5wsslpam1ykbsc7pzmk8.ls error="server returned 404: 404 page not found\n"13752026/10/08 12:58:21 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13762026/10/08 12:58:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13772026/10/08 12:58:21 INFO Signed narinfos id=1 count=313782026/10/08 12:58:21 INFO Uploading 3 narinfos13792026/10/08 12:58:21 WARN Failed to register uploaded object key=kv30vaa807nwb9ass7zjx66zgyv9v3wy.narinfo error="server returned 404: 404 page not found\n"13802026/10/08 12:58:21 WARN Failed to register uploaded object key=g1gcl89qa6lj5wsslpam1ykbsc7pzmk8.narinfo error="server returned 404: 404 page not found\n"13812026/10/08 12:58:21 INFO Received complete push request method=POST path=/api/pushes/1/complete13822026/10/08 12:58:21 WARN Failed to register uploaded object key=9f21isz2yalkh9b2ckan26a8cbmiqyiy.narinfo error="server returned 404: 404 page not found\n"13832026/10/08 12:58:21 INFO Completed push id=1 objects=9 duration=46.292792ms13842026/10/08 12:58:21 INFO Upload complete. (357ms)1385=== NAME TestClientMultipleUploads1386 client_integration_test.go:369: Uploaded 3 paths in 403.007291ms1387--- PASS: TestClientMultipleUploads (12.91s)1388=== CONT TestReadProxyNarinfoAlreadyDecompressed1389=== NAME TestClientIntegration1390 client_integration_test.go:286: Created store path: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientIntegration1686471055/002/store/a19pbf76450k8b47kbwbavnrbl84gic5-test-file.txt13912026/10/08 12:58:21 INFO Received push request method=POST path=/api/pushes13922026/10/08 12:58:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13932026/10/08 12:58:22 INFO Uploading a19pbf76450k8b47kbwbavnrbl84gic5-test-file.txt (152B)13942026/10/08 12:58:22 WARN Failed to register uploaded object key=a19pbf76450k8b47kbwbavnrbl84gic5.ls error="server returned 404: 404 page not found\n"13952026/10/08 12:58:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13962026/10/08 12:58:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13972026/10/08 12:58:22 INFO Signed narinfos id=1 count=113982026/10/08 12:58:22 INFO Uploading 1 narinfos13992026/10/08 12:58:22 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/10/08 12:58:22 WARN Failed to register uploaded object key=a19pbf76450k8b47kbwbavnrbl84gic5.narinfo error="server returned 404: 404 page not found\n"14012026/10/08 12:58:22 INFO Completed push id=1 objects=3 duration=38.835542ms14022026/10/08 12:58:22 INFO Upload complete. (357ms)1403--- PASS: TestCacheStatsHandler (11.59s)1404=== CONT TestReadProxyNarinfo14052026/10/08 12:58:22 INFO All 1 paths already cached1406=== NAME TestClientIntegration1407 client_integration_test.go:312: Retrieved narinfo from S3:1408 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientIntegration1686471055/002/store/a19pbf76450k8b47kbwbavnrbl84gic5-test-file.txt1409 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1410 Compression: zstd1411 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11412 NarSize: 1521413 References: 1414 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11415 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1416 client_integration_test.go:313: Decompressed .ls content (64 bytes):1417 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1418 client_integration_test.go:316: Testing garbage collection...14192026/10/08 12:58:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures14202026/10/08 12:58:22 INFO Garbage collection started14212026/10/08 12:58:22 INFO Aborted multipart uploads count=0 kept=014222026/10/08 12:58:22 WARN Force mode enabled - objects will be deleted immediately without grace period14232026/10/08 12:58:22 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=014242026/10/08 12:58:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14252026/10/08 12:58:22 WARN mTLS auth: bound subjects configured but subject DN unavailable14262026/10/08 12:58:22 INFO Vacuumed table table=pending_closures14272026/10/08 12:58:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1428=== NAME TestClientCADerivations1429 client_ca_test.go:136: Built CA derivation: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientCADerivations2880629854/001/store/f11z4088iija3dpr18qxvwmcy1k4mnr5-ca-test1430--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (10.25s)1431=== CONT TestIsValidCachePath1432=== RUN TestIsValidCachePath/narinfo1433=== PAUSE TestIsValidCachePath/narinfo1434=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1435=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1436=== RUN TestIsValidCachePath/nar_zst1437=== PAUSE TestIsValidCachePath/nar_zst1438=== RUN TestIsValidCachePath/nar_xz1439=== PAUSE TestIsValidCachePath/nar_xz1440=== RUN TestIsValidCachePath/nar_bz21441=== PAUSE TestIsValidCachePath/nar_bz21442=== RUN TestIsValidCachePath/nar_uncompressed1443=== PAUSE TestIsValidCachePath/nar_uncompressed1444=== RUN TestIsValidCachePath/ls1445=== PAUSE TestIsValidCachePath/ls1446=== RUN TestIsValidCachePath/log1447=== PAUSE TestIsValidCachePath/log1448=== RUN TestIsValidCachePath/realisation1449=== PAUSE TestIsValidCachePath/realisation1450=== RUN TestIsValidCachePath/nix-cache-info1451=== PAUSE TestIsValidCachePath/nix-cache-info1452=== RUN TestIsValidCachePath/index.html1453=== PAUSE TestIsValidCachePath/index.html1454=== RUN TestIsValidCachePath/traversal_parent1455=== PAUSE TestIsValidCachePath/traversal_parent1456=== RUN TestIsValidCachePath/traversal_in_middle1457=== PAUSE TestIsValidCachePath/traversal_in_middle1458=== RUN TestIsValidCachePath/invalid_char_e1459=== PAUSE TestIsValidCachePath/invalid_char_e1460=== RUN TestIsValidCachePath/invalid_char_u14612026/10/08 12:58:22 INFO Vacuumed table table=pending_objects1462=== PAUSE TestIsValidCachePath/invalid_char_u1463=== RUN TestIsValidCachePath/random_path1464=== PAUSE TestIsValidCachePath/random_path1465=== RUN TestIsValidCachePath/empty1466=== PAUSE TestIsValidCachePath/empty1467=== RUN TestIsValidCachePath/leading_slash1468=== PAUSE TestIsValidCachePath/leading_slash1469=== RUN TestIsValidCachePath/wrong_extension1470=== PAUSE TestIsValidCachePath/wrong_extension14712026/10/08 12:58:22 INFO Vacuumed table table=multipart_uploads1472=== RUN TestIsValidCachePath/short_hash1473=== PAUSE TestIsValidCachePath/short_hash1474=== CONT TestParseSingleRange1475=== RUN TestParseSingleRange/none1476=== PAUSE TestParseSingleRange/none1477=== RUN TestParseSingleRange/unknown_unit1478=== NAME TestClientCADerivations1479 client_ca_test.go:139: Found 1 dependencies (including self)1480=== PAUSE TestParseSingleRange/unknown_unit1481=== RUN TestParseSingleRange/multi-range_ignored1482=== PAUSE TestParseSingleRange/multi-range_ignored1483=== RUN TestParseSingleRange/malformed_no_dash1484=== PAUSE TestParseSingleRange/malformed_no_dash1485=== RUN TestParseSingleRange/malformed_both_empty1486=== PAUSE TestParseSingleRange/malformed_both_empty1487=== RUN TestParseSingleRange/malformed_end_before_start1488=== PAUSE TestParseSingleRange/malformed_end_before_start1489=== RUN TestParseSingleRange/closed1490=== PAUSE TestParseSingleRange/closed1491=== RUN TestParseSingleRange/open-ended1492=== PAUSE TestParseSingleRange/open-ended1493=== RUN TestParseSingleRange/end_clamped_to_size1494=== PAUSE TestParseSingleRange/end_clamped_to_size1495=== RUN TestParseSingleRange/suffix1496=== PAUSE TestParseSingleRange/suffix1497=== RUN TestParseSingleRange/suffix_exceeds_size1498=== PAUSE TestParseSingleRange/suffix_exceeds_size1499=== RUN TestParseSingleRange/single_byte1500=== PAUSE TestParseSingleRange/single_byte1501=== RUN TestParseSingleRange/start_past_EOF1502=== PAUSE TestParseSingleRange/start_past_EOF1503=== RUN TestParseSingleRange/start_far_past_EOF1504=== PAUSE TestParseSingleRange/start_far_past_EOF1505=== CONT TestSweepRechecksPendingAfterLocking15062026/10/08 12:58:22 INFO Vacuumed table table=closures15072026/10/08 12:58:22 INFO Vacuumed table table=objects15082026/10/08 12:58:22 INFO Received push request method=POST path=/api/pushes15092026/10/08 12:58:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15102026/10/08 12:58:23 INFO Uploading f11z4088iija3dpr18qxvwmcy1k4mnr5-ca-test (144B)15112026/10/08 12:58:23 WARN Failed to register uploaded object key=f11z4088iija3dpr18qxvwmcy1k4mnr5.ls error="server returned 404: 404 page not found\n"15122026/10/08 12:58:23 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15132026/10/08 12:58:23 WARN Failed to register uploaded object key=log/1k94hdx2g6mk4nmiqdcibhm98y31zmp5-ca-test.drv error="server returned 404: 404 page not found\n"1514--- PASS: TestService_ReadAuthMiddleware (10.12s)1515=== CONT TestPushWaitsForSweepHoldingRow15162026/10/08 12:58:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15172026/10/08 12:58:23 INFO Signed narinfos id=1 count=115182026/10/08 12:58:23 INFO Uploading 1 narinfos15192026/10/08 12:58:23 WARN Failed to register uploaded object key=f11z4088iija3dpr18qxvwmcy1k4mnr5.narinfo error="server returned 404: 404 page not found\n"15202026/10/08 12:58:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15212026/10/08 12:58:23 INFO Completed push id=1 objects=4 duration=68.603417ms15222026/10/08 12:58:23 INFO Upload complete. (509ms)1523=== NAME TestClientCADerivations1524 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientCADerivations2880629854/001/store/f11z4088iija3dpr18qxvwmcy1k4mnr5-ca-test1525 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1526 Compression: zstd1527 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1528 NarSize: 1441529 References: 1530 Deriver: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientCADerivations2880629854/001/store/1k94hdx2g6mk4nmiqdcibhm98y31zmp5-ca-test.drv1531 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1532 client_ca_test.go:185: Checking for realisation files in S3...1533 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1534 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1535 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket50?endpoint=http://localhost:52047®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestClientCADerivations2880629854/001/store'1536 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11537--- PASS: TestService_ReadScope_PublicByDefault (10.35s)1538=== CONT TestGetExistingObjectsLocksRows1539--- PASS: TestClientCADerivations (14.03s)1540=== CONT TestObjectStatsTrigger15412026/10/08 12:58:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01542=== NAME TestClientIntegration1543 client_integration_test.go:323: Objects in database after GC:1544 client_integration_test.go:323: Successfully deleted all objects with GC --force1545--- PASS: TestClientIntegration (15.23s)1546=== CONT TestPresentRefreshesOnlyStaleClosures1547--- PASS: TestDeleteClosuresRacingPins (17.44s)1548=== CONT TestPresentReportsOnlyClosureRoots15492026/10/08 12:58:24 WARN readiness check failed error="closed pool"1550--- PASS: TestService_readinessHandler (10.32s)1551=== CONT TestCreatePin_ReservedPins1552=== NAME TestNARDeduplicationMetadataUploadBug1553 metadata_upload_test.go:48: First store path: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestNARDeduplicationMetadataUploadBug3069795433/001/store/iiq30dn2r70y07kh9s8jljrh5b0p32cc-file1.txt15542026/10/08 12:58:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52520/oidc15552026/10/08 12:58:25 INFO Received push request method=POST path=/api/pushes15562026/10/08 12:58:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15572026/10/08 12:58:25 INFO Uploading iiq30dn2r70y07kh9s8jljrh5b0p32cc-file1.txt (160B)15582026/10/08 12:58:25 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15592026/10/08 12:58:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15602026/10/08 12:58:25 WARN Failed to register uploaded object key=iiq30dn2r70y07kh9s8jljrh5b0p32cc.ls error="server returned 404: 404 page not found\n"15612026/10/08 12:58:25 INFO Signed narinfos id=1 count=115622026/10/08 12:58:25 INFO Uploading 1 narinfos15632026/10/08 12:58:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15642026/10/08 12:58:25 WARN Failed to register uploaded object key=iiq30dn2r70y07kh9s8jljrh5b0p32cc.narinfo error="server returned 404: 404 page not found\n"1565--- PASS: TestService_healthCheckHandler (10.78s)1566=== CONT TestOrphanedObjectsGCStressTest15672026/10/08 12:58:25 INFO Completed push id=1 objects=3 duration=102.104667ms15682026/10/08 12:58:25 INFO Upload complete. (462ms)1569=== NAME TestNARDeduplicationMetadataUploadBug1570 metadata_upload_test.go:54: Retrieved narinfo from S3:1571 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestNARDeduplicationMetadataUploadBug3069795433/001/store/iiq30dn2r70y07kh9s8jljrh5b0p32cc-file1.txt1572 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1573 Compression: zstd1574 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1575 NarSize: 1601576 References: 1577 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1578 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1579 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1580 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1581 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestNARDeduplicationMetadataUploadBug3069795433/001/store/qyr4ncs5r4gia1pqc08bmi1zwp6rxhik-file2.txt15822026/10/08 12:58:25 INFO Received push request method=POST path=/api/pushes15832026/10/08 12:58:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15842026/10/08 12:58:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15852026/10/08 12:58:26 WARN Failed to register uploaded object key=qyr4ncs5r4gia1pqc08bmi1zwp6rxhik.ls error="server returned 404: 404 page not found\n"15862026/10/08 12:58:26 INFO Signed narinfos id=2 count=115872026/10/08 12:58:26 INFO Uploading 1 narinfos1588=== RUN TestService_RequireScope_OIDC/builder_may_write1589=== PAUSE TestService_RequireScope_OIDC/builder_may_write1590=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1591=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1592=== RUN TestService_RequireScope_OIDC/ops_may_admin1593=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1594=== RUN TestService_RequireScope_OIDC/ops_may_not_write1595=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1596=== RUN TestService_RequireScope_OIDC/reader_may_not_write1597=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1598=== RUN TestService_RequireScope_OIDC/static_token_may_admin1599=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1600=== RUN TestService_RequireScope_OIDC/static_token_may_write16012026/10/08 12:58:26 INFO Received complete push request method=POST path=/api/pushes/2/complete1602=== PAUSE TestService_RequireScope_OIDC/static_token_may_write16032026/10/08 12:58:26 WARN Failed to register uploaded object key=qyr4ncs5r4gia1pqc08bmi1zwp6rxhik.narinfo error="server returned 404: 404 page not found\n"1604=== RUN TestService_RequireScope_OIDC/reader_may_read16052026/10/08 12:58:26 INFO Completed push id=2 objects=3 duration=4.854833ms1606=== PAUSE TestService_RequireScope_OIDC/reader_may_read1607=== RUN TestService_RequireScope_OIDC/writer_implies_read1608=== PAUSE TestService_RequireScope_OIDC/writer_implies_read16092026/10/08 12:58:26 INFO Upload complete. (329ms)1610=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1611=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1612=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1613=== NAME TestNARDeduplicationMetadataUploadBug1614 metadata_upload_test.go:76: Retrieved narinfo from S3:1615 StorePath: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestNARDeduplicationMetadataUploadBug3069795433/001/store/qyr4ncs5r4gia1pqc08bmi1zwp6rxhik-file2.txt1616 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1617=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1618=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1619=== NAME TestNARDeduplicationMetadataUploadBug1620 Compression: zstd1621 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1622=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1623=== NAME TestNARDeduplicationMetadataUploadBug1624 NarSize: 1601625 References: 1626 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1627=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1628=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1629=== NAME TestNARDeduplicationMetadataUploadBug1630 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1631=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1632=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1633=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1634=== NAME TestNARDeduplicationMetadataUploadBug1635 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1636 {"version":1,"root":{"type":"regular","size":44}}1637--- PASS: TestNARDeduplicationMetadataUploadBug (12.72s)1638=== CONT TestGCTaskStore_GetEmpty1639--- PASS: TestGCTaskStore_GetEmpty (0.00s)1640=== CONT TestGCTaskStore_GetReturnsLatest1641--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1642=== CONT TestOrphanedObjectsGC16432026/10/08 12:58:27 INFO Aborted multipart uploads count=0 kept=016442026/10/08 12:58:27 WARN Force mode enabled - objects will be deleted immediately without grace period16452026/10/08 12:58:27 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=016462026/10/08 12:58:27 INFO Vacuumed table table=pending_closures16472026/10/08 12:58:27 INFO Vacuumed table table=pending_objects16482026/10/08 12:58:27 INFO Vacuumed table table=multipart_uploads16492026/10/08 12:58:27 INFO Vacuumed table table=closures16502026/10/08 12:58:27 INFO Received uploads request method=POST path=/api/pending_closures16512026/10/08 12:58:27 INFO Vacuumed table table=objects1652--- PASS: TestGCSweepDeliversEachKeyOnce (12.47s)1653=== CONT TestMultipartCleanup16542026/10/08 12:58:28 INFO Aborted multipart uploads count=0 kept=016552026/10/08 12:58:28 WARN Force mode enabled - objects will be deleted immediately without grace period16562026/10/08 12:58:28 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=016572026/10/08 12:58:28 INFO Vacuumed table table=pending_closures16582026/10/08 12:58:28 INFO Vacuumed table table=pending_objects16592026/10/08 12:58:28 INFO Vacuumed table table=multipart_uploads16602026/10/08 12:58:28 INFO Vacuumed table table=closures16612026/10/08 12:58:28 INFO Vacuumed table table=objects1662--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (12.28s)1663=== CONT TestPendingCleanupUsesOneCutoff1664--- PASS: TestGCSweepSkipsPendingObjects (12.74s)1665=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1666--- PASS: TestReadProxyDisabled (12.49s)1667=== CONT TestObjectStatsLargeCommit1668--- PASS: TestReadProxyRootRedirectsToIndexHTML (13.12s)1669=== CONT TestGCTaskStore_ConflictDifferentParams1670--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1671=== CONT TestService_NativeMTLS1672--- PASS: TestReadProxyConditionalGet (13.46s)1673=== CONT TestServerTLSConfig1674=== RUN TestServerTLSConfig/no_client_CA1675=== PAUSE TestServerTLSConfig/no_client_CA1676=== RUN TestServerTLSConfig/missing_CA_file1677=== PAUSE TestServerTLSConfig/missing_CA_file1678=== RUN TestServerTLSConfig/not_a_PEM_file1679=== PAUSE TestServerTLSConfig/not_a_PEM_file1680=== CONT TestMetricsCommit1681--- PASS: TestReadProxyHead (14.09s)1682=== CONT TestTombstonedObjectOfferedWithoutWaiting1683--- PASS: TestReadProxyInvalidPath (13.83s)1684=== CONT TestService_AuthMiddleware_OIDC16852026/10/08 12:58:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52586/oidc1686--- PASS: TestReadProxy404 (14.00s)1687=== CONT TestResolveDBConnectionString/flag_wins1688=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1689=== CONT TestResolveDBConnectionString/nothing_configured1690=== CONT TestResolveDBConnectionString/missing_file_is_an_error1691=== CONT TestResolveDBConnectionString/file_when_flag_empty1692=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16932026/10/08 12:58:34 INFO Received uploads request method=POST path=/1694--- PASS: TestResolveDBConnectionString (0.02s)1695 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1696 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1697 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1698 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1699 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1700=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17012026/10/08 12:58:34 INFO Received uploads request method=POST path=/1702=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17032026/10/08 12:58:34 INFO Received request for more parts method=POST path=/1704=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17052026/10/08 12:58:34 INFO Received complete multipart upload request method=POST path=/1706--- PASS: TestReadProxyNarStreaming (13.71s)1707=== CONT TestIsValidUploadKey/narinfo1708=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17092026/10/08 12:58:34 INFO Received request for more parts method=POST path=/1710=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17112026/10/08 12:58:34 INFO Received complete multipart upload request method=POST path=/1712=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17132026/10/08 12:58:34 INFO Received uploads request method=POST path=/1714--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)1715 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.32s)1716 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1717 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1718--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1719 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)1720 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1721 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1722 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1723=== CONT TestPendingClosureWriteTimeout/empty1724=== CONT TestIsValidUploadKey/unknown_type1725=== CONT TestIsValidUploadKey/absolute1726=== CONT TestIsValidUploadKey/empty_key1727=== CONT TestIsValidUploadKey/traversal1728=== CONT TestIsValidUploadKey/traversal_nar1729=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1730=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1731=== CONT TestIsValidUploadKey/index.html1732=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1733=== CONT TestIsValidUploadKey/realisation_plus_in_output1734=== CONT TestIsValidUploadKey/realisation1735=== CONT TestIsValidUploadKey/nix-cache-info1736=== CONT TestIsValidUploadKey/build_log_question_mark1737=== CONT TestIsValidUploadKey/build_log_equals1738=== CONT TestIsValidUploadKey/build_log_home-manager_file1739=== CONT TestIsValidUploadKey/build_log_plus_in_name1740=== CONT TestIsValidUploadKey/listing1741=== CONT TestIsValidUploadKey/build_log1742=== CONT TestIsValidUploadKey/nar_xz1743=== CONT TestIsValidUploadKey/nar_plain1744=== CONT TestProxyWriteTimeout/narinfo1745=== CONT TestIsValidUploadKey/nar_zst1746=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1747=== CONT TestPendingClosureWriteTimeout/670k_objects1748--- PASS: TestIsValidUploadKey (0.00s)1749 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1750 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1751 --- PASS: TestIsValidUploadKey/absolute (0.00s)1752 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1753 --- PASS: TestIsValidUploadKey/traversal (0.00s)1754 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1755 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1756 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1757 --- PASS: TestIsValidUploadKey/index.html (0.00s)1758 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1759 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1760 --- PASS: TestIsValidUploadKey/realisation (0.00s)1761 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1762 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1763 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1764 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1765 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1766 --- PASS: TestIsValidUploadKey/listing (0.00s)1767 --- PASS: TestIsValidUploadKey/build_log (0.00s)1768 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1769 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1770 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1771=== CONT TestPendingClosureWriteTimeout/400_objects1772=== CONT TestProxyWriteTimeout/10_GiB_nar1773=== CONT TestProxyWriteTimeout/unknown_size1774=== CONT TestProxyWriteTimeout/1_GiB_nar1775--- PASS: TestProxyWriteTimeout (0.00s)1776 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1777 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1778 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1779 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1780=== CONT TestGCEndsOnShutdown/before_the_run1781--- PASS: TestReadProxyContentNegotiation (14.33s)1782=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1783--- PASS: TestReadProxyOutlastsServerWriteTimeout (17.64s)1784=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1785--- PASS: TestReadProxyNarinfoAlreadyDecompressed (14.43s)1786=== CONT TestCacheConfigHandler/full_config,_no_issuer1787=== CONT TestCacheConfigHandler/no_signing_keys1788=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1789=== CONT TestCacheConfigHandler/no_cache_url_configured1790--- PASS: TestCacheConfigHandler (0.01s)1791 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1792 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1793 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1794 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1795=== CONT TestClientErrorHandling/InvalidStorePath17962026/10/08 12:58:37 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1797--- PASS: TestReadProxyNarinfo (14.96s)1798=== CONT TestClientErrorHandling/ServerNotAvailable17992026/10/08 12:58:38 INFO Aborted multipart uploads count=0 kept=018002026/10/08 12:58:38 WARN Force mode enabled - objects will be deleted immediately without grace period18012026/10/08 12:58:38 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=018022026/10/08 12:58:38 INFO Vacuumed table table=pending_closures18032026/10/08 12:58:38 INFO Vacuumed table table=pending_objects18042026/10/08 12:58:38 INFO Vacuumed table table=multipart_uploads18052026/10/08 12:58:38 INFO Vacuumed table table=closures18062026/10/08 12:58:38 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/present18072026/10/08 12:58:38 INFO Vacuumed table table=objects1808--- PASS: TestSweepRechecksPendingAfterLocking (15.70s)1809=== CONT TestClientErrorHandling/InvalidAuthToken18102026/10/08 12:58:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.421913ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18112026/10/08 12:58:38 INFO Received uploads request method=POST path=/api/pending_closures18122026/10/08 12:58:38 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=410.140852ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1813--- PASS: TestPushWaitsForSweepHoldingRow (16.02s)1814=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18152026/10/08 12:58:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=838.864374ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1816--- PASS: TestGetExistingObjectsLocksRows (15.72s)1817=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18182026/10/08 12:58:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.751867093s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1819--- PASS: TestObjectStatsTrigger (16.37s)1820=== CONT TestPush_RejectsBadRequests/no_roots18212026/10/08 12:58:40 INFO Received push request method=POST path=/api/pushes1822=== CONT TestPush_RejectsBadRequests/bad_root18232026/10/08 12:58:40 INFO Received push request method=POST path=/api/pushes1824=== CONT TestPush_RejectsBadRequests/root_not_in_objects18252026/10/08 12:58:40 INFO Received push request method=POST path=/api/pushes1826=== CONT TestPush_RejectsBadRequests/no_objects18272026/10/08 12:58:40 INFO Received push request method=POST path=/api/pushes1828=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1829--- PASS: TestPush_RejectsBadRequests (9.61s)1830 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1831 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1832 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1833 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)1834--- PASS: TestPresentReportsOnlyClosureRoots (15.82s)1835=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18362026/10/08 12:58:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18372026/10/08 12:58:41 WARN Refused reserved pin name=worker-x86_64-linux18382026/10/08 12:58:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18392026/10/08 12:58:41 INFO Received create pin request method=POST path=/api/pins/my-app18402026/10/08 12:58:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1841--- PASS: TestCreatePin_ReservedPins (16.36s)1842=== CONT TestIsValidCachePath/narinfo1843=== CONT TestIsValidCachePath/index.html1844=== CONT TestIsValidCachePath/short_hash1845=== CONT TestIsValidCachePath/wrong_extension1846=== CONT TestIsValidCachePath/leading_slash1847=== CONT TestIsValidCachePath/empty1848=== CONT TestIsValidCachePath/random_path1849=== CONT TestIsValidCachePath/invalid_char_u1850=== CONT TestIsValidCachePath/invalid_char_e1851=== CONT TestIsValidCachePath/traversal_in_middle1852=== CONT TestIsValidCachePath/traversal_parent1853=== CONT TestIsValidCachePath/nar_xz1854=== CONT TestIsValidCachePath/nar_bz21855=== CONT TestIsValidCachePath/realisation1856=== CONT TestIsValidCachePath/nix-cache-info1857=== CONT TestIsValidCachePath/nar_uncompressed1858=== CONT TestIsValidCachePath/log1859=== CONT TestIsValidCachePath/ls1860=== CONT TestIsValidCachePath/nar_zst1861=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1862--- PASS: TestIsValidCachePath (0.12s)1863 --- PASS: TestIsValidCachePath/narinfo (0.00s)1864 --- PASS: TestIsValidCachePath/index.html (0.00s)1865 --- PASS: TestIsValidCachePath/short_hash (0.00s)1866 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1867 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1868 --- PASS: TestIsValidCachePath/empty (0.00s)1869 --- PASS: TestIsValidCachePath/random_path (0.00s)1870 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1871 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1872 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1873 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1874 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1875 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1876 --- PASS: TestIsValidCachePath/realisation (0.00s)1877 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1878 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1879 --- PASS: TestIsValidCachePath/log (0.00s)1880 --- PASS: TestIsValidCachePath/ls (0.00s)1881 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1882 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1883=== CONT TestParseSingleRange/none1884=== CONT TestParseSingleRange/open-ended1885=== CONT TestParseSingleRange/start_far_past_EOF1886=== CONT TestParseSingleRange/start_past_EOF1887=== CONT TestParseSingleRange/single_byte1888=== CONT TestParseSingleRange/suffix_exceeds_size1889=== CONT TestParseSingleRange/suffix1890=== CONT TestParseSingleRange/end_clamped_to_size1891=== CONT TestParseSingleRange/malformed_both_empty1892=== CONT TestParseSingleRange/closed1893=== CONT TestParseSingleRange/malformed_end_before_start1894=== CONT TestParseSingleRange/multi-range_ignored1895=== CONT TestParseSingleRange/malformed_no_dash1896=== CONT TestParseSingleRange/unknown_unit1897--- PASS: TestParseSingleRange (0.07s)1898 --- PASS: TestParseSingleRange/none (0.00s)1899 --- PASS: TestParseSingleRange/open-ended (0.00s)1900 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1901 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1902 --- PASS: TestParseSingleRange/single_byte (0.00s)1903 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1904 --- PASS: TestParseSingleRange/suffix (0.00s)1905 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1906 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1907 --- PASS: TestParseSingleRange/closed (0.00s)1908 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1909 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1910 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1911 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1912=== CONT TestService_RequireScope_OIDC/builder_may_write1913=== CONT TestService_RequireScope_OIDC/reader_may_read1914=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1915=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19162026/10/08 12:58:41 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]1917=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1918=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1919=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1920=== CONT TestService_RequireScope_OIDC/writer_implies_read1921=== CONT TestService_RequireScope_OIDC/ops_may_not_write1922=== CONT TestService_RequireScope_OIDC/static_token_may_write1923=== CONT TestService_RequireScope_OIDC/static_token_may_admin1924=== CONT TestService_RequireScope_OIDC/reader_may_not_write1925=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1926=== CONT TestService_RequireScope_OIDC/ops_may_admin1927=== CONT TestServerTLSConfig/no_client_CA1928=== CONT TestServerTLSConfig/not_a_PEM_file1929--- PASS: TestService_RequireScope_OIDC (11.53s)1930 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.01s)1934 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1944=== CONT TestServerTLSConfig/missing_CA_file1945--- PASS: TestServerTLSConfig (0.06s)1946 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1947 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.16s)1948 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)19492026/10/08 12:58:41 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-config19502026/10/08 12:58:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.382621ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1951--- PASS: TestPresentRefreshesOnlyStaleClosures (17.57s)19522026/10/08 12:58:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.303874ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19532026/10/08 12:58:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.184877ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19542026/10/08 12:58:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.593015603s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19552026/10/08 12:58:43 INFO Received uploads request method=POST path=/api/pending_closures1956--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (17.75s)19572026/10/08 12:58:44 INFO Received uploads request method=POST path=/api/pending_closures19582026/10/08 12:58:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"19592026/10/08 12:58:45 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-config19602026/10/08 12:58:45 INFO Received cleanup request method=DELETE path=/api/pending_closures19612026/10/08 12:58:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket83/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""19622026/10/08 12:58:45 INFO Aborted multipart uploads count=0 kept=119632026/10/08 12:58:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=211.698132ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19642026/10/08 12:58:45 INFO Received cleanup request method=DELETE path=/api/pending_closures19652026/10/08 12:58:45 INFO Aborted multipart uploads count=1 kept=01966--- PASS: TestMultipartCleanup (17.47s)19672026/10/08 12:58:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=423.710667ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19682026/10/08 12:58:45 INFO Received uploads request method=POST path=/api/pending_closures19692026/10/08 12:58:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=762.225072ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1970--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (17.40s)1971=== NAME TestOrphanedObjectsGC1972 orphaned_objects_gc_test.go:287: GC Test Summary:1973 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1974 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1975 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1976 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1977 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1978--- PASS: TestOrphanedObjectsGC (19.73s)19792026/10/08 12:58:46 INFO Received uploads request method=POST path=/api/pending_closures19802026/10/08 12:58:46 INFO Received uploads request method=POST path=/api/pending_closures19812026/10/08 12:58:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.579365542s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19822026/10/08 12:58:46 INFO Received cleanup request method=DELETE path=/api/pending_closures19832026/10/08 12:58:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"19842026/10/08 12:58:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1985--- PASS: TestService_NativeMTLS (17.56s)19862026/10/08 12:58:48 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_closures19872026/10/08 12:58:48 INFO Received push request method=POST path=/api/pushes19882026/10/08 12:58:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.461438ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19892026/10/08 12:58:48 INFO Received complete push request method=POST path=/api/pushes/1/complete19902026/10/08 12:58:48 INFO Completed push id=1 objects=4 duration=36.881709ms19912026/10/08 12:58:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19922026/10/08 12:58:48 INFO Completed upload id=2 objects=2 duration=1.971083ms1993--- PASS: TestMetricsCommit (17.46s)19942026/10/08 12:58:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=384.241981ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19952026/10/08 12:58:48 INFO Received uploads request method=POST path=/api/pending_closures1996--- PASS: TestTombstonedObjectOfferedWithoutWaiting (16.29s)19972026/10/08 12:58:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.70434ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1998=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1999=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2000=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2001=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2002=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2003=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2004=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2005=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2006=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2007=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2008=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20092026/10/08 12:58:49 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]2010=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20112026/10/08 12:58:49 WARN Authentication failed token_preview=eyJhbGciOi...qkL8s3axvA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2012--- PASS: TestService_AuthMiddleware_OIDC (16.14s)2013 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2014 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2015 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2016 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20172026/10/08 12:58:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505074065s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20182026/10/08 12:58:50 INFO Received uploads request method=POST path=/api/pending_closures2019--- PASS: TestPendingClosureWriteTimeout (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2021 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2022 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2023 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (16.50s)20242026/10/08 12:58:51 INFO Aborted multipart uploads count=0 kept=020252026/10/08 12:58:51 WARN Force mode enabled - objects will be deleted immediately without grace period20262026/10/08 12:58:51 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52047/bucket93/?delete=\": context canceled"20272026/10/08 12:58:51 INFO Aborted multipart uploads count=0 kept=020282026/10/08 12:58:51 WARN Force mode enabled - objects will be deleted immediately without grace period20292026-10-08 12:58:51.822 UTC [44693] ERROR: canceling statement due to user request20302026-10-08 12:58:51.822 UTC [44693] STATEMENT: -- name: MarkStaleObjects :execrows2031 WITH RECURSIVE ct AS (2032 SELECT timezone('UTC', now()) AS now2033 ),2034 closure_reach AS (2035 -- Start with all closure keys2036 SELECT o.key, o.refs2037 FROM objects o2038 INNER JOIN closures c ON o.key = c.key2039 UNION2040 -- Recursively add all referenced objects2041 SELECT o.key, o.refs2042 FROM objects o2043 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2044 ),2045 reachable_objects AS (2046 SELECT DISTINCT key FROM closure_reach2047 ),2048 stale_objects AS (2049 SELECT o.key2050 FROM objects AS o, ct2051 WHERE2052 NOT EXISTS (2053 SELECT 12054 FROM reachable_objects ro2055 WHERE ro.key = o.key2056 )2057 AND NOT EXISTS (2058 SELECT 12059 FROM pending_objects AS po2060 WHERE po.key = o.key2061 )2062 AND o.deleted_at IS NULL -- Only mark fresh objects2063 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2064 FOR UPDATE2065 )2066 UPDATE objects2067 SET2068 deleted_at = ct.now,2069 first_deleted_at = COALESCE(first_deleted_at, ct.now)2070 FROM stale_objects, ct2071 WHERE objects.key = stale_objects.key2072 2073--- PASS: TestGCEndsOnShutdown (0.00s)2074 --- PASS: TestGCEndsOnShutdown/before_the_run (15.15s)2075 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (15.32s)2076 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (16.22s)20772026/10/08 12:58:52 INFO Aborted multipart uploads count=1 kept=020782026/10/08 12:58:52 INFO Received cleanup request method=DELETE path=/api/pending_closures20792026/10/08 12:58:52 INFO Aborted multipart uploads count=1 kept=02080--- PASS: TestPendingCleanupUsesOneCutoff (24.36s)20812026/10/08 12:58:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20822026/10/08 12:58:53 INFO Received uploads request method=POST path=/api/pending_closures20832026/10/08 12:58:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20842026/10/08 12:58:53 INFO Aborted multipart uploads count=0 kept=020852026/10/08 12:58:53 WARN Force mode enabled - objects will be deleted immediately without grace period20862026/10/08 12:58:53 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=020872026/10/08 12:58:53 INFO Vacuumed table table=pending_closures20882026/10/08 12:58:53 INFO Vacuumed table table=pending_objects20892026/10/08 12:58:53 INFO Vacuumed table table=multipart_uploads20902026/10/08 12:58:53 INFO Vacuumed table table=closures20912026/10/08 12:58:53 INFO Vacuumed table table=objects2092--- PASS: TestClientErrorHandling (0.01s)2093 --- PASS: TestClientErrorHandling/ServerNotAvailable (14.18s)2094 --- PASS: TestClientErrorHandling/InvalidStorePath (16.07s)2095 --- PASS: TestClientErrorHandling/InvalidAuthToken (14.70s)20962026/10/08 12:58:53 INFO Received uploads request method=POST path=/api/pending_closures20972026/10/08 12:58:53 INFO Aborted multipart uploads count=0 kept=020982026/10/08 12:58:53 WARN Force mode enabled - objects will be deleted immediately without grace period20992026/10/08 12:58:53 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=021002026/10/08 12:58:53 INFO Vacuumed table table=pending_closures21012026/10/08 12:58:53 INFO Vacuumed table table=pending_objects21022026/10/08 12:58:53 INFO Vacuumed table table=multipart_uploads21032026/10/08 12:58:53 INFO Vacuumed table table=closures21042026/10/08 12:58:53 INFO Vacuumed table table=objects2105--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2106 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (13.89s)2107 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (14.86s)2108--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2109 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (14.40s)2110 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (14.61s)2111=== NAME TestOrphanedObjectsGCStressTest2112 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2113 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21142026-10-08 12:58:56.700 UTC [42668] LOG: checkpoint starting: wal2115--- PASS: TestObjectStatsLargeCommit (27.87s)2116=== NAME TestOrphanedObjectsGCStressTest2117 orphaned_objects_gc_test.go:503: Stress test completed successfully:2118 orphaned_objects_gc_test.go:504: - Active objects preserved: 202119 orphaned_objects_gc_test.go:505: - Objects deleted: 2102120 orphaned_objects_gc_test.go:506: - Total GC'd: 2102121--- PASS: TestOrphanedObjectsGCStressTest (32.28s)2122PASS2123{"timestamp":"2026-10-08T12:58:57.747035Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52361","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(7)"}21242026-10-08 12:59:01.329 UTC [42660] LOG: received smart shutdown request21252026-10-08 12:59:01.341 UTC [42660] LOG: background worker "logical replication launcher" (PID 42674) exited with exit code 121262026/10/08 12:59:11 INFO killed process group pgid=4266021272026/10/08 12:59:11 ERROR failed to wait for process error="signal: killed"21282026-10-08 12:59:11.626 UTC [42668] PANIC: could not fsync file "pg_multixact/members/0000": No such file or directory2129Running OIDC tests...2130=== RUN TestAudienceForIssuer2131=== PAUSE TestAudienceForIssuer2132=== RUN TestGlobMatch2133=== PAUSE TestGlobMatch2134=== RUN TestValidateToken_ValidToken2135=== PAUSE TestValidateToken_ValidToken2136=== RUN TestValidateToken_WrongAudience2137=== PAUSE TestValidateToken_WrongAudience2138=== RUN TestValidateToken_Expired2139=== PAUSE TestValidateToken_Expired2140=== RUN TestValidateToken_BoundClaimsMismatch2141=== PAUSE TestValidateToken_BoundClaimsMismatch2142=== RUN TestValidateToken_BoundSubjectMismatch2143=== PAUSE TestValidateToken_BoundSubjectMismatch2144=== RUN TestValidateToken_MultipleProviders2145=== PAUSE TestValidateToken_MultipleProviders2146=== RUN TestValidateToken_NoMatchingProvider2147=== PAUSE TestValidateToken_NoMatchingProvider2148=== RUN TestValidateToken_KubernetesServiceAccount2149=== PAUSE TestValidateToken_KubernetesServiceAccount2150=== RUN TestNewValidator_KubernetesRequiresCA2151=== PAUSE TestNewValidator_KubernetesRequiresCA2152=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2153=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2154=== RUN TestPins_ReservedForMatchingRule2155=== PAUSE TestPins_ReservedForMatchingRule2156=== RUN TestPins_TopLevelShorthand2157=== PAUSE TestPins_TopLevelShorthand2158=== RUN TestPins_ConfigValidation2159=== PAUSE TestPins_ConfigValidation2160=== RUN TestScopes_LegacyProviderDefaultsToWrite2161=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2162=== RUN TestScopes_Rules2163=== PAUSE TestScopes_Rules2164=== RUN TestScopes_ConfigValidation2165=== PAUSE TestScopes_ConfigValidation2166=== CONT TestAudienceForIssuer2167--- PASS: TestAudienceForIssuer (0.00s)2168=== CONT TestValidateToken_NoMatchingProvider2169=== CONT TestValidateToken_Expired2170=== CONT TestPins_ConfigValidation2171=== CONT TestPins_TopLevelShorthand2172=== CONT TestPins_ReservedForMatchingRule2173=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2174--- PASS: TestPins_ConfigValidation (0.00s)2175=== CONT TestNewValidator_KubernetesRequiresCA2176=== CONT TestScopes_ConfigValidation2177=== CONT TestScopes_LegacyProviderDefaultsToWrite2178--- PASS: TestScopes_ConfigValidation (0.00s)2179=== CONT TestValidateToken_ValidToken2180=== CONT TestValidateToken_WrongAudience2181=== CONT TestGlobMatch2182=== RUN TestGlobMatch/foo_foo2183=== PAUSE TestGlobMatch/foo_foo2184=== RUN TestGlobMatch/foo_bar2185=== PAUSE TestGlobMatch/foo_bar2186=== RUN TestGlobMatch/*_2187=== PAUSE TestGlobMatch/*_2188=== RUN TestGlobMatch/*_anything2189=== PAUSE TestGlobMatch/*_anything2190=== RUN TestGlobMatch/foo*_foo2191=== PAUSE TestGlobMatch/foo*_foo2192=== RUN TestGlobMatch/foo*_foobar2193=== PAUSE TestGlobMatch/foo*_foobar2194=== RUN TestGlobMatch/foo*_bar2195=== PAUSE TestGlobMatch/foo*_bar2196=== RUN TestGlobMatch/*bar_bar2197=== PAUSE TestGlobMatch/*bar_bar2198=== RUN TestGlobMatch/*bar_foobar2199=== PAUSE TestGlobMatch/*bar_foobar2200=== RUN TestGlobMatch/*bar_foo2201=== PAUSE TestGlobMatch/*bar_foo2202=== RUN TestGlobMatch/foo*bar_foobar2203=== PAUSE TestGlobMatch/foo*bar_foobar2204=== RUN TestGlobMatch/foo*bar_foo123bar2205=== PAUSE TestGlobMatch/foo*bar_foo123bar2206=== RUN TestGlobMatch/foo*bar_foobarbaz2207=== PAUSE TestGlobMatch/foo*bar_foobarbaz2208=== RUN TestGlobMatch/*/*_foo/bar2209=== PAUSE TestGlobMatch/*/*_foo/bar2210=== RUN TestGlobMatch/*/*_foo2211=== PAUSE TestGlobMatch/*/*_foo2212=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2213=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2214=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02215=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02216=== RUN TestGlobMatch/refs/*/main_refs/heads/main2217=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2218=== RUN TestGlobMatch/fo?_foo2219=== PAUSE TestGlobMatch/fo?_foo2220=== RUN TestGlobMatch/fo?_fo2221=== PAUSE TestGlobMatch/fo?_fo2222=== RUN TestGlobMatch/fo?_fooo2223=== PAUSE TestGlobMatch/fo?_fooo2224=== RUN TestGlobMatch/?oo_foo2225=== PAUSE TestGlobMatch/?oo_foo2226=== RUN TestGlobMatch/?oo_boo2227=== PAUSE TestGlobMatch/?oo_boo2228=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2229=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2230=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2231=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2232=== CONT TestGlobMatch/foo_foo2233=== CONT TestValidateToken_BoundSubjectMismatch2234=== CONT TestGlobMatch/*/*_foo/bar2235=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2236=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2237=== CONT TestGlobMatch/?oo_boo2238=== CONT TestGlobMatch/?oo_foo2239=== CONT TestGlobMatch/fo?_fooo2240=== CONT TestGlobMatch/fo?_fo2241=== CONT TestGlobMatch/fo?_foo2242=== CONT TestGlobMatch/refs/*/main_refs/heads/main2243=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02244=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2245=== CONT TestGlobMatch/*/*_foo2246=== CONT TestGlobMatch/*bar_bar2247=== CONT TestGlobMatch/foo*bar_foobarbaz2248=== CONT TestGlobMatch/foo*bar_foo123bar2249=== CONT TestGlobMatch/foo*bar_foobar2250=== CONT TestGlobMatch/*bar_foo2251=== CONT TestGlobMatch/*bar_foobar2252=== CONT TestGlobMatch/foo*_foo2253=== CONT TestGlobMatch/foo*_bar2254=== CONT TestGlobMatch/foo*_foobar2255=== CONT TestGlobMatch/*_2256=== CONT TestGlobMatch/*_anything2257=== CONT TestGlobMatch/foo_bar2258--- PASS: TestGlobMatch (0.00s)2259 --- PASS: TestGlobMatch/foo_foo (0.00s)2260 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2261 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2262 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2263 --- PASS: TestGlobMatch/?oo_boo (0.00s)2264 --- PASS: TestGlobMatch/?oo_foo (0.00s)2265 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2266 --- PASS: TestGlobMatch/fo?_fo (0.00s)2267 --- PASS: TestGlobMatch/fo?_foo (0.00s)2268 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2269 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2270 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2271 --- PASS: TestGlobMatch/*/*_foo (0.00s)2272 --- PASS: TestGlobMatch/*bar_bar (0.00s)2273 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2274 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2275 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2276 --- PASS: TestGlobMatch/*bar_foo (0.00s)2277 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2278 --- PASS: TestGlobMatch/foo*_foo (0.00s)2279 --- PASS: TestGlobMatch/foo*_bar (0.00s)2280 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2281 --- PASS: TestGlobMatch/*_ (0.00s)2282 --- PASS: TestGlobMatch/*_anything (0.00s)2283 --- PASS: TestGlobMatch/foo_bar (0.00s)2284=== CONT TestValidateToken_MultipleProviders2285=== CONT TestValidateToken_BoundClaimsMismatch2286=== CONT TestValidateToken_KubernetesServiceAccount2287=== CONT TestScopes_Rules22882026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53296/oidc22892026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53298/oidc2290--- PASS: TestValidateToken_ValidToken (0.07s)22912026/10/08 12:59:22 http: TLS handshake error from 127.0.0.1:53303: read tcp 127.0.0.1:53302->127.0.0.1:53303: use of closed network connection2292--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)2293--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)22942026/10/08 12:59:22 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322952026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53299/oidc22962026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53307/oidc22972026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53306/oidc2298--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)2299--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)23002026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53315/oidc23012026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53312/oidc23022026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53309/oidc2303--- PASS: TestValidateToken_Expired (0.13s)23042026/10/08 12:59:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53317/oidc2305--- PASS: TestPins_TopLevelShorthand (0.15s)2306--- PASS: TestScopes_Rules (0.11s)2307--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)2308--- PASS: TestPins_ReservedForMatchingRule (0.15s)2309--- PASS: TestValidateToken_WrongAudience (0.14s)23102026/10/08 12:59:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53310/oidc2311--- PASS: TestValidateToken_NoMatchingProvider (0.17s)23122026/10/08 12:59:22 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5332223132026/10/08 12:59:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53323/oidc23142026/10/08 12:59:22 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:53324/oidc2315--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)2316--- PASS: TestValidateToken_MultipleProviders (0.17s)2317PASS2318Running hook tests...2319=== RUN TestSendPathsEmpty2320=== PAUSE TestSendPathsEmpty2321=== RUN TestQueueEnqueueAndFetch2322=== PAUSE TestQueueEnqueueAndFetch2323=== RUN TestQueueDeduplication2324=== PAUSE TestQueueDeduplication2325=== RUN TestQueueRemove2326=== PAUSE TestQueueRemove2327=== RUN TestQueueFetchBatchLimit2328=== PAUSE TestQueueFetchBatchLimit2329=== RUN TestQueueRetryMovesToBack2330=== PAUSE TestQueueRetryMovesToBack2331=== RUN TestQueueFetchRemoveLifecycle2332=== PAUSE TestQueueFetchRemoveLifecycle2333=== RUN TestQueueConcurrentWriters2334=== PAUSE TestQueueConcurrentWriters2335=== RUN TestQueueRemoveLargeClosure2336=== PAUSE TestQueueRemoveLargeClosure2337=== RUN TestServerClientIntegration2338--- PASS: TestServerClientIntegration (0.03s)2339=== RUN TestServerQueueError23402026/10/08 12:59:23 ERROR Failed to queue paths error="permission denied" count=12341--- PASS: TestServerQueueError (0.03s)2342=== RUN TestGetListenerSocketActivation2343 server_test.go:146: systemd socket activation does not exist on darwin2344--- SKIP: TestGetListenerSocketActivation (0.00s)2345=== RUN TestDrainIsolatesPoisonPath2346=== PAUSE TestDrainIsolatesPoisonPath2347=== RUN TestRunNotBlockedByPoisonHead2348=== PAUSE TestRunNotBlockedByPoisonHead2349=== RUN TestDrainGivesUpWhenServerDown2350=== PAUSE TestDrainGivesUpWhenServerDown2351=== RUN TestFailedPathPrunedByLaterClosure2352=== PAUSE TestFailedPathPrunedByLaterClosure2353=== RUN TestWorkerUploadsAndRemoves2354=== PAUSE TestWorkerUploadsAndRemoves2355=== RUN TestWorkerSkipsGCdPaths2356=== PAUSE TestWorkerSkipsGCdPaths2357=== RUN TestWorkerPrunesClosureDeps2358=== PAUSE TestWorkerPrunesClosureDeps2359=== RUN TestDrainTimeout2360=== PAUSE TestDrainTimeout2361=== CONT TestSendPathsEmpty2362--- PASS: TestSendPathsEmpty (0.00s)2363=== CONT TestDrainIsolatesPoisonPath2364=== CONT TestDrainTimeout2365=== CONT TestWorkerPrunesClosureDeps2366=== CONT TestWorkerSkipsGCdPaths2367=== CONT TestWorkerUploadsAndRemoves2368=== CONT TestFailedPathPrunedByLaterClosure2369=== CONT TestDrainGivesUpWhenServerDown2370=== CONT TestRunNotBlockedByPoisonHead2371=== CONT TestQueueRetryMovesToBack2372=== CONT TestQueueRemoveLargeClosure2373=== CONT TestQueueConcurrentWriters2374=== CONT TestQueueFetchRemoveLifecycle2375=== CONT TestQueueRemove2376=== CONT TestQueueFetchBatchLimit2377=== CONT TestQueueDeduplication2378=== CONT TestQueueEnqueueAndFetch23792026/10/08 12:59:23 INFO Uploading batch count=123802026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=123812026/10/08 12:59:23 INFO Upload queue status pending=223822026/10/08 12:59:23 INFO Uploading batch count=22383--- PASS: TestQueueDeduplication (0.08s)23842026/10/08 12:59:23 INFO Uploading batch count=12385--- PASS: TestQueueEnqueueAndFetch (0.08s)23862026/10/08 12:59:23 INFO Uploading batch count=223872026/10/08 12:59:23 INFO Upload queue status pending=223882026/10/08 12:59:23 INFO Upload queue status pending=223892026/10/08 12:59:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestWorkerSkipsGCdPaths3524553278/002/nonexistent2390--- PASS: TestQueueFetchRemoveLifecycle (0.08s)23912026/10/08 12:59:23 INFO Upload queue status pending=323922026/10/08 12:59:23 INFO Uploading batch count=223932026/10/08 12:59:23 INFO Uploading batch count=123942026/10/08 12:59:23 INFO Uploading batch count=123952026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=123962026/10/08 12:59:23 INFO Uploading batch count=123972026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=223982026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/a2399--- PASS: TestQueueRetryMovesToBack (0.09s)24002026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/b24012026/10/08 12:59:23 INFO Uploading batch count=124022026/10/08 12:59:23 INFO Uploading batch count=224032026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=224042026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/c2405--- PASS: TestQueueRemove (0.09s)24062026/10/08 12:59:23 INFO Uploading batch count=424072026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=424082026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/d24092026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainIsolatesPoisonPath1718021207/002/bbb24102026/10/08 12:59:23 INFO Uploading batch count=224112026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=224122026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/e24132026/10/08 12:59:23 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestDrainGivesUpWhenServerDown2134204640/002/f2414--- PASS: TestQueueFetchBatchLimit (0.09s)24152026/10/08 12:59:23 ERROR Drain finished with paths left in queue remaining=1024162026/10/08 12:59:23 INFO Uploading batch count=124172026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=124182026/10/08 12:59:23 INFO Uploading batch count=124192026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=124202026/10/08 12:59:23 INFO Uploading batch count=124212026/10/08 12:59:23 ERROR Upload failed error="upload failed" count=124222026/10/08 12:59:23 ERROR Drain finished with paths left in queue remaining=12423--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)2424--- PASS: TestDrainGivesUpWhenServerDown (0.10s)2425--- PASS: TestDrainIsolatesPoisonPath (0.11s)2426--- PASS: TestWorkerSkipsGCdPaths (0.12s)2427--- PASS: TestWorkerUploadsAndRemoves (0.13s)2428--- PASS: TestWorkerPrunesClosureDeps (0.13s)2429--- PASS: TestQueueRemoveLargeClosure (0.16s)24302026/10/08 12:59:23 ERROR Upload failed error="context deadline exceeded" count=224312026/10/08 12:59:23 ERROR Drain finished with paths left in queue remaining=42432--- PASS: TestDrainTimeout (0.39s)24332026/10/08 12:59:24 INFO Uploading batch count=124342026/10/08 12:59:24 INFO Uploading batch count=124352026/10/08 12:59:24 INFO Uploading batch count=124362026/10/08 12:59:24 ERROR Upload failed error="upload failed" count=124372026/10/08 12:59:24 INFO Uploading batch count=124382026/10/08 12:59:24 ERROR Upload failed error="upload failed" count=124392026/10/08 12:59:24 INFO Uploading batch count=124402026/10/08 12:59:24 ERROR Upload failed error="upload failed" count=124412026/10/08 12:59:24 INFO Uploading batch count=124422026/10/08 12:59:24 ERROR Upload failed error="upload failed" count=124432026/10/08 12:59:24 ERROR Drain finished with paths left in queue remaining=12444--- PASS: TestRunNotBlockedByPoisonHead (1.14s)2445--- PASS: TestQueueConcurrentWriters (2.17s)2446PASS2447Running signing tests...2448=== RUN TestExternalSigner2449=== PAUSE TestExternalSigner2450=== RUN TestExternalSignerWrongPublicKey2451=== PAUSE TestExternalSignerWrongPublicKey2452=== RUN TestExternalSignerErrors2453=== PAUSE TestExternalSignerErrors2454=== RUN TestExternalSignerRestartsAfterCrash2455=== PAUSE TestExternalSignerRestartsAfterCrash2456=== RUN TestExternalSignerProgramErrorKeepsProcess2457=== PAUSE TestExternalSignerProgramErrorKeepsProcess2458=== RUN TestExternalSignerClose2459=== PAUSE TestExternalSignerClose2460=== RUN TestExternalSignerRejectsInvalidPublicKey2461=== PAUSE TestExternalSignerRejectsInvalidPublicKey2462=== RUN TestExternalSignerCancellation2463=== PAUSE TestExternalSignerCancellation2464=== RUN TestGenerateFingerprint2465=== PAUSE TestGenerateFingerprint2466=== RUN TestParseSigningKey2467=== PAUSE TestParseSigningKey2468=== RUN TestSign2469=== PAUSE TestSign2470=== RUN TestSignBatch2471=== PAUSE TestSignBatch2472=== RUN TestNilKeyPublicKey2473=== PAUSE TestNilKeyPublicKey2474=== RUN TestSignErrors2475=== PAUSE TestSignErrors2476=== CONT TestExternalSigner2477=== CONT TestExternalSignerCancellation2478=== CONT TestExternalSignerProgramErrorKeepsProcess2479=== CONT TestExternalSignerErrors2480=== RUN TestExternalSignerErrors/exit_at_startup2481=== PAUSE TestExternalSignerErrors/exit_at_startup2482=== RUN TestExternalSignerErrors/wrong_shape2483=== CONT TestSignBatch2484=== CONT TestSignErrors2485=== CONT TestNilKeyPublicKey2486--- PASS: TestNilKeyPublicKey (0.00s)2487=== CONT TestExternalSignerWrongPublicKey2488=== CONT TestExternalSignerRestartsAfterCrash2489=== CONT TestParseSigningKey2490=== RUN TestParseSigningKey/valid_32-byte_key2491=== PAUSE TestParseSigningKey/valid_32-byte_key2492=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2493=== CONT TestSign2494=== CONT TestExternalSignerRejectsInvalidPublicKey2495=== CONT TestGenerateFingerprint2496=== CONT TestExternalSignerClose2497=== PAUSE TestExternalSignerErrors/wrong_shape2498=== RUN TestExternalSignerRejectsInvalidPublicKey/#002499=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002500=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2501=== RUN TestExternalSignerErrors/null2502=== RUN TestParseSigningKey/no_colon2503=== PAUSE TestParseSigningKey/no_colon2504=== PAUSE TestExternalSignerErrors/null2505=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2506=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2507=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2508=== RUN TestGenerateFingerprint/basic_with_references2509=== PAUSE TestGenerateFingerprint/basic_with_references2510=== RUN TestParseSigningKey/empty_name2511=== RUN TestGenerateFingerprint/no_references2512=== PAUSE TestGenerateFingerprint/no_references2513=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2514=== PAUSE TestParseSigningKey/empty_name2515=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2516=== RUN TestExternalSignerErrors/unrequested_key2517=== PAUSE TestExternalSignerErrors/unrequested_key2518=== RUN TestExternalSignerErrors/wrong_signature_name2519=== PAUSE TestExternalSignerErrors/wrong_signature_name2520=== RUN TestExternalSignerErrors/wrong_signature_length2521=== PAUSE TestExternalSignerErrors/wrong_signature_length2522=== RUN TestExternalSignerErrors/wrong_id2523=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2524=== RUN TestParseSigningKey/invalid_base642525=== PAUSE TestParseSigningKey/invalid_base642526=== RUN TestParseSigningKey/wrong_length2527=== PAUSE TestParseSigningKey/wrong_length2528=== CONT TestParseSigningKey/valid_32-byte_key2529=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2530=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2531=== CONT TestParseSigningKey/empty_name2532=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2533=== RUN TestGenerateFingerprint/invalid_nar_hash_length2534=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2535=== RUN TestGenerateFingerprint/invalid_store_path_prefix2536=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2537=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2538=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2539=== CONT TestExternalSignerRejectsInvalidPublicKey/#002540=== CONT TestParseSigningKey/no_colon2541=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2542=== PAUSE TestExternalSignerErrors/wrong_id2543=== RUN TestExternalSignerErrors/missing_signatures2544=== CONT TestParseSigningKey/wrong_length2545=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2546=== CONT TestParseSigningKey/invalid_base642547=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2548=== RUN TestGenerateFingerprint/invalid_reference_prefix2549=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2550=== CONT TestGenerateFingerprint/basic_with_references2551=== CONT TestGenerateFingerprint/invalid_nar_hash_length2552=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2553=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2554=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2555=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2556--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2557 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2558 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2559 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2560 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2561 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2562=== PAUSE TestExternalSignerErrors/missing_signatures2563=== RUN TestExternalSignerErrors/invalid_signature_base642564=== PAUSE TestExternalSignerErrors/invalid_signature_base642565=== RUN TestExternalSignerErrors/exit_on_request2566=== PAUSE TestExternalSignerErrors/exit_on_request2567=== RUN TestExternalSignerErrors/invalid_JSON2568=== PAUSE TestExternalSignerErrors/invalid_JSON2569=== RUN TestExternalSignerErrors/wrong_signatures_shape2570=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2571=== RUN TestExternalSignerErrors/null_signatures2572=== PAUSE TestExternalSignerErrors/null_signatures2573=== RUN TestExternalSignerErrors/too_few_signatures2574=== PAUSE TestExternalSignerErrors/too_few_signatures2575=== RUN TestExternalSignerErrors/missing_signature_name2576=== PAUSE TestExternalSignerErrors/missing_signature_name2577=== RUN TestExternalSignerErrors/program_error2578=== PAUSE TestExternalSignerErrors/program_error2579=== CONT TestExternalSignerErrors/exit_at_startup2580=== CONT TestExternalSignerErrors/exit_on_request2581=== CONT TestExternalSignerErrors/missing_signatures2582=== CONT TestExternalSignerErrors/wrong_signature_length2583=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2584=== CONT TestExternalSignerErrors/wrong_signature_name2585=== CONT TestExternalSignerErrors/invalid_signature_base642586=== CONT TestGenerateFingerprint/no_references2587=== CONT TestExternalSignerErrors/null2588=== CONT TestGenerateFingerprint/invalid_reference_prefix2589=== CONT TestExternalSignerErrors/wrong_shape2590=== CONT TestGenerateFingerprint/invalid_store_path_prefix2591=== CONT TestExternalSignerErrors/too_few_signatures2592=== CONT TestExternalSignerErrors/program_error2593=== CONT TestExternalSignerErrors/missing_signature_name2594=== CONT TestExternalSignerErrors/wrong_id2595=== RUN TestSignErrors/nil_key2596--- PASS: TestSign (0.00s)2597=== CONT TestExternalSignerErrors/wrong_signatures_shape2598=== CONT TestExternalSignerErrors/null_signatures2599=== CONT TestExternalSignerErrors/invalid_JSON2600=== CONT TestExternalSignerErrors/unrequested_key2601--- PASS: TestSignBatch (0.00s)2602=== PAUSE TestSignErrors/nil_key2603=== RUN TestSignErrors/nil_narinfo2604--- PASS: TestParseSigningKey (0.00s)2605 --- PASS: TestParseSigningKey/empty_name (0.00s)2606 --- PASS: TestParseSigningKey/no_colon (0.00s)2607 --- PASS: TestParseSigningKey/wrong_length (0.00s)2608 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2609 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2610 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2611--- PASS: TestGenerateFingerprint (0.00s)2612 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2613 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2614 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2615 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2616 --- PASS: TestGenerateFingerprint/no_references (0.00s)2617 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2618 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2619=== PAUSE TestSignErrors/nil_narinfo2620=== RUN TestSignErrors/invalid_narinfo2621=== PAUSE TestSignErrors/invalid_narinfo2622=== RUN TestSignErrors/canceled2623=== PAUSE TestSignErrors/canceled2624=== CONT TestSignErrors/nil_key2625=== CONT TestSignErrors/canceled2626=== CONT TestSignErrors/invalid_narinfo2627=== CONT TestSignErrors/nil_narinfo2628--- PASS: TestSignErrors (0.02s)2629 --- PASS: TestSignErrors/nil_key (0.00s)2630 --- PASS: TestSignErrors/canceled (0.00s)2631 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2632 --- PASS: TestSignErrors/nil_narinfo (0.00s)2633--- PASS: TestExternalSignerCancellation (0.28s)2634--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.51s)2635--- PASS: TestExternalSigner (0.71s)2636/private/var/tb/4/scratch/b802c6ef575c14ab/build/TestExternalSignerRestartsAfterCrash3722434782/001/sign program: line 7: /private/var/tb/4/scratch/b802c6ef575c14ab/build/TestExternalSignerRestartsAfterCrash3722434782/001/sign program.starts: No such file or directory2637--- PASS: TestExternalSignerRestartsAfterCrash (2.65s)2638--- PASS: TestExternalSignerWrongPublicKey (3.06s)2639--- PASS: TestExternalSignerClose (3.24s)2640--- PASS: TestExternalSignerErrors (0.00s)2641 --- PASS: TestExternalSignerErrors/invalid_JSON (0.84s)2642 --- PASS: TestExternalSignerErrors/exit_at_startup (1.03s)2643 --- PASS: TestExternalSignerErrors/wrong_id (1.25s)2644 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.41s)2645 --- PASS: TestExternalSignerErrors/exit_on_request (1.64s)2646 --- PASS: TestExternalSignerErrors/unrequested_key (1.85s)2647 --- PASS: TestExternalSignerErrors/null (2.07s)2648 --- PASS: TestExternalSignerErrors/missing_signature_name (2.24s)2649 --- PASS: TestExternalSignerErrors/program_error (2.42s)2650 --- PASS: TestExternalSignerErrors/wrong_shape (2.86s)2651 --- PASS: TestExternalSignerErrors/missing_signatures (3.46s)2652 --- PASS: TestExternalSignerErrors/null_signatures (3.62s)2653 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.87s)2654 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (4.04s)2655 --- PASS: TestExternalSignerErrors/too_few_signatures (4.24s)2656 --- PASS: TestExternalSignerErrors/wrong_signature_length (4.45s)2657PASS2658Running OpenBao signer tests...2659=== RUN TestSign2660=== PAUSE TestSign2661=== RUN TestSignErrors2662=== PAUSE TestSignErrors2663=== RUN TestServe2664=== PAUSE TestServe2665=== RUN TestServeRejectsGarbage2666=== PAUSE TestServeRejectsGarbage2667=== CONT TestSign2668=== CONT TestServe2669=== CONT TestServeRejectsGarbage2670--- PASS: TestServeRejectsGarbage (0.00s)2671=== CONT TestSignErrors2672=== RUN TestSignErrors/no_prefix2673--- PASS: TestServe (0.00s)2674=== PAUSE TestSignErrors/no_prefix2675=== RUN TestSignErrors/invalid_base642676=== PAUSE TestSignErrors/invalid_base642677=== RUN TestSignErrors/http_error2678=== PAUSE TestSignErrors/http_error2679--- PASS: TestSign (0.05s)2680=== RUN TestSignErrors/invalid_json2681=== PAUSE TestSignErrors/invalid_json2682=== CONT TestSignErrors/no_prefix2683=== CONT TestSignErrors/invalid_base642684=== CONT TestSignErrors/http_error2685=== CONT TestSignErrors/invalid_json2686--- PASS: TestSignErrors (0.05s)2687 --- PASS: TestSignErrors/http_error (0.06s)2688 --- PASS: TestSignErrors/invalid_json (0.05s)2689 --- PASS: TestSignErrors/no_prefix (0.06s)2690 --- PASS: TestSignErrors/invalid_base64 (0.07s)2691PASS