niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #380
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.26s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestFileTokenReadsAndCaches100=== CONT TestScriptTokenEmptyCommand101=== CONT TestScriptTokenScriptFails102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestFileTokenMissing104=== CONT TestScriptTokenBadJSON105=== CONT TestScriptTokenEmptyToken106=== CONT TestScriptTokenCachesUntilRefresh107=== CONT TestScriptTokenNoExpiryRerunsEveryCall108--- PASS: TestFileTokenMissing (0.00s)109=== CONT TestDumpPathSingleFile110=== CONT TestFileTokenEmpty111=== CONT TestPathInfoCACompatibility112=== RUN TestPathInfoCACompatibility/null_ca_field113--- PASS: TestFileTokenEmpty (0.00s)114=== CONT TestParsePathInfoJSONMultiplePaths115=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths116=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths117=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths118=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths119=== CONT TestStaticToken120--- PASS: TestStaticToken (0.00s)121=== CONT TestParsePathInfoJSON122=== RUN TestParsePathInfoJSON/Nix_format123=== PAUSE TestParsePathInfoJSON/Nix_format124=== RUN TestParsePathInfoJSON/Lix_format125=== PAUSE TestParsePathInfoJSON/Lix_format126=== RUN TestParsePathInfoJSON/empty_input127=== PAUSE TestParsePathInfoJSON/empty_input128=== RUN TestParsePathInfoJSON/whitespace_only129--- PASS: TestFileTokenReadsAndCaches (0.01s)130=== PAUSE TestParsePathInfoJSON/whitespace_only131=== CONT TestSetClientTLSErrors132=== RUN TestParsePathInfoJSON/invalid_JSON133=== PAUSE TestParsePathInfoJSON/invalid_JSON134=== CONT TestPathInfoHashCompatibility135=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)136=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)137=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon138=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon139=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI140=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI141=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512142=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512143=== CONT TestSetClientTLSDoesNotMutateDefaultTransport144=== PAUSE TestPathInfoCACompatibility/null_ca_field145=== RUN TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text147=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive149=== RUN TestPathInfoCACompatibility/new_structured_format_-_text150=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text151=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method152=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method153=== CONT TestSetClientTLS154--- PASS: TestScriptTokenScriptFails (0.01s)155=== CONT TestEncodeNixBase32156=== RUN TestEncodeNixBase32/test_string_hash157=== PAUSE TestEncodeNixBase32/test_string_hash158=== RUN TestEncodeNixBase32/empty_input159=== PAUSE TestEncodeNixBase32/empty_input160=== CONT TestClientSignaturesByStorePath161--- PASS: TestClientSignaturesByStorePath (0.00s)162=== CONT TestStreamPushReportsSignatures163--- PASS: TestDoServerRequestAttachesToken (0.01s)164=== CONT TestDumpPathWriterError1652026/10/06 21:13:46 ERROR Upload failed error=boom count=1166--- PASS: TestStreamPushReportsSignatures (0.00s)167=== CONT TestStreamPushRequestLine168=== RUN TestSetClientTLSErrors/missing_cert_file169=== PAUSE TestSetClientTLSErrors/missing_cert_file170=== RUN TestSetClientTLSErrors/missing_key_file171=== PAUSE TestSetClientTLSErrors/missing_key_file172=== RUN TestSetClientTLSErrors/missing_ca_file173=== PAUSE TestSetClientTLSErrors/missing_ca_file174=== RUN TestSetClientTLSErrors/invalid_ca_file175=== PAUSE TestSetClientTLSErrors/invalid_ca_file176=== CONT TestStreamPushGivesUpOnDeadServer1772026/10/06 21:13:46 ERROR Upload failed error="connection refused" count=201782026/10/06 21:13:46 ERROR Server seems unavailable, giving up on batch untried=17179--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)180=== CONT TestStreamPushIsolatesFailures1812026/10/06 21:13:46 ERROR Upload failed error="bad path" count=31822026/10/06 21:13:46 ERROR Upload failed error=boom count=1183--- PASS: TestStreamPushIsolatesFailures (0.00s)184=== CONT TestFilterOversizedClosures185=== RUN TestFilterOversizedClosures/no_limit_keeps_everything186=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything187=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped188=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped189=== RUN TestFilterOversizedClosures/all_closures_skipped190=== PAUSE TestFilterOversizedClosures/all_closures_skipped191--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)192=== CONT TestStreamPushBatchesUnderLoad193=== CONT TestDumpPathMatchesNix194=== RUN TestSetClientTLS/rejects_connection_without_client_cert195=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert196=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA197=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA198=== RUN TestSetClientTLS/preserves_debug_logging_transport199=== PAUSE TestSetClientTLS/preserves_debug_logging_transport200=== CONT TestStreamPushReportsEveryPath201--- PASS: TestStreamPushReportsEveryPath (0.00s)202=== CONT TestShellSplitErrors203--- PASS: TestShellSplitErrors (0.00s)204=== CONT TestUploadMultipart_SupersededByPeer205=== RUN TestUploadMultipart_SupersededByPeer/exists206=== PAUSE TestUploadMultipart_SupersededByPeer/exists207=== RUN TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestUploadMultipart_SupersededByPeer/missing209=== CONT TestShellSplit210--- PASS: TestShellSplit (0.00s)211=== CONT TestDoWithRetry_BodyReplayedViaGetBody2122026/10/06 21:13:46 WARN Rate limiter enabled after throttle name=server-test rate=52132026/10/06 21:13:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:653272142026/10/06 21:13:46 WARN Rate limiter backed off name=server-test rate=52152026/10/06 21:13:46 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:65327216--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)217=== CONT TestPartSizeForNAR218=== RUN TestPartSizeForNAR/zero_stays_at_minimum219=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPartSizeForNAR/small_stays_at_minimum221=== PAUSE TestPartSizeForNAR/small_stays_at_minimum222=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum223=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum224=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts225=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts226=== RUN TestPartSizeForNAR/1_TiB227=== PAUSE TestPartSizeForNAR/1_TiB228=== RUN TestPartSizeForNAR/5_TiB_S3_max_object229=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object230=== RUN TestPartSizeForNAR/capped_at_5_GiB231=== PAUSE TestPartSizeForNAR/capped_at_5_GiB232=== CONT TestResolveStorePath233--- PASS: TestStreamPushRequestLine (0.01s)234=== CONT TestUploadMultipart_PartsInParallel235--- PASS: TestResolveStorePath (0.01s)236--- PASS: TestScriptTokenBadJSON (0.02s)237=== CONT TestEncodeNixBase32WithRealHash238--- PASS: TestEncodeNixBase32WithRealHash (0.00s)239=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun240=== CONT TestGetStorePathHash241=== RUN TestGetStorePathHash/valid_store_path242=== PAUSE TestGetStorePathHash/valid_store_path243=== RUN TestGetStorePathHash/basename_without_hyphen_should_error244=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error245=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error246=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error247=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error248=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error249=== CONT TestCaseHackSuffix250--- PASS: TestScriptTokenEmptyToken (0.03s)251=== CONT TestConvertHashToNix32252=== RUN TestConvertHashToNix32/SRI_format_to_Nix32253=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32254=== RUN TestConvertHashToNix32/already_Nix32_format255=== PAUSE TestConvertHashToNix32/already_Nix32_format256=== RUN TestConvertHashToNix32/invalid_format257=== PAUSE TestConvertHashToNix32/invalid_format258=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2592026/10/06 21:13:46 INFO Garbage collection started2602026/10/06 21:13:46 INFO Garbage collection started261--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)262=== CONT TestRegisterUploadedObjectReusesConnections2632026/10/06 21:13:46 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=02642026/10/06 21:13:46 WARN Garbage collection finished on another replica. Its statistics are not available here265--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)266=== CONT TestRateLimiterFeedback267=== RUN TestRateLimiterFeedback/429_enables_limiter268=== PAUSE TestRateLimiterFeedback/429_enables_limiter269=== RUN TestRateLimiterFeedback/503_enables_limiter270=== PAUSE TestRateLimiterFeedback/503_enables_limiter271=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter272=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter273=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter274=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter275=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2762026/10/06 21:13:46 WARN Rate limiter enabled after throttle name=server-test rate=5277--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)278=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths280--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)281=== CONT TestParsePathInfoJSON/Nix_format282--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)283 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)284 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)285=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)286=== CONT TestParsePathInfoJSON/invalid_JSON287=== CONT TestParsePathInfoJSON/empty_input288=== CONT TestParsePathInfoJSON/Lix_format289=== CONT TestParsePathInfoJSON/whitespace_only290--- PASS: TestParsePathInfoJSON (0.00s)291 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)292 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)293 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)294 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)295 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)296=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI297=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon298=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512299--- PASS: TestPathInfoHashCompatibility (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)301 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)302 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)303 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)304=== CONT TestPathInfoCACompatibility/null_ca_field305=== CONT TestPathInfoCACompatibility/new_structured_format_-_text306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== CONT TestPathInfoCACompatibility/old_string_format_-_text308=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method309--- PASS: TestPathInfoCACompatibility (0.00s)310 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)311 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)312 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)313 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)315=== CONT TestEncodeNixBase32/test_string_hash316=== CONT TestEncodeNixBase32/empty_input317--- PASS: TestEncodeNixBase32 (0.00s)318 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)319 --- PASS: TestEncodeNixBase32/empty_input (0.00s)320=== CONT TestSetClientTLSErrors/missing_cert_file321=== CONT TestSetClientTLSErrors/missing_ca_file322=== CONT TestSetClientTLSErrors/invalid_ca_file323=== CONT TestSetClientTLSErrors/missing_key_file324=== CONT TestFilterOversizedClosures/no_limit_keeps_everything325=== CONT TestFilterOversizedClosures/all_closures_skipped3262026/10/06 21:13:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50327=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3282026/10/06 21:13:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000329=== CONT TestSetClientTLS/preserves_debug_logging_transport330--- PASS: TestSetClientTLSErrors (0.00s)331 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)332 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)333 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335--- PASS: TestFilterOversizedClosures (0.00s)336 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)337 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)338 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)339=== CONT TestSetClientTLS/rejects_connection_without_client_cert340=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA341--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)342=== CONT TestUploadMultipart_SupersededByPeer/exists343=== CONT TestUploadMultipart_SupersededByPeer/missing344--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)345 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)347=== CONT TestPartSizeForNAR/zero_stays_at_minimum348=== CONT TestPartSizeForNAR/capped_at_5_GiB349=== CONT TestPartSizeForNAR/5_TiB_S3_max_object350=== CONT TestPartSizeForNAR/1_TiB351=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts352=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum353=== CONT TestPartSizeForNAR/small_stays_at_minimum354--- PASS: TestPartSizeForNAR (0.00s)355 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)357 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)358 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)359 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)360 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)361 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362=== CONT TestGetStorePathHash/valid_store_path363=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error364=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error365=== CONT TestGetStorePathHash/basename_without_hyphen_should_error366--- PASS: TestGetStorePathHash (0.00s)367 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)368 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)369 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)370 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)371=== CONT TestConvertHashToNix32/SRI_format_to_Nix32372=== CONT TestConvertHashToNix32/invalid_format373=== CONT TestConvertHashToNix32/already_Nix32_format374--- PASS: TestConvertHashToNix32 (0.00s)375 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)376 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)377 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)378=== CONT TestRateLimiterFeedback/429_enables_limiter379=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3802026/10/06 21:13:46 WARN Rate limiter enabled after throttle name=server-test rate=53812026/10/06 21:13:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:654143822026/10/06 21:13:46 WARN Rate limiter backed off name=server-test rate=5383=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter384=== CONT TestRateLimiterFeedback/503_enables_limiter3852026/10/06 21:13:46 WARN Rate limiter enabled after throttle name=server-test rate=53862026/10/06 21:13:46 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:654203872026/10/06 21:13:46 WARN Rate limiter backed off name=server-test rate=5388--- PASS: TestRateLimiterFeedback (0.00s)389 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)392 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)393--- PASS: TestDumpPathWriterError (0.09s)3942026/10/06 21:13:46 http: TLS handshake error from 127.0.0.1:65406: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestStreamPushBatchesUnderLoad (0.11s)400--- PASS: TestDumpPathSingleFile (0.16s)401--- PASS: TestCaseHackSuffix (0.15s)402--- PASS: TestDumpPathMatchesNix (0.27s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld18".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-25968-2128199257/postgres3785700510/data ... ok417creating subdirectories ... ok418selecting dynamic shared memory implementation ... posix419selecting default "max_connections" ... 100420selecting default "shared_buffers" ... 128MB421selecting default time zone ... UTC422creating configuration files ... ok423running bootstrap script ... ok424performing post-bootstrap initialization ... ok425syncing data to disk ... ok426427initdb: warning: enabling "trust" authentication for local connections428initdb: 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.429430Success. You can now start the database server using:431432 pg_ctl -D /nix/var/nix/builds/nix-25968-2128199257/postgres3785700510/data -l logfile start433434/nix/var/nix/builds/nix-25968-2128199257/postgres3785700510:5432 - no response4352026-10-06 21:13:51.394 UTC [26509] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 21:13:51.394 UTC [26509] LOG: listening on Unix socket "/nix/var/nix/builds/nix-25968-2128199257/postgres3785700510/.s.PGSQL.5432"4372026-10-06 21:13:51.398 UTC [26525] LOG: database system was shut down at 2026-10-06 21:13:51 UTC4382026-10-06 21:13:51.399 UTC [26509] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-25968-2128199257/postgres3785700510:5432 - accepting connections440{"timestamp":"2026-10-06T21:13:51.663126Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c16e12d7-28e8-4750-90fb-e90ceb96d773","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":13,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}441{"timestamp":"2026-10-06T21:13:51.769661Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5e3dd66c-03ef-4489-bb62-f639709a4e8d","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(9)"}442{"timestamp":"2026-10-06T21:13:51.878376Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c927397c-b380-4384-9945-2854dd92fa9f","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(9)"}443{"timestamp":"2026-10-06T21:13:51.983702Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5ad017d6-6f8e-4908-8c3c-3cdb777c1bf3","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(8)"}444{"timestamp":"2026-10-06T21:13:52.09086Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"20abee46-9114-476f-8571-833a432272c7","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(11)"}445=== RUN TestService_AuthMiddleware446=== PAUSE TestService_AuthMiddleware447=== RUN TestService_AuthMiddleware_MTLSProxyHeader448=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader449=== RUN TestService_AuthMiddleware_MTLSBoundSubjects450=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects451=== RUN TestService_ReadAuthMiddleware452=== PAUSE TestService_ReadAuthMiddleware453=== RUN TestService_AuthMiddleware_OIDC454=== PAUSE TestService_AuthMiddleware_OIDC455=== RUN TestService_RequireScope_OIDC456=== PAUSE TestService_RequireScope_OIDC457=== RUN TestService_ReadScope_PublicByDefault458=== PAUSE TestService_ReadScope_PublicByDefault459=== RUN TestCacheConfigHandler460=== PAUSE TestCacheConfigHandler461=== RUN TestCacheStatsHandler462=== PAUSE TestCacheStatsHandler463=== RUN TestClientCADerivations464=== PAUSE TestClientCADerivations465=== RUN TestClientErrorHandling466=== PAUSE TestClientErrorHandling467=== RUN TestClientIntegration468=== PAUSE TestClientIntegration469=== RUN TestClientMultipleUploads470=== PAUSE TestClientMultipleUploads471=== RUN TestClientWithDependencies472=== PAUSE TestClientWithDependencies473=== RUN TestClientSharedPathCommittedMidPush474=== PAUSE TestClientSharedPathCommittedMidPush475=== RUN TestPinProtectsFromGC476=== PAUSE TestPinProtectsFromGC477=== RUN TestClientPushesUseOnePush478=== PAUSE TestClientPushesUseOnePush479=== RUN TestClientFallsBackToClosures480=== PAUSE TestClientFallsBackToClosures481=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock483=== RUN TestResolveDBConnectionString484=== PAUSE TestResolveDBConnectionString485=== RUN TestConnectWaitsForAPeerMigration486=== PAUSE TestConnectWaitsForAPeerMigration487=== RUN TestLeadElectsOneAndHandsOver488=== PAUSE TestLeadElectsOneAndHandsOver489=== RUN TestLeadIncumbentWinsAfterRestart4902026/10/06 21:13:52 INFO lead: acquired remote=192.0.2.1:12344912026/10/06 21:13:53 INFO lead: released remote=192.0.2.1:12344922026/10/06 21:13:53 INFO lead: acquired remote=192.0.2.1:12344932026/10/06 21:13:54 INFO lead: released remote=192.0.2.1:1234494--- PASS: TestLeadIncumbentWinsAfterRestart (2.32s)495=== RUN TestLeadIncumbentAnnouncesAtOnce496=== PAUSE TestLeadIncumbentAnnouncesAtOnce497=== RUN TestLeadEndsOnShutdown498=== PAUSE TestLeadEndsOnShutdown499=== RUN TestLeadEndsWhenItsConnectionHangs5002026/10/06 21:13:54 INFO lead: acquired remote=192.0.2.1:12345012026-10-06 21:13:56.133 UTC [27030] FATAL: terminating connection due to administrator command5022026/10/06 21:13:56 INFO lead: acquired remote=192.0.2.1:12345032026/10/06 21:13:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"5042026/10/06 21:13:57 INFO lead: released remote=192.0.2.1:12345052026/10/06 21:13:57 INFO lead: released remote=192.0.2.1:1234506--- PASS: TestLeadEndsWhenItsConnectionHangs (3.02s)507=== RUN TestGCAdvisoryLockBlocksConcurrentRun508=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun509=== RUN TestGCBugBareHashReferences510=== PAUSE TestGCBugBareHashReferences511=== RUN TestGCMetrics512=== PAUSE TestGCMetrics513=== RUN TestPushDedupSurvivesConcurrentGC514=== PAUSE TestPushDedupSurvivesConcurrentGC515=== RUN TestDeduplicatedObjectsRecordedAsPending516=== PAUSE TestDeduplicatedObjectsRecordedAsPending517=== RUN TestGCSweepSkipsPendingObjects518=== PAUSE TestGCSweepSkipsPendingObjects519=== RUN TestTombstonedObjectOfferedWithoutWaiting520=== PAUSE TestTombstonedObjectOfferedWithoutWaiting521=== RUN TestGCSweepDeliversEachKeyOnce522=== PAUSE TestGCSweepDeliversEachKeyOnce523=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection525=== RUN TestForceGCDuringPushOffersSweptObject526=== PAUSE TestForceGCDuringPushOffersSweptObject527=== RUN TestFailedS3DeleteKeepsTombstone528=== PAUSE TestFailedS3DeleteKeepsTombstone529=== RUN TestSweepSkipsRowsLockedByPush530=== PAUSE TestSweepSkipsRowsLockedByPush531=== RUN TestRegisterCompletedObjectNeedsPendingRow532=== PAUSE TestRegisterCompletedObjectNeedsPendingRow533=== RUN TestGetExistingObjectsLocksRows534=== PAUSE TestGetExistingObjectsLocksRows535=== RUN TestSweepRechecksPendingAfterLocking536=== PAUSE TestSweepRechecksPendingAfterLocking537=== RUN TestPushWaitsForSweepHoldingRow538=== PAUSE TestPushWaitsForSweepHoldingRow539=== RUN TestCommitRacingPendingCleanupKeepsObjects540=== PAUSE TestCommitRacingPendingCleanupKeepsObjects541=== RUN TestGCEndsOnShutdown542=== PAUSE TestGCEndsOnShutdown543=== RUN TestGCTaskStore_StartNew544=== PAUSE TestGCTaskStore_StartNew545=== RUN TestGCTaskStore_DeduplicateSameParams546=== PAUSE TestGCTaskStore_DeduplicateSameParams547=== RUN TestGCTaskStore_ConflictDifferentParams548=== PAUSE TestGCTaskStore_ConflictDifferentParams549=== RUN TestGCTaskStore_GetEmpty550=== PAUSE TestGCTaskStore_GetEmpty551=== RUN TestGCTaskStore_GetReturnsLatest552=== PAUSE TestGCTaskStore_GetReturnsLatest553=== RUN TestGCTaskStore_CompletedAllowsNewTask554=== PAUSE TestGCTaskStore_CompletedAllowsNewTask555=== RUN TestGCTaskStore_PhaseUpdates556=== PAUSE TestGCTaskStore_PhaseUpdates557=== RUN TestGCTaskStore_Fail558=== PAUSE TestGCTaskStore_Fail559=== RUN TestGracefulShutdownDrainsInflight560=== PAUSE TestGracefulShutdownDrainsInflight561=== RUN TestService_healthCheckHandler562=== PAUSE TestService_healthCheckHandler563=== RUN TestService_readinessHandler564=== PAUSE TestService_readinessHandler565=== RUN TestGenerateLandingPage566=== PAUSE TestGenerateLandingPage567=== RUN TestCacheConfigHandlerMaxNarSize568=== PAUSE TestCacheConfigHandlerMaxNarSize569=== RUN TestCreatePendingClosureRejectsOversizedNAR570=== PAUSE TestCreatePendingClosureRejectsOversizedNAR571=== RUN TestNARDeduplicationMetadataUploadBug572=== PAUSE TestNARDeduplicationMetadataUploadBug573=== RUN TestMetricsInventory574=== PAUSE TestMetricsInventory575=== RUN TestService_NativeMTLS576=== PAUSE TestService_NativeMTLS577=== RUN TestServerTLSConfig578=== PAUSE TestServerTLSConfig579=== RUN TestMultipartCleanup580=== PAUSE TestMultipartCleanup581=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded583=== RUN TestPendingCleanupUsesOneCutoff584=== PAUSE TestPendingCleanupUsesOneCutoff585=== RUN TestObjectStatsTrigger586=== PAUSE TestObjectStatsTrigger587=== RUN TestOrphanedObjectsGC588=== PAUSE TestOrphanedObjectsGC589=== RUN TestOrphanedObjectsGCStressTest590=== PAUSE TestOrphanedObjectsGCStressTest591=== RUN TestCreatePin_ReservedPins592=== PAUSE TestCreatePin_ReservedPins593=== RUN TestPresentReportsOnlyClosureRoots594=== PAUSE TestPresentReportsOnlyClosureRoots595=== RUN TestPresentNotReportedWhileGCDeletesClosure596=== PAUSE TestPresentNotReportedWhileGCDeletesClosure597=== RUN TestParseSingleRange598=== PAUSE TestParseSingleRange599=== RUN TestProxyHeadersOnlyTrustedOnSocket600=== PAUSE TestProxyHeadersOnlyTrustedOnSocket601=== RUN TestIsValidCachePath602=== PAUSE TestIsValidCachePath603=== RUN TestReadProxyNarinfo604=== PAUSE TestReadProxyNarinfo605=== RUN TestReadProxyNarinfoAlreadyDecompressed606=== PAUSE TestReadProxyNarinfoAlreadyDecompressed607=== RUN TestReadProxyContentNegotiation608=== PAUSE TestReadProxyContentNegotiation609=== RUN TestReadProxyNarStreaming610=== PAUSE TestReadProxyNarStreaming611=== RUN TestReadProxy404612=== PAUSE TestReadProxy404613=== RUN TestReadProxyInvalidPath614=== PAUSE TestReadProxyInvalidPath615=== RUN TestReadProxyHead616=== PAUSE TestReadProxyHead617=== RUN TestReadProxyOutlastsServerWriteTimeout618=== PAUSE TestReadProxyOutlastsServerWriteTimeout619=== RUN TestReadProxyConditionalGet620=== PAUSE TestReadProxyConditionalGet621=== RUN TestReadProxyRootRedirectsToIndexHTML622=== PAUSE TestReadProxyRootRedirectsToIndexHTML623=== RUN TestReadProxyDisabled624=== PAUSE TestReadProxyDisabled625=== RUN TestReadRedirectNar626=== PAUSE TestReadRedirectNar627=== RUN TestReadRedirectKeepsNarinfoProxied628=== PAUSE TestReadRedirectKeepsNarinfoProxied629=== RUN TestReadProxyRangeRequest630=== PAUSE TestReadProxyRangeRequest631=== RUN TestReadRedirectUsesPublicS3URL632=== PAUSE TestReadRedirectUsesPublicS3URL633=== RUN TestPush_OverlappingRootsStoreOneRowPerKey634=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey635=== RUN TestPush_CompleteCommitsEveryRoot636=== PAUSE TestPush_CompleteCommitsEveryRoot637=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit638=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit639=== RUN TestPush_RejectsBadRequests640=== PAUSE TestPush_RejectsBadRequests641=== RUN TestPush_SignsNarinfosOfItsPendingObjects642=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects643=== RUN TestRedundantMultipartUpload644=== PAUSE TestRedundantMultipartUpload645=== RUN TestCompleteMultipartUpload_ErrorButObjectExists646=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists647=== RUN TestCompletedNarNotReofferedAcrossClosures648=== PAUSE TestCompletedNarNotReofferedAcrossClosures649=== RUN TestPresignedUploadRegisteredBeforeCommit650=== PAUSE TestPresignedUploadRegisteredBeforeCommit651=== RUN TestService_Rustfstest652=== PAUSE TestService_Rustfstest653=== RUN TestParseSize654=== PAUSE TestParseSize655=== RUN TestSkippedUploadsHandler656=== PAUSE TestSkippedUploadsHandler657=== RUN TestSystemdListenerNotActivated658--- PASS: TestSystemdListenerNotActivated (0.00s)659=== RUN TestWatchdogBeatsWhenHealthy660--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)661=== RUN TestWatchdogSkipsWhenUnhealthy6622026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:13:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"672--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)673=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle674=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle675=== RUN TestProxyWriteTimeout676=== PAUSE TestProxyWriteTimeout677=== RUN TestPendingClosureWriteTimeout678=== PAUSE TestPendingClosureWriteTimeout679=== RUN TestIsValidUploadKey680=== PAUSE TestIsValidUploadKey681=== RUN TestUploadHandlersRejectInvalidKeys682=== PAUSE TestUploadHandlersRejectInvalidKeys683=== RUN TestUploadHandlersRejectOversizedBody684=== PAUSE TestUploadHandlersRejectOversizedBody685=== RUN TestService_cleanupPendingClosuresHandler686=== PAUSE TestService_cleanupPendingClosuresHandler687=== RUN TestService_createPendingClosureHandler688=== PAUSE TestService_createPendingClosureHandler689=== RUN TestService_verifyS3Integrity690=== PAUSE TestService_verifyS3Integrity691=== RUN TestCompleteMultipartUnregistered692=== PAUSE TestCompleteMultipartUnregistered693=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT694=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT695=== CONT TestService_AuthMiddleware696=== CONT TestCreatePendingClosureRejectsOversizedNAR697=== CONT TestDeduplicatedObjectsRecordedAsPending6982026/10/06 21:13:57 INFO Received uploads request method=POST path=/api/pending_closures699=== CONT TestGCTaskStore_StartNew700--- PASS: TestGCTaskStore_StartNew (0.00s)701=== CONT TestCacheConfigHandlerMaxNarSize702--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)703=== CONT TestReadRedirectNar704=== CONT TestService_healthCheckHandler705--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)706=== CONT TestSweepRechecksPendingAfterLocking707=== CONT TestGenerateLandingPage708--- PASS: TestGenerateLandingPage (0.00s)709=== CONT TestGetExistingObjectsLocksRows710=== CONT TestGCEndsOnShutdown711=== RUN TestGCEndsOnShutdown/before_the_run712=== PAUSE TestGCEndsOnShutdown/before_the_run713=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete714=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete715=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark716=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark717=== CONT TestCommitRacingPendingCleanupKeepsObjects718=== CONT TestService_readinessHandler719=== CONT TestPushWaitsForSweepHoldingRow720=== CONT TestRegisterCompletedObjectNeedsPendingRow7212026/10/06 21:13:58 INFO Received uploads request method=POST path=/api/pending_closures722--- PASS: TestReadRedirectNar (0.86s)723=== CONT TestSweepSkipsRowsLockedByPush7242026/10/06 21:13:58 INFO Aborted multipart uploads count=0 kept=07252026/10/06 21:13:58 WARN Force mode enabled - objects will be deleted immediately without grace period7262026/10/06 21:13:58 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=07272026/10/06 21:13:58 INFO Vacuumed table table=pending_closures7282026/10/06 21:13:58 INFO Vacuumed table table=pending_objects7292026/10/06 21:13:58 INFO Vacuumed table table=multipart_uploads7302026/10/06 21:13:58 INFO Vacuumed table table=closures7312026/10/06 21:13:58 INFO Vacuumed table table=objects732--- PASS: TestSweepRechecksPendingAfterLocking (1.11s)733=== CONT TestFailedS3DeleteKeepsTombstone734--- PASS: TestPushWaitsForSweepHoldingRow (1.19s)735=== CONT TestForceGCDuringPushOffersSweptObject736=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows737=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows738=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check739=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check740=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection741--- PASS: TestService_healthCheckHandler (1.23s)742=== CONT TestGCSweepDeliversEachKeyOnce7432026/10/06 21:13:59 INFO Received uploads request method=POST path=/api/pending_closures744--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.44s)745=== CONT TestTombstonedObjectOfferedWithoutWaiting7462026/10/06 21:13:59 WARN readiness check failed error="closed pool"747--- PASS: TestService_readinessHandler (1.63s)748=== CONT TestGCSweepSkipsPendingObjects749--- PASS: TestGetExistingObjectsLocksRows (1.82s)750=== CONT TestClientSharedPathCommittedMidPush7512026/10/06 21:13:59 INFO Aborted multipart uploads count=0 kept=07522026/10/06 21:13:59 WARN Force mode enabled - objects will be deleted immediately without grace period7532026/10/06 21:13:59 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=07542026/10/06 21:13:59 INFO Vacuumed table table=pending_closures7552026/10/06 21:13:59 INFO Vacuumed table table=pending_objects7562026/10/06 21:13:59 INFO Vacuumed table table=multipart_uploads7572026/10/06 21:13:59 INFO Vacuumed table table=closures7582026/10/06 21:13:59 INFO Vacuumed table table=objects759--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.14s)760=== CONT TestPushDedupSurvivesConcurrentGC761--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.24s)762=== CONT TestGCMetrics7632026/10/06 21:14:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"764--- PASS: TestService_AuthMiddleware (2.42s)765=== CONT TestGCBugBareHashReferences7662026/10/06 21:14:00 INFO Aborted multipart uploads count=0 kept=07672026/10/06 21:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period7682026/10/06 21:14:00 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=07692026/10/06 21:14:00 INFO Vacuumed table table=pending_closures7702026/10/06 21:14:00 INFO Vacuumed table table=pending_objects7712026/10/06 21:14:00 INFO Vacuumed table table=multipart_uploads7722026/10/06 21:14:00 INFO Vacuumed table table=closures7732026/10/06 21:14:00 INFO Vacuumed table table=objects7742026/10/06 21:14:00 INFO Aborted multipart uploads count=0 kept=07752026/10/06 21:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period7762026/10/06 21:14:00 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=07772026/10/06 21:14:00 INFO Vacuumed table table=pending_closures7782026/10/06 21:14:00 INFO Vacuumed table table=pending_objects7792026/10/06 21:14:00 INFO Vacuumed table table=multipart_uploads7802026/10/06 21:14:00 INFO Vacuumed table table=closures7812026/10/06 21:14:00 INFO Vacuumed table table=objects782--- PASS: TestSweepSkipsRowsLockedByPush (1.94s)783=== CONT TestGCAdvisoryLockBlocksConcurrentRun7842026/10/06 21:14:00 INFO Received uploads request method=POST path=/api/pending_closures7852026/10/06 21:14:00 INFO Aborted multipart uploads count=0 kept=07862026/10/06 21:14:00 WARN Force mode enabled - objects will be deleted immediately without grace period7872026/10/06 21:14:00 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."7882026/10/06 21:14:00 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."789--- PASS: TestFailedS3DeleteKeepsTombstone (1.94s)790=== CONT TestLeadEndsOnShutdown7912026/10/06 21:14:00 INFO Received uploads request method=POST path=/api/pending_closures792--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.16s)793=== CONT TestLeadIncumbentAnnouncesAtOnce7942026/10/06 21:14:01 INFO Aborted multipart uploads count=0 kept=07952026/10/06 21:14:01 WARN Force mode enabled - objects will be deleted immediately without grace period7962026/10/06 21:14:01 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=07972026/10/06 21:14:01 INFO Vacuumed table table=pending_closures7982026/10/06 21:14:01 INFO Vacuumed table table=pending_objects7992026/10/06 21:14:01 INFO Vacuumed table table=multipart_uploads8002026/10/06 21:14:01 INFO Vacuumed table table=closures8012026/10/06 21:14:01 INFO Vacuumed table table=objects802--- PASS: TestGCSweepDeliversEachKeyOnce (2.30s)803=== CONT TestLeadElectsOneAndHandsOver8042026/10/06 21:14:01 INFO Received uploads request method=POST path=/api/pending_closures8052026/10/06 21:14:01 INFO Aborted multipart uploads count=0 kept=08062026/10/06 21:14:01 WARN Force mode enabled - objects will be deleted immediately without grace period8072026/10/06 21:14:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08082026/10/06 21:14:01 INFO Vacuumed table table=pending_closures8092026/10/06 21:14:01 INFO Vacuumed table table=pending_objects8102026/10/06 21:14:01 INFO Vacuumed table table=multipart_uploads8112026/10/06 21:14:01 INFO Vacuumed table table=closures8122026/10/06 21:14:01 INFO Vacuumed table table=objects813--- PASS: TestGCSweepSkipsPendingObjects (2.11s)814=== CONT TestConnectWaitsForAPeerMigration8152026/10/06 21:14:01 INFO Received uploads request method=POST path=/api/pending_closures816--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.42s)817=== CONT TestResolveDBConnectionString818=== RUN TestResolveDBConnectionString/flag_wins819=== PAUSE TestResolveDBConnectionString/flag_wins820=== RUN TestResolveDBConnectionString/file_when_flag_empty821=== PAUSE TestResolveDBConnectionString/file_when_flag_empty822=== RUN TestResolveDBConnectionString/missing_file_is_an_error823=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error824=== RUN TestResolveDBConnectionString/PGHOST_allows_empty825=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty826=== RUN TestResolveDBConnectionString/nothing_configured827=== PAUSE TestResolveDBConnectionString/nothing_configured828=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock8292026/10/06 21:14:02 INFO Aborted multipart uploads count=0 kept=08302026/10/06 21:14:02 WARN Force mode enabled - objects will be deleted immediately without grace period8312026/10/06 21:14: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=08322026/10/06 21:14:02 INFO Vacuumed table table=pending_closures8332026/10/06 21:14:02 INFO Vacuumed table table=pending_objects8342026/10/06 21:14:02 INFO Vacuumed table table=multipart_uploads8352026/10/06 21:14:02 INFO Vacuumed table table=closures8362026/10/06 21:14:02 INFO Vacuumed table table=objects837--- PASS: TestGCMetrics (2.05s)838=== CONT TestClientFallsBackToClosures8392026/10/06 21:14:02 INFO Received push request method=POST path=/api/pushes8402026/10/06 21:14:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8412026/10/06 21:14:02 INFO Uploading 3255gbwmzh761xyyn462ay62y6ahykcf-top (256B)8422026/10/06 21:14:02 INFO Uploading 74b506n0hagczf11drvw0p6lr1m0mvkl-shared-dep (136B)8432026/10/06 21:14:02 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/06 21:14:02 WARN Failed to register uploaded object key=74b506n0hagczf11drvw0p6lr1m0mvkl.ls error="server returned 404: 404 page not found\n"8452026/10/06 21:14:02 WARN Failed to register uploaded object key=nar/15bp4rwviy6fc4wnpz76vkx68sfpzff0b0x4djvn4csm37w49wv7.nar.zst error="server returned 404: 404 page not found\n"8462026/10/06 21:14:02 WARN Failed to register uploaded object key=3255gbwmzh761xyyn462ay62y6ahykcf.ls error="server returned 404: 404 page not found\n"8472026/10/06 21:14:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8482026/10/06 21:14:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8492026/10/06 21:14:02 INFO Signed narinfos id=1 count=28502026/10/06 21:14:02 INFO Uploading 2 narinfos8512026/10/06 21:14:02 INFO Received complete push request method=POST path=/api/pushes/1/complete8522026/10/06 21:14:02 WARN Failed to register uploaded object key=3255gbwmzh761xyyn462ay62y6ahykcf.narinfo error="server returned 404: 404 page not found\n"8532026/10/06 21:14:02 WARN Failed to register uploaded object key=74b506n0hagczf11drvw0p6lr1m0mvkl.narinfo error="server returned 404: 404 page not found\n"8542026/10/06 21:14:02 INFO Upload complete. (217ms)855=== NAME TestClientSharedPathCommittedMidPush856 client_integration_test.go:680: Retrieved narinfo from S3:857 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientSharedPathCommittedMidPush3726774698/001/store/74b506n0hagczf11drvw0p6lr1m0mvkl-shared-dep858 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst859 Compression: zstd860 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82861 NarSize: 136862 References: 863 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n864 client_integration_test.go:680: Retrieved narinfo from S3:865 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientSharedPathCommittedMidPush3726774698/001/store/3255gbwmzh761xyyn462ay62y6ahykcf-top866 URL: nar/15bp4rwviy6fc4wnpz76vkx68sfpzff0b0x4djvn4csm37w49wv7.nar.zst867 Compression: zstd868 NarHash: sha256:15bp4rwviy6fc4wnpz76vkx68sfpzff0b0x4djvn4csm37w49wv7869 NarSize: 256870 References: /nix/var/nix/builds/nix-25968-2128199257/TestClientSharedPathCommittedMidPush3726774698/001/store/74b506n0hagczf11drvw0p6lr1m0mvkl-shared-dep871 CA: text:sha256:1h84vb46z5crl84g1c3q43x4v6yssxb1s42afgyz8vhzxpjf84618722026/10/06 21:14:02 INFO Aborted multipart uploads count=0 kept=08732026/10/06 21:14:02 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=08742026/10/06 21:14:02 INFO Vacuumed table table=pending_closures875--- PASS: TestClientSharedPathCommittedMidPush (2.91s)876=== CONT TestClientPushesUseOnePush8772026/10/06 21:14:02 INFO Vacuumed table table=pending_objects8782026/10/06 21:14:02 INFO Vacuumed table table=multipart_uploads8792026/10/06 21:14:02 INFO Vacuumed table table=closures8802026/10/06 21:14:02 INFO Vacuumed table table=objects8812026/10/06 21:14:02 INFO Aborted multipart uploads count=0 kept=08822026/10/06 21:14:02 WARN Force mode enabled - objects will be deleted immediately without grace period8832026/10/06 21:14: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=08842026/10/06 21:14:02 INFO Vacuumed table table=pending_closures8852026/10/06 21:14:02 INFO Vacuumed table table=pending_objects8862026/10/06 21:14:02 INFO Vacuumed table table=multipart_uploads8872026/10/06 21:14:02 INFO Vacuumed table table=closures8882026/10/06 21:14:02 INFO Vacuumed table table=objects889--- PASS: TestPushDedupSurvivesConcurrentGC (2.67s)890=== CONT TestPinProtectsFromGC8912026/10/06 21:14:02 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld18 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"892--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.23s)893=== CONT TestParseSingleRange894=== RUN TestParseSingleRange/none895=== PAUSE TestParseSingleRange/none896=== RUN TestParseSingleRange/unknown_unit897=== PAUSE TestParseSingleRange/unknown_unit898=== RUN TestParseSingleRange/multi-range_ignored899=== PAUSE TestParseSingleRange/multi-range_ignored900=== RUN TestParseSingleRange/malformed_no_dash901=== PAUSE TestParseSingleRange/malformed_no_dash902=== RUN TestParseSingleRange/malformed_both_empty903=== PAUSE TestParseSingleRange/malformed_both_empty904=== RUN TestParseSingleRange/malformed_end_before_start905=== PAUSE TestParseSingleRange/malformed_end_before_start906=== RUN TestParseSingleRange/closed907=== PAUSE TestParseSingleRange/closed908=== RUN TestParseSingleRange/open-ended909=== PAUSE TestParseSingleRange/open-ended910=== RUN TestParseSingleRange/end_clamped_to_size911=== PAUSE TestParseSingleRange/end_clamped_to_size912=== RUN TestParseSingleRange/suffix913=== PAUSE TestParseSingleRange/suffix914=== RUN TestParseSingleRange/suffix_exceeds_size915=== PAUSE TestParseSingleRange/suffix_exceeds_size916=== RUN TestParseSingleRange/single_byte917=== PAUSE TestParseSingleRange/single_byte918=== RUN TestParseSingleRange/start_past_EOF919=== PAUSE TestParseSingleRange/start_past_EOF920=== RUN TestParseSingleRange/start_far_past_EOF921=== PAUSE TestParseSingleRange/start_far_past_EOF922=== CONT TestReadProxyDisabled923--- PASS: TestGCBugBareHashReferences (2.61s)924=== CONT TestGracefulShutdownDrainsInflight9252026/10/06 21:14:02 INFO Starting HTTP server address=127.0.0.1:655189262026/10/06 21:14:02 INFO Shutdown signal received, draining in-flight requests timeout=10s927--- PASS: TestGracefulShutdownDrainsInflight (0.08s)928=== CONT TestGCTaskStore_Fail929--- PASS: TestGCTaskStore_Fail (0.00s)930=== CONT TestGCTaskStore_PhaseUpdates931--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)932=== CONT TestGCTaskStore_CompletedAllowsNewTask933--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)934=== CONT TestReadProxyConditionalGet9352026/10/06 21:14:03 INFO lead: acquired remote=192.0.2.1:12349362026/10/06 21:14:03 INFO lead: acquired remote=192.0.2.1:12349372026/10/06 21:14:03 INFO lead: released remote=192.0.2.1:1234938--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.14s)939=== CONT TestGCTaskStore_GetReturnsLatest940--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)941=== CONT TestReadProxyOutlastsServerWriteTimeout9422026/10/06 21:14:03 INFO lead: acquired remote=192.0.2.1:12349432026/10/06 21:14:04 INFO lead: released remote=192.0.2.1:1234944--- PASS: TestLeadEndsOnShutdown (3.30s)945=== CONT TestReadProxyRootRedirectsToIndexHTML9462026/10/06 21:14:04 INFO lead: released remote=192.0.2.1:12349472026/10/06 21:14:04 INFO lead: acquired remote=192.0.2.1:1234948--- PASS: TestReadProxyDisabled (2.29s)949=== CONT TestReadProxyHead950=== NAME TestPinProtectsFromGC951 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-25968-2128199257/TestPinProtectsFromGC792690770/001/store/86n07snrwdkjmk2c1i13j08xyic34hdw-pinned-file.txt952 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-25968-2128199257/TestPinProtectsFromGC792690770/001/store/bg315bj4g8bfknn87frgm6bcfdf3qrl8-unpinned-file.txt9532026/10/06 21:14:05 INFO Received uploads request method=POST path=/api/pending_closures954--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.76s)955=== CONT TestGCTaskStore_GetEmpty956--- PASS: TestGCTaskStore_GetEmpty (0.00s)957=== CONT TestReadProxyInvalidPath9582026/10/06 21:14:05 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/06 21:14:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9602026/10/06 21:14:05 INFO Uploading wj0pp4qy94p6gmwpxj26yb5jf8y2wdwr-a (248B)9612026/10/06 21:14:05 INFO Uploading 3jyyg9ji7wss5w5d3flr41fv7nfgvlwk-shared-dep (136B)962--- PASS: TestReadProxyConditionalGet (2.57s)963=== CONT TestGCTaskStore_ConflictDifferentParams964--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)965=== CONT TestReadProxy4049662026/10/06 21:14:05 WARN Failed to register uploaded object key=wj0pp4qy94p6gmwpxj26yb5jf8y2wdwr.ls error="server returned 404: 404 page not found\n"9672026/10/06 21:14:05 WARN Failed to register uploaded object key=81qi256lvn95ayjvrycyxf4bydfrg4dv.ls error="server returned 404: 404 page not found\n"9682026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/0nxx4svjgab26gcam3ibx64hbpkzw9i9c5inign73xdq20qcfphr.nar.zst error="server returned 404: 404 page not found\n"9692026/10/06 21:14:05 WARN Failed to register uploaded object key=3jyyg9ji7wss5w5d3flr41fv7nfgvlwk.ls error="server returned 404: 404 page not found\n"9702026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9712026/10/06 21:14:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9722026/10/06 21:14:05 INFO Signed narinfos id=1 count=29732026/10/06 21:14:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9742026/10/06 21:14:05 INFO Signed narinfos id=2 count=29752026/10/06 21:14:05 INFO Uploading 4 narinfos9762026/10/06 21:14:05 INFO Received push request method=POST path=/api/pushes9772026/10/06 21:14:05 WARN Failed to register uploaded object key=81qi256lvn95ayjvrycyxf4bydfrg4dv.narinfo error="server returned 404: 404 page not found\n"9782026/10/06 21:14:05 WARN Failed to register uploaded object key=3jyyg9ji7wss5w5d3flr41fv7nfgvlwk.narinfo error="server returned 404: 404 page not found\n"9792026/10/06 21:14:05 WARN Failed to register uploaded object key=wj0pp4qy94p6gmwpxj26yb5jf8y2wdwr.narinfo error="server returned 404: 404 page not found\n"9802026/10/06 21:14:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9812026/10/06 21:14:05 INFO Uploading 8dy7x37kwcl4wdcl3nljnzn0difdn3gk-a (248B)9822026/10/06 21:14:05 INFO Uploading ayd3acdq3qhh3n36hbnpka75b7z7a12d-shared-dep (136B)9832026/10/06 21:14:05 INFO Received push request method=POST path=/api/pushes9842026/10/06 21:14:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9852026/10/06 21:14:05 WARN Failed to register uploaded object key=3jyyg9ji7wss5w5d3flr41fv7nfgvlwk.narinfo error="server returned 404: 404 page not found\n"9862026/10/06 21:14:05 WARN Failed to register uploaded object key=ayd3acdq3qhh3n36hbnpka75b7z7a12d.ls error="server returned 404: 404 page not found\n"9872026/10/06 21:14:05 WARN Failed to register uploaded object key=01v0dfpczwml63ijpgynhf6z5fgvrlxi.ls error="server returned 404: 404 page not found\n"9882026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9892026/10/06 21:14:05 WARN Failed to register uploaded object key=8dy7x37kwcl4wdcl3nljnzn0difdn3gk.ls error="server returned 404: 404 page not found\n"9902026/10/06 21:14:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9912026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/1ldklv3djpabhm0f0pb22fpsgpsh7jz08fpmgwjh7qbb7lys07cz.nar.zst error="server returned 404: 404 page not found\n"9922026/10/06 21:14:05 INFO Signed narinfos id=1 count=39932026/10/06 21:14:05 INFO Uploading 3 narinfos9942026/10/06 21:14:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9952026/10/06 21:14:05 INFO Uploading 86n07snrwdkjmk2c1i13j08xyic34hdw-pinned-file.txt (128B)9962026/10/06 21:14:05 WARN Failed to register uploaded object key=01v0dfpczwml63ijpgynhf6z5fgvrlxi.narinfo error="server returned 404: 404 page not found\n"9972026/10/06 21:14:05 INFO Completed upload id=19982026/10/06 21:14:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9992026/10/06 21:14:05 INFO Completed upload id=210002026/10/06 21:14:05 INFO Upload complete. (359ms)10012026/10/06 21:14:05 WARN Failed to register uploaded object key=8dy7x37kwcl4wdcl3nljnzn0difdn3gk.narinfo error="server returned 404: 404 page not found\n"10022026/10/06 21:14:05 INFO Received complete push request method=POST path=/api/pushes/1/complete10032026/10/06 21:14:05 WARN Failed to register uploaded object key=ayd3acdq3qhh3n36hbnpka75b7z7a12d.narinfo error="server returned 404: 404 page not found\n"1004=== NAME TestClientFallsBackToClosures1005 client_pushes_test.go:112: Retrieved narinfo from S3:1006 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientFallsBackToClosures2822703348/001/store/3jyyg9ji7wss5w5d3flr41fv7nfgvlwk-shared-dep1007 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1008 Compression: zstd1009 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821010 NarSize: 1361011 References: 1012 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1013 client_pushes_test.go:112: Retrieved narinfo from S3:1014 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientFallsBackToClosures2822703348/001/store/wj0pp4qy94p6gmwpxj26yb5jf8y2wdwr-a1015 URL: nar/0nxx4svjgab26gcam3ibx64hbpkzw9i9c5inign73xdq20qcfphr.nar.zst1016 Compression: zstd1017 NarHash: sha256:0nxx4svjgab26gcam3ibx64hbpkzw9i9c5inign73xdq20qcfphr1018 NarSize: 2481019 References: /nix/var/nix/builds/nix-25968-2128199257/TestClientFallsBackToClosures2822703348/001/store/3jyyg9ji7wss5w5d3flr41fv7nfgvlwk-shared-dep1020 CA: text:sha256:0v17n54yd98farx150f1d90wkyfiz0fsynx3y5mkslha2cik4yr51021 client_pushes_test.go:112: Retrieved narinfo from S3:1022 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientFallsBackToClosures2822703348/001/store/81qi256lvn95ayjvrycyxf4bydfrg4dv-b1023 URL: nar/0nxx4svjgab26gcam3ibx64hbpkzw9i9c5inign73xdq20qcfphr.nar.zst1024 Compression: zstd1025 NarHash: sha256:0nxx4svjgab26gcam3ibx64hbpkzw9i9c5inign73xdq20qcfphr1026 NarSize: 2481027 References: /nix/var/nix/builds/nix-25968-2128199257/TestClientFallsBackToClosures2822703348/001/store/3jyyg9ji7wss5w5d3flr41fv7nfgvlwk-shared-dep1028 CA: text:sha256:0v17n54yd98farx150f1d90wkyfiz0fsynx3y5mkslha2cik4yr510292026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10302026/10/06 21:14:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10312026/10/06 21:14:05 WARN Failed to register uploaded object key=86n07snrwdkjmk2c1i13j08xyic34hdw.ls error="server returned 404: 404 page not found\n"10322026/10/06 21:14:05 INFO Signed narinfos id=1 count=110332026/10/06 21:14:05 INFO Uploading 1 narinfos10342026/10/06 21:14:05 INFO Upload complete. (269ms)1035=== NAME TestClientPushesUseOnePush1036 client_pushes_test.go:97: Retrieved narinfo from S3:1037 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientPushesUseOnePush57136281/001/store/ayd3acdq3qhh3n36hbnpka75b7z7a12d-shared-dep1038 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1039 Compression: zstd1040 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821041 NarSize: 1361042 References: 1043 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1044 client_pushes_test.go:97: Retrieved narinfo from S3:1045 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientPushesUseOnePush57136281/001/store/8dy7x37kwcl4wdcl3nljnzn0difdn3gk-a1046 URL: nar/1ldklv3djpabhm0f0pb22fpsgpsh7jz08fpmgwjh7qbb7lys07cz.nar.zst1047 Compression: zstd1048 NarHash: sha256:1ldklv3djpabhm0f0pb22fpsgpsh7jz08fpmgwjh7qbb7lys07cz1049 NarSize: 2481050 References: /nix/var/nix/builds/nix-25968-2128199257/TestClientPushesUseOnePush57136281/001/store/ayd3acdq3qhh3n36hbnpka75b7z7a12d-shared-dep1051 CA: text:sha256:0vm3iizi23h9ls5ngrzc54sg8266f9kkl1hxgxgacv7292ibg7ns1052 client_pushes_test.go:97: Retrieved narinfo from S3:1053 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientPushesUseOnePush57136281/001/store/01v0dfpczwml63ijpgynhf6z5fgvrlxi-b1054 URL: nar/1ldklv3djpabhm0f0pb22fpsgpsh7jz08fpmgwjh7qbb7lys07cz.nar.zst1055 Compression: zstd1056 NarHash: sha256:1ldklv3djpabhm0f0pb22fpsgpsh7jz08fpmgwjh7qbb7lys07cz1057 NarSize: 2481058 References: /nix/var/nix/builds/nix-25968-2128199257/TestClientPushesUseOnePush57136281/001/store/ayd3acdq3qhh3n36hbnpka75b7z7a12d-shared-dep1059 CA: text:sha256:0vm3iizi23h9ls5ngrzc54sg8266f9kkl1hxgxgacv7292ibg7ns10602026/10/06 21:14:05 INFO Received complete push request method=POST path=/api/pushes/1/complete10612026/10/06 21:14:05 WARN Failed to register uploaded object key=86n07snrwdkjmk2c1i13j08xyic34hdw.narinfo error="server returned 404: 404 page not found\n"10622026/10/06 21:14:05 INFO Upload complete. (246ms)1063--- PASS: TestClientFallsBackToClosures (3.67s)1064=== CONT TestGCTaskStore_DeduplicateSameParams1065--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1066=== CONT TestReadProxyNarStreaming1067--- PASS: TestClientPushesUseOnePush (3.29s)1068=== CONT TestReadProxyNarinfo10692026/10/06 21:14:05 INFO Received push request method=POST path=/api/pushes10702026/10/06 21:14:05 INFO lead: released remote=192.0.2.1:12341071--- PASS: TestLeadElectsOneAndHandsOver (4.57s)1072=== CONT TestIsValidCachePath1073=== RUN TestIsValidCachePath/narinfo1074=== PAUSE TestIsValidCachePath/narinfo1075=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1076=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1077=== RUN TestIsValidCachePath/nar_zst1078=== PAUSE TestIsValidCachePath/nar_zst1079=== RUN TestIsValidCachePath/nar_xz1080=== PAUSE TestIsValidCachePath/nar_xz1081=== RUN TestIsValidCachePath/nar_bz21082=== PAUSE TestIsValidCachePath/nar_bz21083=== RUN TestIsValidCachePath/nar_uncompressed1084=== PAUSE TestIsValidCachePath/nar_uncompressed1085=== RUN TestIsValidCachePath/ls1086=== PAUSE TestIsValidCachePath/ls1087=== RUN TestIsValidCachePath/log1088=== PAUSE TestIsValidCachePath/log1089=== RUN TestIsValidCachePath/realisation1090=== PAUSE TestIsValidCachePath/realisation1091=== RUN TestIsValidCachePath/nix-cache-info1092=== PAUSE TestIsValidCachePath/nix-cache-info1093=== RUN TestIsValidCachePath/index.html1094=== PAUSE TestIsValidCachePath/index.html1095=== RUN TestIsValidCachePath/traversal_parent1096=== PAUSE TestIsValidCachePath/traversal_parent1097=== RUN TestIsValidCachePath/traversal_in_middle1098=== PAUSE TestIsValidCachePath/traversal_in_middle1099=== RUN TestIsValidCachePath/invalid_char_e1100=== PAUSE TestIsValidCachePath/invalid_char_e1101=== RUN TestIsValidCachePath/invalid_char_u1102=== PAUSE TestIsValidCachePath/invalid_char_u1103=== RUN TestIsValidCachePath/random_path1104=== PAUSE TestIsValidCachePath/random_path1105=== RUN TestIsValidCachePath/empty1106=== PAUSE TestIsValidCachePath/empty1107=== RUN TestIsValidCachePath/leading_slash1108=== PAUSE TestIsValidCachePath/leading_slash1109=== RUN TestIsValidCachePath/wrong_extension1110=== PAUSE TestIsValidCachePath/wrong_extension1111=== RUN TestIsValidCachePath/short_hash1112=== PAUSE TestIsValidCachePath/short_hash1113=== CONT TestProxyHeadersOnlyTrustedOnSocket11142026/10/06 21:14:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11152026/10/06 21:14:05 INFO Uploading bg315bj4g8bfknn87frgm6bcfdf3qrl8-unpinned-file.txt (128B)11162026/10/06 21:14:05 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11172026/10/06 21:14:05 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11182026/10/06 21:14:05 WARN Failed to register uploaded object key=bg315bj4g8bfknn87frgm6bcfdf3qrl8.ls error="server returned 404: 404 page not found\n"11192026/10/06 21:14:05 INFO Signed narinfos id=2 count=111202026/10/06 21:14:05 INFO Uploading 1 narinfos11212026/10/06 21:14:05 INFO Received complete push request method=POST path=/api/pushes/2/complete11222026/10/06 21:14:05 WARN Failed to register uploaded object key=bg315bj4g8bfknn87frgm6bcfdf3qrl8.narinfo error="server returned 404: 404 page not found\n"11232026/10/06 21:14:05 INFO Upload complete. (181ms)11242026/10/06 21:14:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures11252026/10/06 21:14:06 INFO Garbage collection started11262026/10/06 21:14:06 INFO Aborted multipart uploads count=0 kept=011272026/10/06 21:14:06 WARN Force mode enabled - objects will be deleted immediately without grace period11282026/10/06 21:14:06 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=011292026/10/06 21:14:06 INFO Vacuumed table table=pending_closures11302026/10/06 21:14:06 INFO Vacuumed table table=pending_objects11312026/10/06 21:14:06 INFO Vacuumed table table=multipart_uploads11322026/10/06 21:14:06 INFO Vacuumed table table=closures11332026/10/06 21:14:06 INFO Vacuumed table table=objects1134--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.51s)1135=== CONT TestReadProxyContentNegotiation1136--- PASS: TestReadProxyHead (2.53s)1137=== CONT TestReadProxyNarinfoAlreadyDecompressed1138--- PASS: TestReadProxy404 (2.57s)1139=== CONT TestPendingCleanupUsesOneCutoff11402026/10/06 21:14:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011412026/10/06 21:14:08 INFO Received create pin request method=POST path=/api/pins/myapp11422026/10/06 21:14:08 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-25968-2128199257/TestPinProtectsFromGC792690770/001/store/86n07snrwdkjmk2c1i13j08xyic34hdw-pinned-file.txt narinfo_key=86n07snrwdkjmk2c1i13j08xyic34hdw.narinfo11432026/10/06 21:14:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures11442026/10/06 21:14:08 INFO Garbage collection started11452026/10/06 21:14:08 INFO Aborted multipart uploads count=0 kept=011462026/10/06 21:14:08 WARN Force mode enabled - objects will be deleted immediately without grace period11472026/10/06 21:14:08 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=011482026/10/06 21:14:08 INFO Vacuumed table table=pending_closures11492026/10/06 21:14:08 INFO Vacuumed table table=pending_objects11502026/10/06 21:14:08 INFO Vacuumed table table=multipart_uploads11512026/10/06 21:14:08 INFO Vacuumed table table=closures11522026/10/06 21:14:08 INFO Vacuumed table table=objects1153--- PASS: TestConnectWaitsForAPeerMigration (6.65s)1154=== CONT TestCreatePin_ReservedPins11552026/10/06 21:14:08 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1156--- PASS: TestReadProxyNarinfo (2.49s)1157=== CONT TestPresentNotReportedWhileGCDeletesClosure11582026/10/06 21:14:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49225/oidc1159--- PASS: TestReadProxyInvalidPath (3.24s)1160=== CONT TestPresentReportsOnlyClosureRoots11612026/10/06 21:14:08 INFO Starting HTTP server address=/nix/var/nix/builds/nix-25968-2128199257/TestProxyHeadersOnlyTrustedOnSocket2686711469/001/proxy.sock11622026/10/06 21:14:08 INFO Starting HTTP server address=127.0.0.1:4923211632026/10/06 21:14:08 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11642026/10/06 21:14:08 INFO Shutdown signal received, draining in-flight requests timeout=10s1165=== CONT TestOrphanedObjectsGCStressTest1166--- PASS: TestProxyHeadersOnlyTrustedOnSocket (3.02s)1167--- PASS: TestReadProxyNarStreaming (3.42s)1168=== CONT TestOrphanedObjectsGC1169--- PASS: TestReadProxyContentNegotiation (2.86s)1170=== CONT TestObjectStatsTrigger1171--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.04s)1172=== CONT TestCacheConfigHandler1173=== RUN TestCacheConfigHandler/full_config,_no_issuer1174=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1175=== RUN TestCacheConfigHandler/no_cache_url_configured1176=== PAUSE TestCacheConfigHandler/no_cache_url_configured1177=== RUN TestCacheConfigHandler/no_signing_keys1178=== PAUSE TestCacheConfigHandler/no_signing_keys1179=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1180=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1181=== CONT TestClientIntegration11822026/10/06 21:14:09 INFO Received uploads request method=POST path=/api/pending_closures11832026/10/06 21:14:09 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/06 21:14:10 INFO Received cleanup request method=DELETE path=/api/pending_closures1185=== NAME TestPinProtectsFromGC1186 client_integration_test.go:840: Pin successfully protected closure from garbage collection1187--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.84s)1188=== CONT TestClientWithDependencies1189--- PASS: TestPinProtectsFromGC (7.53s)1190=== CONT TestClientErrorHandling1191=== RUN TestClientErrorHandling/InvalidStorePath1192=== PAUSE TestClientErrorHandling/InvalidStorePath1193=== RUN TestClientErrorHandling/InvalidAuthToken1194=== PAUSE TestClientErrorHandling/InvalidAuthToken1195=== RUN TestClientErrorHandling/ServerNotAvailable1196=== PAUSE TestClientErrorHandling/ServerNotAvailable1197=== CONT TestClientMultipleUploads11982026/10/06 21:14:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11992026/10/06 21:14:10 WARN Refused reserved pin name=worker-x86_64-linux12002026/10/06 21:14:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12012026/10/06 21:14:10 INFO Received create pin request method=POST path=/api/pins/my-app12022026/10/06 21:14:10 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1203--- PASS: TestCreatePin_ReservedPins (2.08s)1204=== CONT TestClientCADerivations1205--- PASS: TestPresentReportsOnlyClosureRoots (2.30s)1206=== CONT TestCacheStatsHandler1207--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.74s)1208=== CONT TestParseSize1209--- PASS: TestParseSize (0.00s)1210=== CONT TestPush_RejectsBadRequests1211--- PASS: TestObjectStatsTrigger (2.43s)1212=== CONT TestService_Rustfstest1213=== NAME TestOrphanedObjectsGC1214 orphaned_objects_gc_test.go:290: GC Test Summary:1215 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1216 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1217 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1218 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1219 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1220--- PASS: TestOrphanedObjectsGC (3.08s)1221=== CONT TestPresignedUploadRegisteredBeforeCommit1222=== NAME TestClientIntegration1223 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-25968-2128199257/TestClientIntegration3835695324/002/store/hyzmdlnd1pfy4d8ijnjj44zfv89wxnzi-test-file.txt12242026/10/06 21:14:12 INFO Received push request method=POST path=/api/pushes12252026/10/06 21:14:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12262026/10/06 21:14:12 INFO Uploading hyzmdlnd1pfy4d8ijnjj44zfv89wxnzi-test-file.txt (152B)12272026/10/06 21:14:12 WARN Failed to register uploaded object key=hyzmdlnd1pfy4d8ijnjj44zfv89wxnzi.ls error="server returned 404: 404 page not found\n"12282026/10/06 21:14:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12292026/10/06 21:14:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12302026/10/06 21:14:12 INFO Signed narinfos id=1 count=112312026/10/06 21:14:12 INFO Uploading 1 narinfos12322026/10/06 21:14:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12332026/10/06 21:14:12 WARN Failed to register uploaded object key=hyzmdlnd1pfy4d8ijnjj44zfv89wxnzi.narinfo error="server returned 404: 404 page not found\n"12342026/10/06 21:14:12 INFO Upload complete. (308ms)12352026/10/06 21:14:12 INFO All 1 paths already cached1236 client_integration_test.go:312: Retrieved narinfo from S3:1237 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientIntegration3835695324/002/store/hyzmdlnd1pfy4d8ijnjj44zfv89wxnzi-test-file.txt1238 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1239 Compression: zstd1240 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11241 NarSize: 1521242 References: 1243 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11244 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1245 client_integration_test.go:313: Decompressed .ls content (64 bytes):1246 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1247 client_integration_test.go:316: Testing garbage collection...12482026/10/06 21:14:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures12492026/10/06 21:14:12 INFO Garbage collection started12502026/10/06 21:14:13 INFO Aborted multipart uploads count=0 kept=012512026/10/06 21:14:13 WARN Force mode enabled - objects will be deleted immediately without grace period1252=== NAME TestClientMultipleUploads1253 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-25968-2128199257/TestClientMultipleUploads3641883990/001/store/yl5pab8schg9jcsvjxpd6ca6blybl59v-test-file-0.txt12542026/10/06 21:14:13 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=012552026/10/06 21:14:13 INFO Vacuumed table table=pending_closures12562026/10/06 21:14:13 INFO Vacuumed table table=pending_objects12572026/10/06 21:14:13 INFO Vacuumed table table=multipart_uploads12582026/10/06 21:14:13 INFO Vacuumed table table=closures12592026/10/06 21:14:13 INFO Vacuumed table table=objects1260 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-25968-2128199257/TestClientMultipleUploads3641883990/001/store/fdrpwzcf416p3504s9dlas9vxbrgbqzq-test-file-1.txt1261=== NAME TestClientWithDependencies1262 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-25968-2128199257/TestClientWithDependencies1469179952/001/store/wcrly3kpf5vfxdmsn2kknqrf45am4385-test-script1263 client_integration_test.go:615: Found 1 dependencies (including self)1264=== NAME TestClientMultipleUploads1265 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-25968-2128199257/TestClientMultipleUploads3641883990/001/store/w7ay17f0amicivqgi8yl2lzmyf3ypi4g-test-file-2.txt12662026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes12672026/10/06 21:14:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12682026/10/06 21:14:13 INFO Uploading wcrly3kpf5vfxdmsn2kknqrf45am4385-test-script (136B)12692026/10/06 21:14:13 INFO Received push request method=POST path=/api/pushes12702026/10/06 21:14:13 WARN Failed to register uploaded object key=wcrly3kpf5vfxdmsn2kknqrf45am4385.ls error="server returned 404: 404 page not found\n"12712026/10/06 21:14:13 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1272--- PASS: TestCacheStatsHandler (2.72s)1273=== CONT TestCompletedNarNotReofferedAcrossClosures12742026/10/06 21:14:13 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12752026/10/06 21:14:13 INFO Uploading w7ay17f0amicivqgi8yl2lzmyf3ypi4g-test-file-2.txt (160B)12762026/10/06 21:14:13 INFO Uploading fdrpwzcf416p3504s9dlas9vxbrgbqzq-test-file-1.txt (160B)12772026/10/06 21:14:13 INFO Uploading yl5pab8schg9jcsvjxpd6ca6blybl59v-test-file-0.txt (160B)12782026/10/06 21:14:13 WARN Failed to register uploaded object key=log/3lk98c05p6fpandd5sb9cksgwad9hj6a-test-script.drv error="server returned 404: 404 page not found\n"12792026/10/06 21:14:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/10/06 21:14:13 INFO Signed narinfos id=1 count=112812026/10/06 21:14:13 INFO Uploading 1 narinfos12822026/10/06 21:14:13 WARN Failed to register uploaded object key=yl5pab8schg9jcsvjxpd6ca6blybl59v.ls error="server returned 404: 404 page not found\n"12832026/10/06 21:14:13 WARN Failed to register uploaded object key=w7ay17f0amicivqgi8yl2lzmyf3ypi4g.ls error="server returned 404: 404 page not found\n"12842026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/1/complete12852026/10/06 21:14:13 WARN Failed to register uploaded object key=fdrpwzcf416p3504s9dlas9vxbrgbqzq.ls error="server returned 404: 404 page not found\n"12862026/10/06 21:14:13 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12872026/10/06 21:14:13 WARN Failed to register uploaded object key=wcrly3kpf5vfxdmsn2kknqrf45am4385.narinfo error="server returned 404: 404 page not found\n"12882026/10/06 21:14:13 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12892026/10/06 21:14:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12902026/10/06 21:14:13 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12912026/10/06 21:14:13 INFO Signed narinfos id=1 count=312922026/10/06 21:14:13 INFO Uploading 3 narinfos12932026/10/06 21:14:13 INFO Upload complete. (307ms)1294=== NAME TestClientWithDependencies1295 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-25968-2128199257/TestClientWithDependencies1469179952/001/store) requires matching store prefix12962026/10/06 21:14:13 WARN Failed to register uploaded object key=w7ay17f0amicivqgi8yl2lzmyf3ypi4g.narinfo error="server returned 404: 404 page not found\n"12972026/10/06 21:14:13 WARN Failed to register uploaded object key=yl5pab8schg9jcsvjxpd6ca6blybl59v.narinfo error="server returned 404: 404 page not found\n"12982026/10/06 21:14:13 WARN Failed to register uploaded object key=fdrpwzcf416p3504s9dlas9vxbrgbqzq.narinfo error="server returned 404: 404 page not found\n"12992026/10/06 21:14:13 INFO Received complete push request method=POST path=/api/pushes/1/complete13002026/10/06 21:14:13 INFO Upload complete. (356ms)1301=== NAME TestClientMultipleUploads1302 client_integration_test.go:369: Uploaded 3 paths in 437.622041ms1303--- PASS: TestClientWithDependencies (3.81s)1304=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1305--- PASS: TestClientMultipleUploads (3.80s)1306=== CONT TestRedundantMultipartUpload1307=== NAME TestClientCADerivations1308 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-25968-2128199257/TestClientCADerivations1776192266/001/store/3zv5jh5hd3xp6czh0j9r3lhi0drbx2bx-ca-test1309 client_ca_test.go:139: Found 1 dependencies (including self)1310=== RUN TestPush_RejectsBadRequests/no_roots1311=== PAUSE TestPush_RejectsBadRequests/no_roots1312=== RUN TestPush_RejectsBadRequests/no_objects1313=== PAUSE TestPush_RejectsBadRequests/no_objects1314=== RUN TestPush_RejectsBadRequests/bad_root1315=== PAUSE TestPush_RejectsBadRequests/bad_root1316=== RUN TestPush_RejectsBadRequests/root_not_in_objects1317=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1318=== CONT TestPush_SignsNarinfosOfItsPendingObjects13192026/10/06 21:14:14 INFO Received push request method=POST path=/api/pushes13202026/10/06 21:14:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13212026/10/06 21:14:14 INFO Uploading 3zv5jh5hd3xp6czh0j9r3lhi0drbx2bx-ca-test (144B)13222026/10/06 21:14:14 WARN Failed to register uploaded object key=3zv5jh5hd3xp6czh0j9r3lhi0drbx2bx.ls error="server returned 404: 404 page not found\n"13232026/10/06 21:14:14 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13242026/10/06 21:14:14 WARN Failed to register uploaded object key=log/izfrv55daisd8y3vjy3l17jq1zr8l2nf-ca-test.drv error="server returned 404: 404 page not found\n"13252026/10/06 21:14:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13262026/10/06 21:14:14 INFO Signed narinfos id=1 count=113272026/10/06 21:14:14 INFO Uploading 1 narinfos13282026/10/06 21:14:14 INFO Received complete push request method=POST path=/api/pushes/1/complete13292026/10/06 21:14:14 WARN Failed to register uploaded object key=3zv5jh5hd3xp6czh0j9r3lhi0drbx2bx.narinfo error="server returned 404: 404 page not found\n"13302026/10/06 21:14:14 INFO Upload complete. (320ms)1331=== NAME TestClientCADerivations1332 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestClientCADerivations1776192266/001/store/3zv5jh5hd3xp6czh0j9r3lhi0drbx2bx-ca-test1333 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1334 Compression: zstd1335 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1336 NarSize: 1441337 References: 1338 Deriver: /nix/var/nix/builds/nix-25968-2128199257/TestClientCADerivations1776192266/001/store/izfrv55daisd8y3vjy3l17jq1zr8l2nf-ca-test.drv1339 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1340 client_ca_test.go:185: Checking for realisation files in S3...1341 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1342 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1343--- PASS: TestService_Rustfstest (2.62s)1344=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1345=== NAME TestClientCADerivations1346 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket53?endpoint=http://localhost:65424®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-25968-2128199257/TestClientCADerivations1776192266/001/store'1347 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11348--- PASS: TestClientCADerivations (4.53s)1349=== CONT TestIsValidUploadKey1350=== RUN TestIsValidUploadKey/narinfo1351=== PAUSE TestIsValidUploadKey/narinfo1352=== RUN TestIsValidUploadKey/nar_zst1353=== PAUSE TestIsValidUploadKey/nar_zst1354=== RUN TestIsValidUploadKey/nar_xz1355=== PAUSE TestIsValidUploadKey/nar_xz1356=== RUN TestIsValidUploadKey/nar_plain1357=== PAUSE TestIsValidUploadKey/nar_plain1358=== RUN TestIsValidUploadKey/listing1359=== PAUSE TestIsValidUploadKey/listing1360=== RUN TestIsValidUploadKey/build_log1361=== PAUSE TestIsValidUploadKey/build_log1362=== RUN TestIsValidUploadKey/build_log_home-manager_file1363=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1364=== RUN TestIsValidUploadKey/build_log_plus_in_name1365=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1366=== RUN TestIsValidUploadKey/build_log_question_mark1367=== PAUSE TestIsValidUploadKey/build_log_question_mark1368=== RUN TestIsValidUploadKey/build_log_equals1369=== PAUSE TestIsValidUploadKey/build_log_equals1370=== RUN TestIsValidUploadKey/realisation1371=== PAUSE TestIsValidUploadKey/realisation1372=== RUN TestIsValidUploadKey/realisation_plus_in_output1373=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1374=== RUN TestIsValidUploadKey/nix-cache-info1375=== PAUSE TestIsValidUploadKey/nix-cache-info1376=== RUN TestIsValidUploadKey/index.html1377=== PAUSE TestIsValidUploadKey/index.html1378=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1379=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1380=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1381=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1382=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1383=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1384=== RUN TestIsValidUploadKey/traversal1385=== PAUSE TestIsValidUploadKey/traversal1386=== RUN TestIsValidUploadKey/traversal_nar1387=== PAUSE TestIsValidUploadKey/traversal_nar1388=== RUN TestIsValidUploadKey/absolute1389=== PAUSE TestIsValidUploadKey/absolute1390=== RUN TestIsValidUploadKey/empty_key1391=== PAUSE TestIsValidUploadKey/empty_key1392=== RUN TestIsValidUploadKey/unknown_type1393=== PAUSE TestIsValidUploadKey/unknown_type1394=== CONT TestPendingClosureWriteTimeout1395=== RUN TestPendingClosureWriteTimeout/empty1396=== PAUSE TestPendingClosureWriteTimeout/empty1397=== RUN TestPendingClosureWriteTimeout/400_objects1398=== PAUSE TestPendingClosureWriteTimeout/400_objects1399=== RUN TestPendingClosureWriteTimeout/670k_objects1400=== PAUSE TestPendingClosureWriteTimeout/670k_objects1401=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1402=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1403=== CONT TestProxyWriteTimeout1404=== RUN TestProxyWriteTimeout/narinfo1405=== PAUSE TestProxyWriteTimeout/narinfo1406=== RUN TestProxyWriteTimeout/1_GiB_nar1407=== PAUSE TestProxyWriteTimeout/1_GiB_nar1408=== RUN TestProxyWriteTimeout/10_GiB_nar1409=== PAUSE TestProxyWriteTimeout/10_GiB_nar1410=== RUN TestProxyWriteTimeout/unknown_size1411=== PAUSE TestProxyWriteTimeout/unknown_size1412=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14132026/10/06 21:14:14 INFO Received uploads request method=POST path=/api/pending_closures14142026/10/06 21:14:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01415=== NAME TestClientIntegration1416 client_integration_test.go:323: Objects in database after GC:1417 client_integration_test.go:323: Successfully deleted all objects with GC --force14182026/10/06 21:14:15 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14192026/10/06 21:14:15 INFO Received uploads request method=POST path=/api/pending_closures1420--- PASS: TestClientIntegration (5.37s)1421=== CONT TestUploadHandlersRejectInvalidKeys1422=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1423=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1424=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1425=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1426=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1427=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1428=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1429=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1430=== CONT TestSkippedUploadsHandler14312026/10/06 21:14:15 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001432--- PASS: TestSkippedUploadsHandler (0.00s)1433=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1434--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.81s)1435=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14362026/10/06 21:14:16 INFO Aborted multipart uploads count=1 kept=014372026/10/06 21:14:16 INFO Received cleanup request method=DELETE path=/api/pending_closures14382026/10/06 21:14:16 INFO Aborted multipart uploads count=1 kept=01439--- PASS: TestPendingCleanupUsesOneCutoff (8.08s)1440=== CONT TestPush_CompleteCommitsEveryRoot14412026/10/06 21:14:16 INFO Received uploads request method=POST path=/api/pending_closures14422026/10/06 21:14:16 INFO Received uploads request method=POST path=/api/pending_closures14432026/10/06 21:14:16 INFO Received uploads request method=POST path=/api/pending_closures14442026/10/06 21:14:17 INFO Received uploads request method=POST path=/api/pending_closures14452026/10/06 21:14:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14462026/10/06 21:14:17 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmZiNDhmMWQ3LTYzOWItNDIyZi1iYTFmLTg3NmRiNDNhMGUwNngxNzkxMzIxMjU2NzE1MTM5MDAw14472026/10/06 21:14:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmZiNDhmMWQ3LTYzOWItNDIyZi1iYTFmLTg3NmRiNDNhMGUwNngxNzkxMzIxMjU2NzE1MTM5MDAw parts=11448--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.40s)1449=== CONT TestReadProxyRangeRequest14502026/10/06 21:14:17 INFO Received push request method=POST path=/api/pushes14512026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14522026/10/06 21:14:18 INFO Signed narinfos id=1 count=114532026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14542026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14552026/10/06 21:14:18 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14562026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14572026/10/06 21:14:18 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14582026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14592026/10/06 21:14:18 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114602026/10/06 21:14:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14612026/10/06 21:14:18 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1462--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.98s)1463=== CONT TestReadRedirectUsesPublicS3URL14642026/10/06 21:14:18 INFO Received uploads request method=POST path=/api/pending_closures1465--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.99s)1466=== CONT TestReadRedirectKeepsNarinfoProxied14672026/10/06 21:14:18 INFO Received push request method=POST path=/api/pushes1468--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.07s)1469=== CONT TestCompleteMultipartUnregistered14702026/10/06 21:14:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14712026/10/06 21:14:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmZlYTQ5NjYyLWI4NTQtNDUxYi05YzI0LTZkMzNiMjc3MTExNHgxNzkxMzIxMjU2MjMxMjQ3MDAw parts=1214722026/10/06 21:14:19 INFO Received uploads request method=POST path=/api/pending_closures14732026/10/06 21:14:19 INFO Received uploads request method=POST path=/api/pending_closures14742026/10/06 21:14:19 INFO Received uploads request method=POST path=/api/pending_closures14752026/10/06 21:14:20 INFO Received push request method=POST path=/api/pushes14762026/10/06 21:14:20 INFO Received complete push request method=POST path=/api/pushes/1/complete14772026/10/06 21:14:20 INFO Received push request method=POST path=/api/pushes14782026/10/06 21:14:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14792026/10/06 21:14:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14802026/10/06 21:14:20 INFO Aborted multipart uploads count=0 kept=014812026/10/06 21:14:20 WARN Force mode enabled - objects will be deleted immediately without grace period14822026/10/06 21:14:20 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=014832026/10/06 21:14:20 INFO Vacuumed table table=pending_closures14842026/10/06 21:14:20 INFO Vacuumed table table=pending_objects14852026/10/06 21:14:20 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLjRkZGEzZmIwLTQ0YWUtNDRkNi1iYzgwLTAyNWJlNjJhNDY5M3gxNzkxMzIxMjU3MzA5MzEwMDAw parts=1214862026/10/06 21:14:20 INFO Received uploads request method=POST path=/api/pending_closures1487--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.88s)1488=== CONT TestService_createPendingClosureHandler14892026/10/06 21:14:20 INFO Vacuumed table table=multipart_uploads14902026/10/06 21:14:20 INFO Vacuumed table table=closures14912026/10/06 21:14:20 INFO Received push request method=POST path=/api/pushes14922026/10/06 21:14:20 INFO Vacuumed table table=objects14932026/10/06 21:14:20 INFO Received complete push request method=POST path=/api/pushes/2/complete1494--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (5.62s)1495=== CONT TestService_cleanupPendingClosuresHandler14962026/10/06 21:14:20 INFO Received complete push request method=POST path=/api/pushes/1/complete1497--- PASS: TestPush_CompleteCommitsEveryRoot (4.70s)1498=== CONT TestService_verifyS3Integrity1499=== NAME TestOrphanedObjectsGCStressTest1500 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1501 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1502--- PASS: TestReadProxyRangeRequest (4.33s)1503=== CONT TestUploadHandlersRejectOversizedBody1504=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1505=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1506=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1507=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1508=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1509=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1510=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15112026/10/06 21:14:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15122026/10/06 21:14:22 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmUzYTIxYjY4LWUyY2YtNDgyNy1iZTE3LWQ1YzIyMjgyZjczMXgxNzkxMzIxMjU5NDQ4MTUzMDAw error="Get \"http://127.0.0.1:1/bucket58/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15132026/10/06 21:14:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmVlYmU1MTZjLTQ1ZGYtNGJjZi05YTVkLTc5YjliYzgwNTg2OXgxNzkxMzIxMjU5NDA5MzQ1MDAw parts=1215142026/10/06 21:14:22 INFO Received cleanup request method=DELETE path=/api/pending_closures15152026/10/06 21:14:22 INFO Aborted multipart uploads count=1 kept=01516--- PASS: TestRedundantMultipartUpload (8.12s)1517=== CONT TestService_AuthMiddleware_OIDC15182026/10/06 21:14:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49476/oidc1519--- PASS: TestReadRedirectUsesPublicS3URL (4.28s)1520=== CONT TestService_ReadScope_PublicByDefault1521--- PASS: TestReadRedirectKeepsNarinfoProxied (4.19s)1522=== CONT TestService_ReadAuthMiddleware15232026/10/06 21:14:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15242026/10/06 21:14:23 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1525--- PASS: TestCompleteMultipartUnregistered (4.00s)1526=== CONT TestService_AuthMiddleware_MTLSProxyHeader15272026/10/06 21:14:24 INFO Received cleanup request method=DELETE path=/api/pending_closures15282026/10/06 21:14:24 INFO Aborted multipart uploads count=0 kept=015292026/10/06 21:14:24 INFO Received uploads request method=POST path=/api/pending_closures15302026/10/06 21:14:24 INFO Received cleanup request method=DELETE path=/api/pending_closures15312026/10/06 21:14:24 INFO Aborted multipart uploads count=1 kept=015322026/10/06 21:14:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15332026-10-06 21:14:24.327 UTC [28923] ERROR: Closure does not exist: id=115342026-10-06 21:14:24.327 UTC [28923] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15352026-10-06 21:14:24.327 UTC [28923] STATEMENT: -- name: CommitPendingClosure :exec1536 SELECT commit_pending_closure($1::bigint)1537 1538--- PASS: TestService_cleanupPendingClosuresHandler (3.67s)1539=== CONT TestServerTLSConfig1540=== RUN TestServerTLSConfig/no_client_CA1541=== PAUSE TestServerTLSConfig/no_client_CA1542=== RUN TestServerTLSConfig/missing_CA_file1543=== PAUSE TestServerTLSConfig/missing_CA_file1544=== RUN TestServerTLSConfig/not_a_PEM_file1545=== PAUSE TestServerTLSConfig/not_a_PEM_file1546=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded15472026/10/06 21:14:24 INFO Received uploads request method=POST path=/api/pending_closures15482026/10/06 21:14:24 INFO Received uploads request method=POST path=/api/pending_closures15492026/10/06 21:14:24 INFO Received uploads request method=POST path=/api/pending_closures15502026/10/06 21:14:25 INFO Received uploads request method=POST path=/api/pending_closures15512026/10/06 21:14:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15522026/10/06 21:14:25 WARN mTLS auth: bound subjects configured but subject DN unavailable15532026/10/06 21:14:25 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1554--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.88s)1555=== CONT TestMultipartCleanup15562026/10/06 21:14:25 WARN Rate limiter enabled after throttle name=s3-test rate=515572026/10/06 21:14:25 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1558=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1559 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101560 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001561--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.85s)1562=== CONT TestService_RequireScope_OIDC15632026/10/06 21:14:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49523/oidc1564=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1565=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1566=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1567=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1568=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1569=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1570=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1571=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1572=== CONT TestMetricsInventory1573=== NAME TestOrphanedObjectsGCStressTest1574 orphaned_objects_gc_test.go:509: Stress test completed successfully:1575 orphaned_objects_gc_test.go:510: - Active objects preserved: 201576 orphaned_objects_gc_test.go:511: - Objects deleted: 2101577 orphaned_objects_gc_test.go:512: - Total GC'd: 2101578--- PASS: TestOrphanedObjectsGCStressTest (17.62s)1579=== CONT TestService_NativeMTLS1580--- PASS: TestService_ReadScope_PublicByDefault (4.29s)1581=== CONT TestNARDeduplicationMetadataUploadBug15822026/10/06 21:14:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15832026/10/06 21:14:26 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLmJlNjQ2ZTI4LWYyOTMtNDVkMC05ZTZkLWQ1YmQ3NzcwMTc1OXgxNzkxMzIxMjY0NjQ4MDQ1MDAw parts=1015842026/10/06 21:14:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15852026/10/06 21:14:26 INFO Completed upload id=115862026/10/06 21:14:26 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015872026/10/06 21:14:26 INFO Received uploads request method=POST path=/api/pending_closures15882026/10/06 21:14:26 INFO Starting cleanup of old closures method=DELETE path=/api/closures15892026/10/06 21:14:26 INFO Aborted multipart uploads count=0 kept=015902026/10/06 21:14:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015912026/10/06 21:14:26 INFO Vacuumed table table=pending_closures15922026/10/06 21:14:26 INFO Vacuumed table table=pending_objects15932026/10/06 21:14:27 INFO Vacuumed table table=multipart_uploads15942026/10/06 21:14:27 INFO Vacuumed table table=closures15952026/10/06 21:14:27 INFO Vacuumed table table=objects15962026/10/06 21:14:27 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001597--- PASS: TestService_createPendingClosureHandler (6.52s)1598=== CONT TestGCEndsOnShutdown/before_the_run1599--- PASS: TestService_ReadAuthMiddleware (4.36s)1600=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16012026/10/06 21:14:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16022026/10/06 21:14:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2FiMGIxMGYtOWRmNy00MGVhLTk2YjctNTZjYTQ0NTNjNjEwLjRlNmU4YTg1LTlmNTItNDA0Ny05MTU4LTliNGIzOGY0Yjk4ZXgxNzkxMzIxMjY1MTA2MzA1MDAw parts=1016032026/10/06 21:14:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16042026/10/06 21:14:27 INFO Completed upload id=116052026/10/06 21:14:27 INFO Received uploads request method=POST path=/api/pending_closures16062026/10/06 21:14:27 INFO Received uploads request method=POST path=/api/pending_closures16072026/10/06 21:14:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16082026/10/06 21:14:27 WARN Found objects in DB but missing from S3, will re-upload count=11609--- PASS: TestService_verifyS3Integrity (6.50s)1610=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1611--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.35s)1612=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16132026/10/06 21:14:28 INFO Received uploads request method=POST path=/api/pending_closures1614--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (4.09s)1615=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16162026/10/06 21:14:29 INFO Received uploads request method=POST path=/api/pending_closures16172026/10/06 21:14:29 INFO Received cleanup request method=DELETE path=/api/pending_closures16182026/10/06 21:14:29 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16192026/10/06 21:14:29 INFO Aborted multipart uploads count=0 kept=116202026/10/06 21:14:29 INFO Received cleanup request method=DELETE path=/api/pending_closures16212026/10/06 21:14:29 INFO Aborted multipart uploads count=1 kept=01622--- PASS: TestMultipartCleanup (3.92s)1623=== CONT TestResolveDBConnectionString/flag_wins1624=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1625=== CONT TestResolveDBConnectionString/nothing_configured1626=== CONT TestResolveDBConnectionString/missing_file_is_an_error1627=== CONT TestResolveDBConnectionString/file_when_flag_empty1628=== CONT TestParseSingleRange/none1629=== CONT TestParseSingleRange/open-ended1630=== CONT TestParseSingleRange/start_far_past_EOF1631=== CONT TestParseSingleRange/start_past_EOF1632=== CONT TestParseSingleRange/single_byte1633=== CONT TestParseSingleRange/suffix_exceeds_size1634=== CONT TestParseSingleRange/suffix1635=== CONT TestParseSingleRange/end_clamped_to_size1636=== CONT TestParseSingleRange/malformed_both_empty1637=== CONT TestParseSingleRange/closed1638=== CONT TestParseSingleRange/malformed_end_before_start1639=== CONT TestParseSingleRange/multi-range_ignored1640=== CONT TestParseSingleRange/malformed_no_dash1641=== CONT TestParseSingleRange/unknown_unit1642--- PASS: TestParseSingleRange (0.00s)1643 --- PASS: TestParseSingleRange/none (0.00s)1644 --- PASS: TestParseSingleRange/open-ended (0.00s)1645 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1646 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1647 --- PASS: TestParseSingleRange/single_byte (0.00s)1648 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1649 --- PASS: TestParseSingleRange/suffix (0.00s)1650 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1651 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1652 --- PASS: TestParseSingleRange/closed (0.00s)1653 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1654 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1655 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1656 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1657=== CONT TestIsValidCachePath/narinfo1658=== CONT TestIsValidCachePath/index.html1659=== CONT TestIsValidCachePath/short_hash1660=== CONT TestIsValidCachePath/wrong_extension1661=== CONT TestIsValidCachePath/leading_slash1662=== CONT TestIsValidCachePath/empty1663=== CONT TestIsValidCachePath/random_path1664=== CONT TestIsValidCachePath/invalid_char_u1665=== CONT TestIsValidCachePath/invalid_char_e1666=== CONT TestIsValidCachePath/traversal_in_middle1667=== CONT TestIsValidCachePath/traversal_parent1668=== CONT TestIsValidCachePath/nar_uncompressed1669=== CONT TestIsValidCachePath/nix-cache-info1670=== CONT TestIsValidCachePath/realisation1671=== CONT TestIsValidCachePath/log1672=== CONT TestIsValidCachePath/ls1673=== CONT TestIsValidCachePath/nar_xz1674=== CONT TestIsValidCachePath/nar_bz21675=== CONT TestIsValidCachePath/nar_zst1676=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1677--- PASS: TestIsValidCachePath (0.00s)1678 --- PASS: TestIsValidCachePath/narinfo (0.00s)1679 --- PASS: TestIsValidCachePath/index.html (0.00s)1680 --- PASS: TestIsValidCachePath/short_hash (0.00s)1681 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1682 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1683 --- PASS: TestIsValidCachePath/empty (0.00s)1684 --- PASS: TestIsValidCachePath/random_path (0.00s)1685 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1686 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1687 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1688 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1689 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1690 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1691 --- PASS: TestIsValidCachePath/realisation (0.00s)1692 --- PASS: TestIsValidCachePath/log (0.00s)1693 --- PASS: TestIsValidCachePath/ls (0.00s)1694 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1695 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1696 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1697 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1698=== CONT TestCacheConfigHandler/full_config,_no_issuer1699=== CONT TestCacheConfigHandler/no_signing_keys1700=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1701=== CONT TestCacheConfigHandler/no_cache_url_configured1702--- PASS: TestCacheConfigHandler (0.00s)1703 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1704 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1705 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1706 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1707=== CONT TestClientErrorHandling/InvalidStorePath1708--- PASS: TestResolveDBConnectionString (0.04s)1709 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1710 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1711 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1712 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1713 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1714--- PASS: TestMetricsInventory (3.52s)1715=== CONT TestClientErrorHandling/ServerNotAvailable17162026/10/06 21:14:30 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/present1717=== RUN TestService_RequireScope_OIDC/builder_may_write1718=== PAUSE TestService_RequireScope_OIDC/builder_may_write1719=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1720=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1721=== RUN TestService_RequireScope_OIDC/ops_may_admin1722=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1723=== RUN TestService_RequireScope_OIDC/ops_may_not_write1724=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1725=== RUN TestService_RequireScope_OIDC/reader_may_not_write1726=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1727=== RUN TestService_RequireScope_OIDC/static_token_may_admin1728=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1729=== RUN TestService_RequireScope_OIDC/static_token_may_write1730=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1731=== RUN TestService_RequireScope_OIDC/reader_may_read1732=== PAUSE TestService_RequireScope_OIDC/reader_may_read1733=== RUN TestService_RequireScope_OIDC/writer_implies_read1734=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1735=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1736=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1737=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1738=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1739=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1740=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1741=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1742=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1743=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1744=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1745=== CONT TestClientErrorHandling/InvalidAuthToken17462026/10/06 21:14:30 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.086919ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17472026/10/06 21:14:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.017794ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17482026/10/06 21:14:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17492026/10/06 21:14:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1750--- PASS: TestService_NativeMTLS (4.07s)1751=== CONT TestPush_RejectsBadRequests/no_roots17522026/10/06 21:14:30 INFO Received push request method=POST path=/api/pushes1753=== CONT TestPush_RejectsBadRequests/bad_root17542026/10/06 21:14:30 INFO Received push request method=POST path=/api/pushes1755=== CONT TestPush_RejectsBadRequests/root_not_in_objects17562026/10/06 21:14:30 INFO Received push request method=POST path=/api/pushes1757=== CONT TestPush_RejectsBadRequests/no_objects17582026/10/06 21:14:30 INFO Received push request method=POST path=/api/pushes1759=== CONT TestIsValidUploadKey/narinfo1760=== CONT TestPendingClosureWriteTimeout/empty1761=== CONT TestIsValidUploadKey/unknown_type1762=== CONT TestIsValidUploadKey/empty_key1763--- PASS: TestPush_RejectsBadRequests (3.07s)1764 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1765 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1766 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1767 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1768=== CONT TestIsValidUploadKey/absolute1769=== CONT TestIsValidUploadKey/traversal_nar1770=== CONT TestIsValidUploadKey/traversal1771=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1772=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1773=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1774=== CONT TestIsValidUploadKey/index.html1775=== CONT TestIsValidUploadKey/nix-cache-info1776=== CONT TestIsValidUploadKey/realisation_plus_in_output1777=== CONT TestIsValidUploadKey/realisation1778=== CONT TestIsValidUploadKey/build_log_equals1779=== CONT TestIsValidUploadKey/build_log_question_mark1780=== CONT TestIsValidUploadKey/build_log_plus_in_name1781=== CONT TestIsValidUploadKey/build_log_home-manager_file1782=== CONT TestIsValidUploadKey/build_log1783=== CONT TestIsValidUploadKey/listing1784=== CONT TestIsValidUploadKey/nar_plain1785=== CONT TestIsValidUploadKey/nar_xz1786=== CONT TestIsValidUploadKey/nar_zst1787--- PASS: TestIsValidUploadKey (0.00s)1788 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1789 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1790 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1791 --- PASS: TestIsValidUploadKey/absolute (0.00s)1792 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1793 --- PASS: TestIsValidUploadKey/traversal (0.00s)1794 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1796 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1797 --- PASS: TestIsValidUploadKey/index.html (0.00s)1798 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1799 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1800 --- PASS: TestIsValidUploadKey/realisation (0.00s)1801 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1802 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1803 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1804 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1805 --- PASS: TestIsValidUploadKey/build_log (0.00s)1806 --- PASS: TestIsValidUploadKey/listing (0.00s)1807 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1808 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1809 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1810=== CONT TestProxyWriteTimeout/narinfo1811=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18122026/10/06 21:14:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=855.636209ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1813{"timestamp":"2026-10-06T21:14:30.930486Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":5,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}1814=== NAME TestNARDeduplicationMetadataUploadBug1815 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-25968-2128199257/TestNARDeduplicationMetadataUploadBug3879395535/001/store/v2zv40nx2sy4a1rdiizw5dgap2rjqmbc-file1.txt18162026/10/06 21:14:31 INFO Aborted multipart uploads count=0 kept=018172026/10/06 21:14:31 WARN Force mode enabled - objects will be deleted immediately without grace period18182026-10-06 21:14:31.428 UTC [29595] ERROR: canceling statement due to user request18192026-10-06 21:14:31.428 UTC [29595] STATEMENT: -- name: MarkStaleObjects :execrows1820 WITH RECURSIVE ct AS (1821 SELECT timezone('UTC', now()) AS now1822 ),1823 closure_reach AS (1824 -- Start with all closure keys1825 SELECT o.key, o.refs1826 FROM objects o1827 INNER JOIN closures c ON o.key = c.key1828 UNION1829 -- Recursively add all referenced objects1830 SELECT o.key, o.refs1831 FROM objects o1832 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1833 ),1834 reachable_objects AS (1835 SELECT DISTINCT key FROM closure_reach1836 ),1837 stale_objects AS (1838 SELECT o.key1839 FROM objects AS o, ct1840 WHERE1841 NOT EXISTS (1842 SELECT 11843 FROM reachable_objects ro1844 WHERE ro.key = o.key1845 )1846 AND NOT EXISTS (1847 SELECT 11848 FROM pending_objects AS po1849 WHERE po.key = o.key1850 )1851 AND o.deleted_at IS NULL -- Only mark fresh objects1852 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1853 FOR UPDATE1854 )1855 UPDATE objects1856 SET1857 deleted_at = ct.now,1858 first_deleted_at = COALESCE(first_deleted_at, ct.now)1859 FROM stale_objects, ct1860 WHERE objects.key = stale_objects.key1861 1862=== CONT TestPendingClosureWriteTimeout/670k_objects1863=== CONT TestPendingClosureWriteTimeout/400_objects1864=== CONT TestProxyWriteTimeout/10_GiB_nar1865=== CONT TestProxyWriteTimeout/unknown_size1866=== CONT TestProxyWriteTimeout/1_GiB_nar1867--- PASS: TestProxyWriteTimeout (0.00s)1868 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1869 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1870 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1871 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1872=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18732026/10/06 21:14:31 INFO Received uploads request method=POST path=/1874=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18752026/10/06 21:14:31 INFO Received request for more parts method=POST path=/1876=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18772026/10/06 21:14:31 INFO Received complete multipart upload request method=POST path=/1878=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18792026/10/06 21:14:31 INFO Received uploads request method=POST path=/1880--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1881 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1882 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1883 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1884 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1885=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18862026/10/06 21:14:31 INFO Received uploads request method=POST path=/18872026/10/06 21:14:31 INFO Received push request method=POST path=/api/pushes18882026/10/06 21:14:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18892026/10/06 21:14:31 INFO Uploading v2zv40nx2sy4a1rdiizw5dgap2rjqmbc-file1.txt (160B)18902026/10/06 21:14:31 WARN Failed to register uploaded object key=v2zv40nx2sy4a1rdiizw5dgap2rjqmbc.ls error="server returned 404: 404 page not found\n"18912026/10/06 21:14:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18922026/10/06 21:14:31 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18932026/10/06 21:14:31 INFO Signed narinfos id=1 count=118942026/10/06 21:14:31 INFO Uploading 1 narinfos18952026/10/06 21:14:31 INFO Received complete push request method=POST path=/api/pushes/1/complete18962026/10/06 21:14:31 WARN Failed to register uploaded object key=v2zv40nx2sy4a1rdiizw5dgap2rjqmbc.narinfo error="server returned 404: 404 page not found\n"18972026/10/06 21:14:31 INFO Upload complete. (224ms)1898=== NAME TestNARDeduplicationMetadataUploadBug1899 metadata_upload_test.go:54: Retrieved narinfo from S3:1900 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestNARDeduplicationMetadataUploadBug3879395535/001/store/v2zv40nx2sy4a1rdiizw5dgap2rjqmbc-file1.txt1901 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1902 Compression: zstd1903 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1904 NarSize: 1601905 References: 1906 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1907 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1908 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1909 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19102026/10/06 21:14:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.536057723s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1911 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-25968-2128199257/TestNARDeduplicationMetadataUploadBug3879395535/001/store/9in93zfaibgsjh50gd34ln3i9mj5bxs9-file2.txt1912=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19132026/10/06 21:14:31 INFO Received request for more parts method=POST path=/1914=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19152026/10/06 21:14:31 INFO Received complete multipart upload request method=POST path=/1916=== CONT TestServerTLSConfig/no_client_CA1917=== CONT TestServerTLSConfig/not_a_PEM_file1918=== CONT TestServerTLSConfig/missing_CA_file1919--- PASS: TestServerTLSConfig (0.00s)1920 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1921 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1922 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1923=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1924=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19252026/10/06 21:14:31 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]1926=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1927=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19282026/10/06 21:14:31 WARN Authentication failed token_preview=eyJhbGciOi...fTwitEgS0A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1929=== CONT TestService_RequireScope_OIDC/builder_may_write1930=== CONT TestService_RequireScope_OIDC/reader_may_read1931=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1932=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19332026/10/06 21:14:31 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]1934=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1935=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1936=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1937=== CONT TestService_RequireScope_OIDC/writer_implies_read1938=== CONT TestService_RequireScope_OIDC/reader_may_not_write1939=== CONT TestService_RequireScope_OIDC/static_token_may_admin1940=== CONT TestService_RequireScope_OIDC/ops_may_admin1941=== CONT TestService_RequireScope_OIDC/ops_may_not_write1942=== CONT TestService_RequireScope_OIDC/static_token_may_write1943=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1944--- PASS: TestService_AuthMiddleware_OIDC (4.19s)1945 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1946 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1947 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1948 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1949--- PASS: TestService_RequireScope_OIDC (4.54s)1950 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1964--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1965 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1966 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1967 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.45s)19682026/10/06 21:14:31 INFO Received push request method=POST path=/api/pushes19692026/10/06 21:14:31 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19702026/10/06 21:14:31 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19712026/10/06 21:14:31 INFO Signed narinfos id=2 count=119722026/10/06 21:14:31 INFO Uploading 1 narinfos19732026/10/06 21:14:31 WARN Failed to register uploaded object key=9in93zfaibgsjh50gd34ln3i9mj5bxs9.ls error="server returned 404: 404 page not found\n"19742026/10/06 21:14:31 INFO Received complete push request method=POST path=/api/pushes/2/complete19752026/10/06 21:14:31 WARN Failed to register uploaded object key=9in93zfaibgsjh50gd34ln3i9mj5bxs9.narinfo error="server returned 404: 404 page not found\n"19762026/10/06 21:14:31 INFO Upload complete. (165ms)1977=== NAME TestNARDeduplicationMetadataUploadBug1978 metadata_upload_test.go:76: Retrieved narinfo from S3:1979 StorePath: /nix/var/nix/builds/nix-25968-2128199257/TestNARDeduplicationMetadataUploadBug3879395535/001/store/9in93zfaibgsjh50gd34ln3i9mj5bxs9-file2.txt1980 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1981 Compression: zstd1982 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1983 NarSize: 1601984 References: 1985 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1986 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1987 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1988 {"version":1,"root":{"type":"regular","size":44}}1989--- PASS: TestNARDeduplicationMetadataUploadBug (5.45s)19902026/10/06 21:14:32 INFO Aborted multipart uploads count=0 kept=019912026/10/06 21:14:32 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/10/06 21:14:32 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:65424/bucket87/?delete=\": context canceled"1993--- PASS: TestGCEndsOnShutdown (0.00s)1994 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.37s)1995 --- PASS: TestGCEndsOnShutdown/before_the_run (4.72s)1996 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.83s)19972026/10/06 21:14:32 INFO Received uploads request method=POST path=/api/pending_closures19982026/10/06 21:14:32 INFO Aborted multipart uploads count=0 kept=019992026/10/06 21:14:32 WARN Force mode enabled - objects will be deleted immediately without grace period20002026/10/06 21:14:32 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=020012026/10/06 21:14:32 INFO Vacuumed table table=pending_closures20022026/10/06 21:14:32 INFO Vacuumed table table=pending_objects20032026/10/06 21:14:32 INFO Vacuumed table table=multipart_uploads20042026/10/06 21:14:32 INFO Vacuumed table table=closures20052026/10/06 21:14:32 INFO Vacuumed table table=objects20062026/10/06 21:14:32 INFO Received uploads request method=POST path=/api/pending_closures20072026/10/06 21:14:32 INFO Aborted multipart uploads count=0 kept=020082026/10/06 21:14:32 WARN Force mode enabled - objects will be deleted immediately without grace period20092026/10/06 21:14:32 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=020102026/10/06 21:14:32 INFO Vacuumed table table=pending_closures20112026/10/06 21:14:32 INFO Vacuumed table table=pending_objects20122026/10/06 21:14:32 INFO Vacuumed table table=multipart_uploads20132026/10/06 21:14:32 INFO Vacuumed table table=closures20142026/10/06 21:14:32 INFO Vacuumed table table=objects2015--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2016 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.18s)2017 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (4.54s)20182026/10/06 21:14:33 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-config20192026/10/06 21:14:33 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=187.33889ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/06 21:14:33 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=369.403417ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20212026/10/06 21:14:33 INFO Received uploads request method=POST path=/api/pending_closures20222026/10/06 21:14:33 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20232026/10/06 21:14:33 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20242026/10/06 21:14:33 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=813.166216ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2025--- PASS: TestPendingClosureWriteTimeout (0.00s)2026 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2027 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2028 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2029 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.92s)20302026/10/06 21:14:34 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.580427378s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 21:14:36 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"20322026/10/06 21:14:36 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-config20332026/10/06 21:14:36 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=183.745011ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 21:14:36 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=401.64244ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 21:14:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.786476ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 21:14:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.699192913s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 21:14:39 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_closures20382026/10/06 21:14:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.438712ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 21:14:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.221456ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 21:14:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=766.578914ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20412026/10/06 21:14:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.720799713s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2042--- PASS: TestClientErrorHandling (0.00s)2043 --- PASS: TestClientErrorHandling/InvalidStorePath (3.70s)2044 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.68s)2045 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.19s)2046PASS2047{"timestamp":"2026-10-06T21:14:42.921873Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49536","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(2)"}2048{"timestamp":"2026-10-06T21:14:42.921979Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49396","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(4)"}20492026-10-06 21:14:46.834 UTC [26509] LOG: received smart shutdown request20502026-10-06 21:14:46.839 UTC [26509] LOG: background worker "logical replication launcher" (PID 26528) exited with exit code 120512026-10-06 21:14:46.905 UTC [26523] LOG: shutting down20522026-10-06 21:14:46.906 UTC [26523] LOG: checkpoint starting: shutdown immediate20532026/10/06 21:14:56 INFO killed process group pgid=2650920542026/10/06 21:14:56 ERROR failed to wait for process error="signal: killed"20552026-10-06 21:14:57.472 UTC [26523] PANIC: could not fsync file "base/17885/4149": No such file or directory2056Running OIDC tests...2057=== RUN TestAudienceForIssuer2058=== PAUSE TestAudienceForIssuer2059=== RUN TestGlobMatch2060=== PAUSE TestGlobMatch2061=== RUN TestValidateToken_ValidToken2062=== PAUSE TestValidateToken_ValidToken2063=== RUN TestValidateToken_WrongAudience2064=== PAUSE TestValidateToken_WrongAudience2065=== RUN TestValidateToken_Expired2066=== PAUSE TestValidateToken_Expired2067=== RUN TestValidateToken_BoundClaimsMismatch2068=== PAUSE TestValidateToken_BoundClaimsMismatch2069=== RUN TestValidateToken_BoundSubjectMismatch2070=== PAUSE TestValidateToken_BoundSubjectMismatch2071=== RUN TestValidateToken_MultipleProviders2072=== PAUSE TestValidateToken_MultipleProviders2073=== RUN TestValidateToken_NoMatchingProvider2074=== PAUSE TestValidateToken_NoMatchingProvider2075=== RUN TestValidateToken_KubernetesServiceAccount2076=== PAUSE TestValidateToken_KubernetesServiceAccount2077=== RUN TestNewValidator_KubernetesRequiresCA2078=== PAUSE TestNewValidator_KubernetesRequiresCA2079=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2080=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2081=== RUN TestPins_ReservedForMatchingRule2082=== PAUSE TestPins_ReservedForMatchingRule2083=== RUN TestPins_TopLevelShorthand2084=== PAUSE TestPins_TopLevelShorthand2085=== RUN TestPins_ConfigValidation2086=== PAUSE TestPins_ConfigValidation2087=== RUN TestScopes_LegacyProviderDefaultsToWrite2088=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2089=== RUN TestScopes_Rules2090=== PAUSE TestScopes_Rules2091=== RUN TestScopes_ConfigValidation2092=== PAUSE TestScopes_ConfigValidation2093=== CONT TestAudienceForIssuer2094=== CONT TestScopes_Rules2095--- PASS: TestAudienceForIssuer (0.00s)2096=== CONT TestScopes_LegacyProviderDefaultsToWrite2097=== CONT TestPins_ConfigValidation2098=== CONT TestPins_TopLevelShorthand2099=== CONT TestPins_ReservedForMatchingRule2100=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2101=== CONT TestValidateToken_BoundClaimsMismatch2102=== CONT TestValidateToken_Expired2103=== CONT TestValidateToken_WrongAudience2104=== CONT TestValidateToken_ValidToken2105--- PASS: TestPins_ConfigValidation (0.01s)2106=== CONT TestGlobMatch2107=== RUN TestGlobMatch/foo_foo2108=== PAUSE TestGlobMatch/foo_foo2109=== RUN TestGlobMatch/foo_bar2110=== PAUSE TestGlobMatch/foo_bar2111=== RUN TestGlobMatch/*_2112=== PAUSE TestGlobMatch/*_2113=== RUN TestGlobMatch/*_anything2114=== PAUSE TestGlobMatch/*_anything2115=== RUN TestGlobMatch/foo*_foo2116=== PAUSE TestGlobMatch/foo*_foo2117=== RUN TestGlobMatch/foo*_foobar2118=== PAUSE TestGlobMatch/foo*_foobar2119=== RUN TestGlobMatch/foo*_bar2120=== PAUSE TestGlobMatch/foo*_bar2121=== RUN TestGlobMatch/*bar_bar2122=== PAUSE TestGlobMatch/*bar_bar2123=== RUN TestGlobMatch/*bar_foobar2124=== PAUSE TestGlobMatch/*bar_foobar2125=== RUN TestGlobMatch/*bar_foo2126=== PAUSE TestGlobMatch/*bar_foo2127=== RUN TestGlobMatch/foo*bar_foobar2128=== PAUSE TestGlobMatch/foo*bar_foobar2129=== RUN TestGlobMatch/foo*bar_foo123bar2130=== PAUSE TestGlobMatch/foo*bar_foo123bar2131=== RUN TestGlobMatch/foo*bar_foobarbaz2132=== PAUSE TestGlobMatch/foo*bar_foobarbaz2133=== RUN TestGlobMatch/*/*_foo/bar2134=== PAUSE TestGlobMatch/*/*_foo/bar2135=== RUN TestGlobMatch/*/*_foo2136=== PAUSE TestGlobMatch/*/*_foo2137=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2138=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2139=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02140=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02141=== RUN TestGlobMatch/refs/*/main_refs/heads/main2142=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2143=== RUN TestGlobMatch/fo?_foo2144=== PAUSE TestGlobMatch/fo?_foo2145=== RUN TestGlobMatch/fo?_fo2146=== PAUSE TestGlobMatch/fo?_fo2147=== RUN TestGlobMatch/fo?_fooo2148=== PAUSE TestGlobMatch/fo?_fooo2149=== RUN TestGlobMatch/?oo_foo2150=== PAUSE TestGlobMatch/?oo_foo2151=== RUN TestGlobMatch/?oo_boo2152=== PAUSE TestGlobMatch/?oo_boo2153=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2154=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2155=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2156=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2157=== CONT TestValidateToken_KubernetesServiceAccount21582026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50064/oidc21592026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50066/oidc2160--- PASS: TestPins_TopLevelShorthand (0.06s)2161=== CONT TestNewValidator_KubernetesRequiresCA2162--- PASS: TestScopes_Rules (0.07s)2163=== CONT TestValidateToken_BoundSubjectMismatch21642026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50068/oidc2165--- PASS: TestValidateToken_ValidToken (0.10s)2166=== CONT TestValidateToken_NoMatchingProvider21672026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50070/oidc2168--- PASS: TestValidateToken_BoundClaimsMismatch (0.16s)2169=== CONT TestValidateToken_MultipleProviders21702026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50072/oidc2171--- PASS: TestValidateToken_WrongAudience (0.18s)2172=== CONT TestScopes_ConfigValidation2173--- PASS: TestScopes_ConfigValidation (0.00s)2174=== CONT TestGlobMatch/foo_foo2175=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2176=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2177=== CONT TestGlobMatch/?oo_boo2178=== CONT TestGlobMatch/?oo_foo2179=== CONT TestGlobMatch/fo?_fooo2180=== CONT TestGlobMatch/fo?_fo2181=== CONT TestGlobMatch/fo?_foo2182=== CONT TestGlobMatch/refs/*/main_refs/heads/main2183=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02184=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2185=== CONT TestGlobMatch/*/*_foo2186=== CONT TestGlobMatch/*/*_foo/bar2187=== CONT TestGlobMatch/foo*bar_foobarbaz2188=== CONT TestGlobMatch/foo*bar_foo123bar2189=== CONT TestGlobMatch/foo*bar_foobar2190=== CONT TestGlobMatch/*bar_foo2191=== CONT TestGlobMatch/*bar_foobar2192=== CONT TestGlobMatch/*bar_bar2193=== CONT TestGlobMatch/foo*_bar2194=== CONT TestGlobMatch/foo*_foobar2195=== CONT TestGlobMatch/foo*_foo2196=== CONT TestGlobMatch/*_anything2197=== CONT TestGlobMatch/*_2198=== CONT TestGlobMatch/foo_bar2199--- PASS: TestGlobMatch (0.00s)2200 --- PASS: TestGlobMatch/foo_foo (0.00s)2201 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2202 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/?oo_boo (0.00s)2204 --- PASS: TestGlobMatch/?oo_foo (0.00s)2205 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2206 --- PASS: TestGlobMatch/fo?_fo (0.00s)2207 --- PASS: TestGlobMatch/fo?_foo (0.00s)2208 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2209 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2210 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2211 --- PASS: TestGlobMatch/*/*_foo (0.00s)2212 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2213 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2214 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2215 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2216 --- PASS: TestGlobMatch/*bar_foo (0.00s)2217 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2218 --- PASS: TestGlobMatch/*bar_bar (0.00s)2219 --- PASS: TestGlobMatch/foo*_bar (0.00s)2220 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2221 --- PASS: TestGlobMatch/foo*_foo (0.00s)2222 --- PASS: TestGlobMatch/*_anything (0.00s)2223 --- PASS: TestGlobMatch/*_ (0.00s)2224 --- PASS: TestGlobMatch/foo_bar (0.00s)22252026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50075/oidc22262026/10/06 21:15:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232227--- PASS: TestPins_ReservedForMatchingRule (0.24s)2228--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.24s)22292026/10/06 21:15:15 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5008022302026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50078/oidc22312026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50082/oidc2232--- PASS: TestValidateToken_Expired (0.28s)2233--- PASS: TestValidateToken_KubernetesServiceAccount (0.29s)2234--- PASS: TestValidateToken_BoundSubjectMismatch (0.24s)22352026/10/06 21:15:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50086/oidc22362026/10/06 21:15:15 http: TLS handshake error from 127.0.0.1:50085: remote error: tls: bad certificate2237--- PASS: TestNewValidator_KubernetesRequiresCA (0.25s)2238--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.31s)22392026/10/06 21:15:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50091/oidc2240--- PASS: TestValidateToken_NoMatchingProvider (0.85s)22412026/10/06 21:15:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50092/oidc22422026/10/06 21:15:16 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50095/oidc2243--- PASS: TestValidateToken_MultipleProviders (0.98s)2244PASS2245Running hook tests...2246=== RUN TestSendPathsEmpty2247=== PAUSE TestSendPathsEmpty2248=== RUN TestQueueEnqueueAndFetch2249=== PAUSE TestQueueEnqueueAndFetch2250=== RUN TestQueueDeduplication2251=== PAUSE TestQueueDeduplication2252=== RUN TestQueueRemove2253=== PAUSE TestQueueRemove2254=== RUN TestQueueFetchBatchLimit2255=== PAUSE TestQueueFetchBatchLimit2256=== RUN TestQueueRetryMovesToBack2257=== PAUSE TestQueueRetryMovesToBack2258=== RUN TestQueueFetchRemoveLifecycle2259=== PAUSE TestQueueFetchRemoveLifecycle2260=== RUN TestQueueConcurrentWriters2261=== PAUSE TestQueueConcurrentWriters2262=== RUN TestQueueRemoveLargeClosure2263=== PAUSE TestQueueRemoveLargeClosure2264=== RUN TestServerClientIntegration2265=== PAUSE TestServerClientIntegration2266=== RUN TestServerQueueError2267=== PAUSE TestServerQueueError2268=== RUN TestGetListenerSocketActivation2269 server_test.go:210: === RUN TestGetListenerSocketActivation2270 --- PASS: TestGetListenerSocketActivation (0.00s)2271 PASS2272 2273--- PASS: TestGetListenerSocketActivation (0.02s)2274=== RUN TestDrainIsolatesPoisonPath2275=== PAUSE TestDrainIsolatesPoisonPath2276=== RUN TestRunNotBlockedByPoisonHead2277=== PAUSE TestRunNotBlockedByPoisonHead2278=== RUN TestDrainGivesUpWhenServerDown2279=== PAUSE TestDrainGivesUpWhenServerDown2280=== RUN TestFailedPathPrunedByLaterClosure2281=== PAUSE TestFailedPathPrunedByLaterClosure2282=== RUN TestWorkerUploadsAndRemoves2283=== PAUSE TestWorkerUploadsAndRemoves2284=== RUN TestWorkerSkipsGCdPaths2285=== PAUSE TestWorkerSkipsGCdPaths2286=== RUN TestWorkerPrunesClosureDeps2287=== PAUSE TestWorkerPrunesClosureDeps2288=== RUN TestDrainTimeout2289=== PAUSE TestDrainTimeout2290=== CONT TestSendPathsEmpty2291--- PASS: TestSendPathsEmpty (0.00s)2292=== CONT TestDrainTimeout2293=== CONT TestServerClientIntegration2294=== CONT TestWorkerSkipsGCdPaths2295=== CONT TestFailedPathPrunedByLaterClosure2296=== CONT TestQueueRetryMovesToBack2297=== CONT TestServerQueueError22982026/10/06 21:15:17 ERROR Failed to queue paths error="permission denied" count=12299=== CONT TestQueueFetchBatchLimit2300=== CONT TestDrainGivesUpWhenServerDown2301=== CONT TestRunNotBlockedByPoisonHead2302=== CONT TestDrainIsolatesPoisonPath2303--- PASS: TestServerQueueError (0.00s)2304=== CONT TestWorkerUploadsAndRemoves2305--- PASS: TestServerClientIntegration (0.00s)2306=== CONT TestQueueDeduplication2307--- PASS: TestQueueDeduplication (0.04s)2308=== CONT TestQueueRemove2309--- PASS: TestQueueFetchBatchLimit (0.04s)2310=== CONT TestQueueEnqueueAndFetch23112026/10/06 21:15:17 INFO Uploading batch count=223122026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=223132026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/a23142026/10/06 21:15:17 INFO Upload queue status pending=323152026/10/06 21:15:17 INFO Uploading batch count=123162026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=123172026/10/06 21:15:17 INFO Uploading batch count=22318--- PASS: TestQueueRetryMovesToBack (0.04s)2319=== CONT TestWorkerPrunesClosureDeps23202026/10/06 21:15:17 INFO Uploading batch count=423212026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=423222026/10/06 21:15:17 INFO Upload queue status pending=223232026/10/06 21:15:17 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-25968-2128199257/TestWorkerSkipsGCdPaths1903938145/002/nonexistent23242026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/b23252026/10/06 21:15:17 INFO Uploading batch count=123262026/10/06 21:15:17 INFO Uploading batch count=223272026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=223282026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/c23292026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainIsolatesPoisonPath932033785/002/bbb23302026/10/06 21:15:17 INFO Uploading batch count=123312026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=123322026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/d23332026/10/06 21:15:17 INFO Upload queue status pending=223342026/10/06 21:15:17 INFO Uploading batch count=123352026/10/06 21:15:17 INFO Uploading batch count=223362026/10/06 21:15:17 INFO Uploading batch count=223372026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=223382026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/e23392026/10/06 21:15:17 INFO Uploading batch count=123402026/10/06 21:15:17 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-25968-2128199257/TestDrainGivesUpWhenServerDown3070054810/002/f23412026/10/06 21:15:17 INFO Uploading batch count=123422026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=123432026/10/06 21:15:17 ERROR Drain finished with paths left in queue remaining=1023442026/10/06 21:15:17 INFO Uploading batch count=123452026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=123462026/10/06 21:15:17 INFO Uploading batch count=123472026/10/06 21:15:17 ERROR Upload failed error="upload failed" count=123482026/10/06 21:15:17 ERROR Drain finished with paths left in queue remaining=12349--- PASS: TestQueueEnqueueAndFetch (0.03s)2350=== CONT TestQueueFetchRemoveLifecycle2351--- PASS: TestFailedPathPrunedByLaterClosure (0.07s)2352=== CONT TestQueueRemoveLargeClosure23532026/10/06 21:15:17 INFO Upload queue status pending=22354--- PASS: TestQueueRemove (0.04s)2355=== CONT TestQueueConcurrentWriters23562026/10/06 21:15:17 INFO Uploading batch count=12357--- PASS: TestDrainGivesUpWhenServerDown (0.08s)2358--- PASS: TestWorkerSkipsGCdPaths (0.08s)2359--- PASS: TestWorkerUploadsAndRemoves (0.09s)2360--- PASS: TestDrainIsolatesPoisonPath (0.09s)2361--- PASS: TestWorkerPrunesClosureDeps (0.07s)2362--- PASS: TestQueueFetchRemoveLifecycle (0.04s)2363--- PASS: TestQueueRemoveLargeClosure (0.11s)23642026/10/06 21:15:17 ERROR Upload failed error="context deadline exceeded" count=223652026/10/06 21:15:17 ERROR Drain finished with paths left in queue remaining=42366--- PASS: TestDrainTimeout (0.26s)2367--- PASS: TestQueueConcurrentWriters (0.61s)23682026/10/06 21:15:18 INFO Uploading batch count=123692026/10/06 21:15:18 INFO Uploading batch count=123702026/10/06 21:15:18 INFO Uploading batch count=123712026/10/06 21:15:18 ERROR Upload failed error="upload failed" count=123722026/10/06 21:15:18 INFO Uploading batch count=123732026/10/06 21:15:18 ERROR Upload failed error="upload failed" count=123742026/10/06 21:15:18 INFO Uploading batch count=123752026/10/06 21:15:18 ERROR Upload failed error="upload failed" count=123762026/10/06 21:15:18 INFO Uploading batch count=123772026/10/06 21:15:18 ERROR Upload failed error="upload failed" count=123782026/10/06 21:15:18 ERROR Drain finished with paths left in queue remaining=12379--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2380PASS2381Running signing tests...2382=== RUN TestExternalSigner2383=== PAUSE TestExternalSigner2384=== RUN TestExternalSignerWrongPublicKey2385=== PAUSE TestExternalSignerWrongPublicKey2386=== RUN TestExternalSignerErrors2387=== PAUSE TestExternalSignerErrors2388=== RUN TestExternalSignerRestartsAfterCrash2389=== PAUSE TestExternalSignerRestartsAfterCrash2390=== RUN TestExternalSignerProgramErrorKeepsProcess2391=== PAUSE TestExternalSignerProgramErrorKeepsProcess2392=== RUN TestExternalSignerClose2393=== PAUSE TestExternalSignerClose2394=== RUN TestExternalSignerRejectsInvalidPublicKey2395=== PAUSE TestExternalSignerRejectsInvalidPublicKey2396=== RUN TestExternalSignerCancellation2397=== PAUSE TestExternalSignerCancellation2398=== RUN TestGenerateFingerprint2399=== PAUSE TestGenerateFingerprint2400=== RUN TestParseSigningKey2401=== PAUSE TestParseSigningKey2402=== RUN TestSign2403=== PAUSE TestSign2404=== RUN TestSignBatch2405=== PAUSE TestSignBatch2406=== RUN TestNilKeyPublicKey2407=== PAUSE TestNilKeyPublicKey2408=== RUN TestSignErrors2409=== PAUSE TestSignErrors2410=== CONT TestExternalSigner2411=== CONT TestExternalSignerCancellation2412=== CONT TestExternalSignerRejectsInvalidPublicKey2413=== RUN TestExternalSignerRejectsInvalidPublicKey/#002414=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002415=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2416=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2417=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2418=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2419=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2420=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2421=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2422=== CONT TestExternalSignerRestartsAfterCrash2423=== CONT TestExternalSignerClose2424=== CONT TestExternalSignerProgramErrorKeepsProcess2425=== CONT TestExternalSignerErrors2426=== RUN TestExternalSignerErrors/exit_on_request2427=== PAUSE TestExternalSignerErrors/exit_on_request2428=== RUN TestExternalSignerErrors/invalid_JSON2429=== PAUSE TestExternalSignerErrors/invalid_JSON2430=== RUN TestExternalSignerErrors/null2431=== PAUSE TestExternalSignerErrors/null2432=== RUN TestExternalSignerErrors/unrequested_key2433=== PAUSE TestExternalSignerErrors/unrequested_key2434=== RUN TestExternalSignerErrors/program_error2435=== PAUSE TestExternalSignerErrors/program_error2436=== RUN TestExternalSignerErrors/wrong_id2437=== PAUSE TestExternalSignerErrors/wrong_id2438=== RUN TestExternalSignerErrors/null_signatures2439=== PAUSE TestExternalSignerErrors/null_signatures2440=== RUN TestExternalSignerErrors/wrong_signatures_shape2441=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2442=== RUN TestExternalSignerErrors/exit_at_startup2443=== PAUSE TestExternalSignerErrors/exit_at_startup2444=== RUN TestExternalSignerErrors/wrong_shape2445=== CONT TestSignBatch2446=== PAUSE TestExternalSignerErrors/wrong_shape2447=== RUN TestExternalSignerErrors/too_few_signatures2448=== PAUSE TestExternalSignerErrors/too_few_signatures2449=== RUN TestExternalSignerErrors/missing_signature_name2450=== PAUSE TestExternalSignerErrors/missing_signature_name2451=== RUN TestExternalSignerErrors/wrong_signature_name2452=== PAUSE TestExternalSignerErrors/wrong_signature_name2453=== RUN TestExternalSignerErrors/missing_signatures2454=== PAUSE TestExternalSignerErrors/missing_signatures2455=== RUN TestExternalSignerErrors/invalid_signature_base642456=== PAUSE TestExternalSignerErrors/invalid_signature_base642457=== RUN TestExternalSignerErrors/wrong_signature_length2458=== PAUSE TestExternalSignerErrors/wrong_signature_length2459=== CONT TestExternalSignerWrongPublicKey2460=== CONT TestSignErrors2461=== CONT TestNilKeyPublicKey2462--- PASS: TestNilKeyPublicKey (0.00s)2463=== CONT TestParseSigningKey2464=== RUN TestParseSigningKey/valid_32-byte_key2465=== PAUSE TestParseSigningKey/valid_32-byte_key2466=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2467=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2468=== RUN TestParseSigningKey/no_colon2469=== PAUSE TestParseSigningKey/no_colon2470=== RUN TestParseSigningKey/empty_name2471=== PAUSE TestParseSigningKey/empty_name2472=== RUN TestParseSigningKey/invalid_base642473=== PAUSE TestParseSigningKey/invalid_base642474=== RUN TestParseSigningKey/wrong_length2475=== PAUSE TestParseSigningKey/wrong_length2476=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2477=== CONT TestSign2478=== CONT TestGenerateFingerprint2479=== RUN TestGenerateFingerprint/basic_with_references2480=== PAUSE TestGenerateFingerprint/basic_with_references2481=== RUN TestGenerateFingerprint/no_references2482=== PAUSE TestGenerateFingerprint/no_references2483=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2484=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2485=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2486=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2487=== RUN TestGenerateFingerprint/invalid_nar_hash_length2488=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2489=== RUN TestGenerateFingerprint/invalid_store_path_prefix2490=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2491=== RUN TestGenerateFingerprint/invalid_reference_prefix2492=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2493=== CONT TestExternalSignerErrors/exit_on_request2494=== RUN TestSignErrors/nil_key2495=== PAUSE TestSignErrors/nil_key2496--- PASS: TestSign (0.00s)2497=== CONT TestExternalSignerErrors/exit_at_startup2498=== RUN TestSignErrors/nil_narinfo2499=== PAUSE TestSignErrors/nil_narinfo2500=== RUN TestSignErrors/invalid_narinfo2501=== PAUSE TestSignErrors/invalid_narinfo2502=== RUN TestSignErrors/canceled2503=== PAUSE TestSignErrors/canceled2504=== CONT TestExternalSignerErrors/wrong_signature_length2505--- PASS: TestSignBatch (0.00s)2506=== CONT TestExternalSignerErrors/invalid_signature_base642507--- PASS: TestExternalSignerRestartsAfterCrash (0.23s)2508=== CONT TestExternalSignerErrors/missing_signatures2509/nix/var/nix/builds/nix-25968-2128199257/TestExternalSignerRestartsAfterCrash46859091/001/sign program: line 7: /nix/var/nix/builds/nix-25968-2128199257/TestExternalSignerRestartsAfterCrash46859091/001/sign program.starts: No such file or directory2510--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.40s)2511=== CONT TestExternalSignerErrors/wrong_signature_name2512--- PASS: TestExternalSigner (0.64s)2513=== CONT TestExternalSignerErrors/missing_signature_name2514=== CONT TestExternalSignerErrors/too_few_signatures2515--- PASS: TestExternalSignerCancellation (1.03s)2516=== CONT TestExternalSignerErrors/wrong_shape2517--- PASS: TestExternalSignerWrongPublicKey (1.21s)2518=== CONT TestExternalSignerErrors/program_error2519--- PASS: TestExternalSignerClose (1.43s)2520=== CONT TestExternalSignerErrors/wrong_signatures_shape2521=== CONT TestExternalSignerErrors/null_signatures2522=== CONT TestExternalSignerErrors/wrong_id2523=== CONT TestExternalSignerErrors/null2524=== CONT TestExternalSignerErrors/unrequested_key2525=== CONT TestExternalSignerErrors/invalid_JSON2526=== CONT TestParseSigningKey/valid_32-byte_key2527=== CONT TestExternalSignerRejectsInvalidPublicKey/#002528=== CONT TestParseSigningKey/wrong_length2529=== CONT TestParseSigningKey/invalid_base642530=== CONT TestParseSigningKey/empty_name2531=== CONT TestParseSigningKey/no_colon2532=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2533--- PASS: TestParseSigningKey (0.00s)2534 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2535 --- PASS: TestParseSigningKey/wrong_length (0.00s)2536 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2537 --- PASS: TestParseSigningKey/empty_name (0.00s)2538 --- PASS: TestParseSigningKey/no_colon (0.00s)2539 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2540=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2541=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2542=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2543=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2544--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2545 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2546 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2547 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2548 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2549 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2550=== CONT TestGenerateFingerprint/basic_with_references2551=== CONT TestGenerateFingerprint/invalid_nar_hash_length2552=== CONT TestGenerateFingerprint/invalid_reference_prefix2553=== CONT TestGenerateFingerprint/invalid_store_path_prefix2554=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2555=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2556=== CONT TestGenerateFingerprint/no_references2557--- PASS: TestGenerateFingerprint (0.00s)2558 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2559 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2560 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2561 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2562 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2563 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2564 --- PASS: TestGenerateFingerprint/no_references (0.00s)2565=== CONT TestSignErrors/nil_key2566=== CONT TestSignErrors/invalid_narinfo2567=== CONT TestSignErrors/canceled2568=== CONT TestSignErrors/nil_narinfo2569--- PASS: TestSignErrors (0.00s)2570 --- PASS: TestSignErrors/nil_key (0.00s)2571 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2572 --- PASS: TestSignErrors/canceled (0.00s)2573 --- PASS: TestSignErrors/nil_narinfo (0.00s)2574--- PASS: TestExternalSignerErrors (0.00s)2575 --- PASS: TestExternalSignerErrors/exit_on_request (0.81s)2576 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.63s)2577 --- PASS: TestExternalSignerErrors/exit_at_startup (1.83s)2578 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.04s)2579 --- PASS: TestExternalSignerErrors/missing_signatures (2.00s)2580 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.06s)2581 --- PASS: TestExternalSignerErrors/missing_signature_name (1.99s)2582 --- PASS: TestExternalSignerErrors/too_few_signatures (2.03s)2583 --- PASS: TestExternalSignerErrors/wrong_shape (2.02s)2584 --- PASS: TestExternalSignerErrors/program_error (2.04s)2585 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.01s)2586 --- PASS: TestExternalSignerErrors/null_signatures (2.01s)2587 --- PASS: TestExternalSignerErrors/wrong_id (2.00s)2588 --- PASS: TestExternalSignerErrors/null (1.99s)2589 --- PASS: TestExternalSignerErrors/unrequested_key (2.00s)2590 --- PASS: TestExternalSignerErrors/invalid_JSON (1.96s)2591PASS2592Running OpenBao signer tests...2593=== RUN TestSign2594=== PAUSE TestSign2595=== RUN TestSignErrors2596=== PAUSE TestSignErrors2597=== RUN TestServe2598=== PAUSE TestServe2599=== RUN TestServeRejectsGarbage2600=== PAUSE TestServeRejectsGarbage2601=== CONT TestSign2602=== CONT TestServeRejectsGarbage2603=== CONT TestServe2604=== CONT TestSignErrors2605=== RUN TestSignErrors/http_error2606=== PAUSE TestSignErrors/http_error2607=== RUN TestSignErrors/invalid_json2608=== PAUSE TestSignErrors/invalid_json2609=== RUN TestSignErrors/no_prefix2610=== PAUSE TestSignErrors/no_prefix2611=== RUN TestSignErrors/invalid_base642612=== PAUSE TestSignErrors/invalid_base642613=== CONT TestSignErrors/http_error2614--- PASS: TestServeRejectsGarbage (0.00s)2615=== CONT TestSignErrors/invalid_base642616=== CONT TestSignErrors/no_prefix2617=== CONT TestSignErrors/invalid_json2618--- PASS: TestServe (0.00s)2619--- PASS: TestSign (0.01s)2620--- PASS: TestSignErrors (0.00s)2621 --- PASS: TestSignErrors/invalid_json (0.01s)2622 --- PASS: TestSignErrors/no_prefix (0.01s)2623 --- PASS: TestSignErrors/invalid_base64 (0.01s)2624 --- PASS: TestSignErrors/http_error (0.01s)2625PASS