niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #366
· 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.18s)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 TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestScriptTokenEmptyCommand101=== CONT TestSetClientTLSDoesNotMutateDefaultTransport102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestSetClientTLS104=== CONT TestEncodeNixBase32105=== RUN TestEncodeNixBase32/test_string_hash106=== PAUSE TestEncodeNixBase32/test_string_hash107=== RUN TestEncodeNixBase32/empty_input108=== PAUSE TestEncodeNixBase32/empty_input109=== CONT TestEncodeNixBase32/test_string_hash110=== CONT TestResolveStorePath111=== CONT TestClientSignaturesByStorePath112--- PASS: TestClientSignaturesByStorePath (0.00s)113=== CONT TestStreamPushReportsSignatures114=== CONT TestStreamPushRequestLine115=== CONT TestStreamPushGivesUpOnDeadServer116=== CONT TestStreamPushIsolatesFailures117=== CONT TestStreamPushBatchesUnderLoad1182026/10/06 08:59:36 ERROR Upload failed error="bad path" count=3119--- PASS: TestStreamPushIsolatesFailures (0.00s)120=== CONT TestStreamPushReportsEveryPath1212026/10/06 08:59:36 ERROR Upload failed error=boom count=11222026/10/06 08:59:36 ERROR Upload failed error="connection refused" count=201232026/10/06 08:59:36 ERROR Server seems unavailable, giving up on batch untried=17124--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)125=== CONT TestShellSplitErrors126--- PASS: TestShellSplitErrors (0.00s)127=== CONT TestShellSplit128--- PASS: TestShellSplit (0.00s)129--- PASS: TestStreamPushReportsEveryPath (0.00s)1302026/10/06 08:59:36 ERROR Upload failed error=boom count=1131--- PASS: TestStreamPushReportsSignatures (0.00s)132=== CONT TestScriptTokenNoExpiryRerunsEveryCall133=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1342026/10/06 08:59:36 WARN Rate limiter enabled after throttle name=server-test rate=5135=== CONT TestScriptTokenScriptFails136--- PASS: TestResolveStorePath (0.00s)137=== CONT TestFileTokenEmpty138--- PASS: TestFileTokenEmpty (0.00s)139=== CONT TestFileTokenMissing140--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)141=== CONT TestFileTokenReadsAndCaches142--- PASS: TestFileTokenMissing (0.00s)143=== CONT TestStaticToken144--- PASS: TestStaticToken (0.00s)145=== CONT TestSetClientTLSErrors146--- PASS: TestFileTokenReadsAndCaches (0.00s)147=== CONT TestPathInfoHashCompatibility148=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)150=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon151=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon152=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI153=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI154=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512155=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512156=== CONT TestRateLimiterFeedback157=== RUN TestRateLimiterFeedback/429_enables_limiter158=== PAUSE TestRateLimiterFeedback/429_enables_limiter159=== RUN TestRateLimiterFeedback/503_enables_limiter160=== PAUSE TestRateLimiterFeedback/503_enables_limiter161=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter162=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter163=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter164=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter165=== CONT TestPathInfoCACompatibility166=== RUN TestPathInfoCACompatibility/null_ca_field167=== RUN TestSetClientTLS/rejects_connection_without_client_cert168=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert169=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA170=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA171=== RUN TestSetClientTLS/preserves_debug_logging_transport172=== PAUSE TestSetClientTLS/preserves_debug_logging_transport173=== CONT TestParsePathInfoJSONMultiplePaths174=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths177=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths178=== CONT TestParsePathInfoJSON179=== RUN TestParsePathInfoJSON/Nix_format180=== PAUSE TestParsePathInfoJSON/Nix_format181=== RUN TestParsePathInfoJSON/Lix_format182=== PAUSE TestParsePathInfoJSON/Lix_format183=== RUN TestParsePathInfoJSON/empty_input184=== PAUSE TestParsePathInfoJSON/empty_input185=== RUN TestParsePathInfoJSON/whitespace_only186=== PAUSE TestParsePathInfoJSON/whitespace_only187=== RUN TestParsePathInfoJSON/invalid_JSON188=== PAUSE TestParsePathInfoJSON/invalid_JSON189=== CONT TestFilterOversizedClosures190=== RUN TestFilterOversizedClosures/no_limit_keeps_everything191=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything192=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped193=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped194=== RUN TestFilterOversizedClosures/all_closures_skipped195=== PAUSE TestFilterOversizedClosures/all_closures_skipped196=== PAUSE TestPathInfoCACompatibility/null_ca_field197=== RUN TestPathInfoCACompatibility/old_string_format_-_text198=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text199=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive200=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== RUN TestPathInfoCACompatibility/new_structured_format_-_text202=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text203=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method204=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method205=== CONT TestDumpPathSingleFile206--- PASS: TestScriptTokenScriptFails (0.01s)207=== CONT TestDumpPathWriterError208=== RUN TestSetClientTLSErrors/missing_cert_file209=== PAUSE TestSetClientTLSErrors/missing_cert_file210=== RUN TestSetClientTLSErrors/missing_key_file211=== PAUSE TestSetClientTLSErrors/missing_key_file212=== RUN TestSetClientTLSErrors/missing_ca_file213=== PAUSE TestSetClientTLSErrors/missing_ca_file214=== RUN TestSetClientTLSErrors/invalid_ca_file215=== PAUSE TestSetClientTLSErrors/invalid_ca_file216=== CONT TestUploadMultipart_SupersededByPeer217=== RUN TestUploadMultipart_SupersededByPeer/exists218=== PAUSE TestUploadMultipart_SupersededByPeer/exists219=== CONT TestDumpPathMatchesNix220=== RUN TestUploadMultipart_SupersededByPeer/missing221=== PAUSE TestUploadMultipart_SupersededByPeer/missing2222026/10/06 08:59:36 WARN Rate limiter enabled after throttle name=server-test rate=5223=== CONT TestPartSizeForNAR2242026/10/06 08:59:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50477225=== RUN TestPartSizeForNAR/zero_stays_at_minimum226=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum227=== RUN TestPartSizeForNAR/small_stays_at_minimum228=== PAUSE TestPartSizeForNAR/small_stays_at_minimum229=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum230=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum231=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts232=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts233=== RUN TestPartSizeForNAR/1_TiB234=== PAUSE TestPartSizeForNAR/1_TiB235=== RUN TestPartSizeForNAR/5_TiB_S3_max_object236=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object237=== RUN TestPartSizeForNAR/capped_at_5_GiB238=== PAUSE TestPartSizeForNAR/capped_at_5_GiB239=== CONT TestUploadMultipart_PartsInParallel2402026/10/06 08:59:36 WARN Rate limiter backed off name=server-test rate=52412026/10/06 08:59:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:50477242--- PASS: TestDoServerRequestAttachesToken (0.01s)243=== CONT TestConvertHashToNix32244=== RUN TestConvertHashToNix32/SRI_format_to_Nix32245=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32246=== RUN TestConvertHashToNix32/already_Nix32_format247=== PAUSE TestConvertHashToNix32/already_Nix32_format248=== RUN TestConvertHashToNix32/invalid_format249=== PAUSE TestConvertHashToNix32/invalid_format250--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)251=== CONT TestScriptTokenEmptyToken252=== CONT TestGetStorePathHash253=== RUN TestGetStorePathHash/valid_store_path254=== PAUSE TestGetStorePathHash/valid_store_path255=== RUN TestGetStorePathHash/basename_without_hyphen_should_error256=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error257=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error258=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error259=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestScriptTokenBadJSON262--- PASS: TestStreamPushRequestLine (0.02s)263=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2642026/10/06 08:59:36 INFO Garbage collection started2652026/10/06 08:59:36 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=02662026/10/06 08:59:36 WARN Garbage collection finished on another replica. Its statistics are not available here267--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)268=== CONT TestCaseHackSuffix269--- PASS: TestScriptTokenBadJSON (0.03s)270=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun271--- PASS: TestScriptTokenEmptyToken (0.03s)272=== CONT TestScriptTokenCachesUntilRefresh2732026/10/06 08:59:36 INFO Garbage collection started274--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)275=== CONT TestRegisterUploadedObjectReusesConnections276--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)277=== CONT TestEncodeNixBase32/empty_input278--- PASS: TestEncodeNixBase32 (0.00s)279 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)280 --- PASS: TestEncodeNixBase32/empty_input (0.00s)281=== CONT TestEncodeNixBase32WithRealHash282--- PASS: TestEncodeNixBase32WithRealHash (0.00s)283=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)284=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI285=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512286=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon287--- PASS: TestPathInfoHashCompatibility (0.00s)288 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)289 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)290 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)291 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)292=== CONT TestRateLimiterFeedback/429_enables_limiter2932026/10/06 08:59:36 WARN Rate limiter enabled after throttle name=server-test rate=52942026/10/06 08:59:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:505562952026/10/06 08:59:36 WARN Rate limiter backed off name=server-test rate=5296=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter297=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter298=== CONT TestRateLimiterFeedback/503_enables_limiter2992026/10/06 08:59:36 WARN Rate limiter enabled after throttle name=server-test rate=53002026/10/06 08:59:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:50562301--- PASS: TestDumpPathWriterError (0.06s)302=== CONT TestSetClientTLS/rejects_connection_without_client_cert3032026/10/06 08:59:36 WARN Rate limiter backed off name=server-test rate=5304--- PASS: TestRateLimiterFeedback (0.00s)305 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)306 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)307 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)308 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)309=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths310=== CONT TestSetClientTLS/preserves_debug_logging_transport311=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA312=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths313--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)316=== CONT TestParsePathInfoJSON/Nix_format317=== CONT TestParsePathInfoJSON/whitespace_only318=== CONT TestParsePathInfoJSON/invalid_JSON319=== CONT TestParsePathInfoJSON/empty_input320=== CONT TestParsePathInfoJSON/Lix_format321--- PASS: TestParsePathInfoJSON (0.00s)322 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)323 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)324 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)325 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)326 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)327=== CONT TestFilterOversizedClosures/no_limit_keeps_everything328=== CONT TestPathInfoCACompatibility/null_ca_field329=== CONT TestFilterOversizedClosures/all_closures_skipped3302026/10/06 08:59:36 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=50331=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3322026/10/06 08:59:36 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=2000333--- PASS: TestFilterOversizedClosures (0.00s)334 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)335 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)336 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)337=== CONT TestSetClientTLSErrors/missing_cert_file338=== CONT TestSetClientTLSErrors/invalid_ca_file339=== CONT TestSetClientTLSErrors/missing_ca_file340=== CONT TestSetClientTLSErrors/missing_key_file341=== CONT TestPathInfoCACompatibility/old_string_format_-_text342=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method343=== CONT TestPathInfoCACompatibility/new_structured_format_-_text344=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive345--- PASS: TestPathInfoCACompatibility (0.00s)346 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)348 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)349 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)350 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)351=== CONT TestUploadMultipart_SupersededByPeer/exists352--- PASS: TestSetClientTLSErrors (0.00s)353 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)354 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)355 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)356 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)357=== CONT TestUploadMultipart_SupersededByPeer/missing358--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)360 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)361=== CONT TestPartSizeForNAR/zero_stays_at_minimum362=== CONT TestPartSizeForNAR/capped_at_5_GiB363=== CONT TestPartSizeForNAR/5_TiB_S3_max_object364=== CONT TestPartSizeForNAR/1_TiB365=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts366=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum367=== CONT TestPartSizeForNAR/small_stays_at_minimum368--- PASS: TestPartSizeForNAR (0.00s)369 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)373 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)374 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376=== CONT TestConvertHashToNix32/SRI_format_to_Nix32377=== CONT TestGetStorePathHash/valid_store_path378=== CONT TestConvertHashToNix32/invalid_format379=== CONT TestConvertHashToNix32/already_Nix32_format380--- PASS: TestConvertHashToNix32 (0.01s)381 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)382 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)383 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)384=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error385=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error386=== CONT TestGetStorePathHash/basename_without_hyphen_should_error387--- PASS: TestGetStorePathHash (0.00s)388 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)389 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)390 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)391 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)392--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)3932026/10/06 08:59:36 http: TLS handshake error from 127.0.0.1:50570: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.01s)395 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)398--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)399--- PASS: TestStreamPushBatchesUnderLoad (0.10s)400--- PASS: TestDumpPathSingleFile (0.11s)401--- PASS: TestCaseHackSuffix (0.09s)402--- PASS: TestDumpPathMatchesNix (0.12s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld10".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-72355-3875258282/postgres2367514881/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-72355-3875258282/postgres2367514881/data -l logfile start433434/nix/var/nix/builds/nix-72355-3875258282/postgres2367514881:5432 - no response4352026-10-06 08:59:39.048 UTC [72989] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 08:59:39.048 UTC [72989] LOG: listening on Unix socket "/nix/var/nix/builds/nix-72355-3875258282/postgres2367514881/.s.PGSQL.5432"4372026-10-06 08:59:39.052 UTC [72997] LOG: database system was shut down at 2026-10-06 08:59:39 UTC4382026-10-06 08:59:39.053 UTC [72989] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-72355-3875258282/postgres2367514881:5432 - accepting connections440{"timestamp":"2026-10-06T08:59:39.307394Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"4345fbb0-1e52-4d4e-9117-e9dcc92c9a3e","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":9,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}441{"timestamp":"2026-10-06T08:59:39.416829Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"79d98a88-4b4b-4523-b673-fc2683401d97","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-06T08:59:39.519815Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"84bd19e9-d285-402a-bea4-e8fba534085f","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)"}443=== RUN TestService_AuthMiddleware444=== PAUSE TestService_AuthMiddleware445=== RUN TestService_AuthMiddleware_MTLSProxyHeader446=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader447=== RUN TestService_AuthMiddleware_MTLSBoundSubjects448=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects449=== RUN TestService_ReadAuthMiddleware450=== PAUSE TestService_ReadAuthMiddleware451=== RUN TestService_AuthMiddleware_OIDC452=== PAUSE TestService_AuthMiddleware_OIDC453=== RUN TestService_RequireScope_OIDC454=== PAUSE TestService_RequireScope_OIDC455=== RUN TestService_ReadScope_PublicByDefault456=== PAUSE TestService_ReadScope_PublicByDefault457=== RUN TestCacheConfigHandler458=== PAUSE TestCacheConfigHandler459=== RUN TestCacheStatsHandler460=== PAUSE TestCacheStatsHandler461=== RUN TestClientCADerivations462=== PAUSE TestClientCADerivations463=== RUN TestClientErrorHandling464=== PAUSE TestClientErrorHandling465=== RUN TestClientIntegration466=== PAUSE TestClientIntegration467=== RUN TestClientMultipleUploads468=== PAUSE TestClientMultipleUploads469=== RUN TestClientWithDependencies470=== PAUSE TestClientWithDependencies471=== RUN TestClientSharedPathCommittedMidPush472=== PAUSE TestClientSharedPathCommittedMidPush473=== RUN TestPinProtectsFromGC474=== PAUSE TestPinProtectsFromGC475=== RUN TestClientPushesUseOnePush476=== PAUSE TestClientPushesUseOnePush477=== RUN TestClientFallsBackToClosures478=== PAUSE TestClientFallsBackToClosures479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/06 08:59:39 INFO lead: acquired remote=192.0.2.1:12344892026/10/06 08:59:40 INFO lead: released remote=192.0.2.1:12344902026/10/06 08:59:40 INFO lead: acquired remote=192.0.2.1:12344912026/10/06 08:59:41 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (2.01s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/06 08:59:41 INFO lead: acquired remote=192.0.2.1:12344992026-10-06 08:59:43.201 UTC [73105] FATAL: terminating connection due to administrator command5002026/10/06 08:59:43 INFO lead: acquired remote=192.0.2.1:12345012026/10/06 08:59:44 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/06 08:59:44 INFO lead: released remote=192.0.2.1:12345032026/10/06 08:59:44 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (2.97s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestService_NativeMTLS574=== PAUSE TestService_NativeMTLS575=== RUN TestServerTLSConfig576=== PAUSE TestServerTLSConfig577=== RUN TestMultipartCleanup578=== PAUSE TestMultipartCleanup579=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== RUN TestPendingCleanupUsesOneCutoff582=== PAUSE TestPendingCleanupUsesOneCutoff583=== RUN TestObjectStatsTrigger584=== PAUSE TestObjectStatsTrigger585=== RUN TestOrphanedObjectsGC586=== PAUSE TestOrphanedObjectsGC587=== RUN TestOrphanedObjectsGCStressTest588=== PAUSE TestOrphanedObjectsGCStressTest589=== RUN TestCreatePin_ReservedPins590=== PAUSE TestCreatePin_ReservedPins591=== RUN TestPresentReportsOnlyClosureRoots592=== PAUSE TestPresentReportsOnlyClosureRoots593=== RUN TestPresentNotReportedWhileGCDeletesClosure594=== PAUSE TestPresentNotReportedWhileGCDeletesClosure595=== RUN TestParseSingleRange596=== PAUSE TestParseSingleRange597=== RUN TestProxyHeadersOnlyTrustedOnSocket598=== PAUSE TestProxyHeadersOnlyTrustedOnSocket599=== RUN TestIsValidCachePath600=== PAUSE TestIsValidCachePath601=== RUN TestReadProxyNarinfo602=== PAUSE TestReadProxyNarinfo603=== RUN TestReadProxyNarinfoAlreadyDecompressed604=== PAUSE TestReadProxyNarinfoAlreadyDecompressed605=== RUN TestReadProxyContentNegotiation606=== PAUSE TestReadProxyContentNegotiation607=== RUN TestReadProxyNarStreaming608=== PAUSE TestReadProxyNarStreaming609=== RUN TestReadProxy404610=== PAUSE TestReadProxy404611=== RUN TestReadProxyInvalidPath612=== PAUSE TestReadProxyInvalidPath613=== RUN TestReadProxyHead614=== PAUSE TestReadProxyHead615=== RUN TestReadProxyOutlastsServerWriteTimeout616=== PAUSE TestReadProxyOutlastsServerWriteTimeout617=== RUN TestReadProxyConditionalGet618=== PAUSE TestReadProxyConditionalGet619=== RUN TestReadProxyRootRedirectsToIndexHTML620=== PAUSE TestReadProxyRootRedirectsToIndexHTML621=== RUN TestReadProxyDisabled622=== PAUSE TestReadProxyDisabled623=== RUN TestReadRedirectNar624=== PAUSE TestReadRedirectNar625=== RUN TestReadRedirectKeepsNarinfoProxied626=== PAUSE TestReadRedirectKeepsNarinfoProxied627=== RUN TestReadProxyRangeRequest628=== PAUSE TestReadProxyRangeRequest629=== RUN TestReadRedirectUsesPublicS3URL630=== PAUSE TestReadRedirectUsesPublicS3URL631=== RUN TestPush_OverlappingRootsStoreOneRowPerKey632=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey633=== RUN TestPush_CompleteCommitsEveryRoot634=== PAUSE TestPush_CompleteCommitsEveryRoot635=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit636=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit637=== RUN TestPush_RejectsBadRequests638=== PAUSE TestPush_RejectsBadRequests639=== RUN TestPush_SignsNarinfosOfItsPendingObjects640=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects641=== RUN TestRedundantMultipartUpload642=== PAUSE TestRedundantMultipartUpload643=== RUN TestCompleteMultipartUpload_ErrorButObjectExists644=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists645=== RUN TestCompletedNarNotReofferedAcrossClosures646=== PAUSE TestCompletedNarNotReofferedAcrossClosures647=== RUN TestPresignedUploadRegisteredBeforeCommit648=== PAUSE TestPresignedUploadRegisteredBeforeCommit649=== RUN TestService_Rustfstest650=== PAUSE TestService_Rustfstest651=== RUN TestParseSize652=== PAUSE TestParseSize653=== RUN TestSkippedUploadsHandler654=== PAUSE TestSkippedUploadsHandler655=== RUN TestSystemdListenerNotActivated656--- PASS: TestSystemdListenerNotActivated (0.00s)657=== RUN TestWatchdogBeatsWhenHealthy658--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)659=== RUN TestWatchdogSkipsWhenUnhealthy6602026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 08:59:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"670--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)671=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle673=== RUN TestProxyWriteTimeout674=== PAUSE TestProxyWriteTimeout675=== RUN TestPendingClosureWriteTimeout676=== PAUSE TestPendingClosureWriteTimeout677=== RUN TestIsValidUploadKey678=== PAUSE TestIsValidUploadKey679=== RUN TestUploadHandlersRejectInvalidKeys680=== PAUSE TestUploadHandlersRejectInvalidKeys681=== RUN TestUploadHandlersRejectOversizedBody682=== PAUSE TestUploadHandlersRejectOversizedBody683=== RUN TestService_cleanupPendingClosuresHandler684=== PAUSE TestService_cleanupPendingClosuresHandler685=== RUN TestService_createPendingClosureHandler686=== PAUSE TestService_createPendingClosureHandler687=== RUN TestService_verifyS3Integrity688=== PAUSE TestService_verifyS3Integrity689=== RUN TestCompleteMultipartUnregistered690=== PAUSE TestCompleteMultipartUnregistered691=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT692=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT693=== CONT TestService_verifyS3Integrity694=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT695=== CONT TestService_AuthMiddleware696=== CONT TestCacheConfigHandlerMaxNarSize697=== CONT TestCompleteMultipartUnregistered698=== CONT TestGenerateLandingPage699--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)700=== CONT TestService_createPendingClosureHandler701=== CONT TestCommitRacingPendingCleanupKeepsObjects702=== CONT TestService_readinessHandler703=== CONT TestService_healthCheckHandler704=== CONT TestPushDedupSurvivesConcurrentGC705--- PASS: TestGenerateLandingPage (0.00s)706=== CONT TestReadProxyOutlastsServerWriteTimeout7072026/10/06 08:59:45 INFO Received uploads request method=POST path=/api/pending_closures7082026/10/06 08:59:45 INFO Received uploads request method=POST path=/api/pending_closures7092026/10/06 08:59:45 INFO Aborted multipart uploads count=0 kept=07102026/10/06 08:59:45 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=07112026/10/06 08:59:45 INFO Vacuumed table table=pending_closures7122026/10/06 08:59:45 INFO Vacuumed table table=pending_objects7132026/10/06 08:59:45 INFO Vacuumed table table=multipart_uploads7142026/10/06 08:59:45 INFO Vacuumed table table=closures7152026/10/06 08:59:45 INFO Vacuumed table table=objects7162026/10/06 08:59:45 INFO Aborted multipart uploads count=0 kept=07172026/10/06 08:59:45 WARN Force mode enabled - objects will be deleted immediately without grace period7182026/10/06 08:59:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07192026/10/06 08:59:45 INFO Vacuumed table table=pending_closures7202026/10/06 08:59:45 INFO Vacuumed table table=pending_objects7212026/10/06 08:59:45 INFO Vacuumed table table=multipart_uploads7222026/10/06 08:59:45 INFO Vacuumed table table=closures7232026/10/06 08:59:45 INFO Vacuumed table table=objects724--- PASS: TestPushDedupSurvivesConcurrentGC (0.84s)725=== CONT TestReadProxyHead7262026/10/06 08:59:45 INFO Aborted multipart uploads count=0 kept=07272026/10/06 08:59:45 WARN Force mode enabled - objects will be deleted immediately without grace period7282026/10/06 08:59:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07292026/10/06 08:59:45 INFO Vacuumed table table=pending_closures7302026/10/06 08:59:45 INFO Vacuumed table table=pending_objects7312026/10/06 08:59:45 INFO Vacuumed table table=multipart_uploads7322026/10/06 08:59:45 INFO Vacuumed table table=closures7332026/10/06 08:59:45 INFO Vacuumed table table=objects734--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.92s)735=== CONT TestReadProxyInvalidPath7362026/10/06 08:59:45 INFO Received uploads request method=POST path=/api/pending_closures737--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.08s)738=== CONT TestReadProxy4047392026/10/06 08:59:46 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"740--- PASS: TestService_AuthMiddleware (1.18s)741=== CONT TestReadProxyNarStreaming7422026/10/06 08:59:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7432026/10/06 08:59:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst744--- PASS: TestCompleteMultipartUnregistered (1.37s)745=== CONT TestReadProxyContentNegotiation7462026/10/06 08:59:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7472026/10/06 08:59:46 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLmRiMDU5N2U3LWI1MDktNDljYS04MDQxLTU5ZTFmNzU4OWNmZXgxNzkxMjc3MTg1Mjg4MDIxMDAw parts=107482026/10/06 08:59:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7492026/10/06 08:59:46 INFO Completed upload id=17502026/10/06 08:59:46 INFO Received uploads request method=POST path=/api/pending_closures7512026/10/06 08:59:46 INFO Received uploads request method=POST path=/api/pending_closures7522026/10/06 08:59:46 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7532026/10/06 08:59:46 WARN Found objects in DB but missing from S3, will re-upload count=1754--- PASS: TestService_verifyS3Integrity (1.56s)755=== CONT TestReadProxyNarinfoAlreadyDecompressed7562026/10/06 08:59:46 INFO Received uploads request method=POST path=/api/pending_closures7572026/10/06 08:59:46 INFO Received uploads request method=POST path=/api/pending_closures7582026/10/06 08:59:46 INFO Received uploads request method=POST path=/api/pending_closures759--- PASS: TestService_healthCheckHandler (1.81s)760=== CONT TestReadProxyNarinfo7612026/10/06 08:59:46 WARN readiness check failed error="closed pool"762--- PASS: TestService_readinessHandler (2.02s)763=== CONT TestIsValidCachePath764=== RUN TestIsValidCachePath/narinfo765=== PAUSE TestIsValidCachePath/narinfo766=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars767=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars768=== RUN TestIsValidCachePath/nar_zst769=== PAUSE TestIsValidCachePath/nar_zst770=== RUN TestIsValidCachePath/nar_xz771=== PAUSE TestIsValidCachePath/nar_xz772=== RUN TestIsValidCachePath/nar_bz2773=== PAUSE TestIsValidCachePath/nar_bz2774=== RUN TestIsValidCachePath/nar_uncompressed775=== PAUSE TestIsValidCachePath/nar_uncompressed776=== RUN TestIsValidCachePath/ls777=== PAUSE TestIsValidCachePath/ls778=== RUN TestIsValidCachePath/log779=== PAUSE TestIsValidCachePath/log780=== RUN TestIsValidCachePath/realisation781=== PAUSE TestIsValidCachePath/realisation782=== RUN TestIsValidCachePath/nix-cache-info783=== PAUSE TestIsValidCachePath/nix-cache-info784=== RUN TestIsValidCachePath/index.html785=== PAUSE TestIsValidCachePath/index.html786=== RUN TestIsValidCachePath/traversal_parent787=== PAUSE TestIsValidCachePath/traversal_parent788=== RUN TestIsValidCachePath/traversal_in_middle789=== PAUSE TestIsValidCachePath/traversal_in_middle790=== RUN TestIsValidCachePath/invalid_char_e791=== PAUSE TestIsValidCachePath/invalid_char_e792=== RUN TestIsValidCachePath/invalid_char_u793=== PAUSE TestIsValidCachePath/invalid_char_u794=== RUN TestIsValidCachePath/random_path795=== PAUSE TestIsValidCachePath/random_path796=== RUN TestIsValidCachePath/empty797=== PAUSE TestIsValidCachePath/empty798=== RUN TestIsValidCachePath/leading_slash799=== PAUSE TestIsValidCachePath/leading_slash800=== RUN TestIsValidCachePath/wrong_extension801=== PAUSE TestIsValidCachePath/wrong_extension802=== RUN TestIsValidCachePath/short_hash803=== PAUSE TestIsValidCachePath/short_hash804=== CONT TestProxyHeadersOnlyTrustedOnSocket805--- PASS: TestReadProxyInvalidPath (1.59s)806=== CONT TestParseSingleRange807=== RUN TestParseSingleRange/none808=== PAUSE TestParseSingleRange/none809=== RUN TestParseSingleRange/unknown_unit810=== PAUSE TestParseSingleRange/unknown_unit811=== RUN TestParseSingleRange/multi-range_ignored812=== PAUSE TestParseSingleRange/multi-range_ignored813=== RUN TestParseSingleRange/malformed_no_dash814=== PAUSE TestParseSingleRange/malformed_no_dash815=== RUN TestParseSingleRange/malformed_both_empty816=== PAUSE TestParseSingleRange/malformed_both_empty817=== RUN TestParseSingleRange/malformed_end_before_start818=== PAUSE TestParseSingleRange/malformed_end_before_start819=== RUN TestParseSingleRange/closed820=== PAUSE TestParseSingleRange/closed821=== RUN TestParseSingleRange/open-ended822=== PAUSE TestParseSingleRange/open-ended823=== RUN TestParseSingleRange/end_clamped_to_size824=== PAUSE TestParseSingleRange/end_clamped_to_size825=== RUN TestParseSingleRange/suffix826=== PAUSE TestParseSingleRange/suffix827=== RUN TestParseSingleRange/suffix_exceeds_size828=== PAUSE TestParseSingleRange/suffix_exceeds_size829=== RUN TestParseSingleRange/single_byte830=== PAUSE TestParseSingleRange/single_byte831=== RUN TestParseSingleRange/start_past_EOF832=== PAUSE TestParseSingleRange/start_past_EOF833=== RUN TestParseSingleRange/start_far_past_EOF834=== PAUSE TestParseSingleRange/start_far_past_EOF835=== CONT TestPresentNotReportedWhileGCDeletesClosure836--- PASS: TestReadProxyHead (1.93s)837=== CONT TestPresentReportsOnlyClosureRoots8382026/10/06 08:59:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8392026/10/06 08:59:47 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjRhMWQyNmMyLWI3OWQtNGRjNy04YWZlLTkxYzRmNWE5MDkxOXgxNzkxMjc3MTg2NDM4MTUwMDAw parts=108402026/10/06 08:59:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8412026/10/06 08:59:47 INFO Completed upload id=18422026/10/06 08:59:47 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008432026/10/06 08:59:47 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/06 08:59:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures8452026/10/06 08:59:47 INFO Aborted multipart uploads count=0 kept=08462026/10/06 08:59:47 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=08472026/10/06 08:59:47 INFO Vacuumed table table=pending_closures8482026/10/06 08:59:47 INFO Vacuumed table table=pending_objects8492026/10/06 08:59:47 INFO Vacuumed table table=multipart_uploads8502026/10/06 08:59:47 INFO Vacuumed table table=closures8512026/10/06 08:59:47 INFO Vacuumed table table=objects8522026/10/06 08:59:47 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000853--- PASS: TestService_createPendingClosureHandler (3.00s)854=== CONT TestCreatePin_ReservedPins8552026/10/06 08:59:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50760/oidc856--- PASS: TestReadProxy404 (2.05s)857=== CONT TestOrphanedObjectsGCStressTest858--- PASS: TestReadProxyNarStreaming (2.12s)859=== CONT TestOrphanedObjectsGC860--- PASS: TestReadProxyContentNegotiation (2.16s)861=== CONT TestObjectStatsTrigger862--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.15s)863=== CONT TestPendingCleanupUsesOneCutoff8642026/10/06 08:59:48 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>865--- PASS: TestReadProxyNarinfo (2.14s)866=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8672026/10/06 08:59:48 INFO Starting HTTP server address=127.0.0.1:509028682026/10/06 08:59:48 INFO Starting HTTP server address=/nix/var/nix/builds/nix-72355-3875258282/TestProxyHeadersOnlyTrustedOnSocket1565577894/001/proxy.sock8692026/10/06 08:59:48 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8702026/10/06 08:59:48 INFO Shutdown signal received, draining in-flight requests timeout=10s871--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.07s)872=== CONT TestMultipartCleanup873--- PASS: TestPresentReportsOnlyClosureRoots (1.71s)874=== CONT TestServerTLSConfig875=== RUN TestServerTLSConfig/no_client_CA876=== PAUSE TestServerTLSConfig/no_client_CA877=== RUN TestServerTLSConfig/missing_CA_file878=== PAUSE TestServerTLSConfig/missing_CA_file879=== RUN TestServerTLSConfig/not_a_PEM_file880=== PAUSE TestServerTLSConfig/not_a_PEM_file881=== CONT TestService_NativeMTLS882--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.31s)883=== CONT TestMetricsInventory8842026/10/06 08:59:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux8852026/10/06 08:59:49 WARN Refused reserved pin name=worker-x86_64-linux8862026/10/06 08:59:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux8872026/10/06 08:59:49 INFO Received create pin request method=POST path=/api/pins/my-app8882026/10/06 08:59:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux889--- PASS: TestCreatePin_ReservedPins (1.91s)890=== CONT TestNARDeduplicationMetadataUploadBug891--- PASS: TestObjectStatsTrigger (1.87s)892=== CONT TestCreatePendingClosureRejectsOversizedNAR8932026/10/06 08:59:50 INFO Received uploads request method=POST path=/api/pending_closures894--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)895=== CONT TestFailedS3DeleteKeepsTombstone8962026/10/06 08:59:50 INFO Received uploads request method=POST path=/api/pending_closures8972026/10/06 08:59:50 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/06 08:59:50 INFO Received cleanup request method=DELETE path=/api/pending_closures899=== NAME TestOrphanedObjectsGC900 orphaned_objects_gc_test.go:290: GC Test Summary:901 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A902 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B903 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)904 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)905 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects906--- PASS: TestOrphanedObjectsGC (2.54s)907=== CONT TestPushWaitsForSweepHoldingRow9082026/10/06 08:59:50 INFO Received uploads request method=POST path=/api/pending_closures909--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.03s)910=== CONT TestSweepRechecksPendingAfterLocking9112026/10/06 08:59:51 INFO Received uploads request method=POST path=/api/pending_closures9122026/10/06 08:59:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9132026/10/06 08:59:51 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket29/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9142026/10/06 08:59:51 INFO Aborted multipart uploads count=0 kept=19152026/10/06 08:59:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9162026/10/06 08:59:51 INFO Aborted multipart uploads count=1 kept=0917--- PASS: TestMultipartCleanup (2.30s)918=== CONT TestGetExistingObjectsLocksRows919--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.51s)920=== CONT TestRegisterCompletedObjectNeedsPendingRow9212026/10/06 08:59:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9222026/10/06 08:59:51 WARN mTLS auth: subject not in bound subjects subject="CN=reader"923--- PASS: TestService_NativeMTLS (2.31s)924=== CONT TestSweepSkipsRowsLockedByPush925--- PASS: TestMetricsInventory (2.34s)926=== CONT TestForceGCDuringPushOffersSweptObject927=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows928=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows929=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check930=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check931=== CONT TestGCTaskStore_GetReturnsLatest932--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)933=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection934=== NAME TestNARDeduplicationMetadataUploadBug935 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-72355-3875258282/TestNARDeduplicationMetadataUploadBug28170510/001/store/1v38bxkj5xzjbif4m6296rw7fk5r4f6v-file1.txt9362026/10/06 08:59:52 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/06 08:59:52 INFO Received push request method=POST path=/api/pushes9382026/10/06 08:59:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9392026/10/06 08:59:52 INFO Uploading 1v38bxkj5xzjbif4m6296rw7fk5r4f6v-file1.txt (160B)9402026/10/06 08:59:52 WARN Failed to register uploaded object key=1v38bxkj5xzjbif4m6296rw7fk5r4f6v.ls error="server returned 404: 404 page not found\n"9412026/10/06 08:59:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9422026/10/06 08:59:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9432026/10/06 08:59:52 INFO Signed narinfos id=1 count=19442026/10/06 08:59:52 INFO Uploading 1 narinfos9452026/10/06 08:59:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9462026/10/06 08:59:52 WARN Failed to register uploaded object key=1v38bxkj5xzjbif4m6296rw7fk5r4f6v.narinfo error="server returned 404: 404 page not found\n"9472026/10/06 08:59:52 INFO Upload complete. (129ms)948 metadata_upload_test.go:54: Retrieved narinfo from S3:949 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestNARDeduplicationMetadataUploadBug28170510/001/store/1v38bxkj5xzjbif4m6296rw7fk5r4f6v-file1.txt950 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst951 Compression: zstd952 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf953 NarSize: 160954 References: 955 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf956 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)957 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):958 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9592026/10/06 08:59:52 INFO Aborted multipart uploads count=0 kept=09602026/10/06 08:59:52 WARN Force mode enabled - objects will be deleted immediately without grace period961 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-72355-3875258282/TestNARDeduplicationMetadataUploadBug28170510/001/store/v85avqj5wdm8j18ab789bjjllndnlggf-file2.txt9622026/10/06 08:59:52 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9632026/10/06 08:59:52 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."964--- PASS: TestFailedS3DeleteKeepsTombstone (2.58s)965=== CONT TestGracefulShutdownDrainsInflight9662026/10/06 08:59:52 INFO Starting HTTP server address=127.0.0.1:510479672026/10/06 08:59:52 INFO Shutdown signal received, draining in-flight requests timeout=10s968--- PASS: TestGracefulShutdownDrainsInflight (0.07s)969=== CONT TestGCTaskStore_Fail970--- PASS: TestGCTaskStore_Fail (0.00s)971=== CONT TestGCSweepDeliversEachKeyOnce9722026/10/06 08:59:52 INFO Received push request method=POST path=/api/pushes9732026/10/06 08:59:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)9742026/10/06 08:59:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9752026/10/06 08:59:52 INFO Signed narinfos id=2 count=19762026/10/06 08:59:52 WARN Failed to register uploaded object key=v85avqj5wdm8j18ab789bjjllndnlggf.ls error="server returned 404: 404 page not found\n"9772026/10/06 08:59:52 INFO Uploading 1 narinfos9782026/10/06 08:59:52 INFO Received complete push request method=POST path=/api/pushes/2/complete9792026/10/06 08:59:52 WARN Failed to register uploaded object key=v85avqj5wdm8j18ab789bjjllndnlggf.narinfo error="server returned 404: 404 page not found\n"9802026/10/06 08:59:52 INFO Upload complete. (100ms)981=== NAME TestNARDeduplicationMetadataUploadBug982 metadata_upload_test.go:76: Retrieved narinfo from S3:983 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestNARDeduplicationMetadataUploadBug28170510/001/store/v85avqj5wdm8j18ab789bjjllndnlggf-file2.txt984 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst985 Compression: zstd986 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf987 NarSize: 160988 References: 989 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf990 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)991 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):992 {"version":1,"root":{"type":"regular","size":44}}993--- PASS: TestNARDeduplicationMetadataUploadBug (3.32s)994=== CONT TestTombstonedObjectOfferedWithoutWaiting9952026/10/06 08:59:53 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/06 08:59:53 INFO Aborted multipart uploads count=0 kept=09972026/10/06 08:59:53 WARN Force mode enabled - objects will be deleted immediately without grace period9982026/10/06 08:59:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09992026/10/06 08:59:53 INFO Vacuumed table table=pending_closures10002026/10/06 08:59:53 INFO Vacuumed table table=pending_objects10012026/10/06 08:59:53 INFO Vacuumed table table=multipart_uploads10022026/10/06 08:59:53 INFO Vacuumed table table=closures1003--- PASS: TestPushWaitsForSweepHoldingRow (3.07s)1004=== CONT TestGCSweepSkipsPendingObjects10052026/10/06 08:59:53 INFO Vacuumed table table=objects1006--- PASS: TestSweepRechecksPendingAfterLocking (2.97s)1007=== CONT TestGCTaskStore_PhaseUpdates1008--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1009=== CONT TestGCTaskStore_CompletedAllowsNewTask1010--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1011=== CONT TestDeduplicatedObjectsRecordedAsPending1012--- PASS: TestGetExistingObjectsLocksRows (2.80s)1013=== CONT TestClientSharedPathCommittedMidPush1014--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.03s)1015=== CONT TestCacheConfigHandler1016=== RUN TestCacheConfigHandler/full_config,_no_issuer1017=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1018=== RUN TestCacheConfigHandler/no_cache_url_configured1019=== PAUSE TestCacheConfigHandler/no_cache_url_configured1020=== RUN TestCacheConfigHandler/no_signing_keys1021=== PAUSE TestCacheConfigHandler/no_signing_keys1022=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1023=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1024=== CONT TestClientWithDependencies10252026/10/06 08:59:54 INFO Aborted multipart uploads count=0 kept=010262026/10/06 08:59:54 WARN Force mode enabled - objects will be deleted immediately without grace period10272026/10/06 08:59:54 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=010282026/10/06 08:59:54 INFO Vacuumed table table=pending_closures10292026/10/06 08:59:54 INFO Vacuumed table table=pending_objects10302026/10/06 08:59:54 INFO Vacuumed table table=multipart_uploads10312026/10/06 08:59:54 INFO Vacuumed table table=closures10322026/10/06 08:59:54 INFO Vacuumed table table=objects10332026/10/06 08:59:54 INFO Aborted multipart uploads count=0 kept=010342026/10/06 08:59:54 WARN Force mode enabled - objects will be deleted immediately without grace period10352026/10/06 08:59:54 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=010362026/10/06 08:59:54 INFO Vacuumed table table=pending_closures10372026/10/06 08:59:54 INFO Vacuumed table table=pending_objects10382026/10/06 08:59:54 INFO Vacuumed table table=multipart_uploads10392026/10/06 08:59:54 INFO Vacuumed table table=closures10402026/10/06 08:59:54 INFO Vacuumed table table=objects1041--- PASS: TestSweepSkipsRowsLockedByPush (3.26s)1042=== CONT TestClientMultipleUploads1043=== NAME TestOrphanedObjectsGCStressTest1044 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1045 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion10462026/10/06 08:59:55 INFO Received uploads request method=POST path=/api/pending_closures1047--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (3.50s)1048=== CONT TestClientIntegration10492026/10/06 08:59:55 INFO Aborted multipart uploads count=0 kept=010502026/10/06 08:59:55 WARN Force mode enabled - objects will be deleted immediately without grace period10512026/10/06 08:59:55 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=010522026/10/06 08:59:55 INFO Vacuumed table table=pending_closures10532026/10/06 08:59:55 INFO Vacuumed table table=pending_objects10542026/10/06 08:59:55 INFO Vacuumed table table=multipart_uploads10552026/10/06 08:59:55 INFO Vacuumed table table=closures10562026/10/06 08:59:55 INFO Vacuumed table table=objects1057--- PASS: TestGCSweepDeliversEachKeyOnce (2.80s)1058=== CONT TestClientErrorHandling1059=== RUN TestClientErrorHandling/InvalidStorePath1060=== PAUSE TestClientErrorHandling/InvalidStorePath1061=== RUN TestClientErrorHandling/InvalidAuthToken1062=== PAUSE TestClientErrorHandling/InvalidAuthToken1063=== RUN TestClientErrorHandling/ServerNotAvailable1064=== PAUSE TestClientErrorHandling/ServerNotAvailable1065=== CONT TestClientCADerivations10662026/10/06 08:59:55 INFO Received uploads request method=POST path=/api/pending_closures1067--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.79s)1068=== CONT TestCacheStatsHandler10692026/10/06 08:59:56 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/06 08:59:56 INFO Aborted multipart uploads count=0 kept=010712026/10/06 08:59:56 WARN Force mode enabled - objects will be deleted immediately without grace period10722026/10/06 08:59:56 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=010732026/10/06 08:59:56 INFO Vacuumed table table=pending_closures10742026/10/06 08:59:56 INFO Vacuumed table table=pending_objects10752026/10/06 08:59:56 INFO Vacuumed table table=multipart_uploads10762026/10/06 08:59:56 INFO Vacuumed table table=closures10772026/10/06 08:59:56 INFO Vacuumed table table=objects1078--- PASS: TestGCSweepSkipsPendingObjects (2.45s)1079=== CONT TestGCMetrics10802026/10/06 08:59:56 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.53s)1082=== CONT TestGCBugBareHashReferences10832026/10/06 08:59:56 INFO Aborted multipart uploads count=1 kept=010842026/10/06 08:59:56 INFO Received cleanup request method=DELETE path=/api/pending_closures10852026/10/06 08:59:56 INFO Aborted multipart uploads count=1 kept=01086--- PASS: TestPendingCleanupUsesOneCutoff (8.07s)1087=== CONT TestGCAdvisoryLockBlocksConcurrentRun10882026/10/06 08:59:56 INFO Received push request method=POST path=/api/pushes10892026/10/06 08:59:56 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10902026/10/06 08:59:56 INFO Uploading faa28q8nrls6isll1fdwd032p55bqc3m-top (256B)10912026/10/06 08:59:56 INFO Uploading 9s59llhjxr2g7k5r357vkx25yqp9lyc3-shared-dep (136B)10922026/10/06 08:59:56 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10932026/10/06 08:59:56 WARN Failed to register uploaded object key=faa28q8nrls6isll1fdwd032p55bqc3m.ls error="server returned 404: 404 page not found\n"10942026/10/06 08:59:56 WARN Failed to register uploaded object key=nar/0fs6v4j3bycq3bm3cr9b88y4qwx7gaqwjqhv0crj372n83p69s48.nar.zst error="server returned 404: 404 page not found\n"10952026/10/06 08:59:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10962026/10/06 08:59:56 WARN Failed to register uploaded object key=9s59llhjxr2g7k5r357vkx25yqp9lyc3.ls error="server returned 404: 404 page not found\n"10972026/10/06 08:59:56 INFO Signed narinfos id=1 count=210982026/10/06 08:59:56 INFO Uploading 2 narinfos10992026/10/06 08:59:56 WARN Failed to register uploaded object key=faa28q8nrls6isll1fdwd032p55bqc3m.narinfo error="server returned 404: 404 page not found\n"11002026/10/06 08:59:56 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/06 08:59:56 WARN Failed to register uploaded object key=9s59llhjxr2g7k5r357vkx25yqp9lyc3.narinfo error="server returned 404: 404 page not found\n"11022026/10/06 08:59:56 INFO Upload complete. (184ms)1103=== NAME TestClientSharedPathCommittedMidPush1104 client_integration_test.go:680: Retrieved narinfo from S3:1105 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientSharedPathCommittedMidPush981916817/001/store/9s59llhjxr2g7k5r357vkx25yqp9lyc3-shared-dep1106 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1107 Compression: zstd1108 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821109 NarSize: 1361110 References: 1111 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1112 client_integration_test.go:680: Retrieved narinfo from S3:1113 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientSharedPathCommittedMidPush981916817/001/store/faa28q8nrls6isll1fdwd032p55bqc3m-top1114 URL: nar/0fs6v4j3bycq3bm3cr9b88y4qwx7gaqwjqhv0crj372n83p69s48.nar.zst1115 Compression: zstd1116 NarHash: sha256:0fs6v4j3bycq3bm3cr9b88y4qwx7gaqwjqhv0crj372n83p69s481117 NarSize: 2561118 References: /nix/var/nix/builds/nix-72355-3875258282/TestClientSharedPathCommittedMidPush981916817/001/store/9s59llhjxr2g7k5r357vkx25yqp9lyc3-shared-dep1119 CA: text:sha256:07jaqaxn8l4yac5xdf867h3ydki4xsx2039x1zqjaihn7rwiimds1120--- PASS: TestClientSharedPathCommittedMidPush (2.98s)1121=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1122=== NAME TestOrphanedObjectsGCStressTest1123 orphaned_objects_gc_test.go:509: Stress test completed successfully:1124 orphaned_objects_gc_test.go:510: - Active objects preserved: 201125 orphaned_objects_gc_test.go:511: - Objects deleted: 2101126 orphaned_objects_gc_test.go:512: - Total GC'd: 2101127--- PASS: TestOrphanedObjectsGCStressTest (9.06s)1128=== CONT TestService_cleanupPendingClosuresHandler1129=== NAME TestClientMultipleUploads1130 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-72355-3875258282/TestClientMultipleUploads3767386860/001/store/mcyi22jw7cagcy523m647l82a56adgm0-test-file-0.txt1131=== NAME TestClientWithDependencies1132 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-72355-3875258282/TestClientWithDependencies3152348417/001/store/n0iiiss6w19wqf6v6zp3p337x7fkidwh-test-script1133 client_integration_test.go:615: Found 1 dependencies (including self)1134=== NAME TestClientMultipleUploads1135 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-72355-3875258282/TestClientMultipleUploads3767386860/001/store/gqaikzmk499q20d90ws86nxlhgaakpz7-test-file-1.txt1136 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-72355-3875258282/TestClientMultipleUploads3767386860/001/store/gzqs08a9ihcbxbhknj9zm7w3wvjpjzvx-test-file-2.txt11372026/10/06 08:59:57 INFO Received push request method=POST path=/api/pushes11382026/10/06 08:59:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11392026/10/06 08:59:57 INFO Uploading n0iiiss6w19wqf6v6zp3p337x7fkidwh-test-script (136B)11402026/10/06 08:59:57 WARN Failed to register uploaded object key=n0iiiss6w19wqf6v6zp3p337x7fkidwh.ls error="server returned 404: 404 page not found\n"11412026/10/06 08:59:57 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11422026/10/06 08:59:57 INFO Received push request method=POST path=/api/pushes11432026/10/06 08:59:57 WARN Failed to register uploaded object key=log/a3h5l82ndd9hcyhxk156z5xhw0vqdx75-test-script.drv error="server returned 404: 404 page not found\n"11442026/10/06 08:59:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11452026/10/06 08:59:57 INFO Signed narinfos id=1 count=111462026/10/06 08:59:57 INFO Uploading 1 narinfos11472026/10/06 08:59:57 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11482026/10/06 08:59:57 INFO Uploading gzqs08a9ihcbxbhknj9zm7w3wvjpjzvx-test-file-2.txt (160B)11492026/10/06 08:59:57 INFO Uploading gqaikzmk499q20d90ws86nxlhgaakpz7-test-file-1.txt (160B)11502026/10/06 08:59:57 INFO Uploading mcyi22jw7cagcy523m647l82a56adgm0-test-file-0.txt (160B)11512026/10/06 08:59:57 INFO Received complete push request method=POST path=/api/pushes/1/complete11522026/10/06 08:59:57 WARN Failed to register uploaded object key=n0iiiss6w19wqf6v6zp3p337x7fkidwh.narinfo error="server returned 404: 404 page not found\n"11532026/10/06 08:59:57 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11542026/10/06 08:59:57 WARN Failed to register uploaded object key=mcyi22jw7cagcy523m647l82a56adgm0.ls error="server returned 404: 404 page not found\n"11552026/10/06 08:59:57 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11562026/10/06 08:59:57 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11572026/10/06 08:59:57 WARN Failed to register uploaded object key=gzqs08a9ihcbxbhknj9zm7w3wvjpjzvx.ls error="server returned 404: 404 page not found\n"11582026/10/06 08:59:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11592026/10/06 08:59:57 WARN Failed to register uploaded object key=gqaikzmk499q20d90ws86nxlhgaakpz7.ls error="server returned 404: 404 page not found\n"11602026/10/06 08:59:57 INFO Signed narinfos id=1 count=311612026/10/06 08:59:57 INFO Uploading 3 narinfos11622026/10/06 08:59:57 INFO Upload complete. (181ms)1163=== NAME TestClientWithDependencies1164 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-72355-3875258282/TestClientWithDependencies3152348417/001/store) requires matching store prefix11652026/10/06 08:59:57 WARN Failed to register uploaded object key=gqaikzmk499q20d90ws86nxlhgaakpz7.narinfo error="server returned 404: 404 page not found\n"11662026/10/06 08:59:57 WARN Failed to register uploaded object key=mcyi22jw7cagcy523m647l82a56adgm0.narinfo error="server returned 404: 404 page not found\n"11672026/10/06 08:59:57 INFO Received complete push request method=POST path=/api/pushes/1/complete11682026/10/06 08:59:57 WARN Failed to register uploaded object key=gzqs08a9ihcbxbhknj9zm7w3wvjpjzvx.narinfo error="server returned 404: 404 page not found\n"11692026/10/06 08:59:57 INFO Upload complete. (144ms)1170=== NAME TestClientMultipleUploads1171 client_integration_test.go:369: Uploaded 3 paths in 175.245292ms1172=== NAME TestClientIntegration1173 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-72355-3875258282/TestClientIntegration607506444/002/store/lychm9llslzaqcd788549a8fkga9i23n-test-file.txt1174--- PASS: TestClientWithDependencies (3.12s)1175=== CONT TestUploadHandlersRejectOversizedBody1176=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1177=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1178=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1179=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1180=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1181=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1182=== CONT TestUploadHandlersRejectInvalidKeys1183=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1184=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1185=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1186=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1187=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1188=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1189=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1190=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1191=== CONT TestIsValidUploadKey1192=== RUN TestIsValidUploadKey/narinfo1193=== PAUSE TestIsValidUploadKey/narinfo1194=== RUN TestIsValidUploadKey/nar_zst1195=== PAUSE TestIsValidUploadKey/nar_zst1196=== RUN TestIsValidUploadKey/nar_xz1197=== PAUSE TestIsValidUploadKey/nar_xz1198=== RUN TestIsValidUploadKey/nar_plain1199=== PAUSE TestIsValidUploadKey/nar_plain1200=== RUN TestIsValidUploadKey/listing1201=== PAUSE TestIsValidUploadKey/listing1202=== RUN TestIsValidUploadKey/build_log1203=== PAUSE TestIsValidUploadKey/build_log1204=== RUN TestIsValidUploadKey/build_log_home-manager_file1205=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1206=== RUN TestIsValidUploadKey/build_log_plus_in_name1207=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1208=== RUN TestIsValidUploadKey/build_log_question_mark1209=== PAUSE TestIsValidUploadKey/build_log_question_mark1210=== RUN TestIsValidUploadKey/build_log_equals1211=== PAUSE TestIsValidUploadKey/build_log_equals1212=== RUN TestIsValidUploadKey/realisation1213=== PAUSE TestIsValidUploadKey/realisation1214=== RUN TestIsValidUploadKey/realisation_plus_in_output1215=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1216=== RUN TestIsValidUploadKey/nix-cache-info1217=== PAUSE TestIsValidUploadKey/nix-cache-info1218=== RUN TestIsValidUploadKey/index.html1219=== PAUSE TestIsValidUploadKey/index.html1220=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1221=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1222=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1223=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1224=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1225=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1226=== RUN TestIsValidUploadKey/traversal1227=== PAUSE TestIsValidUploadKey/traversal1228=== RUN TestIsValidUploadKey/traversal_nar1229=== PAUSE TestIsValidUploadKey/traversal_nar1230=== RUN TestIsValidUploadKey/absolute1231=== PAUSE TestIsValidUploadKey/absolute1232=== RUN TestIsValidUploadKey/empty_key1233=== PAUSE TestIsValidUploadKey/empty_key1234=== RUN TestIsValidUploadKey/unknown_type1235=== PAUSE TestIsValidUploadKey/unknown_type1236=== CONT TestPendingClosureWriteTimeout1237=== RUN TestPendingClosureWriteTimeout/empty1238=== PAUSE TestPendingClosureWriteTimeout/empty1239=== RUN TestPendingClosureWriteTimeout/400_objects1240=== PAUSE TestPendingClosureWriteTimeout/400_objects1241=== RUN TestPendingClosureWriteTimeout/670k_objects1242=== PAUSE TestPendingClosureWriteTimeout/670k_objects1243=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1244=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1245=== CONT TestProxyWriteTimeout1246=== RUN TestProxyWriteTimeout/narinfo1247=== PAUSE TestProxyWriteTimeout/narinfo1248=== RUN TestProxyWriteTimeout/1_GiB_nar1249=== PAUSE TestProxyWriteTimeout/1_GiB_nar1250=== RUN TestProxyWriteTimeout/10_GiB_nar1251=== PAUSE TestProxyWriteTimeout/10_GiB_nar1252=== RUN TestProxyWriteTimeout/unknown_size1253=== PAUSE TestProxyWriteTimeout/unknown_size1254=== CONT TestLeadEndsOnShutdown1255--- PASS: TestClientMultipleUploads (2.65s)1256=== CONT TestLeadIncumbentAnnouncesAtOnce12572026/10/06 08:59:57 INFO Received push request method=POST path=/api/pushes12582026/10/06 08:59:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12592026/10/06 08:59:57 INFO Uploading lychm9llslzaqcd788549a8fkga9i23n-test-file.txt (152B)12602026/10/06 08:59:57 WARN Failed to register uploaded object key=lychm9llslzaqcd788549a8fkga9i23n.ls error="server returned 404: 404 page not found\n"12612026/10/06 08:59:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12622026/10/06 08:59:57 INFO Signed narinfos id=1 count=112632026/10/06 08:59:57 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12642026/10/06 08:59:57 INFO Uploading 1 narinfos12652026/10/06 08:59:57 INFO Received complete push request method=POST path=/api/pushes/1/complete12662026/10/06 08:59:57 WARN Failed to register uploaded object key=lychm9llslzaqcd788549a8fkga9i23n.narinfo error="server returned 404: 404 page not found\n"12672026/10/06 08:59:57 INFO Upload complete. (137ms)12682026/10/06 08:59:57 INFO All 1 paths already cached1269=== NAME TestClientIntegration1270 client_integration_test.go:312: Retrieved narinfo from S3:1271 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientIntegration607506444/002/store/lychm9llslzaqcd788549a8fkga9i23n-test-file.txt1272 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1273 Compression: zstd1274 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11275 NarSize: 1521276 References: 1277 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11278 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1279 client_integration_test.go:313: Decompressed .ls content (64 bytes):1280 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1281 client_integration_test.go:316: Testing garbage collection...12822026/10/06 08:59:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures12832026/10/06 08:59:57 INFO Garbage collection started12842026/10/06 08:59:57 INFO Aborted multipart uploads count=0 kept=012852026/10/06 08:59:57 WARN Force mode enabled - objects will be deleted immediately without grace period12862026/10/06 08:59:57 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=012872026/10/06 08:59:57 INFO Vacuumed table table=pending_closures12882026/10/06 08:59:57 INFO Vacuumed table table=pending_objects12892026/10/06 08:59:57 INFO Vacuumed table table=multipart_uploads12902026/10/06 08:59:57 INFO Vacuumed table table=closures1291--- PASS: TestCacheStatsHandler (1.98s)1292=== CONT TestLeadElectsOneAndHandsOver12932026/10/06 08:59:57 INFO Vacuumed table table=objects1294=== NAME TestClientCADerivations1295 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-72355-3875258282/TestClientCADerivations4077643186/001/store/jincxg20165gciz0f3cy57g9chkd954z-ca-test1296 client_ca_test.go:139: Found 1 dependencies (including self)12972026/10/06 08:59:58 INFO Aborted multipart uploads count=0 kept=012982026/10/06 08:59:58 WARN Force mode enabled - objects will be deleted immediately without grace period12992026/10/06 08:59: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=013002026/10/06 08:59:58 INFO Vacuumed table table=pending_closures13012026/10/06 08:59:58 INFO Vacuumed table table=pending_objects13022026/10/06 08:59:58 INFO Vacuumed table table=multipart_uploads13032026/10/06 08:59:58 INFO Vacuumed table table=closures13042026/10/06 08:59:58 INFO Vacuumed table table=objects1305--- PASS: TestGCMetrics (1.89s)1306=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13072026/10/06 08:59:58 INFO Received push request method=POST path=/api/pushes13082026/10/06 08:59:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13092026/10/06 08:59:58 INFO Uploading jincxg20165gciz0f3cy57g9chkd954z-ca-test (144B)13102026/10/06 08:59:58 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13112026/10/06 08:59:58 WARN Failed to register uploaded object key=jincxg20165gciz0f3cy57g9chkd954z.ls error="server returned 404: 404 page not found\n"13122026/10/06 08:59:58 WARN Failed to register uploaded object key=log/l30kr2nfb1vk6a95y2xffxcag9g2jr6f-ca-test.drv error="server returned 404: 404 page not found\n"13132026/10/06 08:59:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13142026/10/06 08:59:58 INFO Signed narinfos id=1 count=113152026/10/06 08:59:58 INFO Uploading 1 narinfos13162026/10/06 08:59:58 INFO Received complete push request method=POST path=/api/pushes/1/complete13172026/10/06 08:59:58 WARN Failed to register uploaded object key=jincxg20165gciz0f3cy57g9chkd954z.narinfo error="server returned 404: 404 page not found\n"13182026/10/06 08:59:58 INFO Upload complete. (180ms)1319=== NAME TestClientCADerivations1320 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientCADerivations4077643186/001/store/jincxg20165gciz0f3cy57g9chkd954z-ca-test1321 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1322 Compression: zstd1323 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1324 NarSize: 1441325 References: 1326 Deriver: /nix/var/nix/builds/nix-72355-3875258282/TestClientCADerivations4077643186/001/store/l30kr2nfb1vk6a95y2xffxcag9g2jr6f-ca-test.drv1327 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1328 client_ca_test.go:185: Checking for realisation files in S3...1329 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1330 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1331 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket48?endpoint=http://localhost:50581®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-72355-3875258282/TestClientCADerivations4077643186/001/store'1332 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11333--- PASS: TestClientCADerivations (2.67s)1334=== CONT TestSkippedUploadsHandler13352026/10/06 08:59:58 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001336--- PASS: TestSkippedUploadsHandler (0.00s)1337=== CONT TestParseSize1338--- PASS: TestParseSize (0.00s)1339=== CONT TestService_Rustfstest13402026/10/06 08:59:58 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld10 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1341--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.90s)1342=== CONT TestConnectWaitsForAPeerMigration1343--- PASS: TestGCBugBareHashReferences (2.25s)1344=== CONT TestResolveDBConnectionString1345=== RUN TestResolveDBConnectionString/flag_wins1346=== PAUSE TestResolveDBConnectionString/flag_wins1347=== RUN TestResolveDBConnectionString/file_when_flag_empty1348=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1349=== RUN TestResolveDBConnectionString/missing_file_is_an_error1350=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1351=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1352=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1353=== RUN TestResolveDBConnectionString/nothing_configured1354=== PAUSE TestResolveDBConnectionString/nothing_configured1355=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13562026/10/06 08:59:58 INFO Received cleanup request method=DELETE path=/api/pending_closures13572026/10/06 08:59:58 INFO Aborted multipart uploads count=0 kept=013582026/10/06 08:59:58 INFO Received uploads request method=POST path=/api/pending_closures13592026/10/06 08:59:58 INFO Received cleanup request method=DELETE path=/api/pending_closures13602026/10/06 08:59:58 INFO Aborted multipart uploads count=1 kept=013612026/10/06 08:59:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13622026-10-06 08:59:58.785 UTC [73515] ERROR: Closure does not exist: id=113632026-10-06 08:59:58.785 UTC [73515] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13642026-10-06 08:59:58.785 UTC [73515] STATEMENT: -- name: CommitPendingClosure :exec1365 SELECT commit_pending_closure($1::bigint)1366 1367--- PASS: TestService_cleanupPendingClosuresHandler (1.77s)1368=== CONT TestPresignedUploadRegisteredBeforeCommit13692026/10/06 08:59:58 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/06 08:59:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13712026/10/06 08:59:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjE2Y2U5M2QxLTMxOGUtNGU4MC04N2ZkLWMxOGJkMjExZmU3OHgxNzkxMjc3MTk4OTYyMDk3MDAw13722026/10/06 08:59:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjE2Y2U5M2QxLTMxOGUtNGU4MC04N2ZkLWMxOGJkMjExZmU3OHgxNzkxMjc3MTk4OTYyMDk3MDAw parts=11373--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.16s)1374=== CONT TestClientFallsBackToClosures13752026/10/06 08:59:59 INFO lead: acquired remote=192.0.2.1:123413762026/10/06 08:59:59 INFO lead: released remote=192.0.2.1:12341377--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.63s)1378=== CONT TestClientPushesUseOnePush13792026/10/06 08:59:59 INFO lead: acquired remote=192.0.2.1:123413802026/10/06 08:59:59 INFO lead: acquired remote=192.0.2.1:123413812026/10/06 08:59:59 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01382=== NAME TestClientIntegration1383 client_integration_test.go:323: Objects in database after GC:1384 client_integration_test.go:323: Successfully deleted all objects with GC --force1385--- PASS: TestClientIntegration (4.31s)1386=== CONT TestPinProtectsFromGC13872026/10/06 08:59:59 INFO Received uploads request method=POST path=/api/pending_closures1388--- PASS: TestService_Rustfstest (1.79s)1389=== CONT TestGCTaskStore_DeduplicateSameParams1390--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1391=== CONT TestGCTaskStore_GetEmpty1392--- PASS: TestGCTaskStore_GetEmpty (0.00s)1393=== CONT TestGCTaskStore_ConflictDifferentParams1394--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1395=== CONT TestCompletedNarNotReofferedAcrossClosures13962026/10/06 09:00:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13972026/10/06 09:00:00 INFO lead: released remote=192.0.2.1:12341398--- PASS: TestLeadEndsOnShutdown (2.95s)1399=== CONT TestService_AuthMiddleware_OIDC14002026/10/06 09:00:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51213/oidc14012026/10/06 09:00:00 INFO lead: released remote=192.0.2.1:123414022026/10/06 09:00:00 INFO Received uploads request method=POST path=/api/pending_closures14032026/10/06 09:00:00 INFO lead: acquired remote=192.0.2.1:123414042026/10/06 09:00:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14052026/10/06 09:00:00 INFO Received uploads request method=POST path=/api/pending_closures1406--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.07s)1407=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14082026/10/06 09:00:01 INFO Received push request method=POST path=/api/pushes14092026/10/06 09:00:01 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14102026/10/06 09:00:01 INFO Uploading mcn2yd9467ksaz47lagmxaw2a0hnb5pq-a (248B)14112026/10/06 09:00:01 INFO Uploading vi8ym2jliqyfg3ddpf92v3favx6ywvw6-shared-dep (136B)14122026/10/06 09:00:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14132026/10/06 09:00:01 WARN Failed to register uploaded object key=ldpy6zawvdm0d97a6nx8na44p94di8gl.ls error="server returned 404: 404 page not found\n"14142026/10/06 09:00:01 WARN Failed to register uploaded object key=mcn2yd9467ksaz47lagmxaw2a0hnb5pq.ls error="server returned 404: 404 page not found\n"14152026/10/06 09:00:01 WARN Failed to register uploaded object key=nar/1fab2k1rdinvnrphdigh6h8vlzpd8scll3kzqgzkfz6sh1838vd4.nar.zst error="server returned 404: 404 page not found\n"14162026/10/06 09:00:01 WARN Failed to register uploaded object key=vi8ym2jliqyfg3ddpf92v3favx6ywvw6.ls error="server returned 404: 404 page not found\n"14172026/10/06 09:00:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14182026/10/06 09:00:01 INFO Signed narinfos id=1 count=314192026/10/06 09:00:01 INFO Uploading 3 narinfos14202026/10/06 09:00:01 WARN Failed to register uploaded object key=mcn2yd9467ksaz47lagmxaw2a0hnb5pq.narinfo error="server returned 404: 404 page not found\n"14212026/10/06 09:00:01 WARN Failed to register uploaded object key=vi8ym2jliqyfg3ddpf92v3favx6ywvw6.narinfo error="server returned 404: 404 page not found\n"14222026/10/06 09:00:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/06 09:00:01 WARN Failed to register uploaded object key=ldpy6zawvdm0d97a6nx8na44p94di8gl.narinfo error="server returned 404: 404 page not found\n"1424--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.01s)1425=== CONT TestService_ReadScope_PublicByDefault14262026/10/06 09:00:01 INFO Upload complete. (137ms)1427=== NAME TestClientPushesUseOnePush1428 client_pushes_test.go:97: Retrieved narinfo from S3:1429 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientPushesUseOnePush3199360076/001/store/vi8ym2jliqyfg3ddpf92v3favx6ywvw6-shared-dep1430 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1431 Compression: zstd1432 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821433 NarSize: 1361434 References: 1435 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1436 client_pushes_test.go:97: Retrieved narinfo from S3:1437 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientPushesUseOnePush3199360076/001/store/mcn2yd9467ksaz47lagmxaw2a0hnb5pq-a1438 URL: nar/1fab2k1rdinvnrphdigh6h8vlzpd8scll3kzqgzkfz6sh1838vd4.nar.zst1439 Compression: zstd1440 NarHash: sha256:1fab2k1rdinvnrphdigh6h8vlzpd8scll3kzqgzkfz6sh1838vd41441 NarSize: 2481442 References: /nix/var/nix/builds/nix-72355-3875258282/TestClientPushesUseOnePush3199360076/001/store/vi8ym2jliqyfg3ddpf92v3favx6ywvw6-shared-dep1443 CA: text:sha256:1zviahzqbm2zgfb4fxskvf36nilij1347grql4zccm1gzq6bahv31444 client_pushes_test.go:97: Retrieved narinfo from S3:1445 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientPushesUseOnePush3199360076/001/store/ldpy6zawvdm0d97a6nx8na44p94di8gl-b1446 URL: nar/1fab2k1rdinvnrphdigh6h8vlzpd8scll3kzqgzkfz6sh1838vd4.nar.zst1447 Compression: zstd1448 NarHash: sha256:1fab2k1rdinvnrphdigh6h8vlzpd8scll3kzqgzkfz6sh1838vd41449 NarSize: 2481450 References: /nix/var/nix/builds/nix-72355-3875258282/TestClientPushesUseOnePush3199360076/001/store/vi8ym2jliqyfg3ddpf92v3favx6ywvw6-shared-dep1451 CA: text:sha256:1zviahzqbm2zgfb4fxskvf36nilij1347grql4zccm1gzq6bahv31452--- PASS: TestClientPushesUseOnePush (2.49s)1453=== CONT TestService_ReadAuthMiddleware14542026/10/06 09:00:01 INFO Received uploads request method=POST path=/api/pending_closures14552026/10/06 09:00:01 INFO Received uploads request method=POST path=/api/pending_closures14562026/10/06 09:00:01 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14572026/10/06 09:00:01 INFO Uploading v89gdms42xi92p09hj8zayimi9c57gsc-shared-dep (136B)14582026/10/06 09:00:01 INFO Uploading n9020dgi059xnf03f9m259j3m0aad40m-a (248B)14592026/10/06 09:00:01 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14602026/10/06 09:00:01 WARN Failed to register uploaded object key=n9020dgi059xnf03f9m259j3m0aad40m.ls error="server returned 404: 404 page not found\n"14612026/10/06 09:00:01 WARN Failed to register uploaded object key=6kp766sq5ahjcsjsvj06xw63qnjjgxpi.ls error="server returned 404: 404 page not found\n"14622026/10/06 09:00:01 WARN Failed to register uploaded object key=v89gdms42xi92p09hj8zayimi9c57gsc.ls error="server returned 404: 404 page not found\n"14632026/10/06 09:00:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14642026/10/06 09:00:01 WARN Failed to register uploaded object key=nar/1fp9nq8jjh8r6kk35m0yb5i6jsjh0qk8vl22lbwbfqswq0nljhhj.nar.zst error="server returned 404: 404 page not found\n"14652026/10/06 09:00:01 INFO Signed narinfos id=2 count=214662026/10/06 09:00:01 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14672026/10/06 09:00:01 INFO Signed narinfos id=1 count=214682026/10/06 09:00:01 INFO Uploading 4 narinfos14692026/10/06 09:00:01 WARN Failed to register uploaded object key=n9020dgi059xnf03f9m259j3m0aad40m.narinfo error="server returned 404: 404 page not found\n"14702026/10/06 09:00:01 WARN Failed to register uploaded object key=6kp766sq5ahjcsjsvj06xw63qnjjgxpi.narinfo error="server returned 404: 404 page not found\n"14712026/10/06 09:00:01 WARN Failed to register uploaded object key=v89gdms42xi92p09hj8zayimi9c57gsc.narinfo error="server returned 404: 404 page not found\n"14722026/10/06 09:00:01 INFO lead: released remote=192.0.2.1:12341473--- PASS: TestLeadElectsOneAndHandsOver (4.04s)1474=== CONT TestService_RequireScope_OIDC14752026/10/06 09:00:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14762026/10/06 09:00:01 WARN Failed to register uploaded object key=v89gdms42xi92p09hj8zayimi9c57gsc.narinfo error="server returned 404: 404 page not found\n"14772026/10/06 09:00:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51254/oidc14782026/10/06 09:00:01 INFO Completed upload id=114792026/10/06 09:00:01 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14802026/10/06 09:00:01 INFO Completed upload id=214812026/10/06 09:00:01 INFO Upload complete. (240ms)1482=== NAME TestClientFallsBackToClosures1483 client_pushes_test.go:112: Retrieved narinfo from S3:1484 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientFallsBackToClosures1338139245/001/store/v89gdms42xi92p09hj8zayimi9c57gsc-shared-dep1485 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1486 Compression: zstd1487 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821488 NarSize: 1361489 References: 1490 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1491 client_pushes_test.go:112: Retrieved narinfo from S3:1492 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientFallsBackToClosures1338139245/001/store/n9020dgi059xnf03f9m259j3m0aad40m-a1493 URL: nar/1fp9nq8jjh8r6kk35m0yb5i6jsjh0qk8vl22lbwbfqswq0nljhhj.nar.zst1494 Compression: zstd1495 NarHash: sha256:1fp9nq8jjh8r6kk35m0yb5i6jsjh0qk8vl22lbwbfqswq0nljhhj1496 NarSize: 2481497 References: /nix/var/nix/builds/nix-72355-3875258282/TestClientFallsBackToClosures1338139245/001/store/v89gdms42xi92p09hj8zayimi9c57gsc-shared-dep1498 CA: text:sha256:0hkm29r1pzvnzkl5ny9979mw3gv4gc8bnz5h1d290hzyc1gkc6qs1499 client_pushes_test.go:112: Retrieved narinfo from S3:1500 StorePath: /nix/var/nix/builds/nix-72355-3875258282/TestClientFallsBackToClosures1338139245/001/store/6kp766sq5ahjcsjsvj06xw63qnjjgxpi-b1501 URL: nar/1fp9nq8jjh8r6kk35m0yb5i6jsjh0qk8vl22lbwbfqswq0nljhhj.nar.zst1502 Compression: zstd1503 NarHash: sha256:1fp9nq8jjh8r6kk35m0yb5i6jsjh0qk8vl22lbwbfqswq0nljhhj1504 NarSize: 2481505 References: /nix/var/nix/builds/nix-72355-3875258282/TestClientFallsBackToClosures1338139245/001/store/v89gdms42xi92p09hj8zayimi9c57gsc-shared-dep1506 CA: text:sha256:0hkm29r1pzvnzkl5ny9979mw3gv4gc8bnz5h1d290hzyc1gkc6qs1507--- PASS: TestClientFallsBackToClosures (2.85s)1508=== CONT TestService_AuthMiddleware_MTLSProxyHeader15092026/10/06 09:00:02 INFO Received uploads request method=POST path=/api/pending_closures1510=== NAME TestPinProtectsFromGC1511 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-72355-3875258282/TestPinProtectsFromGC4024607932/001/store/h59a6if94ryrhh34clc8aczh5pv2m2ag-pinned-file.txt1512 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-72355-3875258282/TestPinProtectsFromGC4024607932/001/store/iwm8k176m4m5hnwvlr5pr8vf9k761iri-unpinned-file.txt15132026/10/06 09:00:02 INFO Received push request method=POST path=/api/pushes15142026/10/06 09:00:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15152026/10/06 09:00:02 INFO Uploading h59a6if94ryrhh34clc8aczh5pv2m2ag-pinned-file.txt (128B)15162026/10/06 09:00:02 WARN Failed to register uploaded object key=h59a6if94ryrhh34clc8aczh5pv2m2ag.ls error="server returned 404: 404 page not found\n"15172026/10/06 09:00:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15182026/10/06 09:00:02 INFO Signed narinfos id=1 count=115192026/10/06 09:00:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15202026/10/06 09:00:02 INFO Uploading 1 narinfos15212026/10/06 09:00:02 INFO Received complete push request method=POST path=/api/pushes/1/complete15222026/10/06 09:00:02 WARN Failed to register uploaded object key=h59a6if94ryrhh34clc8aczh5pv2m2ag.narinfo error="server returned 404: 404 page not found\n"15232026/10/06 09:00:02 INFO Upload complete. (136ms)15242026/10/06 09:00:02 INFO Received push request method=POST path=/api/pushes15252026/10/06 09:00:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15262026/10/06 09:00:02 INFO Uploading iwm8k176m4m5hnwvlr5pr8vf9k761iri-unpinned-file.txt (128B)15272026/10/06 09:00:02 WARN Failed to register uploaded object key=iwm8k176m4m5hnwvlr5pr8vf9k761iri.ls error="server returned 404: 404 page not found\n"15282026/10/06 09:00:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15292026/10/06 09:00:02 INFO Signed narinfos id=2 count=115302026/10/06 09:00:02 INFO Uploading 1 narinfos15312026/10/06 09:00:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15322026/10/06 09:00:02 INFO Received complete push request method=POST path=/api/pushes/2/complete15332026/10/06 09:00:02 WARN Failed to register uploaded object key=iwm8k176m4m5hnwvlr5pr8vf9k761iri.narinfo error="server returned 404: 404 page not found\n"15342026/10/06 09:00:02 INFO Upload complete. (61ms)15352026/10/06 09:00:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures15362026/10/06 09:00:02 INFO Garbage collection started15372026/10/06 09:00:02 INFO Aborted multipart uploads count=0 kept=015382026/10/06 09:00:02 WARN Force mode enabled - objects will be deleted immediately without grace period15392026/10/06 09:00:02 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=015402026/10/06 09:00:02 INFO Vacuumed table table=pending_closures15412026/10/06 09:00:02 INFO Vacuumed table table=pending_objects15422026/10/06 09:00:02 INFO Vacuumed table table=multipart_uploads15432026/10/06 09:00:02 INFO Vacuumed table table=closures15442026/10/06 09:00:02 INFO Vacuumed table table=objects1545=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1546=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1547=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1548=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1549=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1550=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1551=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1552=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1553=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15542026/10/06 09:00:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15552026/10/06 09:00:03 WARN mTLS auth: bound subjects configured but subject DN unavailable15562026/10/06 09:00:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1557--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.15s)1558=== CONT TestRedundantMultipartUpload15592026/10/06 09:00:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15602026/10/06 09:00:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjhmMDJiMTAzLWYzYzItNDM3My05MGNlLWJlMDc3NWNhMGZmOHgxNzkxMjc3MjAyMTI3NzAzMDAw parts=1215612026/10/06 09:00:03 INFO Received uploads request method=POST path=/api/pending_closures1562--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.35s)1563=== CONT TestReadRedirectKeepsNarinfoProxied1564--- PASS: TestService_ReadScope_PublicByDefault (2.09s)1565=== CONT TestPush_SignsNarinfosOfItsPendingObjects1566--- PASS: TestService_ReadAuthMiddleware (2.26s)1567=== CONT TestReadRedirectUsesPublicS3URL1568=== RUN TestService_RequireScope_OIDC/builder_may_write1569=== PAUSE TestService_RequireScope_OIDC/builder_may_write1570=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1571=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1572=== RUN TestService_RequireScope_OIDC/ops_may_admin1573=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1574=== RUN TestService_RequireScope_OIDC/ops_may_not_write1575=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1576=== RUN TestService_RequireScope_OIDC/reader_may_not_write1577=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1578=== RUN TestService_RequireScope_OIDC/static_token_may_admin1579=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1580=== RUN TestService_RequireScope_OIDC/static_token_may_write1581=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1582=== RUN TestService_RequireScope_OIDC/reader_may_read1583=== PAUSE TestService_RequireScope_OIDC/reader_may_read1584=== RUN TestService_RequireScope_OIDC/writer_implies_read1585=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1586=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1587=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1588=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1589=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1590=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1591=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1592=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1593=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1594=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1595=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1596=== CONT TestReadProxyRangeRequest15972026/10/06 09:00:04 WARN Rate limiter enabled after throttle name=s3-test rate=515982026/10/06 09:00:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1599=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1600 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101601 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001602--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.13s)1603=== CONT TestGCTaskStore_StartNew1604--- PASS: TestGCTaskStore_StartNew (0.00s)1605=== CONT TestGCEndsOnShutdown1606=== RUN TestGCEndsOnShutdown/before_the_run1607=== PAUSE TestGCEndsOnShutdown/before_the_run1608=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1609=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1610=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1611=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1612=== CONT TestPush_RejectsBadRequests1613--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.43s)1614=== CONT TestPush_CompleteCommitsEveryRoot16152026/10/06 09:00:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016162026/10/06 09:00:04 INFO Received create pin request method=POST path=/api/pins/myapp16172026/10/06 09:00:04 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-72355-3875258282/TestPinProtectsFromGC4024607932/001/store/h59a6if94ryrhh34clc8aczh5pv2m2ag-pinned-file.txt narinfo_key=h59a6if94ryrhh34clc8aczh5pv2m2ag.narinfo16182026/10/06 09:00:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures16192026/10/06 09:00:04 INFO Garbage collection started16202026/10/06 09:00:04 INFO Aborted multipart uploads count=0 kept=016212026/10/06 09:00:04 WARN Force mode enabled - objects will be deleted immediately without grace period16222026/10/06 09:00:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016232026/10/06 09:00:04 INFO Vacuumed table table=pending_closures16242026/10/06 09:00:04 INFO Vacuumed table table=pending_objects16252026/10/06 09:00:04 INFO Vacuumed table table=multipart_uploads16262026/10/06 09:00:04 INFO Vacuumed table table=closures16272026/10/06 09:00:04 INFO Vacuumed table table=objects16282026/10/06 09:00:04 INFO Received push request method=POST path=/api/pushes1629--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.18s)1630=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16312026/10/06 09:00:05 INFO Received uploads request method=POST path=/api/pending_closures16322026/10/06 09:00:05 INFO Received uploads request method=POST path=/api/pending_closures1633--- PASS: TestConnectWaitsForAPeerMigration (6.71s)1634=== CONT TestReadProxyDisabled1635--- PASS: TestReadRedirectKeepsNarinfoProxied (2.20s)1636=== CONT TestReadProxyRootRedirectsToIndexHTML16372026/10/06 09:00:06 INFO Received push request method=POST path=/api/pushes16382026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16392026/10/06 09:00:06 INFO Signed narinfos id=1 count=116402026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16422026/10/06 09:00:06 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16432026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16442026/10/06 09:00:06 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16452026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16462026/10/06 09:00:06 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116472026/10/06 09:00:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16482026/10/06 09:00:06 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1649--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.59s)1650=== CONT TestReadRedirectNar1651=== NAME TestPinProtectsFromGC1652 client_integration_test.go:840: Pin successfully protected closure from garbage collection1653--- PASS: TestReadRedirectUsesPublicS3URL (2.61s)1654=== CONT TestReadProxyConditionalGet1655--- PASS: TestPinProtectsFromGC (6.80s)1656=== CONT TestIsValidCachePath/narinfo1657=== CONT TestIsValidCachePath/index.html1658=== CONT TestIsValidCachePath/short_hash1659=== CONT TestIsValidCachePath/wrong_extension1660=== CONT TestIsValidCachePath/leading_slash1661=== CONT TestIsValidCachePath/empty1662=== CONT TestIsValidCachePath/traversal_in_middle1663=== CONT TestIsValidCachePath/traversal_parent1664=== CONT TestIsValidCachePath/nar_uncompressed1665=== CONT TestIsValidCachePath/nix-cache-info1666=== CONT TestIsValidCachePath/invalid_char_e1667=== CONT TestIsValidCachePath/realisation1668=== CONT TestIsValidCachePath/random_path1669=== CONT TestIsValidCachePath/log1670=== CONT TestIsValidCachePath/invalid_char_u1671=== CONT TestIsValidCachePath/ls1672=== CONT TestIsValidCachePath/nar_xz1673=== CONT TestIsValidCachePath/nar_zst1674=== CONT TestIsValidCachePath/nar_bz21675=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1676--- PASS: TestIsValidCachePath (0.00s)1677 --- PASS: TestIsValidCachePath/narinfo (0.00s)1678 --- PASS: TestIsValidCachePath/index.html (0.00s)1679 --- PASS: TestIsValidCachePath/short_hash (0.00s)1680 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1681 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1682 --- PASS: TestIsValidCachePath/empty (0.00s)1683 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1684 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1685 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1686 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1687 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1688 --- PASS: TestIsValidCachePath/realisation (0.00s)1689 --- PASS: TestIsValidCachePath/random_path (0.00s)1690 --- PASS: TestIsValidCachePath/log (0.00s)1691 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1692 --- PASS: TestIsValidCachePath/ls (0.00s)1693 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1694 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1695 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1696 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1697=== CONT TestParseSingleRange/none1698=== CONT TestParseSingleRange/open-ended1699=== CONT TestParseSingleRange/start_far_past_EOF1700=== CONT TestParseSingleRange/start_past_EOF1701=== CONT TestParseSingleRange/single_byte1702=== CONT TestParseSingleRange/suffix_exceeds_size1703=== CONT TestParseSingleRange/malformed_both_empty1704=== CONT TestParseSingleRange/closed1705=== CONT TestParseSingleRange/malformed_end_before_start1706=== CONT TestParseSingleRange/multi-range_ignored1707=== CONT TestParseSingleRange/malformed_no_dash1708=== CONT TestParseSingleRange/unknown_unit1709=== CONT TestParseSingleRange/end_clamped_to_size1710=== CONT TestParseSingleRange/suffix1711--- PASS: TestParseSingleRange (0.00s)1712 --- PASS: TestParseSingleRange/none (0.00s)1713 --- PASS: TestParseSingleRange/open-ended (0.00s)1714 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1715 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1716 --- PASS: TestParseSingleRange/single_byte (0.00s)1717 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1718 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1719 --- PASS: TestParseSingleRange/closed (0.00s)1720 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1721 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1722 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1723 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1724 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1725 --- PASS: TestParseSingleRange/suffix (0.00s)1726=== CONT TestServerTLSConfig/no_client_CA1727=== CONT TestServerTLSConfig/not_a_PEM_file1728=== CONT TestServerTLSConfig/missing_CA_file1729--- PASS: TestServerTLSConfig (0.00s)1730 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1731 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1732 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1733=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17342026/10/06 09:00:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17352026/10/06 09:00:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLmQzNjhlZTJlLWIxZmUtNGJkNy1hYTcxLTZiNDYxY2YwNWQ5N3gxNzkxMjc3MjA1MTA2MTc0MDAw parts=121736=== RUN TestPush_RejectsBadRequests/no_roots1737=== PAUSE TestPush_RejectsBadRequests/no_roots1738=== RUN TestPush_RejectsBadRequests/no_objects1739=== PAUSE TestPush_RejectsBadRequests/no_objects1740=== RUN TestPush_RejectsBadRequests/bad_root1741=== PAUSE TestPush_RejectsBadRequests/bad_root1742=== RUN TestPush_RejectsBadRequests/root_not_in_objects1743=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1744=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17452026/10/06 09:00:06 INFO Received uploads request method=POST path=/api/pending_closures17462026/10/06 09:00:06 INFO Received uploads request method=POST path=/api/pending_closures1747--- PASS: TestReadProxyRangeRequest (3.09s)1748=== CONT TestCacheConfigHandler/full_config,_no_issuer1749=== CONT TestCacheConfigHandler/no_signing_keys1750=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1751=== CONT TestCacheConfigHandler/no_cache_url_configured1752--- PASS: TestCacheConfigHandler (0.00s)1753 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1754 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1755 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1756 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1757=== CONT TestClientErrorHandling/InvalidStorePath17582026/10/06 09:00:07 INFO Received push request method=POST path=/api/pushes17592026/10/06 09:00:07 INFO Received complete push request method=POST path=/api/pushes/1/complete1760--- PASS: TestPush_CompleteCommitsEveryRoot (3.28s)1761=== CONT TestClientErrorHandling/ServerNotAvailable17622026/10/06 09:00:07 INFO Received push request method=POST path=/api/pushes17632026/10/06 09:00:08 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/present17642026/10/06 09:00:08 INFO Received complete push request method=POST path=/api/pushes/1/complete17652026/10/06 09:00:08 INFO Received push request method=POST path=/api/pushes17662026/10/06 09:00:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=180.445093ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17672026/10/06 09:00:08 INFO Aborted multipart uploads count=0 kept=017682026/10/06 09:00:08 WARN Force mode enabled - objects will be deleted immediately without grace period17692026/10/06 09:00:08 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=017702026/10/06 09:00:08 INFO Vacuumed table table=pending_closures17712026/10/06 09:00:08 INFO Vacuumed table table=pending_objects17722026/10/06 09:00:08 INFO Vacuumed table table=multipart_uploads17732026/10/06 09:00:08 INFO Vacuumed table table=closures1774--- PASS: TestReadProxyDisabled (3.05s)1775=== CONT TestClientErrorHandling/InvalidAuthToken17762026/10/06 09:00:08 INFO Vacuumed table table=objects17772026/10/06 09:00:08 INFO Received complete push request method=POST path=/api/pushes/2/complete1778--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.38s)1779=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17802026/10/06 09:00:08 INFO Received uploads request method=POST path=/17812026/10/06 09:00:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=419.449963ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1782=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17832026/10/06 09:00:08 INFO Received request for more parts method=POST path=/1784=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17852026/10/06 09:00:08 INFO Received complete multipart upload request method=POST path=/1786=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17872026/10/06 09:00:08 INFO Received uploads request method=POST path=/1788--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1789 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.29s)1790 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1791 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1792=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17932026/10/06 09:00:08 INFO Received complete multipart upload request method=POST path=/1794=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17952026/10/06 09:00:08 INFO Received request for more parts method=POST path=/1796=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17972026/10/06 09:00:08 INFO Received uploads request method=POST path=/1798--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1799 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1800 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1801 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1802 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1803=== CONT TestIsValidUploadKey/narinfo1804=== CONT TestIsValidUploadKey/absolute1805=== CONT TestIsValidUploadKey/traversal_nar1806=== CONT TestIsValidUploadKey/traversal1807=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1808=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1809=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1810=== CONT TestIsValidUploadKey/index.html1811=== CONT TestIsValidUploadKey/nix-cache-info1812=== CONT TestIsValidUploadKey/realisation_plus_in_output1813=== CONT TestIsValidUploadKey/realisation1814=== CONT TestIsValidUploadKey/build_log_equals1815=== CONT TestIsValidUploadKey/build_log_question_mark1816=== CONT TestIsValidUploadKey/build_log_plus_in_name1817=== CONT TestIsValidUploadKey/build_log_home-manager_file1818=== CONT TestIsValidUploadKey/build_log1819=== CONT TestIsValidUploadKey/listing1820=== CONT TestIsValidUploadKey/nar_plain1821=== CONT TestIsValidUploadKey/nar_xz1822=== CONT TestIsValidUploadKey/nar_zst1823=== CONT TestIsValidUploadKey/empty_key1824=== CONT TestIsValidUploadKey/unknown_type1825--- PASS: TestIsValidUploadKey (0.00s)1826 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1827 --- PASS: TestIsValidUploadKey/absolute (0.00s)1828 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1829 --- PASS: TestIsValidUploadKey/traversal (0.00s)1830 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1831 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1832 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1833 --- PASS: TestIsValidUploadKey/index.html (0.00s)1834 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1835 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1836 --- PASS: TestIsValidUploadKey/realisation (0.00s)1837 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1838 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1839 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1840 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1841 --- PASS: TestIsValidUploadKey/build_log (0.00s)1842 --- PASS: TestIsValidUploadKey/listing (0.00s)1843 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1844 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1845 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1846 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1847 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1848=== CONT TestPendingClosureWriteTimeout/empty1849=== CONT TestPendingClosureWriteTimeout/670k_objects1850=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18512026/10/06 09:00:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1852--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.98s)1853=== CONT TestPendingClosureWriteTimeout/400_objects1854=== CONT TestProxyWriteTimeout/narinfo1855=== CONT TestProxyWriteTimeout/10_GiB_nar1856=== CONT TestProxyWriteTimeout/unknown_size1857=== CONT TestProxyWriteTimeout/1_GiB_nar1858--- PASS: TestProxyWriteTimeout (0.00s)1859 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1860 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1861 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1862 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1863=== CONT TestResolveDBConnectionString/flag_wins1864=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1865=== CONT TestResolveDBConnectionString/nothing_configured1866=== CONT TestResolveDBConnectionString/missing_file_is_an_error1867=== CONT TestResolveDBConnectionString/file_when_flag_empty1868=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1869=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1870=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18712026/10/06 09:00:08 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]1872=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18732026/10/06 09:00:08 WARN Authentication failed token_preview=eyJhbGciOi...vwzDJolrJg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1874=== CONT TestService_RequireScope_OIDC/builder_may_write1875=== CONT TestService_RequireScope_OIDC/reader_may_read1876=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1877=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18782026/10/06 09:00:08 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]1879=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1880=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1881=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1882=== CONT TestService_RequireScope_OIDC/writer_implies_read1883=== CONT TestService_RequireScope_OIDC/reader_may_not_write1884=== CONT TestService_RequireScope_OIDC/static_token_may_write1885=== CONT TestService_RequireScope_OIDC/static_token_may_admin1886=== CONT TestService_RequireScope_OIDC/ops_may_admin1887=== CONT TestService_RequireScope_OIDC/ops_may_not_write1888=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1889=== CONT TestGCEndsOnShutdown/before_the_run1890--- PASS: TestResolveDBConnectionString (0.04s)1891 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1892 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1893 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1894 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1895 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1896--- PASS: TestService_AuthMiddleware_OIDC (2.30s)1897 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1898 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1899 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1900 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1901--- PASS: TestService_RequireScope_OIDC (2.35s)1902 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1910 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1911 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1912 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19162026/10/06 09:00:08 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=836.716866ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19172026/10/06 09:00:08 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjFjZTZmMWJkLTQ3ZTUtNDVkNy05ZTQ2LWNkMmE4NTJjOTYwNngxNzkxMjc3MjA2OTk2OTQwMDAw error="Get \"http://127.0.0.1:1/bucket73/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19182026/10/06 09:00:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmMzNGQzZjgtNzcyMy00OWY5LTk4MjQtY2FhNzBmMGU5NTBkLjNmZjIwZTljLWI3ZmQtNDY4NC1hYWIxLTM4NjFkMjQ2NjJkY3gxNzkxMjc3MjA2OTQxMzU4MDAw parts=1219192026/10/06 09:00:08 INFO Received cleanup request method=DELETE path=/api/pending_closures19202026/10/06 09:00:08 INFO Aborted multipart uploads count=1 kept=01921--- PASS: TestRedundantMultipartUpload (5.79s)1922=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1923--- PASS: TestReadRedirectNar (2.72s)1924=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1925--- PASS: TestReadProxyConditionalGet (2.67s)1926=== CONT TestPush_RejectsBadRequests/no_roots19272026/10/06 09:00:09 INFO Received push request method=POST path=/api/pushes1928=== CONT TestPush_RejectsBadRequests/bad_root19292026/10/06 09:00:09 INFO Received push request method=POST path=/api/pushes1930=== CONT TestPush_RejectsBadRequests/root_not_in_objects19312026/10/06 09:00:09 INFO Received push request method=POST path=/api/pushes1932=== CONT TestPush_RejectsBadRequests/no_objects19332026/10/06 09:00:09 INFO Received push request method=POST path=/api/pushes1934--- PASS: TestPush_RejectsBadRequests (2.73s)1935 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1936 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1937 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1938 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19392026/10/06 09:00:09 INFO Received uploads request method=POST path=/api/pending_closures19402026/10/06 09:00:09 INFO Aborted multipart uploads count=0 kept=019412026/10/06 09:00:09 WARN Force mode enabled - objects will be deleted immediately without grace period19422026/10/06 09:00:09 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=019432026/10/06 09:00:09 INFO Vacuumed table table=pending_closures19442026/10/06 09:00:09 INFO Vacuumed table table=pending_objects19452026/10/06 09:00:09 INFO Vacuumed table table=multipart_uploads19462026/10/06 09:00:09 INFO Vacuumed table table=closures19472026/10/06 09:00:09 INFO Vacuumed table table=objects19482026/10/06 09:00:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.702037256s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19492026/10/06 09:00:09 INFO Received uploads request method=POST path=/api/pending_closures19502026/10/06 09:00:09 INFO Aborted multipart uploads count=0 kept=019512026/10/06 09:00:09 WARN Force mode enabled - objects will be deleted immediately without grace period19522026/10/06 09:00:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019532026/10/06 09:00:09 INFO Vacuumed table table=pending_closures19542026/10/06 09:00:09 INFO Vacuumed table table=pending_objects19552026/10/06 09:00:09 INFO Vacuumed table table=multipart_uploads19562026/10/06 09:00:09 INFO Vacuumed table table=closures19572026/10/06 09:00:09 INFO Vacuumed table table=objects1958--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1959 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.89s)1960 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.81s)19612026/10/06 09:00:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19622026/10/06 09:00:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19632026/10/06 09:00:10 INFO Aborted multipart uploads count=0 kept=019642026/10/06 09:00:10 WARN Force mode enabled - objects will be deleted immediately without grace period19652026-10-06 09:00:10.222 UTC [73809] ERROR: canceling statement due to user request19662026-10-06 09:00:10.222 UTC [73809] STATEMENT: -- name: MarkStaleObjects :execrows1967 WITH RECURSIVE ct AS (1968 SELECT timezone('UTC', now()) AS now1969 ),1970 closure_reach AS (1971 -- Start with all closure keys1972 SELECT o.key, o.refs1973 FROM objects o1974 INNER JOIN closures c ON o.key = c.key1975 UNION1976 -- Recursively add all referenced objects1977 SELECT o.key, o.refs1978 FROM objects o1979 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1980 ),1981 reachable_objects AS (1982 SELECT DISTINCT key FROM closure_reach1983 ),1984 stale_objects AS (1985 SELECT o.key1986 FROM objects AS o, ct1987 WHERE1988 NOT EXISTS (1989 SELECT 11990 FROM reachable_objects ro1991 WHERE ro.key = o.key1992 )1993 AND NOT EXISTS (1994 SELECT 11995 FROM pending_objects AS po1996 WHERE po.key = o.key1997 )1998 AND o.deleted_at IS NULL -- Only mark fresh objects1999 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2000 FOR UPDATE2001 )2002 UPDATE objects2003 SET2004 deleted_at = ct.now,2005 first_deleted_at = COALESCE(first_deleted_at, ct.now)2006 FROM stale_objects, ct2007 WHERE objects.key = stale_objects.key2008 20092026/10/06 09:00:10 INFO Received uploads request method=POST path=/api/pending_closures20102026/10/06 09:00:10 INFO Aborted multipart uploads count=0 kept=020112026/10/06 09:00:10 WARN Force mode enabled - objects will be deleted immediately without grace period20122026/10/06 09:00:10 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:50581/bucket92/?delete=\": context canceled"2013--- PASS: TestGCEndsOnShutdown (0.00s)2014 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (1.43s)2015 --- PASS: TestGCEndsOnShutdown/before_the_run (1.66s)2016 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.67s)2017--- PASS: TestPendingClosureWriteTimeout (0.00s)2018 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2019 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2020 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2021 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.66s)20222026/10/06 09:00:11 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-config20232026/10/06 09:00:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.021272ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20242026/10/06 09:00:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.096281ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20252026/10/06 09:00:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.413258ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/06 09:00:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.552360303s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20272026/10/06 09:00:14 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"20282026/10/06 09:00:14 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-config20292026/10/06 09:00:14 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.187904ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/06 09:00:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.683465ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 09:00:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.955402ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 09:00:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.531182448s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 09:00:17 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_closures20342026/10/06 09:00:17 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=201.801613ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20352026/10/06 09:00:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.216446ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20362026/10/06 09:00:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=826.377977ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20372026/10/06 09:00:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.584769282s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2038--- PASS: TestClientErrorHandling (0.00s)2039 --- PASS: TestClientErrorHandling/InvalidStorePath (2.60s)2040 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.96s)2041 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2042PASS2043{"timestamp":"2026-10-06T09:00:20.415247Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50720","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(3)"}20442026-10-06 09:00:20.525 UTC [72989] LOG: received smart shutdown request20452026-10-06 09:00:20.526 UTC [72989] LOG: background worker "logical replication launcher" (PID 73000) exited with exit code 120462026-10-06 09:00:20.529 UTC [72995] LOG: shutting down20472026-10-06 09:00:20.529 UTC [72995] LOG: checkpoint starting: shutdown immediate20482026-10-06 09:00:21.838 UTC [72995] LOG: checkpoint complete: wrote 12812 buffers (78.2%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.729 s, sync=0.568 s, total=1.309 s; sync files=31335, longest=0.001 s, average=0.001 s; distance=440369 kB, estimate=440369 kB; lsn=0/1C599388, redo lsn=0/1C59938820492026-10-06 09:00:21.844 UTC [72989] LOG: database system is shut down2050Running OIDC tests...2051=== RUN TestAudienceForIssuer2052=== PAUSE TestAudienceForIssuer2053=== RUN TestGlobMatch2054=== PAUSE TestGlobMatch2055=== RUN TestValidateToken_ValidToken2056=== PAUSE TestValidateToken_ValidToken2057=== RUN TestValidateToken_WrongAudience2058=== PAUSE TestValidateToken_WrongAudience2059=== RUN TestValidateToken_Expired2060=== PAUSE TestValidateToken_Expired2061=== RUN TestValidateToken_BoundClaimsMismatch2062=== PAUSE TestValidateToken_BoundClaimsMismatch2063=== RUN TestValidateToken_BoundSubjectMismatch2064=== PAUSE TestValidateToken_BoundSubjectMismatch2065=== RUN TestValidateToken_MultipleProviders2066=== PAUSE TestValidateToken_MultipleProviders2067=== RUN TestValidateToken_NoMatchingProvider2068=== PAUSE TestValidateToken_NoMatchingProvider2069=== RUN TestValidateToken_KubernetesServiceAccount2070=== PAUSE TestValidateToken_KubernetesServiceAccount2071=== RUN TestNewValidator_KubernetesRequiresCA2072=== PAUSE TestNewValidator_KubernetesRequiresCA2073=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2074=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2075=== RUN TestPins_ReservedForMatchingRule2076=== PAUSE TestPins_ReservedForMatchingRule2077=== RUN TestPins_TopLevelShorthand2078=== PAUSE TestPins_TopLevelShorthand2079=== RUN TestPins_ConfigValidation2080=== PAUSE TestPins_ConfigValidation2081=== RUN TestScopes_LegacyProviderDefaultsToWrite2082=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2083=== RUN TestScopes_Rules2084=== PAUSE TestScopes_Rules2085=== RUN TestScopes_ConfigValidation2086=== PAUSE TestScopes_ConfigValidation2087=== CONT TestAudienceForIssuer2088--- PASS: TestAudienceForIssuer (0.00s)2089=== CONT TestValidateToken_NoMatchingProvider2090=== CONT TestValidateToken_KubernetesServiceAccount2091=== CONT TestValidateToken_Expired2092=== CONT TestPins_ConfigValidation2093=== CONT TestScopes_Rules2094=== CONT TestValidateToken_BoundSubjectMismatch2095=== CONT TestScopes_ConfigValidation2096=== CONT TestScopes_LegacyProviderDefaultsToWrite2097=== CONT TestPins_ReservedForMatchingRule2098=== CONT TestValidateToken_ValidToken2099--- PASS: TestPins_ConfigValidation (0.00s)2100=== CONT TestGlobMatch2101=== RUN TestGlobMatch/foo_foo2102=== PAUSE TestGlobMatch/foo_foo2103=== RUN TestGlobMatch/foo_bar2104=== PAUSE TestGlobMatch/foo_bar2105=== RUN TestGlobMatch/*_2106=== PAUSE TestGlobMatch/*_2107=== RUN TestGlobMatch/*_anything2108=== PAUSE TestGlobMatch/*_anything2109=== RUN TestGlobMatch/foo*_foo2110=== PAUSE TestGlobMatch/foo*_foo2111=== RUN TestGlobMatch/foo*_foobar2112=== PAUSE TestGlobMatch/foo*_foobar2113=== RUN TestGlobMatch/foo*_bar2114=== PAUSE TestGlobMatch/foo*_bar2115=== RUN TestGlobMatch/*bar_bar2116=== PAUSE TestGlobMatch/*bar_bar2117=== RUN TestGlobMatch/*bar_foobar2118=== PAUSE TestGlobMatch/*bar_foobar2119=== RUN TestGlobMatch/*bar_foo2120=== PAUSE TestGlobMatch/*bar_foo2121=== RUN TestGlobMatch/foo*bar_foobar2122=== PAUSE TestGlobMatch/foo*bar_foobar2123=== RUN TestGlobMatch/foo*bar_foo123bar2124=== PAUSE TestGlobMatch/foo*bar_foo123bar2125=== RUN TestGlobMatch/foo*bar_foobarbaz2126=== PAUSE TestGlobMatch/foo*bar_foobarbaz2127=== RUN TestGlobMatch/*/*_foo/bar2128=== PAUSE TestGlobMatch/*/*_foo/bar2129=== RUN TestGlobMatch/*/*_foo2130=== PAUSE TestGlobMatch/*/*_foo2131=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2132=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2133=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02134=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02135=== RUN TestGlobMatch/refs/*/main_refs/heads/main2136=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2137=== RUN TestGlobMatch/fo?_foo2138=== PAUSE TestGlobMatch/fo?_foo2139=== RUN TestGlobMatch/fo?_fo2140=== PAUSE TestGlobMatch/fo?_fo2141=== RUN TestGlobMatch/fo?_fooo2142=== PAUSE TestGlobMatch/fo?_fooo2143=== RUN TestGlobMatch/?oo_foo2144=== PAUSE TestGlobMatch/?oo_foo2145=== RUN TestGlobMatch/?oo_boo2146=== PAUSE TestGlobMatch/?oo_boo2147=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2148=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2149=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2150=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2151=== CONT TestValidateToken_WrongAudience2152--- PASS: TestScopes_ConfigValidation (0.00s)2153=== CONT TestPins_TopLevelShorthand21542026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51493/oidc2155--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.02s)2156=== CONT TestValidateToken_BoundClaimsMismatch21572026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51495/oidc21582026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51497/oidc2159--- PASS: TestValidateToken_Expired (0.04s)2160=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2161--- PASS: TestScopes_Rules (0.04s)2162=== CONT TestValidateToken_MultipleProviders21632026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51500/oidc2164--- PASS: TestPins_TopLevelShorthand (0.05s)2165=== CONT TestNewValidator_KubernetesRequiresCA21662026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51502/oidc2167--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2168=== CONT TestGlobMatch/foo_foo2169=== CONT TestGlobMatch/*/*_foo/bar2170=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2171=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2172=== CONT TestGlobMatch/?oo_boo2173=== CONT TestGlobMatch/?oo_foo2174=== CONT TestGlobMatch/fo?_fooo2175=== CONT TestGlobMatch/fo?_fo2176=== CONT TestGlobMatch/fo?_foo2177=== CONT TestGlobMatch/refs/*/main_refs/heads/main2178=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02179=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2180=== CONT TestGlobMatch/*/*_foo2181=== CONT TestGlobMatch/*bar_bar2182=== CONT TestGlobMatch/foo*bar_foobarbaz2183=== CONT TestGlobMatch/foo*bar_foo123bar2184=== CONT TestGlobMatch/foo*bar_foobar2185=== CONT TestGlobMatch/*bar_foo2186=== CONT TestGlobMatch/*bar_foobar2187=== CONT TestGlobMatch/foo*_foo2188=== CONT TestGlobMatch/foo*_bar2189=== CONT TestGlobMatch/foo*_foobar2190=== CONT TestGlobMatch/*_2191=== CONT TestGlobMatch/*_anything2192=== CONT TestGlobMatch/foo_bar2193--- PASS: TestGlobMatch (0.00s)2194 --- PASS: TestGlobMatch/foo_foo (0.00s)2195 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2196 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2197 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/?oo_boo (0.00s)2199 --- PASS: TestGlobMatch/?oo_foo (0.00s)2200 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fo (0.00s)2202 --- PASS: TestGlobMatch/fo?_foo (0.00s)2203 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2204 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2206 --- PASS: TestGlobMatch/*/*_foo (0.00s)2207 --- PASS: TestGlobMatch/*bar_bar (0.00s)2208 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2209 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2210 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2211 --- PASS: TestGlobMatch/*bar_foo (0.00s)2212 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2213 --- PASS: TestGlobMatch/foo*_foo (0.00s)2214 --- PASS: TestGlobMatch/foo*_bar (0.00s)2215 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2216 --- PASS: TestGlobMatch/*_ (0.00s)2217 --- PASS: TestGlobMatch/*_anything (0.00s)2218 --- PASS: TestGlobMatch/foo_bar (0.00s)22192026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51504/oidc2220--- PASS: TestValidateToken_WrongAudience (0.07s)22212026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51506/oidc2222--- PASS: TestValidateToken_ValidToken (0.08s)22232026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51509/oidc22242026/10/06 09:00:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:51508/oidc22252026/10/06 09:00:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:51511/oidc2226--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2227--- PASS: TestValidateToken_MultipleProviders (0.05s)22282026/10/06 09:00:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:51499/oidc22292026/10/06 09:00:23 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232230--- PASS: TestValidateToken_NoMatchingProvider (0.12s)2231--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)22322026/10/06 09:00:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:51520/oidc22332026/10/06 09:00:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:515182234--- PASS: TestPins_ReservedForMatchingRule (0.13s)2235--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)22362026/10/06 09:00:23 http: TLS handshake error from 127.0.0.1:51523: remote error: tls: bad certificate2237--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)2238PASS2239Running hook tests...2240=== RUN TestSendPathsEmpty2241=== PAUSE TestSendPathsEmpty2242=== RUN TestQueueEnqueueAndFetch2243=== PAUSE TestQueueEnqueueAndFetch2244=== RUN TestQueueDeduplication2245=== PAUSE TestQueueDeduplication2246=== RUN TestQueueRemove2247=== PAUSE TestQueueRemove2248=== RUN TestQueueFetchBatchLimit2249=== PAUSE TestQueueFetchBatchLimit2250=== RUN TestQueueRetryMovesToBack2251=== PAUSE TestQueueRetryMovesToBack2252=== RUN TestQueueFetchRemoveLifecycle2253=== PAUSE TestQueueFetchRemoveLifecycle2254=== RUN TestQueueConcurrentWriters2255=== PAUSE TestQueueConcurrentWriters2256=== RUN TestQueueRemoveLargeClosure2257=== PAUSE TestQueueRemoveLargeClosure2258=== RUN TestServerClientIntegration2259=== PAUSE TestServerClientIntegration2260=== RUN TestServerQueueError2261=== PAUSE TestServerQueueError2262=== RUN TestGetListenerSocketActivation2263 server_test.go:210: === RUN TestGetListenerSocketActivation2264 --- PASS: TestGetListenerSocketActivation (0.00s)2265 PASS2266 2267--- PASS: TestGetListenerSocketActivation (0.01s)2268=== RUN TestDrainIsolatesPoisonPath2269=== PAUSE TestDrainIsolatesPoisonPath2270=== RUN TestRunNotBlockedByPoisonHead2271=== PAUSE TestRunNotBlockedByPoisonHead2272=== RUN TestDrainGivesUpWhenServerDown2273=== PAUSE TestDrainGivesUpWhenServerDown2274=== RUN TestFailedPathPrunedByLaterClosure2275=== PAUSE TestFailedPathPrunedByLaterClosure2276=== RUN TestWorkerUploadsAndRemoves2277=== PAUSE TestWorkerUploadsAndRemoves2278=== RUN TestWorkerSkipsGCdPaths2279=== PAUSE TestWorkerSkipsGCdPaths2280=== RUN TestWorkerPrunesClosureDeps2281=== PAUSE TestWorkerPrunesClosureDeps2282=== RUN TestDrainTimeout2283=== PAUSE TestDrainTimeout2284=== CONT TestSendPathsEmpty2285--- PASS: TestSendPathsEmpty (0.00s)2286=== CONT TestDrainTimeout2287=== CONT TestServerClientIntegration2288=== CONT TestQueueRetryMovesToBack2289=== CONT TestFailedPathPrunedByLaterClosure2290=== CONT TestRunNotBlockedByPoisonHead2291=== CONT TestQueueRemove2292=== CONT TestQueueConcurrentWriters2293=== CONT TestQueueFetchRemoveLifecycle2294=== CONT TestDrainIsolatesPoisonPath2295=== CONT TestQueueFetchBatchLimit2296--- PASS: TestServerClientIntegration (0.00s)2297=== CONT TestQueueRemoveLargeClosure22982026/10/06 09:00:23 INFO Upload queue status pending=322992026/10/06 09:00:23 INFO Uploading batch count=123002026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=12301--- PASS: TestQueueFetchBatchLimit (0.01s)23022026/10/06 09:00:23 INFO Uploading batch count=423032026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=423042026/10/06 09:00:23 INFO Uploading batch count=22305=== CONT TestQueueDeduplication23062026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainIsolatesPoisonPath272321154/002/bbb2307--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2308=== CONT TestServerQueueError23092026/10/06 09:00:23 INFO Uploading batch count=123102026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=123112026/10/06 09:00:23 INFO Uploading batch count=123122026/10/06 09:00:23 INFO Uploading batch count=123132026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=12314--- PASS: TestQueueRemove (0.01s)2315=== CONT TestQueueEnqueueAndFetch23162026/10/06 09:00:23 INFO Uploading batch count=123172026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=123182026/10/06 09:00:23 ERROR Failed to queue paths error="permission denied" count=123192026/10/06 09:00:23 INFO Uploading batch count=12320--- PASS: TestQueueRetryMovesToBack (0.01s)2321=== CONT TestDrainGivesUpWhenServerDown23222026/10/06 09:00:23 INFO Uploading batch count=123232026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=123242026/10/06 09:00:23 ERROR Drain finished with paths left in queue remaining=12325--- PASS: TestServerQueueError (0.00s)2326=== CONT TestWorkerSkipsGCdPaths2327--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2328=== CONT TestWorkerPrunesClosureDeps2329--- PASS: TestDrainIsolatesPoisonPath (0.01s)2330=== CONT TestWorkerUploadsAndRemoves2331--- PASS: TestQueueEnqueueAndFetch (0.00s)2332--- PASS: TestQueueDeduplication (0.00s)23332026/10/06 09:00:23 INFO Upload queue status pending=223342026/10/06 09:00:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-72355-3875258282/TestWorkerSkipsGCdPaths2865635130/002/nonexistent23352026/10/06 09:00:23 INFO Uploading batch count=123362026/10/06 09:00:23 INFO Upload queue status pending=223372026/10/06 09:00:23 INFO Uploading batch count=123382026/10/06 09:00:23 INFO Upload queue status pending=223392026/10/06 09:00:23 INFO Uploading batch count=223402026/10/06 09:00:23 INFO Uploading batch count=223412026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=223422026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/a23432026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/b23442026/10/06 09:00:23 INFO Uploading batch count=223452026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=223462026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/c23472026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/d23482026/10/06 09:00:23 INFO Uploading batch count=223492026/10/06 09:00:23 ERROR Upload failed error="upload failed" count=223502026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/e23512026/10/06 09:00:23 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-72355-3875258282/TestDrainGivesUpWhenServerDown1393904039/002/f23522026/10/06 09:00:23 ERROR Drain finished with paths left in queue remaining=102353--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2354--- PASS: TestWorkerSkipsGCdPaths (0.02s)2355--- PASS: TestQueueRemoveLargeClosure (0.03s)2356--- PASS: TestWorkerPrunesClosureDeps (0.02s)2357--- PASS: TestWorkerUploadsAndRemoves (0.02s)2358--- PASS: TestQueueConcurrentWriters (0.15s)23592026/10/06 09:00:23 ERROR Upload failed error="context deadline exceeded" count=223602026/10/06 09:00:23 ERROR Drain finished with paths left in queue remaining=42361--- PASS: TestDrainTimeout (0.21s)23622026/10/06 09:00:24 INFO Uploading batch count=123632026/10/06 09:00:24 INFO Uploading batch count=123642026/10/06 09:00:24 INFO Uploading batch count=123652026/10/06 09:00:24 ERROR Upload failed error="upload failed" count=123662026/10/06 09:00:24 INFO Uploading batch count=123672026/10/06 09:00:24 ERROR Upload failed error="upload failed" count=123682026/10/06 09:00:24 INFO Uploading batch count=123692026/10/06 09:00:24 ERROR Upload failed error="upload failed" count=123702026/10/06 09:00:24 INFO Uploading batch count=123712026/10/06 09:00:24 ERROR Upload failed error="upload failed" count=123722026/10/06 09:00:24 ERROR Drain finished with paths left in queue remaining=12373--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2374PASS2375Running signing tests...2376=== RUN TestExternalSigner2377=== PAUSE TestExternalSigner2378=== RUN TestExternalSignerWrongPublicKey2379=== PAUSE TestExternalSignerWrongPublicKey2380=== RUN TestExternalSignerErrors2381=== PAUSE TestExternalSignerErrors2382=== RUN TestExternalSignerRestartsAfterCrash2383=== PAUSE TestExternalSignerRestartsAfterCrash2384=== RUN TestExternalSignerProgramErrorKeepsProcess2385=== PAUSE TestExternalSignerProgramErrorKeepsProcess2386=== RUN TestExternalSignerClose2387=== PAUSE TestExternalSignerClose2388=== RUN TestExternalSignerRejectsInvalidPublicKey2389=== PAUSE TestExternalSignerRejectsInvalidPublicKey2390=== RUN TestExternalSignerCancellation2391=== PAUSE TestExternalSignerCancellation2392=== RUN TestGenerateFingerprint2393=== PAUSE TestGenerateFingerprint2394=== RUN TestParseSigningKey2395=== PAUSE TestParseSigningKey2396=== RUN TestSign2397=== PAUSE TestSign2398=== RUN TestSignBatch2399=== PAUSE TestSignBatch2400=== RUN TestNilKeyPublicKey2401=== PAUSE TestNilKeyPublicKey2402=== RUN TestSignErrors2403=== PAUSE TestSignErrors2404=== CONT TestExternalSigner2405=== CONT TestExternalSignerCancellation2406=== CONT TestSignBatch2407=== CONT TestParseSigningKey2408=== RUN TestParseSigningKey/valid_32-byte_key2409=== PAUSE TestParseSigningKey/valid_32-byte_key2410=== CONT TestSignErrors2411=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2412=== CONT TestGenerateFingerprint2413=== RUN TestGenerateFingerprint/basic_with_references2414=== PAUSE TestGenerateFingerprint/basic_with_references2415=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2416=== CONT TestExternalSignerProgramErrorKeepsProcess2417=== RUN TestParseSigningKey/no_colon2418=== CONT TestSign2419=== PAUSE TestParseSigningKey/no_colon2420=== RUN TestParseSigningKey/empty_name2421=== PAUSE TestParseSigningKey/empty_name2422=== RUN TestParseSigningKey/invalid_base642423=== PAUSE TestParseSigningKey/invalid_base642424=== RUN TestParseSigningKey/wrong_length2425=== RUN TestGenerateFingerprint/no_references2426=== PAUSE TestGenerateFingerprint/no_references2427=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2428=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2429=== CONT TestExternalSignerRejectsInvalidPublicKey2430=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2431=== RUN TestExternalSignerRejectsInvalidPublicKey/#002432=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2433=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002434=== CONT TestExternalSignerClose2435=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2436=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2437=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2438=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2439=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2440=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2441=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2442=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2443=== RUN TestGenerateFingerprint/invalid_nar_hash_length2444=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2445=== RUN TestGenerateFingerprint/invalid_store_path_prefix2446=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2447=== RUN TestGenerateFingerprint/invalid_reference_prefix2448=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2449=== CONT TestExternalSignerErrors2450=== RUN TestExternalSignerErrors/exit_on_request2451=== PAUSE TestExternalSignerErrors/exit_on_request2452=== RUN TestExternalSignerErrors/wrong_signatures_shape2453=== PAUSE TestParseSigningKey/wrong_length2454=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2455=== RUN TestExternalSignerErrors/unrequested_key2456=== CONT TestNilKeyPublicKey2457=== CONT TestExternalSignerRestartsAfterCrash2458=== PAUSE TestExternalSignerErrors/unrequested_key2459--- PASS: TestNilKeyPublicKey (0.00s)2460=== RUN TestExternalSignerErrors/wrong_signature_name2461=== PAUSE TestExternalSignerErrors/wrong_signature_name2462=== RUN TestExternalSignerErrors/invalid_JSON2463=== PAUSE TestExternalSignerErrors/invalid_JSON2464=== CONT TestExternalSignerWrongPublicKey2465=== RUN TestExternalSignerErrors/null2466=== PAUSE TestExternalSignerErrors/null2467=== RUN TestExternalSignerErrors/wrong_id2468=== PAUSE TestExternalSignerErrors/wrong_id2469=== RUN TestExternalSignerErrors/null_signatures2470=== PAUSE TestExternalSignerErrors/null_signatures2471=== RUN TestExternalSignerErrors/too_few_signatures2472=== PAUSE TestExternalSignerErrors/too_few_signatures2473=== RUN TestExternalSignerErrors/invalid_signature_base642474=== PAUSE TestExternalSignerErrors/invalid_signature_base642475=== RUN TestExternalSignerErrors/program_error2476=== PAUSE TestExternalSignerErrors/program_error2477=== RUN TestExternalSignerErrors/exit_at_startup2478=== PAUSE TestExternalSignerErrors/exit_at_startup2479=== RUN TestExternalSignerErrors/wrong_shape2480=== PAUSE TestExternalSignerErrors/wrong_shape2481=== RUN TestExternalSignerErrors/missing_signature_name2482=== PAUSE TestExternalSignerErrors/missing_signature_name2483=== RUN TestExternalSignerErrors/wrong_signature_length2484=== PAUSE TestExternalSignerErrors/wrong_signature_length2485=== RUN TestExternalSignerErrors/missing_signatures2486=== PAUSE TestExternalSignerErrors/missing_signatures2487=== CONT TestExternalSignerRejectsInvalidPublicKey/#002488=== CONT TestGenerateFingerprint/basic_with_references2489=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2490=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2491=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2492=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2493--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2494 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2495 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2496 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2497 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2498 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2499=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2500=== CONT TestGenerateFingerprint/invalid_reference_prefix2501=== CONT TestGenerateFingerprint/invalid_store_path_prefix2502=== CONT TestGenerateFingerprint/invalid_nar_hash_length2503=== CONT TestParseSigningKey/valid_32-byte_key2504=== RUN TestSignErrors/nil_key2505=== PAUSE TestSignErrors/nil_key2506=== RUN TestSignErrors/nil_narinfo2507=== PAUSE TestSignErrors/nil_narinfo2508=== RUN TestSignErrors/invalid_narinfo2509=== PAUSE TestSignErrors/invalid_narinfo2510=== RUN TestSignErrors/canceled2511=== PAUSE TestSignErrors/canceled2512=== CONT TestParseSigningKey/empty_name2513=== CONT TestParseSigningKey/wrong_length2514--- PASS: TestSign (0.00s)2515=== CONT TestParseSigningKey/invalid_base642516=== CONT TestParseSigningKey/no_colon2517=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2518=== CONT TestGenerateFingerprint/no_references2519=== CONT TestExternalSignerErrors/exit_on_request2520--- PASS: TestParseSigningKey (0.00s)2521 --- PASS: TestParseSigningKey/empty_name (0.00s)2522 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2523 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2524 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2525 --- PASS: TestParseSigningKey/no_colon (0.00s)2526 --- PASS: TestParseSigningKey/wrong_length (0.00s)2527=== CONT TestExternalSignerErrors/too_few_signatures2528=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2529=== CONT TestExternalSignerErrors/missing_signatures2530--- PASS: TestGenerateFingerprint (0.00s)2531 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2532 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2533 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2534 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2535 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2536 --- PASS: TestGenerateFingerprint/no_references (0.00s)2537 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2538--- PASS: TestSignBatch (0.01s)2539=== CONT TestExternalSignerErrors/wrong_signature_length2540--- PASS: TestExternalSigner (0.23s)2541=== CONT TestExternalSignerErrors/missing_signature_name2542--- PASS: TestExternalSignerCancellation (0.42s)2543=== CONT TestExternalSignerErrors/wrong_shape2544--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.58s)2545=== CONT TestExternalSignerErrors/exit_at_startup2546--- PASS: TestExternalSignerRestartsAfterCrash (0.77s)2547=== CONT TestExternalSignerErrors/program_error2548/nix/var/nix/builds/nix-72355-3875258282/TestExternalSignerRestartsAfterCrash637202898/001/sign program: line 7: /nix/var/nix/builds/nix-72355-3875258282/TestExternalSignerRestartsAfterCrash637202898/001/sign program.starts: No such file or directory2549--- PASS: TestExternalSignerWrongPublicKey (0.97s)2550=== CONT TestExternalSignerErrors/invalid_signature_base642551--- PASS: TestExternalSignerClose (1.15s)2552=== CONT TestExternalSignerErrors/invalid_JSON2553=== CONT TestExternalSignerErrors/null_signatures2554=== CONT TestExternalSignerErrors/wrong_id2555=== CONT TestExternalSignerErrors/null2556=== CONT TestExternalSignerErrors/unrequested_key2557=== CONT TestExternalSignerErrors/wrong_signatures_shape2558=== CONT TestExternalSignerErrors/wrong_signature_name2559=== CONT TestSignErrors/nil_key2560=== CONT TestSignErrors/invalid_narinfo2561=== CONT TestSignErrors/canceled2562=== CONT TestSignErrors/nil_narinfo2563--- PASS: TestSignErrors (0.00s)2564 --- PASS: TestSignErrors/nil_key (0.00s)2565 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2566 --- PASS: TestSignErrors/canceled (0.00s)2567 --- PASS: TestSignErrors/nil_narinfo (0.00s)2568--- PASS: TestExternalSignerErrors (0.00s)2569 --- PASS: TestExternalSignerErrors/too_few_signatures (1.34s)2570 --- PASS: TestExternalSignerErrors/missing_signatures (1.53s)2571 --- PASS: TestExternalSignerErrors/exit_on_request (1.72s)2572 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.95s)2573 --- PASS: TestExternalSignerErrors/missing_signature_name (1.91s)2574 --- PASS: TestExternalSignerErrors/wrong_shape (1.91s)2575 --- PASS: TestExternalSignerErrors/exit_at_startup (1.94s)2576 --- PASS: TestExternalSignerErrors/program_error (2.17s)2577 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.16s)2578 --- PASS: TestExternalSignerErrors/invalid_JSON (2.15s)2579 --- PASS: TestExternalSignerErrors/null_signatures (2.14s)2580 --- PASS: TestExternalSignerErrors/wrong_id (2.13s)2581 --- PASS: TestExternalSignerErrors/null (2.12s)2582 --- PASS: TestExternalSignerErrors/unrequested_key (2.07s)2583 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.05s)2584 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.05s)2585PASS2586Running OpenBao signer tests...2587=== RUN TestSign2588=== PAUSE TestSign2589=== RUN TestSignErrors2590=== PAUSE TestSignErrors2591=== RUN TestServe2592=== PAUSE TestServe2593=== RUN TestServeRejectsGarbage2594=== PAUSE TestServeRejectsGarbage2595=== CONT TestSign2596=== CONT TestSignErrors2597=== RUN TestSignErrors/invalid_base642598=== CONT TestServe2599=== PAUSE TestSignErrors/invalid_base642600=== CONT TestServeRejectsGarbage2601=== RUN TestSignErrors/http_error2602=== PAUSE TestSignErrors/http_error2603=== RUN TestSignErrors/invalid_json2604=== PAUSE TestSignErrors/invalid_json2605=== RUN TestSignErrors/no_prefix2606=== PAUSE TestSignErrors/no_prefix2607=== CONT TestSignErrors/invalid_base642608--- PASS: TestServeRejectsGarbage (0.00s)2609=== CONT TestSignErrors/invalid_json2610=== CONT TestSignErrors/no_prefix2611--- PASS: TestServe (0.00s)2612=== CONT TestSignErrors/http_error2613--- PASS: TestSign (0.00s)2614--- PASS: TestSignErrors (0.00s)2615 --- PASS: TestSignErrors/http_error (0.00s)2616 --- PASS: TestSignErrors/invalid_base64 (0.00s)2617 --- PASS: TestSignErrors/invalid_json (0.00s)2618 --- PASS: TestSignErrors/no_prefix (0.00s)2619PASS