niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #371
· 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.05s)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 TestSetClientTLSErrors101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestFileTokenMissing104=== CONT TestScriptTokenScriptFails105=== CONT TestScriptTokenBadJSON106--- PASS: TestFileTokenMissing (0.00s)107=== CONT TestFileTokenReadsAndCaches108=== CONT TestScriptTokenEmptyToken109=== CONT TestScriptTokenCachesUntilRefresh110=== CONT TestScriptTokenNoExpiryRerunsEveryCall111--- PASS: TestFileTokenReadsAndCaches (0.00s)112=== CONT TestFileTokenEmpty113=== CONT TestStaticToken114--- PASS: TestStaticToken (0.00s)115=== CONT TestStreamPushReportsEveryPath116=== RUN TestSetClientTLSErrors/missing_cert_file117--- PASS: TestStreamPushReportsEveryPath (0.00s)118=== PAUSE TestSetClientTLSErrors/missing_cert_file119=== CONT TestStreamPushIsolatesFailures120=== RUN TestSetClientTLSErrors/missing_key_file121=== PAUSE TestSetClientTLSErrors/missing_key_file122=== RUN TestSetClientTLSErrors/missing_ca_file123=== PAUSE TestSetClientTLSErrors/missing_ca_file124=== RUN TestSetClientTLSErrors/invalid_ca_file125=== PAUSE TestSetClientTLSErrors/invalid_ca_file126=== CONT TestStreamPushBatchesUnderLoad1272026/10/06 10:52:19 ERROR Upload failed error="bad path" count=31282026/10/06 10:52:19 WARN Rate limiter enabled after throttle name=server-test rate=51292026/10/06 10:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53900130--- PASS: TestDoServerRequestAttachesToken (0.01s)131=== CONT TestClientSignaturesByStorePath132--- PASS: TestStreamPushIsolatesFailures (0.00s)133=== CONT TestSetClientTLSDoesNotMutateDefaultTransport134=== CONT TestSetClientTLS135--- PASS: TestClientSignaturesByStorePath (0.00s)136--- PASS: TestFileTokenEmpty (0.00s)137=== CONT TestStreamPushReportsSignatures1382026/10/06 10:52:19 WARN Rate limiter backed off name=server-test rate=5139--- PASS: TestScriptTokenScriptFails (0.01s)1402026/10/06 10:52:19 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53900141=== CONT TestStreamPushRequestLine1422026/10/06 10:52:19 ERROR Upload failed error=boom count=1143--- PASS: TestStreamPushReportsSignatures (0.00s)144=== CONT TestShellSplitErrors145--- PASS: TestShellSplitErrors (0.00s)146=== CONT TestEncodeNixBase32147=== RUN TestEncodeNixBase32/test_string_hash148=== PAUSE TestEncodeNixBase32/test_string_hash149=== RUN TestEncodeNixBase32/empty_input150=== PAUSE TestEncodeNixBase32/empty_input151=== CONT TestResolveStorePath1522026/10/06 10:52:19 ERROR Upload failed error=boom count=1153--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)154=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1552026/10/06 10:52:19 WARN Rate limiter enabled after throttle name=server-test rate=5156--- PASS: TestResolveStorePath (0.00s)157--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)158=== CONT TestPathInfoCACompatibility159=== RUN TestPathInfoCACompatibility/null_ca_field160=== PAUSE TestPathInfoCACompatibility/null_ca_field161=== CONT TestRateLimiterFeedback162=== RUN TestRateLimiterFeedback/429_enables_limiter163=== PAUSE TestRateLimiterFeedback/429_enables_limiter164=== RUN TestRateLimiterFeedback/503_enables_limiter165=== RUN TestPathInfoCACompatibility/old_string_format_-_text166=== PAUSE TestRateLimiterFeedback/503_enables_limiter167=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text168=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter169=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter170=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive171=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter172=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter173=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive174=== RUN TestPathInfoCACompatibility/new_structured_format_-_text175=== CONT TestParsePathInfoJSONMultiplePaths176=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text177=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths178=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths179=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths183=== CONT TestParsePathInfoJSON184=== RUN TestParsePathInfoJSON/Nix_format185=== CONT TestPathInfoHashCompatibility186=== PAUSE TestParsePathInfoJSON/Nix_format187=== RUN TestParsePathInfoJSON/Lix_format188=== PAUSE TestParsePathInfoJSON/Lix_format189=== RUN TestParsePathInfoJSON/empty_input190=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)191=== PAUSE TestParsePathInfoJSON/empty_input192=== RUN TestParsePathInfoJSON/whitespace_only193=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)194=== PAUSE TestParsePathInfoJSON/whitespace_only195=== RUN TestParsePathInfoJSON/invalid_JSON196=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon197=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon198=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI200=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512202=== PAUSE TestParsePathInfoJSON/invalid_JSON203=== CONT TestGetStorePathHash204=== RUN TestGetStorePathHash/valid_store_path205=== PAUSE TestGetStorePathHash/valid_store_path206=== RUN TestSetClientTLS/rejects_connection_without_client_cert207=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert208=== RUN TestGetStorePathHash/basename_without_hyphen_should_error209=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA210=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA211=== CONT TestConvertHashToNix32212=== RUN TestConvertHashToNix32/SRI_format_to_Nix32213=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error214=== RUN TestSetClientTLS/preserves_debug_logging_transport215=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error216=== PAUSE TestSetClientTLS/preserves_debug_logging_transport217=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error218=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error219=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32220=== RUN TestConvertHashToNix32/already_Nix32_format221=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error222=== CONT TestEncodeNixBase32WithRealHash223=== CONT TestShellSplit224--- PASS: TestEncodeNixBase32WithRealHash (0.00s)225--- PASS: TestShellSplit (0.00s)226=== PAUSE TestConvertHashToNix32/already_Nix32_format227=== RUN TestConvertHashToNix32/invalid_format228=== PAUSE TestConvertHashToNix32/invalid_format229=== CONT TestStreamPushGivesUpOnDeadServer230=== CONT TestUploadMultipart_PartsInParallel2312026/10/06 10:52:19 ERROR Upload failed error="connection refused" count=202322026/10/06 10:52:19 ERROR Server seems unavailable, giving up on batch untried=17233=== CONT TestDumpPathWriterError234--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)235=== CONT TestDumpPathSingleFile236--- PASS: TestScriptTokenBadJSON (0.01s)237=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun238--- PASS: TestScriptTokenEmptyToken (0.01s)239=== CONT TestDumpPathMatchesNix2402026/10/06 10:52:19 INFO Garbage collection started241--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)242=== CONT TestUploadMultipart_SupersededByPeer243=== RUN TestUploadMultipart_SupersededByPeer/exists244=== PAUSE TestUploadMultipart_SupersededByPeer/exists245=== RUN TestUploadMultipart_SupersededByPeer/missing246=== PAUSE TestUploadMultipart_SupersededByPeer/missing247=== CONT TestFilterOversizedClosures248=== RUN TestFilterOversizedClosures/no_limit_keeps_everything249=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything250=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped251=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped252=== RUN TestFilterOversizedClosures/all_closures_skipped253=== PAUSE TestFilterOversizedClosures/all_closures_skipped254=== CONT TestPartSizeForNAR255=== RUN TestPartSizeForNAR/zero_stays_at_minimum256=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum257=== RUN TestPartSizeForNAR/small_stays_at_minimum258=== PAUSE TestPartSizeForNAR/small_stays_at_minimum259=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum260=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum261=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts262=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts263=== RUN TestPartSizeForNAR/1_TiB264=== PAUSE TestPartSizeForNAR/1_TiB265=== RUN TestPartSizeForNAR/5_TiB_S3_max_object266=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object267=== RUN TestPartSizeForNAR/capped_at_5_GiB268=== PAUSE TestPartSizeForNAR/capped_at_5_GiB269=== CONT TestCaseHackSuffix270--- PASS: TestStreamPushRequestLine (0.01s)271=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2722026/10/06 10:52:19 INFO Garbage collection started2732026/10/06 10:52:19 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=02742026/10/06 10:52:19 WARN Garbage collection finished on another replica. Its statistics are not available here275--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)276=== CONT TestRegisterUploadedObjectReusesConnections277--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)278=== CONT TestSetClientTLSErrors/missing_cert_file279=== CONT TestSetClientTLSErrors/missing_ca_file280--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)281=== CONT TestSetClientTLSErrors/invalid_ca_file282=== CONT TestSetClientTLSErrors/missing_key_file283=== CONT TestEncodeNixBase32/test_string_hash284=== CONT TestEncodeNixBase32/empty_input285--- PASS: TestEncodeNixBase32 (0.00s)286 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)287 --- PASS: TestEncodeNixBase32/empty_input (0.00s)288=== CONT TestRateLimiterFeedback/429_enables_limiter289--- PASS: TestSetClientTLSErrors (0.01s)290 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)291 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)292 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)293 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)294=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter295=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2962026/10/06 10:52:19 WARN Rate limiter enabled after throttle name=server-test rate=52972026/10/06 10:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:53980298=== CONT TestRateLimiterFeedback/503_enables_limiter2992026/10/06 10:52:19 WARN Rate limiter backed off name=server-test rate=5300=== CONT TestPathInfoCACompatibility/null_ca_field301=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths302=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths303--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)304 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)305 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)306=== CONT TestPathInfoCACompatibility/new_structured_format_-_text307=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method308=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive309=== CONT TestPathInfoCACompatibility/old_string_format_-_text310--- PASS: TestPathInfoCACompatibility (0.00s)311 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)312 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)313 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)314 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3162026/10/06 10:52:19 WARN Rate limiter enabled after throttle name=server-test rate=53172026/10/06 10:52:19 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:53986318=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)319=== CONT TestParsePathInfoJSON/Nix_format320=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512322=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon323--- PASS: TestPathInfoHashCompatibility (0.00s)324 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)325 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)326 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)327 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)328=== CONT TestParsePathInfoJSON/empty_input329=== CONT TestParsePathInfoJSON/invalid_JSON330=== CONT TestParsePathInfoJSON/whitespace_only331=== CONT TestParsePathInfoJSON/Lix_format332--- PASS: TestParsePathInfoJSON (0.00s)333 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)336 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)337 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)338=== CONT TestSetClientTLS/rejects_connection_without_client_cert3392026/10/06 10:52:19 WARN Rate limiter backed off name=server-test rate=5340--- PASS: TestRateLimiterFeedback (0.00s)341 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)342 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)343 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)344 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)345=== CONT TestSetClientTLS/preserves_debug_logging_transport346=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA347=== CONT TestGetStorePathHash/valid_store_path348=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error349=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error350=== CONT TestGetStorePathHash/basename_without_hyphen_should_error351--- PASS: TestGetStorePathHash (0.00s)352 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)353 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)354 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)355 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)356=== CONT TestConvertHashToNix32/SRI_format_to_Nix32357=== CONT TestConvertHashToNix32/invalid_format358=== CONT TestConvertHashToNix32/already_Nix32_format359--- PASS: TestConvertHashToNix32 (0.00s)360 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)361 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)362 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)363=== CONT TestUploadMultipart_SupersededByPeer/exists364=== CONT TestUploadMultipart_SupersededByPeer/missing365--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)366 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)367 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)368=== CONT TestFilterOversizedClosures/no_limit_keeps_everything369=== CONT TestFilterOversizedClosures/all_closures_skipped3702026/10/06 10:52:19 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=50371=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3722026/10/06 10:52:19 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=2000373--- PASS: TestFilterOversizedClosures (0.00s)374 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)375 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)376 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)377=== CONT TestPartSizeForNAR/zero_stays_at_minimum378=== CONT TestPartSizeForNAR/1_TiB379=== CONT TestPartSizeForNAR/5_TiB_S3_max_object380=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum381=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts382=== CONT TestPartSizeForNAR/small_stays_at_minimum383=== CONT TestPartSizeForNAR/capped_at_5_GiB384--- PASS: TestPartSizeForNAR (0.00s)385 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)386 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)387 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)388 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)389 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)390 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)391 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)3922026/10/06 10:52:19 http: TLS handshake error from 127.0.0.1:53988: remote error: tls: bad certificate393--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)394--- PASS: TestDumpPathWriterError (0.04s)395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.04s)401--- PASS: TestDumpPathMatchesNix (0.06s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld1".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-30484-2750109167/postgres4004179200/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-30484-2750109167/postgres4004179200/data -l logfile start433434/nix/var/nix/builds/nix-30484-2750109167/postgres4004179200:5432 - no response4352026-10-06 10:52:21.360 UTC [30524] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 10:52:21.360 UTC [30524] LOG: listening on Unix socket "/nix/var/nix/builds/nix-30484-2750109167/postgres4004179200/.s.PGSQL.5432"4372026-10-06 10:52:21.362 UTC [30531] LOG: database system was shut down at 2026-10-06 10:52:21 UTC4382026-10-06 10:52:21.363 UTC [30524] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-30484-2750109167/postgres4004179200:5432 - accepting connections440{"timestamp":"2026-10-06T10:52:21.577047Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"74c131f7-de53-4646-bd4e-4ade06e8556d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}441{"timestamp":"2026-10-06T10:52:21.680932Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a1079583-2492-4ab2-92a0-b6ed9bb0e446","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 10:52:21 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:52:22 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:52:22 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:52:23 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:52:23 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:52:25.059 UTC [30566] FATAL: terminating connection due to administrator command4992026/10/06 10:52:25 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:52:26 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:52:26 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:52:26 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:52:26 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestService_AuthMiddleware693=== CONT TestService_cleanupPendingClosuresHandler694=== CONT TestRegisterCompletedObjectNeedsPendingRow695=== CONT TestPush_CompleteCommitsEveryRoot696=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock697=== CONT TestIsValidCachePath698=== RUN TestIsValidCachePath/narinfo699=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT700=== CONT TestCompleteMultipartUnregistered701=== PAUSE TestIsValidCachePath/narinfo702=== CONT TestService_verifyS3Integrity703=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars704=== CONT TestService_createPendingClosureHandler705=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars706=== RUN TestIsValidCachePath/nar_zst707=== PAUSE TestIsValidCachePath/nar_zst708=== RUN TestIsValidCachePath/nar_xz709=== PAUSE TestIsValidCachePath/nar_xz710=== RUN TestIsValidCachePath/nar_bz2711=== PAUSE TestIsValidCachePath/nar_bz2712=== RUN TestIsValidCachePath/nar_uncompressed713=== PAUSE TestIsValidCachePath/nar_uncompressed714=== RUN TestIsValidCachePath/ls715=== PAUSE TestIsValidCachePath/ls716=== RUN TestIsValidCachePath/log717=== PAUSE TestIsValidCachePath/log718=== RUN TestIsValidCachePath/realisation719=== PAUSE TestIsValidCachePath/realisation720=== RUN TestIsValidCachePath/nix-cache-info721=== PAUSE TestIsValidCachePath/nix-cache-info722=== RUN TestIsValidCachePath/index.html723=== PAUSE TestIsValidCachePath/index.html724=== RUN TestIsValidCachePath/traversal_parent725=== PAUSE TestIsValidCachePath/traversal_parent726=== RUN TestIsValidCachePath/traversal_in_middle727=== PAUSE TestIsValidCachePath/traversal_in_middle728=== RUN TestIsValidCachePath/invalid_char_e729=== PAUSE TestIsValidCachePath/invalid_char_e730=== RUN TestIsValidCachePath/invalid_char_u731=== PAUSE TestIsValidCachePath/invalid_char_u732=== RUN TestIsValidCachePath/random_path733=== PAUSE TestIsValidCachePath/random_path734=== RUN TestIsValidCachePath/empty735=== PAUSE TestIsValidCachePath/empty736=== RUN TestIsValidCachePath/leading_slash737=== PAUSE TestIsValidCachePath/leading_slash738=== RUN TestIsValidCachePath/wrong_extension739=== PAUSE TestIsValidCachePath/wrong_extension740=== RUN TestIsValidCachePath/short_hash741=== PAUSE TestIsValidCachePath/short_hash742=== CONT TestReadProxyConditionalGet7432026/10/06 10:52:27 INFO Received cleanup request method=DELETE path=/api/pending_closures7442026/10/06 10:52:27 INFO Aborted multipart uploads count=0 kept=07452026/10/06 10:52:27 INFO Received uploads request method=POST path=/api/pending_closures7462026/10/06 10:52:27 INFO Received cleanup request method=DELETE path=/api/pending_closures7472026/10/06 10:52:27 INFO Aborted multipart uploads count=1 kept=07482026/10/06 10:52:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7492026-10-06 10:52:27.152 UTC [30588] ERROR: Closure does not exist: id=17502026-10-06 10:52:27.152 UTC [30588] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE7512026-10-06 10:52:27.152 UTC [30588] STATEMENT: -- name: CommitPendingClosure :exec752 SELECT commit_pending_closure($1::bigint)753 754--- PASS: TestService_cleanupPendingClosuresHandler (0.46s)755=== CONT TestPush_OverlappingRootsStoreOneRowPerKey756--- PASS: TestReadProxyConditionalGet (0.57s)757=== CONT TestReadRedirectUsesPublicS3URL7582026/10/06 10:52:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"759--- PASS: TestService_AuthMiddleware (0.90s)760=== CONT TestReadProxyRangeRequest7612026/10/06 10:52:27 INFO Received uploads request method=POST path=/api/pending_closures7622026/10/06 10:52:27 INFO Received uploads request method=POST path=/api/pending_closures7632026/10/06 10:52:27 INFO Received uploads request method=POST path=/api/pending_closures7642026/10/06 10:52:27 INFO Received uploads request method=POST path=/api/pending_closures765--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.28s)766=== CONT TestReadRedirectKeepsNarinfoProxied7672026/10/06 10:52:28 INFO Received push request method=POST path=/api/pushes768--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.43s)769=== CONT TestReadRedirectNar7702026/10/06 10:52:28 INFO Received complete push request method=POST path=/api/pushes/1/complete771--- PASS: TestPush_CompleteCommitsEveryRoot (1.52s)772=== CONT TestReadProxyDisabled7732026/10/06 10:52:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7742026/10/06 10:52:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst775--- PASS: TestCompleteMultipartUnregistered (1.65s)776=== CONT TestReadProxyRootRedirectsToIndexHTML7772026/10/06 10:52:28 INFO Received uploads request method=POST path=/api/pending_closures778--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.03s)779=== CONT TestPushDedupSurvivesConcurrentGC7802026/10/06 10:52:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7812026/10/06 10:52:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LjZkYzE2YzAxLTRiMzUtNGIzYS05Y2MyLWM5MmUyMTdmN2Q4MXgxNzkxMjgzOTQ3NzM3NjgzMDAw parts=107822026/10/06 10:52:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7832026/10/06 10:52:28 INFO Completed upload id=17842026/10/06 10:52:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000007852026/10/06 10:52:28 INFO Received uploads request method=POST path=/api/pending_closures7862026/10/06 10:52:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures7872026/10/06 10:52:28 INFO Aborted multipart uploads count=0 kept=07882026/10/06 10:52:28 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=07892026/10/06 10:52:28 INFO Vacuumed table table=pending_closures7902026/10/06 10:52:28 INFO Vacuumed table table=pending_objects7912026/10/06 10:52:28 INFO Vacuumed table table=multipart_uploads7922026/10/06 10:52:28 INFO Received push request method=POST path=/api/pushes7932026/10/06 10:52:28 INFO Vacuumed table table=closures7942026/10/06 10:52:28 INFO Vacuumed table table=objects7952026/10/06 10:52:29 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000796--- PASS: TestService_createPendingClosureHandler (2.34s)797=== CONT TestSweepSkipsRowsLockedByPush798--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.93s)799=== CONT TestFailedS3DeleteKeepsTombstone800--- PASS: TestReadRedirectUsesPublicS3URL (1.96s)801=== CONT TestForceGCDuringPushOffersSweptObject802=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows803=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows804=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check805=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check806=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection807--- PASS: TestReadProxyRangeRequest (1.88s)808=== CONT TestGCSweepDeliversEachKeyOnce8092026/10/06 10:52:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8102026/10/06 10:52:29 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LjlmOTM4YTFkLTZjOGUtNDRjMi1hNGNhLWMxMjI2ODQyNDI5YXgxNzkxMjgzOTQ4NTM0MDkzMDAw parts=108112026/10/06 10:52:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8122026/10/06 10:52:29 INFO Completed upload id=18132026/10/06 10:52:29 INFO Received uploads request method=POST path=/api/pending_closures8142026/10/06 10:52:29 INFO Received uploads request method=POST path=/api/pending_closures8152026/10/06 10:52:29 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8162026/10/06 10:52:29 WARN Found objects in DB but missing from S3, will re-upload count=1817--- PASS: TestService_verifyS3Integrity (3.05s)818=== CONT TestTombstonedObjectOfferedWithoutWaiting819--- PASS: TestReadRedirectKeepsNarinfoProxied (1.94s)820=== CONT TestGCSweepSkipsPendingObjects821--- PASS: TestReadRedirectNar (2.02s)822=== CONT TestDeduplicatedObjectsRecordedAsPending823--- PASS: TestReadProxyDisabled (2.17s)824=== CONT TestLeadEndsOnShutdown825--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.29s)826=== CONT TestGCMetrics8272026/10/06 10:52:30 INFO Received uploads request method=POST path=/api/pending_closures8282026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08292026/10/06 10:52:31 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=08302026/10/06 10:52:31 INFO Vacuumed table table=pending_closures8312026/10/06 10:52:31 INFO Vacuumed table table=pending_objects8322026/10/06 10:52:31 INFO Vacuumed table table=multipart_uploads8332026/10/06 10:52:31 INFO Vacuumed table table=closures8342026/10/06 10:52:31 INFO Vacuumed table table=objects8352026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08362026/10/06 10:52:31 WARN Force mode enabled - objects will be deleted immediately without grace period8372026/10/06 10:52:31 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=08382026/10/06 10:52:31 INFO Vacuumed table table=pending_closures8392026/10/06 10:52:31 INFO Vacuumed table table=pending_objects8402026/10/06 10:52:31 INFO Vacuumed table table=multipart_uploads8412026/10/06 10:52:31 INFO Vacuumed table table=closures8422026/10/06 10:52:31 INFO Vacuumed table table=objects843--- PASS: TestPushDedupSurvivesConcurrentGC (2.47s)844=== CONT TestGCBugBareHashReferences8452026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08462026/10/06 10:52:31 WARN Force mode enabled - objects will be deleted immediately without grace period8472026/10/06 10:52:31 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=08482026/10/06 10:52:31 INFO Vacuumed table table=pending_closures8492026/10/06 10:52:31 INFO Vacuumed table table=pending_objects8502026/10/06 10:52:31 INFO Vacuumed table table=multipart_uploads8512026/10/06 10:52:31 INFO Vacuumed table table=closures8522026/10/06 10:52:31 INFO Vacuumed table table=objects8532026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08542026/10/06 10:52:31 WARN Force mode enabled - objects will be deleted immediately without grace period8552026/10/06 10:52:31 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=08562026/10/06 10:52:31 INFO Vacuumed table table=pending_closures8572026/10/06 10:52:31 INFO Vacuumed table table=pending_objects8582026/10/06 10:52:31 INFO Vacuumed table table=multipart_uploads8592026/10/06 10:52:31 INFO Vacuumed table table=closures8602026/10/06 10:52:31 INFO Vacuumed table table=objects861--- PASS: TestSweepSkipsRowsLockedByPush (2.31s)862=== CONT TestGCAdvisoryLockBlocksConcurrentRun8632026/10/06 10:52:31 INFO Received uploads request method=POST path=/api/pending_closures8642026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08652026/10/06 10:52:31 WARN Force mode enabled - objects will be deleted immediately without grace period8662026/10/06 10:52:31 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8672026/10/06 10:52:31 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."868--- PASS: TestFailedS3DeleteKeepsTombstone (2.48s)869=== CONT TestReadProxy4048702026/10/06 10:52:31 INFO Received uploads request method=POST path=/api/pending_closures871--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.64s)872=== CONT TestReadProxyOutlastsServerWriteTimeout8732026/10/06 10:52:31 INFO Aborted multipart uploads count=0 kept=08742026/10/06 10:52:31 WARN Force mode enabled - objects will be deleted immediately without grace period8752026/10/06 10:52:31 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=08762026/10/06 10:52:31 INFO Vacuumed table table=pending_closures8772026/10/06 10:52:31 INFO Vacuumed table table=pending_objects8782026/10/06 10:52:31 INFO Vacuumed table table=multipart_uploads8792026/10/06 10:52:31 INFO Vacuumed table table=closures8802026/10/06 10:52:31 INFO Vacuumed table table=objects881--- PASS: TestGCSweepDeliversEachKeyOnce (2.49s)882=== CONT TestReadProxyHead8832026/10/06 10:52:32 INFO Received uploads request method=POST path=/api/pending_closures884--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.34s)885=== CONT TestReadProxyInvalidPath8862026/10/06 10:52:32 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/06 10:52:32 INFO Aborted multipart uploads count=0 kept=08882026/10/06 10:52:32 WARN Force mode enabled - objects will be deleted immediately without grace period8892026/10/06 10:52:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08902026/10/06 10:52:32 INFO Vacuumed table table=pending_closures8912026/10/06 10:52:32 INFO Vacuumed table table=pending_objects8922026/10/06 10:52:32 INFO Vacuumed table table=multipart_uploads8932026/10/06 10:52:32 INFO Vacuumed table table=closures8942026/10/06 10:52:32 INFO Vacuumed table table=objects895--- PASS: TestGCSweepSkipsPendingObjects (2.49s)896=== CONT TestClientCADerivations8972026/10/06 10:52:32 INFO Received uploads request method=POST path=/api/pending_closures898--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.36s)899=== CONT TestClientFallsBackToClosures9002026/10/06 10:52:32 INFO lead: acquired remote=192.0.2.1:12349012026/10/06 10:52:33 INFO Aborted multipart uploads count=0 kept=09022026/10/06 10:52:33 WARN Force mode enabled - objects will be deleted immediately without grace period9032026/10/06 10:52:33 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=09042026/10/06 10:52:33 INFO Vacuumed table table=pending_closures9052026/10/06 10:52:33 INFO Vacuumed table table=pending_objects9062026/10/06 10:52:33 INFO Vacuumed table table=multipart_uploads9072026/10/06 10:52:33 INFO Vacuumed table table=closures9082026/10/06 10:52:33 INFO Vacuumed table table=objects909--- PASS: TestGCMetrics (2.39s)910=== CONT TestClientPushesUseOnePush911--- PASS: TestGCBugBareHashReferences (2.43s)912=== CONT TestPinProtectsFromGC9132026/10/06 10:52:33 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"914--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.31s)915=== CONT TestClientSharedPathCommittedMidPush9162026/10/06 10:52:33 INFO lead: released remote=192.0.2.1:1234917--- PASS: TestLeadEndsOnShutdown (3.38s)918=== CONT TestClientWithDependencies919--- PASS: TestReadProxy404 (2.53s)920=== CONT TestClientMultipleUploads921--- PASS: TestReadProxyHead (2.77s)922=== CONT TestClientIntegration923--- PASS: TestReadProxyInvalidPath (2.97s)924=== CONT TestClientErrorHandling925=== RUN TestClientErrorHandling/InvalidStorePath926=== PAUSE TestClientErrorHandling/InvalidStorePath927=== RUN TestClientErrorHandling/InvalidAuthToken928=== PAUSE TestClientErrorHandling/InvalidAuthToken929=== RUN TestClientErrorHandling/ServerNotAvailable930=== PAUSE TestClientErrorHandling/ServerNotAvailable931=== CONT TestCacheConfigHandlerMaxNarSize932--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)933=== CONT TestProxyHeadersOnlyTrustedOnSocket934=== NAME TestClientCADerivations935 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-30484-2750109167/TestClientCADerivations104294736/001/store/lz30frfn0bajg1f8r7qyr0wsd6c91137-ca-test936 client_ca_test.go:139: Found 1 dependencies (including self)9372026/10/06 10:52:36 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/06 10:52:36 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/06 10:52:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9402026/10/06 10:52:36 INFO Uploading d42h1ashq2fhm9w41zafma1ngds60r2c-shared-dep (136B)9412026/10/06 10:52:36 INFO Uploading bk3p6n2wa0hwr8vpffj5is85v9hpq35j-b (248B)9422026/10/06 10:52:36 WARN Failed to register uploaded object key=pm6walcsrbp38dz5328bzp1fv9gzw9lv.ls error="server returned 404: 404 page not found\n"9432026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/0n2r94lxxvif0zp3w9q1mp1gw3z3v91dk6914p9qi5g61fwa0d67.nar.zst error="server returned 404: 404 page not found\n"9442026/10/06 10:52:36 WARN Failed to register uploaded object key=bk3p6n2wa0hwr8vpffj5is85v9hpq35j.ls error="server returned 404: 404 page not found\n"9452026/10/06 10:52:36 WARN Failed to register uploaded object key=d42h1ashq2fhm9w41zafma1ngds60r2c.ls error="server returned 404: 404 page not found\n"9462026/10/06 10:52:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9472026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9482026/10/06 10:52:36 INFO Signed narinfos id=1 count=29492026/10/06 10:52:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9502026/10/06 10:52:36 INFO Signed narinfos id=2 count=29512026/10/06 10:52:36 INFO Uploading 4 narinfos9522026/10/06 10:52:36 WARN Failed to register uploaded object key=d42h1ashq2fhm9w41zafma1ngds60r2c.narinfo error="server returned 404: 404 page not found\n"9532026/10/06 10:52:36 WARN Failed to register uploaded object key=pm6walcsrbp38dz5328bzp1fv9gzw9lv.narinfo error="server returned 404: 404 page not found\n"9542026/10/06 10:52:36 WARN Failed to register uploaded object key=bk3p6n2wa0hwr8vpffj5is85v9hpq35j.narinfo error="server returned 404: 404 page not found\n"9552026/10/06 10:52:36 INFO Received push request method=POST path=/api/pushes9562026/10/06 10:52:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9572026/10/06 10:52:36 WARN Failed to register uploaded object key=d42h1ashq2fhm9w41zafma1ngds60r2c.narinfo error="server returned 404: 404 page not found\n"9582026/10/06 10:52:36 INFO Completed upload id=19592026/10/06 10:52:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9602026/10/06 10:52:36 INFO Uploading lz30frfn0bajg1f8r7qyr0wsd6c91137-ca-test (144B)9612026/10/06 10:52:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9622026/10/06 10:52:36 INFO Completed upload id=29632026/10/06 10:52:36 INFO Upload complete. (114ms)964=== NAME TestClientFallsBackToClosures965 client_pushes_test.go:112: Retrieved narinfo from S3:966 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientFallsBackToClosures2790244794/001/store/d42h1ashq2fhm9w41zafma1ngds60r2c-shared-dep967 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst968 Compression: zstd969 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82970 NarSize: 136971 References: 972 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n973 client_pushes_test.go:112: Retrieved narinfo from S3:974 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientFallsBackToClosures2790244794/001/store/pm6walcsrbp38dz5328bzp1fv9gzw9lv-a975 URL: nar/0n2r94lxxvif0zp3w9q1mp1gw3z3v91dk6914p9qi5g61fwa0d67.nar.zst976 Compression: zstd977 NarHash: sha256:0n2r94lxxvif0zp3w9q1mp1gw3z3v91dk6914p9qi5g61fwa0d67978 NarSize: 248979 References: /nix/var/nix/builds/nix-30484-2750109167/TestClientFallsBackToClosures2790244794/001/store/d42h1ashq2fhm9w41zafma1ngds60r2c-shared-dep980 CA: text:sha256:15cpfspbq1wdy2mwsk9f3jvgiwhx7hhsyzxnfq8qal1yx02rf08x981 client_pushes_test.go:112: Retrieved narinfo from S3:982 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientFallsBackToClosures2790244794/001/store/bk3p6n2wa0hwr8vpffj5is85v9hpq35j-b983 URL: nar/0n2r94lxxvif0zp3w9q1mp1gw3z3v91dk6914p9qi5g61fwa0d67.nar.zst984 Compression: zstd985 NarHash: sha256:0n2r94lxxvif0zp3w9q1mp1gw3z3v91dk6914p9qi5g61fwa0d67986 NarSize: 248987 References: /nix/var/nix/builds/nix-30484-2750109167/TestClientFallsBackToClosures2790244794/001/store/d42h1ashq2fhm9w41zafma1ngds60r2c-shared-dep988 CA: text:sha256:15cpfspbq1wdy2mwsk9f3jvgiwhx7hhsyzxnfq8qal1yx02rf08x9892026/10/06 10:52:36 WARN Failed to register uploaded object key=lz30frfn0bajg1f8r7qyr0wsd6c91137.ls error="server returned 404: 404 page not found\n"9902026/10/06 10:52:36 WARN Failed to register uploaded object key=log/0bxciddw9s70i798kacrvazm4c1zbmnl-ca-test.drv error="server returned 404: 404 page not found\n"9912026/10/06 10:52:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9922026/10/06 10:52:36 INFO Signed narinfos id=1 count=19932026/10/06 10:52:36 INFO Uploading 1 narinfos9942026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"9952026/10/06 10:52:36 INFO Received complete push request method=POST path=/api/pushes/1/complete9962026/10/06 10:52:36 WARN Failed to register uploaded object key=lz30frfn0bajg1f8r7qyr0wsd6c91137.narinfo error="server returned 404: 404 page not found\n"9972026/10/06 10:52:36 INFO Upload complete. (179ms)998--- PASS: TestClientFallsBackToClosures (3.81s)999=== CONT TestParseSingleRange1000=== RUN TestParseSingleRange/none1001=== PAUSE TestParseSingleRange/none1002=== RUN TestParseSingleRange/unknown_unit1003=== PAUSE TestParseSingleRange/unknown_unit1004=== RUN TestParseSingleRange/multi-range_ignored1005=== PAUSE TestParseSingleRange/multi-range_ignored1006=== RUN TestParseSingleRange/malformed_no_dash1007=== PAUSE TestParseSingleRange/malformed_no_dash1008=== RUN TestParseSingleRange/malformed_both_empty1009=== PAUSE TestParseSingleRange/malformed_both_empty1010=== RUN TestParseSingleRange/malformed_end_before_start1011=== PAUSE TestParseSingleRange/malformed_end_before_start1012=== RUN TestParseSingleRange/closed1013=== PAUSE TestParseSingleRange/closed1014=== RUN TestParseSingleRange/open-ended1015=== PAUSE TestParseSingleRange/open-ended1016=== RUN TestParseSingleRange/end_clamped_to_size1017=== PAUSE TestParseSingleRange/end_clamped_to_size1018=== RUN TestParseSingleRange/suffix1019=== PAUSE TestParseSingleRange/suffix1020=== RUN TestParseSingleRange/suffix_exceeds_size1021=== PAUSE TestParseSingleRange/suffix_exceeds_size1022=== RUN TestParseSingleRange/single_byte1023=== PAUSE TestParseSingleRange/single_byte1024=== RUN TestParseSingleRange/start_past_EOF1025=== PAUSE TestParseSingleRange/start_past_EOF1026=== RUN TestParseSingleRange/start_far_past_EOF1027=== PAUSE TestParseSingleRange/start_far_past_EOF1028=== CONT TestPresentNotReportedWhileGCDeletesClosure1029=== NAME TestClientCADerivations1030 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientCADerivations104294736/001/store/lz30frfn0bajg1f8r7qyr0wsd6c91137-ca-test1031 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1032 Compression: zstd1033 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1034 NarSize: 1441035 References: 1036 Deriver: /nix/var/nix/builds/nix-30484-2750109167/TestClientCADerivations104294736/001/store/0bxciddw9s70i798kacrvazm4c1zbmnl-ca-test.drv1037 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1038 client_ca_test.go:185: Checking for realisation files in S3...1039 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1040 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1041 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket36?endpoint=http://localhost:53997®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-30484-2750109167/TestClientCADerivations104294736/001/store'1042 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11043--- PASS: TestClientCADerivations (4.02s)1044=== CONT TestPresentReportsOnlyClosureRoots10452026/10/06 10:52:36 INFO Received push request method=POST path=/api/pushes10462026/10/06 10:52:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10472026/10/06 10:52:36 INFO Uploading wpvgrdz5fb3xn9kjk8xxm0ksjsarlvwk-b (248B)10482026/10/06 10:52:36 INFO Uploading ciyxdy9kgssdfg1v4wc255hliq8iqv58-shared-dep (136B)10492026/10/06 10:52:36 WARN Failed to register uploaded object key=anp2lwca1907f8fk0r80b3p3plw4qzx6.ls error="server returned 404: 404 page not found\n"10502026/10/06 10:52:36 WARN Failed to register uploaded object key=ciyxdy9kgssdfg1v4wc255hliq8iqv58.ls error="server returned 404: 404 page not found\n"10512026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10522026/10/06 10:52:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10532026/10/06 10:52:36 WARN Failed to register uploaded object key=wpvgrdz5fb3xn9kjk8xxm0ksjsarlvwk.ls error="server returned 404: 404 page not found\n"10542026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/0g3yjy6i4xxyxdlswpdjb3ckz1dmmjplqm6hrhbij9cfvbm9flxn.nar.zst error="server returned 404: 404 page not found\n"10552026/10/06 10:52:36 INFO Signed narinfos id=1 count=310562026/10/06 10:52:36 INFO Uploading 3 narinfos10572026/10/06 10:52:36 WARN Failed to register uploaded object key=wpvgrdz5fb3xn9kjk8xxm0ksjsarlvwk.narinfo error="server returned 404: 404 page not found\n"10582026/10/06 10:52:36 WARN Failed to register uploaded object key=ciyxdy9kgssdfg1v4wc255hliq8iqv58.narinfo error="server returned 404: 404 page not found\n"10592026/10/06 10:52:36 INFO Received complete push request method=POST path=/api/pushes/1/complete10602026/10/06 10:52:36 WARN Failed to register uploaded object key=anp2lwca1907f8fk0r80b3p3plw4qzx6.narinfo error="server returned 404: 404 page not found\n"10612026/10/06 10:52:36 INFO Upload complete. (115ms)1062=== NAME TestClientPushesUseOnePush1063 client_pushes_test.go:97: Retrieved narinfo from S3:1064 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientPushesUseOnePush1603862656/001/store/ciyxdy9kgssdfg1v4wc255hliq8iqv58-shared-dep1065 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1066 Compression: zstd1067 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821068 NarSize: 1361069 References: 1070 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1071 client_pushes_test.go:97: Retrieved narinfo from S3:1072 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientPushesUseOnePush1603862656/001/store/anp2lwca1907f8fk0r80b3p3plw4qzx6-a1073 URL: nar/0g3yjy6i4xxyxdlswpdjb3ckz1dmmjplqm6hrhbij9cfvbm9flxn.nar.zst1074 Compression: zstd1075 NarHash: sha256:0g3yjy6i4xxyxdlswpdjb3ckz1dmmjplqm6hrhbij9cfvbm9flxn1076 NarSize: 2481077 References: /nix/var/nix/builds/nix-30484-2750109167/TestClientPushesUseOnePush1603862656/001/store/ciyxdy9kgssdfg1v4wc255hliq8iqv58-shared-dep1078 CA: text:sha256:0nw0s1y9qc0v3jn25wg83s4iw9i49dsbcysgqsnnijy1ad94ya0j1079 client_pushes_test.go:97: Retrieved narinfo from S3:1080 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientPushesUseOnePush1603862656/001/store/wpvgrdz5fb3xn9kjk8xxm0ksjsarlvwk-b1081 URL: nar/0g3yjy6i4xxyxdlswpdjb3ckz1dmmjplqm6hrhbij9cfvbm9flxn.nar.zst1082 Compression: zstd1083 NarHash: sha256:0g3yjy6i4xxyxdlswpdjb3ckz1dmmjplqm6hrhbij9cfvbm9flxn1084 NarSize: 2481085 References: /nix/var/nix/builds/nix-30484-2750109167/TestClientPushesUseOnePush1603862656/001/store/ciyxdy9kgssdfg1v4wc255hliq8iqv58-shared-dep1086 CA: text:sha256:0nw0s1y9qc0v3jn25wg83s4iw9i49dsbcysgqsnnijy1ad94ya0j1087--- PASS: TestClientPushesUseOnePush (3.64s)1088=== CONT TestCreatePin_ReservedPins10892026/10/06 10:52:36 INFO Received push request method=POST path=/api/pushes10902026/10/06 10:52:36 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10912026/10/06 10:52:36 INFO Uploading 865j3mwi6743g5mhy6ml9jm08jq5l2f1-shared-dep (136B)10922026/10/06 10:52:36 INFO Uploading d9hmsl91ijcz7n6bk499niz1gzzb29zk-top (256B)10932026/10/06 10:52:36 WARN Failed to register uploaded object key=865j3mwi6743g5mhy6ml9jm08jq5l2f1.ls error="server returned 404: 404 page not found\n"10942026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10952026/10/06 10:52:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10962026/10/06 10:52:36 WARN Failed to register uploaded object key=d9hmsl91ijcz7n6bk499niz1gzzb29zk.ls error="server returned 404: 404 page not found\n"10972026/10/06 10:52:36 WARN Failed to register uploaded object key=nar/0l6pphddsxbdy7qx5n0bj0qv6ympivg3dj3q6a79s8s5ps1bypq3.nar.zst error="server returned 404: 404 page not found\n"10982026/10/06 10:52:36 INFO Signed narinfos id=1 count=210992026/10/06 10:52:36 INFO Uploading 2 narinfos11002026/10/06 10:52:36 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/06 10:52:36 WARN Failed to register uploaded object key=d9hmsl91ijcz7n6bk499niz1gzzb29zk.narinfo error="server returned 404: 404 page not found\n"11022026/10/06 10:52:36 WARN Failed to register uploaded object key=865j3mwi6743g5mhy6ml9jm08jq5l2f1.narinfo error="server returned 404: 404 page not found\n"11032026/10/06 10:52:36 INFO Upload complete. (112ms)1104=== NAME TestClientSharedPathCommittedMidPush1105 client_integration_test.go:680: Retrieved narinfo from S3:1106 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientSharedPathCommittedMidPush3933062688/001/store/865j3mwi6743g5mhy6ml9jm08jq5l2f1-shared-dep1107 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1108 Compression: zstd1109 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821110 NarSize: 1361111 References: 1112 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1113 client_integration_test.go:680: Retrieved narinfo from S3:1114 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientSharedPathCommittedMidPush3933062688/001/store/d9hmsl91ijcz7n6bk499niz1gzzb29zk-top1115 URL: nar/0l6pphddsxbdy7qx5n0bj0qv6ympivg3dj3q6a79s8s5ps1bypq3.nar.zst1116 Compression: zstd1117 NarHash: sha256:0l6pphddsxbdy7qx5n0bj0qv6ympivg3dj3q6a79s8s5ps1bypq31118 NarSize: 2561119 References: /nix/var/nix/builds/nix-30484-2750109167/TestClientSharedPathCommittedMidPush3933062688/001/store/865j3mwi6743g5mhy6ml9jm08jq5l2f1-shared-dep1120 CA: text:sha256:1g5zfhfyxg7fa2zgpknm4050014r00a854f3rn607c3fngbgwfxg11212026/10/06 10:52:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54201/oidc1122--- PASS: TestClientSharedPathCommittedMidPush (3.18s)1123=== CONT TestOrphanedObjectsGCStressTest1124=== NAME TestPinProtectsFromGC1125 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-30484-2750109167/TestPinProtectsFromGC3338159003/001/store/1l8imvfn1rgcib32j5vxc2fihizvpdak-pinned-file.txt1126 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-30484-2750109167/TestPinProtectsFromGC3338159003/001/store/12fpjkg05p5951cpnl8v45m69qyh38ns-unpinned-file.txt11272026/10/06 10:52:36 INFO Received push request method=POST path=/api/pushes11282026/10/06 10:52:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11292026/10/06 10:52:36 INFO Uploading 1l8imvfn1rgcib32j5vxc2fihizvpdak-pinned-file.txt (128B)11302026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11312026/10/06 10:52:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11322026/10/06 10:52:37 WARN Failed to register uploaded object key=1l8imvfn1rgcib32j5vxc2fihizvpdak.ls error="server returned 404: 404 page not found\n"11332026/10/06 10:52:37 INFO Signed narinfos id=1 count=111342026/10/06 10:52:37 INFO Uploading 1 narinfos11352026/10/06 10:52:37 INFO Received complete push request method=POST path=/api/pushes/1/complete11362026/10/06 10:52:37 WARN Failed to register uploaded object key=1l8imvfn1rgcib32j5vxc2fihizvpdak.narinfo error="server returned 404: 404 page not found\n"11372026/10/06 10:52:37 INFO Upload complete. (182ms)11382026/10/06 10:52:37 INFO Received push request method=POST path=/api/pushes11392026/10/06 10:52:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11402026/10/06 10:52:37 INFO Uploading 12fpjkg05p5951cpnl8v45m69qyh38ns-unpinned-file.txt (128B)11412026/10/06 10:52:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11422026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11432026/10/06 10:52:37 INFO Signed narinfos id=2 count=111442026/10/06 10:52:37 WARN Failed to register uploaded object key=12fpjkg05p5951cpnl8v45m69qyh38ns.ls error="server returned 404: 404 page not found\n"11452026/10/06 10:52:37 INFO Uploading 1 narinfos11462026/10/06 10:52:37 INFO Received complete push request method=POST path=/api/pushes/2/complete11472026/10/06 10:52:37 WARN Failed to register uploaded object key=12fpjkg05p5951cpnl8v45m69qyh38ns.narinfo error="server returned 404: 404 page not found\n"11482026/10/06 10:52:37 INFO Upload complete. (65ms)11492026/10/06 10:52:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures11502026/10/06 10:52:37 INFO Garbage collection started11512026/10/06 10:52:37 INFO Aborted multipart uploads count=0 kept=011522026/10/06 10:52:37 WARN Force mode enabled - objects will be deleted immediately without grace period11532026/10/06 10:52:37 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=01154=== NAME TestClientWithDependencies1155 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-30484-2750109167/TestClientWithDependencies993536428/001/store/4skr5yk3dcs8vflrgj0y336amibnzzdj-test-script11562026/10/06 10:52:37 INFO Vacuumed table table=pending_closures1157=== NAME TestClientMultipleUploads1158 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-30484-2750109167/TestClientMultipleUploads3676560505/001/store/6sx1adij76f2ir3xn5szhx605cwb068p-test-file-0.txt11592026/10/06 10:52:37 INFO Vacuumed table table=pending_objects11602026/10/06 10:52:37 INFO Vacuumed table table=multipart_uploads11612026/10/06 10:52:37 INFO Vacuumed table table=closures1162=== NAME TestClientWithDependencies1163 client_integration_test.go:615: Found 1 dependencies (including self)11642026/10/06 10:52:37 INFO Vacuumed table table=objects1165=== NAME TestClientMultipleUploads1166 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-30484-2750109167/TestClientMultipleUploads3676560505/001/store/wzd7h1v5vr15nd05qfv08rd9fgk0f3h2-test-file-1.txt11672026/10/06 10:52:37 INFO Received push request method=POST path=/api/pushes1168 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-30484-2750109167/TestClientMultipleUploads3676560505/001/store/8b4mng7cn9m5sr7hsfvs6xsm422d0ai8-test-file-2.txt11692026/10/06 10:52:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11702026/10/06 10:52:37 INFO Uploading 4skr5yk3dcs8vflrgj0y336amibnzzdj-test-script (136B)11712026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11722026/10/06 10:52:37 WARN Failed to register uploaded object key=4skr5yk3dcs8vflrgj0y336amibnzzdj.ls error="server returned 404: 404 page not found\n"11732026/10/06 10:52:37 WARN Failed to register uploaded object key=log/6hm1fa7wn3jd954m62pnlc3d59v1918i-test-script.drv error="server returned 404: 404 page not found\n"11742026/10/06 10:52:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11752026/10/06 10:52:37 INFO Signed narinfos id=1 count=111762026/10/06 10:52:37 INFO Uploading 1 narinfos11772026/10/06 10:52:37 INFO Received complete push request method=POST path=/api/pushes/1/complete11782026/10/06 10:52:37 WARN Failed to register uploaded object key=4skr5yk3dcs8vflrgj0y336amibnzzdj.narinfo error="server returned 404: 404 page not found\n"11792026/10/06 10:52:37 INFO Received push request method=POST path=/api/pushes11802026/10/06 10:52:37 INFO Upload complete. (140ms)1181=== NAME TestClientWithDependencies1182 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-30484-2750109167/TestClientWithDependencies993536428/001/store) requires matching store prefix1183=== NAME TestClientIntegration1184 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-30484-2750109167/TestClientIntegration4026318059/002/store/x0bn318q9n0n9slm4yaxl3rq5nsw1qzb-test-file.txt11852026/10/06 10:52:37 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11862026/10/06 10:52:37 INFO Uploading 6sx1adij76f2ir3xn5szhx605cwb068p-test-file-0.txt (160B)11872026/10/06 10:52:37 INFO Uploading 8b4mng7cn9m5sr7hsfvs6xsm422d0ai8-test-file-2.txt (160B)11882026/10/06 10:52:37 INFO Uploading wzd7h1v5vr15nd05qfv08rd9fgk0f3h2-test-file-1.txt (160B)11892026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11902026/10/06 10:52:37 WARN Failed to register uploaded object key=wzd7h1v5vr15nd05qfv08rd9fgk0f3h2.ls error="server returned 404: 404 page not found\n"11912026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11922026/10/06 10:52:37 WARN Failed to register uploaded object key=6sx1adij76f2ir3xn5szhx605cwb068p.ls error="server returned 404: 404 page not found\n"11932026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11942026/10/06 10:52:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11952026/10/06 10:52:37 WARN Failed to register uploaded object key=8b4mng7cn9m5sr7hsfvs6xsm422d0ai8.ls error="server returned 404: 404 page not found\n"11962026/10/06 10:52:37 INFO Signed narinfos id=1 count=311972026/10/06 10:52:37 INFO Uploading 3 narinfos11982026/10/06 10:52:37 WARN Failed to register uploaded object key=6sx1adij76f2ir3xn5szhx605cwb068p.narinfo error="server returned 404: 404 page not found\n"11992026/10/06 10:52:37 WARN Failed to register uploaded object key=wzd7h1v5vr15nd05qfv08rd9fgk0f3h2.narinfo error="server returned 404: 404 page not found\n"12002026/10/06 10:52:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12012026/10/06 10:52:37 WARN Failed to register uploaded object key=8b4mng7cn9m5sr7hsfvs6xsm422d0ai8.narinfo error="server returned 404: 404 page not found\n"1202--- PASS: TestClientWithDependencies (3.84s)1203=== CONT TestOrphanedObjectsGC12042026/10/06 10:52:37 INFO Upload complete. (136ms)1205=== NAME TestClientMultipleUploads1206 client_integration_test.go:369: Uploaded 3 paths in 169.423208ms12072026/10/06 10:52:37 INFO Received push request method=POST path=/api/pushes12082026/10/06 10:52:37 INFO Starting HTTP server address=/nix/var/nix/builds/nix-30484-2750109167/TestProxyHeadersOnlyTrustedOnSocket599210081/001/proxy.sock12092026/10/06 10:52:37 INFO Starting HTTP server address=127.0.0.1:5425112102026/10/06 10:52:37 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12112026/10/06 10:52:37 INFO Shutdown signal received, draining in-flight requests timeout=10s1212--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.59s)1213=== CONT TestObjectStatsTrigger12142026/10/06 10:52:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12152026/10/06 10:52:37 INFO Uploading x0bn318q9n0n9slm4yaxl3rq5nsw1qzb-test-file.txt (152B)1216--- PASS: TestClientMultipleUploads (3.55s)1217=== CONT TestPendingCleanupUsesOneCutoff12182026/10/06 10:52:37 WARN Failed to register uploaded object key=x0bn318q9n0n9slm4yaxl3rq5nsw1qzb.ls error="server returned 404: 404 page not found\n"12192026/10/06 10:52:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12202026/10/06 10:52:37 INFO Signed narinfos id=1 count=112212026/10/06 10:52:37 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12222026/10/06 10:52:37 INFO Uploading 1 narinfos12232026/10/06 10:52:37 INFO Received complete push request method=POST path=/api/pushes/1/complete12242026/10/06 10:52:37 WARN Failed to register uploaded object key=x0bn318q9n0n9slm4yaxl3rq5nsw1qzb.narinfo error="server returned 404: 404 page not found\n"12252026/10/06 10:52:37 INFO Upload complete. (96ms)12262026/10/06 10:52:37 INFO All 1 paths already cached1227=== NAME TestClientIntegration1228 client_integration_test.go:312: Retrieved narinfo from S3:1229 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestClientIntegration4026318059/002/store/x0bn318q9n0n9slm4yaxl3rq5nsw1qzb-test-file.txt1230 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1231 Compression: zstd1232 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11233 NarSize: 1521234 References: 1235 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11236 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1237 client_integration_test.go:313: Decompressed .ls content (64 bytes):1238 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1239 client_integration_test.go:316: Testing garbage collection...12402026/10/06 10:52:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures12412026/10/06 10:52:37 INFO Garbage collection started12422026/10/06 10:52:37 INFO Aborted multipart uploads count=0 kept=012432026/10/06 10:52:37 WARN Force mode enabled - objects will be deleted immediately without grace period12442026/10/06 10:52:37 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=012452026/10/06 10:52:37 INFO Vacuumed table table=pending_closures12462026/10/06 10:52:37 INFO Vacuumed table table=pending_objects12472026/10/06 10:52:37 INFO Vacuumed table table=multipart_uploads12482026/10/06 10:52:37 INFO Vacuumed table table=closures12492026/10/06 10:52:37 INFO Vacuumed table table=objects1250--- PASS: TestPresentReportsOnlyClosureRoots (1.67s)1251=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12522026/10/06 10:52:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12532026/10/06 10:52:38 WARN Refused reserved pin name=worker-x86_64-linux12542026/10/06 10:52:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12552026/10/06 10:52:38 INFO Received create pin request method=POST path=/api/pins/my-app12562026/10/06 10:52:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1257--- PASS: TestCreatePin_ReservedPins (1.62s)1258=== CONT TestMultipartCleanup1259--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.10s)1260=== CONT TestServerTLSConfig1261=== RUN TestServerTLSConfig/no_client_CA1262=== PAUSE TestServerTLSConfig/no_client_CA1263=== RUN TestServerTLSConfig/missing_CA_file1264=== PAUSE TestServerTLSConfig/missing_CA_file1265=== RUN TestServerTLSConfig/not_a_PEM_file1266=== PAUSE TestServerTLSConfig/not_a_PEM_file1267=== CONT TestService_NativeMTLS1268--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.69s)1269=== CONT TestMetricsInventory12702026/10/06 10:52:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=012712026/10/06 10:52:39 INFO Received create pin request method=POST path=/api/pins/myapp12722026/10/06 10:52:39 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-30484-2750109167/TestPinProtectsFromGC3338159003/001/store/1l8imvfn1rgcib32j5vxc2fihizvpdak-pinned-file.txt narinfo_key=1l8imvfn1rgcib32j5vxc2fihizvpdak.narinfo12732026/10/06 10:52:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures12742026/10/06 10:52:39 INFO Garbage collection started12752026/10/06 10:52:39 INFO Aborted multipart uploads count=0 kept=012762026/10/06 10:52:39 WARN Force mode enabled - objects will be deleted immediately without grace period12772026/10/06 10:52:39 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=01278--- PASS: TestObjectStatsTrigger (1.63s)1279=== CONT TestNARDeduplicationMetadataUploadBug12802026/10/06 10:52:39 INFO Vacuumed table table=pending_closures12812026/10/06 10:52:39 INFO Vacuumed table table=pending_objects12822026/10/06 10:52:39 INFO Vacuumed table table=multipart_uploads12832026/10/06 10:52:39 INFO Vacuumed table table=closures12842026/10/06 10:52:39 INFO Vacuumed table table=objects12852026/10/06 10:52:39 INFO Received uploads request method=POST path=/api/pending_closures12862026/10/06 10:52:39 INFO Received uploads request method=POST path=/api/pending_closures12872026/10/06 10:52:39 INFO Received cleanup request method=DELETE path=/api/pending_closures1288=== NAME TestOrphanedObjectsGC1289 orphaned_objects_gc_test.go:290: GC Test Summary:1290 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1291 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1292 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1293 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1294 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1295--- PASS: TestOrphanedObjectsGC (2.01s)1296=== CONT TestCreatePendingClosureRejectsOversizedNAR12972026/10/06 10:52:39 INFO Received uploads request method=POST path=/api/pending_closures1298--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1299=== CONT TestGCTaskStore_GetEmpty1300--- PASS: TestGCTaskStore_GetEmpty (0.00s)1301=== CONT TestGenerateLandingPage1302--- PASS: TestGenerateLandingPage (0.00s)1303=== CONT TestService_readinessHandler13042026/10/06 10:52:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01305=== NAME TestClientIntegration1306 client_integration_test.go:323: Objects in database after GC:1307 client_integration_test.go:323: Successfully deleted all objects with GC --force1308--- PASS: TestClientIntegration (5.06s)1309=== CONT TestService_healthCheckHandler13102026/10/06 10:52:39 INFO Received uploads request method=POST path=/api/pending_closures1311--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.88s)1312=== CONT TestGracefulShutdownDrainsInflight13132026/10/06 10:52:39 INFO Starting HTTP server address=127.0.0.1:5428513142026/10/06 10:52:39 INFO Shutdown signal received, draining in-flight requests timeout=10s1315--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1316=== CONT TestGCTaskStore_Fail1317--- PASS: TestGCTaskStore_Fail (0.00s)1318=== CONT TestGCTaskStore_PhaseUpdates1319--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1320=== CONT TestGCTaskStore_CompletedAllowsNewTask1321--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1322=== CONT TestGCTaskStore_GetReturnsLatest1323--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1324=== CONT TestService_RequireScope_OIDC13252026/10/06 10:52:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54289/oidc13262026/10/06 10:52:40 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/06 10:52:40 INFO Received cleanup request method=DELETE path=/api/pending_closures13282026/10/06 10:52:40 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket53/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13292026/10/06 10:52:40 INFO Aborted multipart uploads count=0 kept=113302026/10/06 10:52:40 INFO Received cleanup request method=DELETE path=/api/pending_closures13312026/10/06 10:52:40 INFO Aborted multipart uploads count=1 kept=01332--- PASS: TestMultipartCleanup (2.22s)1333=== CONT TestCacheStatsHandler13342026/10/06 10:52:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13352026/10/06 10:52:40 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1336--- PASS: TestService_NativeMTLS (2.16s)1337=== CONT TestCacheConfigHandler1338=== RUN TestCacheConfigHandler/full_config,_no_issuer1339=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1340=== RUN TestCacheConfigHandler/no_cache_url_configured1341=== PAUSE TestCacheConfigHandler/no_cache_url_configured1342=== RUN TestCacheConfigHandler/no_signing_keys1343=== PAUSE TestCacheConfigHandler/no_signing_keys1344=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1345=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1346=== CONT TestService_ReadScope_PublicByDefault1347--- PASS: TestMetricsInventory (2.28s)1348=== CONT TestService_ReadAuthMiddleware1349=== NAME TestPinProtectsFromGC1350 client_integration_test.go:840: Pin successfully protected closure from garbage collection1351--- PASS: TestPinProtectsFromGC (7.74s)1352=== CONT TestService_AuthMiddleware_OIDC13532026/10/06 10:52:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54298/oidc1354=== NAME TestNARDeduplicationMetadataUploadBug1355 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-30484-2750109167/TestNARDeduplicationMetadataUploadBug612797845/001/store/spi9w4jhfyhl2j2f1wjbkm37iir1iwf8-file1.txt13562026/10/06 10:52:41 WARN readiness check failed error="closed pool"1357--- PASS: TestService_readinessHandler (2.11s)1358=== CONT TestLeadElectsOneAndHandsOver13592026/10/06 10:52:41 INFO Received push request method=POST path=/api/pushes13602026/10/06 10:52:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13612026/10/06 10:52:41 INFO Uploading spi9w4jhfyhl2j2f1wjbkm37iir1iwf8-file1.txt (160B)13622026/10/06 10:52:41 WARN Failed to register uploaded object key=spi9w4jhfyhl2j2f1wjbkm37iir1iwf8.ls error="server returned 404: 404 page not found\n"13632026/10/06 10:52:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13642026/10/06 10:52:41 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13652026/10/06 10:52:41 INFO Signed narinfos id=1 count=113662026/10/06 10:52:41 INFO Uploading 1 narinfos13672026/10/06 10:52:41 INFO Received complete push request method=POST path=/api/pushes/1/complete13682026/10/06 10:52:41 WARN Failed to register uploaded object key=spi9w4jhfyhl2j2f1wjbkm37iir1iwf8.narinfo error="server returned 404: 404 page not found\n"13692026/10/06 10:52:41 INFO Upload complete. (164ms)1370=== NAME TestNARDeduplicationMetadataUploadBug1371 metadata_upload_test.go:54: Retrieved narinfo from S3:1372 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestNARDeduplicationMetadataUploadBug612797845/001/store/spi9w4jhfyhl2j2f1wjbkm37iir1iwf8-file1.txt1373 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1374 Compression: zstd1375 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1376 NarSize: 1601377 References: 1378 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1379 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1380 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1381 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1382 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-30484-2750109167/TestNARDeduplicationMetadataUploadBug612797845/001/store/0vmf354xd9y5r2h4kchsscxljvij3c2m-file2.txt1383--- PASS: TestService_healthCheckHandler (2.22s)1384=== CONT TestLeadIncumbentAnnouncesAtOnce13852026/10/06 10:52:42 INFO Received push request method=POST path=/api/pushes13862026/10/06 10:52:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13872026/10/06 10:52:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13882026/10/06 10:52:42 INFO Signed narinfos id=2 count=113892026/10/06 10:52:42 WARN Failed to register uploaded object key=0vmf354xd9y5r2h4kchsscxljvij3c2m.ls error="server returned 404: 404 page not found\n"13902026/10/06 10:52:42 INFO Uploading 1 narinfos13912026/10/06 10:52:42 INFO Received complete push request method=POST path=/api/pushes/2/complete13922026/10/06 10:52:42 WARN Failed to register uploaded object key=0vmf354xd9y5r2h4kchsscxljvij3c2m.narinfo error="server returned 404: 404 page not found\n"13932026/10/06 10:52:42 INFO Upload complete. (87ms)1394=== NAME TestNARDeduplicationMetadataUploadBug1395 metadata_upload_test.go:76: Retrieved narinfo from S3:1396 StorePath: /nix/var/nix/builds/nix-30484-2750109167/TestNARDeduplicationMetadataUploadBug612797845/001/store/0vmf354xd9y5r2h4kchsscxljvij3c2m-file2.txt1397 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1398 Compression: zstd1399 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1400 NarSize: 1601401 References: 1402 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1403 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1404 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1405 {"version":1,"root":{"type":"regular","size":44}}1406--- PASS: TestNARDeduplicationMetadataUploadBug (2.92s)1407=== CONT TestParseSize1408--- PASS: TestParseSize (0.00s)1409=== CONT TestUploadHandlersRejectOversizedBody1410=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1411=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1412=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1413=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1414=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1415=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1416=== CONT TestUploadHandlersRejectInvalidKeys1417=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1418=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1419=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1420=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1421=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1422=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1423=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1424=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1425=== CONT TestIsValidUploadKey1426=== RUN TestIsValidUploadKey/narinfo1427=== PAUSE TestIsValidUploadKey/narinfo1428=== RUN TestIsValidUploadKey/nar_zst1429=== PAUSE TestIsValidUploadKey/nar_zst1430=== RUN TestIsValidUploadKey/nar_xz1431=== PAUSE TestIsValidUploadKey/nar_xz1432=== RUN TestIsValidUploadKey/nar_plain1433=== PAUSE TestIsValidUploadKey/nar_plain1434=== RUN TestIsValidUploadKey/listing1435=== PAUSE TestIsValidUploadKey/listing1436=== RUN TestIsValidUploadKey/build_log1437=== PAUSE TestIsValidUploadKey/build_log1438=== RUN TestIsValidUploadKey/build_log_home-manager_file1439=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1440=== RUN TestIsValidUploadKey/build_log_plus_in_name1441=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1442=== RUN TestIsValidUploadKey/build_log_question_mark1443=== PAUSE TestIsValidUploadKey/build_log_question_mark1444=== RUN TestIsValidUploadKey/build_log_equals1445=== PAUSE TestIsValidUploadKey/build_log_equals1446=== RUN TestIsValidUploadKey/realisation1447=== PAUSE TestIsValidUploadKey/realisation1448=== RUN TestIsValidUploadKey/realisation_plus_in_output1449=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1450=== RUN TestIsValidUploadKey/nix-cache-info1451=== PAUSE TestIsValidUploadKey/nix-cache-info1452=== RUN TestIsValidUploadKey/index.html1453=== PAUSE TestIsValidUploadKey/index.html1454=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1455=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1456=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1457=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1458=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1459=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1460=== RUN TestIsValidUploadKey/traversal1461=== PAUSE TestIsValidUploadKey/traversal1462=== RUN TestIsValidUploadKey/traversal_nar1463=== PAUSE TestIsValidUploadKey/traversal_nar1464=== RUN TestIsValidUploadKey/absolute1465=== PAUSE TestIsValidUploadKey/absolute1466=== RUN TestIsValidUploadKey/empty_key1467=== PAUSE TestIsValidUploadKey/empty_key1468=== RUN TestIsValidUploadKey/unknown_type1469=== PAUSE TestIsValidUploadKey/unknown_type1470=== CONT TestPendingClosureWriteTimeout1471=== RUN TestPendingClosureWriteTimeout/empty1472=== PAUSE TestPendingClosureWriteTimeout/empty1473=== RUN TestPendingClosureWriteTimeout/400_objects1474=== PAUSE TestPendingClosureWriteTimeout/400_objects1475=== RUN TestPendingClosureWriteTimeout/670k_objects1476=== PAUSE TestPendingClosureWriteTimeout/670k_objects1477=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1478=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1479=== CONT TestProxyWriteTimeout1480=== RUN TestProxyWriteTimeout/narinfo1481=== PAUSE TestProxyWriteTimeout/narinfo1482=== RUN TestProxyWriteTimeout/1_GiB_nar1483=== PAUSE TestProxyWriteTimeout/1_GiB_nar1484=== RUN TestProxyWriteTimeout/10_GiB_nar1485=== PAUSE TestProxyWriteTimeout/10_GiB_nar1486=== RUN TestProxyWriteTimeout/unknown_size1487=== PAUSE TestProxyWriteTimeout/unknown_size1488=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1489=== RUN TestService_RequireScope_OIDC/builder_may_write1490=== PAUSE TestService_RequireScope_OIDC/builder_may_write1491=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1492=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1493=== RUN TestService_RequireScope_OIDC/ops_may_admin1494=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1495=== RUN TestService_RequireScope_OIDC/ops_may_not_write1496=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1497=== RUN TestService_RequireScope_OIDC/reader_may_not_write1498=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1499=== RUN TestService_RequireScope_OIDC/static_token_may_admin1500=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1501=== RUN TestService_RequireScope_OIDC/static_token_may_write1502=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1503=== RUN TestService_RequireScope_OIDC/reader_may_read1504=== PAUSE TestService_RequireScope_OIDC/reader_may_read1505=== RUN TestService_RequireScope_OIDC/writer_implies_read1506=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1507=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1508=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1509=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1510=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1511=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1512=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1513=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1514=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1515=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1516=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1517=== CONT TestSkippedUploadsHandler15182026/10/06 10:52:42 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001519--- PASS: TestSkippedUploadsHandler (0.00s)1520=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1521--- PASS: TestCacheStatsHandler (2.12s)1522=== CONT TestConnectWaitsForAPeerMigration1523--- PASS: TestService_ReadScope_PublicByDefault (2.31s)1524=== CONT TestResolveDBConnectionString1525=== RUN TestResolveDBConnectionString/flag_wins1526=== PAUSE TestResolveDBConnectionString/flag_wins1527=== RUN TestResolveDBConnectionString/file_when_flag_empty1528=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1529=== RUN TestResolveDBConnectionString/missing_file_is_an_error1530=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1531=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1532=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1533=== RUN TestResolveDBConnectionString/nothing_configured1534=== PAUSE TestResolveDBConnectionString/nothing_configured1535=== CONT TestGCEndsOnShutdown1536=== RUN TestGCEndsOnShutdown/before_the_run1537=== PAUSE TestGCEndsOnShutdown/before_the_run1538=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1539=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1540=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1541=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1542=== CONT TestGCTaskStore_ConflictDifferentParams1543--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1544=== CONT TestGCTaskStore_DeduplicateSameParams1545--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1546=== CONT TestGCTaskStore_StartNew1547--- PASS: TestGCTaskStore_StartNew (0.00s)1548=== CONT TestService_AuthMiddleware_MTLSProxyHeader1549--- PASS: TestService_ReadAuthMiddleware (2.33s)1550=== CONT TestPushWaitsForSweepHoldingRow1551=== NAME TestOrphanedObjectsGCStressTest1552 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1553 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1554=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1555=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1556=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1557=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1558=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1559=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1560=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1561=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1562=== CONT TestCommitRacingPendingCleanupKeepsObjects15632026/10/06 10:52:43 INFO lead: acquired remote=192.0.2.1:123415642026/10/06 10:52:44 INFO lead: acquired remote=192.0.2.1:123415652026/10/06 10:52:44 INFO lead: released remote=192.0.2.1:12341566--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.26s)1567=== CONT TestSweepRechecksPendingAfterLocking15682026/10/06 10:52:44 INFO Received uploads request method=POST path=/api/pending_closures15692026/10/06 10:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15702026/10/06 10:52:44 WARN mTLS auth: bound subjects configured but subject DN unavailable15712026/10/06 10:52:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1572--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.39s)1573=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15742026/10/06 10:52:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1575--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.98s)1576=== CONT TestService_Rustfstest15772026/10/06 10:52:45 INFO Received uploads request method=POST path=/api/pending_closures15782026/10/06 10:52:45 INFO lead: released remote=192.0.2.1:123415792026/10/06 10:52:45 INFO lead: acquired remote=192.0.2.1:123415802026/10/06 10:52:45 INFO Aborted multipart uploads count=0 kept=015812026/10/06 10:52:45 WARN Force mode enabled - objects will be deleted immediately without grace period15822026/10/06 10:52: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=015832026/10/06 10:52:45 INFO Vacuumed table table=pending_closures15842026/10/06 10:52:45 INFO Vacuumed table table=pending_objects15852026/10/06 10:52:45 INFO Vacuumed table table=multipart_uploads15862026/10/06 10:52:45 INFO Vacuumed table table=closures15872026/10/06 10:52:45 INFO Vacuumed table table=objects1588--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.76s)1589=== CONT TestPresignedUploadRegisteredBeforeCommit1590=== NAME TestOrphanedObjectsGCStressTest1591 orphaned_objects_gc_test.go:509: Stress test completed successfully:1592 orphaned_objects_gc_test.go:510: - Active objects preserved: 201593 orphaned_objects_gc_test.go:511: - Objects deleted: 2101594 orphaned_objects_gc_test.go:512: - Total GC'd: 2101595--- PASS: TestOrphanedObjectsGCStressTest (8.68s)1596=== CONT TestCompletedNarNotReofferedAcrossClosures1597--- PASS: TestPushWaitsForSweepHoldingRow (2.41s)1598=== CONT TestPush_SignsNarinfosOfItsPendingObjects15992026/10/06 10:52:45 INFO Aborted multipart uploads count=1 kept=016002026/10/06 10:52:45 INFO Received cleanup request method=DELETE path=/api/pending_closures16012026/10/06 10:52:45 INFO Aborted multipart uploads count=1 kept=01602--- PASS: TestPendingCleanupUsesOneCutoff (8.00s)1603=== CONT TestRedundantMultipartUpload16042026/10/06 10:52:45 INFO Aborted multipart uploads count=0 kept=016052026/10/06 10:52:45 WARN Force mode enabled - objects will be deleted immediately without grace period16062026/10/06 10:52: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=016072026/10/06 10:52:45 INFO Vacuumed table table=pending_closures16082026/10/06 10:52:45 INFO Vacuumed table table=pending_objects16092026/10/06 10:52:45 INFO Vacuumed table table=multipart_uploads16102026/10/06 10:52:45 INFO Vacuumed table table=closures16112026/10/06 10:52:45 INFO Vacuumed table table=objects1612--- PASS: TestSweepRechecksPendingAfterLocking (1.50s)1613=== CONT TestPush_RejectsBadRequests16142026/10/06 10:52:45 INFO Received uploads request method=POST path=/api/pending_closures16152026/10/06 10:52:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16162026/10/06 10:52:46 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LmRkNmZmYjEzLWUxODYtNDExMi05ZjM3LThlMTdhODNkNjNjYXgxNzkxMjgzOTY1OTkyNjY0MDAw16172026/10/06 10:52:46 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LmRkNmZmYjEzLWUxODYtNDExMi05ZjM3LThlMTdhODNkNjNjYXgxNzkxMjgzOTY1OTkyNjY0MDAw parts=11618--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.50s)1619=== CONT TestGetExistingObjectsLocksRows16202026/10/06 10:52:46 INFO lead: released remote=192.0.2.1:12341621--- PASS: TestLeadElectsOneAndHandsOver (4.48s)1622=== CONT TestReadProxyContentNegotiation1623--- PASS: TestService_Rustfstest (1.58s)1624=== CONT TestReadProxyNarStreaming16252026/10/06 10:52:47 INFO Received uploads request method=POST path=/api/pending_closures16262026/10/06 10:52:47 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16272026/10/06 10:52:47 INFO Received uploads request method=POST path=/api/pending_closures1628--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.81s)1629=== CONT TestReadProxyNarinfoAlreadyDecompressed16302026/10/06 10:52:47 INFO Received uploads request method=POST path=/api/pending_closures16312026/10/06 10:52:47 INFO Received push request method=POST path=/api/pushes16322026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16332026/10/06 10:52:47 INFO Signed narinfos id=1 count=116342026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16352026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16362026/10/06 10:52:47 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16372026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16382026/10/06 10:52:47 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16392026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16402026/10/06 10:52:47 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116412026/10/06 10:52:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16422026/10/06 10:52:47 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1643--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.30s)1644=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16452026/10/06 10:52:47 WARN Rate limiter enabled after throttle name=s3-test rate=516462026/10/06 10:52:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1647=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1648 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101649 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001650--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.71s)1651=== CONT TestReadProxyNarinfo16522026/10/06 10:52:48 INFO Received uploads request method=POST path=/api/pending_closures16532026/10/06 10:52:48 INFO Received uploads request method=POST path=/api/pending_closures1654=== RUN TestPush_RejectsBadRequests/no_roots1655=== PAUSE TestPush_RejectsBadRequests/no_roots1656=== RUN TestPush_RejectsBadRequests/no_objects1657=== PAUSE TestPush_RejectsBadRequests/no_objects1658=== RUN TestPush_RejectsBadRequests/bad_root1659=== PAUSE TestPush_RejectsBadRequests/bad_root1660=== RUN TestPush_RejectsBadRequests/root_not_in_objects1661=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1662=== CONT TestIsValidCachePath/narinfo1663=== CONT TestIsValidCachePath/index.html1664=== CONT TestIsValidCachePath/short_hash1665=== CONT TestIsValidCachePath/wrong_extension1666=== CONT TestIsValidCachePath/leading_slash1667=== CONT TestIsValidCachePath/empty1668=== CONT TestIsValidCachePath/random_path1669=== CONT TestIsValidCachePath/invalid_char_u1670=== CONT TestIsValidCachePath/invalid_char_e1671=== CONT TestIsValidCachePath/traversal_in_middle1672=== CONT TestIsValidCachePath/traversal_parent1673=== CONT TestIsValidCachePath/nar_uncompressed1674=== CONT TestIsValidCachePath/nix-cache-info1675=== CONT TestIsValidCachePath/realisation1676=== CONT TestIsValidCachePath/log1677=== CONT TestIsValidCachePath/ls1678=== CONT TestIsValidCachePath/nar_xz1679=== CONT TestIsValidCachePath/nar_bz21680=== CONT TestIsValidCachePath/nar_zst1681=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1682--- PASS: TestIsValidCachePath (0.00s)1683 --- PASS: TestIsValidCachePath/narinfo (0.00s)1684 --- PASS: TestIsValidCachePath/index.html (0.00s)1685 --- PASS: TestIsValidCachePath/short_hash (0.00s)1686 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1687 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1688 --- PASS: TestIsValidCachePath/empty (0.00s)1689 --- PASS: TestIsValidCachePath/random_path (0.00s)1690 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1691 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1692 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1693 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1694 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1695 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1696 --- PASS: TestIsValidCachePath/realisation (0.00s)1697 --- PASS: TestIsValidCachePath/log (0.00s)1698 --- PASS: TestIsValidCachePath/ls (0.00s)1699 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1700 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1701 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1702 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1703=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1704--- PASS: TestReadProxyContentNegotiation (2.86s)1705=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17062026/10/06 10:52:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17072026/10/06 10:52:49 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LjBkZjhlMGMxLWI2ZjItNDM0ZC05N2VmLWFkZTkyZGZkODViOHgxNzkxMjgzOTY3NDc5OTg3MDAw parts=1217082026/10/06 10:52:49 INFO Received uploads request method=POST path=/api/pending_closures1709--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.87s)1710=== CONT TestClientErrorHandling/InvalidStorePath1711--- PASS: TestGetExistingObjectsLocksRows (3.21s)1712=== CONT TestClientErrorHandling/ServerNotAvailable1713--- PASS: TestConnectWaitsForAPeerMigration (6.98s)1714=== CONT TestClientErrorHandling/InvalidAuthToken1715--- PASS: TestReadProxyNarStreaming (3.18s)1716=== CONT TestParseSingleRange/none1717=== CONT TestParseSingleRange/open-ended1718=== CONT TestParseSingleRange/start_far_past_EOF1719=== CONT TestParseSingleRange/start_past_EOF1720=== CONT TestParseSingleRange/single_byte1721=== CONT TestParseSingleRange/suffix_exceeds_size1722=== CONT TestParseSingleRange/suffix1723=== CONT TestParseSingleRange/end_clamped_to_size1724=== CONT TestParseSingleRange/malformed_both_empty1725=== CONT TestParseSingleRange/closed1726=== CONT TestParseSingleRange/malformed_end_before_start1727=== CONT TestParseSingleRange/multi-range_ignored1728=== CONT TestParseSingleRange/malformed_no_dash1729=== CONT TestParseSingleRange/unknown_unit1730--- PASS: TestParseSingleRange (0.00s)1731 --- PASS: TestParseSingleRange/none (0.00s)1732 --- PASS: TestParseSingleRange/open-ended (0.00s)1733 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1734 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1735 --- PASS: TestParseSingleRange/single_byte (0.00s)1736 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1737 --- PASS: TestParseSingleRange/suffix (0.00s)1738 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1739 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1740 --- PASS: TestParseSingleRange/closed (0.00s)1741 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1742 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1743 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1744 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1745=== CONT TestServerTLSConfig/no_client_CA1746=== CONT TestServerTLSConfig/not_a_PEM_file1747=== CONT TestServerTLSConfig/missing_CA_file1748--- PASS: TestServerTLSConfig (0.00s)1749 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1750 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1751 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1752=== CONT TestCacheConfigHandler/full_config,_no_issuer1753=== CONT TestCacheConfigHandler/no_signing_keys1754=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1755=== CONT TestCacheConfigHandler/no_cache_url_configured1756--- PASS: TestCacheConfigHandler (0.00s)1757 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1758 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1759 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1760 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1761=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17622026/10/06 10:52:49 INFO Received uploads request method=POST path=/17632026/10/06 10:52:49 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 10:52:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.63161ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17652026/10/06 10:52:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17662026/10/06 10:52:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LjhhNzdkYmY4LTU5YmItNGJkNi05N2U1LWMyOGQ2ZDU2MjBjNHgxNzkxMjgzOTY4MTczNTg5MDAw parts=1217672026/10/06 10:52:49 INFO Received uploads request method=POST path=/api/pending_closures1768=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17692026/10/06 10:52:49 INFO Received uploads request method=POST path=/1770=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17712026/10/06 10:52:49 INFO Received request for more parts method=POST path=/1772=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17732026/10/06 10:52:49 INFO Received complete multipart upload request method=POST path=/17742026/10/06 10:52:49 INFO Received uploads request method=POST path=/api/pending_closures1775--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1776 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1777 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1778 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1779=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17802026/10/06 10:52:49 INFO Received complete multipart upload request method=POST path=/1781=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17822026/10/06 10:52:49 INFO Received request for more parts method=POST path=/1783=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17842026/10/06 10:52:49 INFO Received uploads request method=POST path=/1785--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1786 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1787 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1788 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1789 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1790=== CONT TestIsValidUploadKey/narinfo1791=== CONT TestPendingClosureWriteTimeout/empty1792=== CONT TestIsValidUploadKey/unknown_type1793=== CONT TestIsValidUploadKey/empty_key1794=== CONT TestIsValidUploadKey/absolute1795=== CONT TestIsValidUploadKey/traversal_nar1796=== CONT TestIsValidUploadKey/traversal1797=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1798=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1799=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1800=== CONT TestIsValidUploadKey/index.html1801=== CONT TestIsValidUploadKey/nix-cache-info1802=== CONT TestIsValidUploadKey/realisation_plus_in_output1803=== CONT TestIsValidUploadKey/realisation1804=== CONT TestIsValidUploadKey/build_log_equals1805=== CONT TestIsValidUploadKey/build_log_question_mark1806=== CONT TestIsValidUploadKey/build_log_plus_in_name1807=== CONT TestIsValidUploadKey/build_log_home-manager_file1808=== CONT TestIsValidUploadKey/build_log1809=== CONT TestIsValidUploadKey/listing1810=== CONT TestIsValidUploadKey/nar_plain1811=== CONT TestIsValidUploadKey/nar_xz1812=== CONT TestIsValidUploadKey/nar_zst1813--- PASS: TestIsValidUploadKey (0.00s)1814 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1815 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1816 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1817 --- PASS: TestIsValidUploadKey/absolute (0.00s)1818 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1819 --- PASS: TestIsValidUploadKey/traversal (0.00s)1820 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1821 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1822 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1823 --- PASS: TestIsValidUploadKey/index.html (0.00s)1824 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1825 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1826 --- PASS: TestIsValidUploadKey/realisation (0.00s)1827 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1828 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1829 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1830 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1831 --- PASS: TestIsValidUploadKey/build_log (0.00s)1832 --- PASS: TestIsValidUploadKey/listing (0.00s)1833 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1834 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1835 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1836=== CONT TestPendingClosureWriteTimeout/670k_objects1837=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18382026/10/06 10:52:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=400.396574ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1839--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.94s)1840=== CONT TestPendingClosureWriteTimeout/400_objects1841=== CONT TestProxyWriteTimeout/narinfo1842=== CONT TestProxyWriteTimeout/10_GiB_nar1843=== CONT TestProxyWriteTimeout/unknown_size1844=== CONT TestProxyWriteTimeout/1_GiB_nar1845--- PASS: TestProxyWriteTimeout (0.00s)1846 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1847 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1848 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1849 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1850=== CONT TestService_RequireScope_OIDC/builder_may_write1851=== CONT TestService_RequireScope_OIDC/reader_may_read1852=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1853=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18542026/10/06 10:52:50 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]1855=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1856=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1857=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1858=== CONT TestService_RequireScope_OIDC/writer_implies_read1859=== CONT TestService_RequireScope_OIDC/reader_may_not_write1860=== CONT TestService_RequireScope_OIDC/static_token_may_write1861=== CONT TestService_RequireScope_OIDC/ops_may_admin1862=== CONT TestService_RequireScope_OIDC/ops_may_not_write1863=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1864=== CONT TestService_RequireScope_OIDC/static_token_may_admin1865=== CONT TestResolveDBConnectionString/flag_wins1866=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1867=== CONT TestResolveDBConnectionString/nothing_configured1868=== CONT TestResolveDBConnectionString/missing_file_is_an_error1869=== CONT TestResolveDBConnectionString/file_when_flag_empty1870=== CONT TestGCEndsOnShutdown/before_the_run1871--- PASS: TestResolveDBConnectionString (0.03s)1872 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1873 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1874 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1875 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1876 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1877--- PASS: TestService_RequireScope_OIDC (2.28s)1878 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1879 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1880 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1881 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1884 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1885 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1886 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1887 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)18922026/10/06 10:52:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=829.135771ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18932026/10/06 10:52:50 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1894--- PASS: TestReadProxyNarinfo (2.56s)1895=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18962026/10/06 10:52:50 INFO Received push request method=POST path=/api/pushes18972026/10/06 10:52:50 INFO Received complete push request method=POST path=/api/pushes/1/complete18982026/10/06 10:52:50 INFO Received push request method=POST path=/api/pushes18992026/10/06 10:52:50 INFO Aborted multipart uploads count=0 kept=019002026/10/06 10:52:50 WARN Force mode enabled - objects will be deleted immediately without grace period19012026/10/06 10:52:50 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=019022026/10/06 10:52:50 INFO Vacuumed table table=pending_closures19032026/10/06 10:52:51 INFO Vacuumed table table=pending_objects19042026/10/06 10:52:51 INFO Vacuumed table table=multipart_uploads19052026/10/06 10:52:51 INFO Vacuumed table table=closures19062026/10/06 10:52:51 INFO Vacuumed table table=objects19072026/10/06 10:52:51 INFO Received complete push request method=POST path=/api/pushes/2/complete1908--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.19s)1909=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19102026/10/06 10:52:51 INFO Received uploads request method=POST path=/api/pending_closures19112026/10/06 10:52:51 INFO Aborted multipart uploads count=0 kept=019122026/10/06 10:52:51 WARN Force mode enabled - objects will be deleted immediately without grace period19132026/10/06 10:52:51 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=019142026/10/06 10:52:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.705717322s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19152026/10/06 10:52:51 INFO Vacuumed table table=pending_closures19162026/10/06 10:52:51 INFO Vacuumed table table=pending_objects19172026/10/06 10:52:51 INFO Vacuumed table table=multipart_uploads19182026/10/06 10:52:51 INFO Vacuumed table table=closures19192026/10/06 10:52:51 INFO Vacuumed table table=objects1920=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1921=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1922=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19232026/10/06 10:52:51 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]1924=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19252026/10/06 10:52:51 WARN Authentication failed token_preview=eyJhbGciOi...v47YFYLedQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1926=== CONT TestPush_RejectsBadRequests/no_roots19272026/10/06 10:52:51 INFO Received push request method=POST path=/api/pushes1928=== CONT TestPush_RejectsBadRequests/bad_root19292026/10/06 10:52:51 INFO Received push request method=POST path=/api/pushes1930=== CONT TestPush_RejectsBadRequests/root_not_in_objects19312026/10/06 10:52:51 INFO Received push request method=POST path=/api/pushes1932=== CONT TestPush_RejectsBadRequests/no_objects19332026/10/06 10:52:51 INFO Received push request method=POST path=/api/pushes1934--- PASS: TestPush_RejectsBadRequests (2.70s)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)1939--- PASS: TestService_AuthMiddleware_OIDC (2.29s)1940 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1942 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1943 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19442026/10/06 10:52:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19452026/10/06 10:52:51 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LmFhNmMyZmNjLTUxMWEtNDAwMi04OGUyLWVjMTM2ZWQwMzIwZngxNzkxMjgzOTY5OTUwNjY5MDAw error="Get \"http://127.0.0.1:1/bucket77/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19462026/10/06 10:52:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjAyOWFhMDctZWE1YS00YmZlLTlhNTktZTEwYmU0ZjdiNDA2LjIxNjcwYzg5LWMxNGItNDhmOS04ZTc3LTJkZjk2OGVhYWFmN3gxNzkxMjgzOTY5OTA3MjU0MDAw parts=1219472026/10/06 10:52:51 INFO Received cleanup request method=DELETE path=/api/pending_closures19482026/10/06 10:52:51 INFO Aborted multipart uploads count=1 kept=01949--- PASS: TestRedundantMultipartUpload (6.11s)19502026/10/06 10:52:52 INFO Received uploads request method=POST path=/api/pending_closures19512026/10/06 10:52:52 INFO Aborted multipart uploads count=0 kept=019522026/10/06 10:52:52 WARN Force mode enabled - objects will be deleted immediately without grace period19532026/10/06 10:52:52 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=019542026/10/06 10:52:52 INFO Vacuumed table table=pending_closures19552026/10/06 10:52:52 INFO Vacuumed table table=pending_objects19562026/10/06 10:52:52 INFO Vacuumed table table=multipart_uploads19572026/10/06 10:52:52 INFO Vacuumed table table=closures19582026/10/06 10:52:52 INFO Vacuumed table table=objects1959--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1960 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.94s)1961 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.15s)19622026/10/06 10:52:52 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19632026/10/06 10:52:52 INFO Received uploads request method=POST path=/api/pending_closures19642026/10/06 10:52:52 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19652026/10/06 10:52:52 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-config19662026/10/06 10:52:53 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.832254ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19672026/10/06 10:52:53 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.623063ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19682026/10/06 10:52:53 INFO Aborted multipart uploads count=0 kept=019692026/10/06 10:52:53 WARN Force mode enabled - objects will be deleted immediately without grace period19702026-10-06 10:52:53.358 UTC [30995] ERROR: canceling statement due to user request19712026-10-06 10:52:53.358 UTC [30995] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block19722026-10-06 10:52:53.358 UTC [30995] STATEMENT: -- name: MarkStaleObjects :execrows1973 WITH RECURSIVE ct AS (1974 SELECT timezone('UTC', now()) AS now1975 ),1976 closure_reach AS (1977 -- Start with all closure keys1978 SELECT o.key, o.refs1979 FROM objects o1980 INNER JOIN closures c ON o.key = c.key1981 UNION1982 -- Recursively add all referenced objects1983 SELECT o.key, o.refs1984 FROM objects o1985 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1986 ),1987 reachable_objects AS (1988 SELECT DISTINCT key FROM closure_reach1989 ),1990 stale_objects AS (1991 SELECT o.key1992 FROM objects AS o, ct1993 WHERE1994 NOT EXISTS (1995 SELECT 11996 FROM reachable_objects ro1997 WHERE ro.key = o.key1998 )1999 AND NOT EXISTS (2000 SELECT 12001 FROM pending_objects AS po2002 WHERE po.key = o.key2003 )2004 AND o.deleted_at IS NULL -- Only mark fresh objects2005 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2006 FOR UPDATE2007 )2008 UPDATE objects2009 SET2010 deleted_at = ct.now,2011 first_deleted_at = COALESCE(first_deleted_at, ct.now)2012 FROM stale_objects, ct2013 WHERE objects.key = stale_objects.key2014 20152026/10/06 10:52:53 INFO Aborted multipart uploads count=0 kept=020162026/10/06 10:52:53 WARN Force mode enabled - objects will be deleted immediately without grace period20172026/10/06 10:52:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53997/bucket92/?delete=\": context canceled"2018--- PASS: TestGCEndsOnShutdown (0.00s)2019 --- PASS: TestGCEndsOnShutdown/before_the_run (2.96s)2020 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.88s)2021 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.50s)2022--- PASS: TestPendingClosureWriteTimeout (0.00s)2023 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2024 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2025 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2026 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.74s)20272026/10/06 10:52:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.671401ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 10:52:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.470951439s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/06 10:52:55 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"20302026/10/06 10:52:55 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-config20312026/10/06 10:52:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.251996ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/06 10:52:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=422.374538ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 10:52:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.079955ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 10:52:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.551189899s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 10:52:59 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_closures20362026/10/06 10:52:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.05757ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20372026/10/06 10:52:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.923245ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20382026/10/06 10:52:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=761.451633ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 10:53:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.456265625s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2040--- PASS: TestClientErrorHandling (0.00s)2041 --- PASS: TestClientErrorHandling/InvalidStorePath (3.01s)2042 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.34s)2043 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)2044PASS20452026-10-06 10:53:02.155 UTC [30524] LOG: received smart shutdown request20462026-10-06 10:53:02.156 UTC [30524] LOG: background worker "logical replication launcher" (PID 30534) exited with exit code 120472026-10-06 10:53:02.163 UTC [30529] LOG: shutting down20482026-10-06 10:53:02.163 UTC [30529] LOG: checkpoint starting: shutdown immediate20492026-10-06 10:53:03.520 UTC [30529] LOG: checkpoint complete: wrote 13081 buffers (79.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.781 s, sync=0.533 s, total=1.358 s; sync files=31336, longest=0.001 s, average=0.001 s; distance=440381 kB, estimate=440381 kB; lsn=0/1C59C560, redo lsn=0/1C59C56020502026-10-06 10:53:03.526 UTC [30524] LOG: database system is shut down2051Running OIDC tests...2052=== RUN TestAudienceForIssuer2053=== PAUSE TestAudienceForIssuer2054=== RUN TestGlobMatch2055=== PAUSE TestGlobMatch2056=== RUN TestValidateToken_ValidToken2057=== PAUSE TestValidateToken_ValidToken2058=== RUN TestValidateToken_WrongAudience2059=== PAUSE TestValidateToken_WrongAudience2060=== RUN TestValidateToken_Expired2061=== PAUSE TestValidateToken_Expired2062=== RUN TestValidateToken_BoundClaimsMismatch2063=== PAUSE TestValidateToken_BoundClaimsMismatch2064=== RUN TestValidateToken_BoundSubjectMismatch2065=== PAUSE TestValidateToken_BoundSubjectMismatch2066=== RUN TestValidateToken_MultipleProviders2067=== PAUSE TestValidateToken_MultipleProviders2068=== RUN TestValidateToken_NoMatchingProvider2069=== PAUSE TestValidateToken_NoMatchingProvider2070=== RUN TestValidateToken_KubernetesServiceAccount2071=== PAUSE TestValidateToken_KubernetesServiceAccount2072=== RUN TestNewValidator_KubernetesRequiresCA2073=== PAUSE TestNewValidator_KubernetesRequiresCA2074=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2075=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2076=== RUN TestPins_ReservedForMatchingRule2077=== PAUSE TestPins_ReservedForMatchingRule2078=== RUN TestPins_TopLevelShorthand2079=== PAUSE TestPins_TopLevelShorthand2080=== RUN TestPins_ConfigValidation2081=== PAUSE TestPins_ConfigValidation2082=== RUN TestScopes_LegacyProviderDefaultsToWrite2083=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2084=== RUN TestScopes_Rules2085=== PAUSE TestScopes_Rules2086=== RUN TestScopes_ConfigValidation2087=== PAUSE TestScopes_ConfigValidation2088=== CONT TestAudienceForIssuer2089--- PASS: TestAudienceForIssuer (0.00s)2090=== CONT TestValidateToken_NoMatchingProvider2091=== CONT TestPins_ConfigValidation2092=== CONT TestValidateToken_KubernetesServiceAccount2093=== CONT TestValidateToken_Expired2094=== CONT TestValidateToken_BoundSubjectMismatch2095=== CONT TestValidateToken_MultipleProviders2096=== CONT TestScopes_Rules2097=== CONT TestValidateToken_ValidToken2098=== CONT TestScopes_LegacyProviderDefaultsToWrite2099--- PASS: TestPins_ConfigValidation (0.01s)2100=== CONT TestPins_ReservedForMatchingRule2101=== CONT TestValidateToken_BoundClaimsMismatch21022026/10/06 10:53:04 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:544672103--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2104=== CONT TestScopes_ConfigValidation21052026/10/06 10:53:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54469/oidc2106--- PASS: TestScopes_ConfigValidation (0.00s)2107=== CONT TestGlobMatch2108=== RUN TestGlobMatch/foo_foo2109=== PAUSE TestGlobMatch/foo_foo2110=== RUN TestGlobMatch/foo_bar2111=== PAUSE TestGlobMatch/foo_bar2112=== RUN TestGlobMatch/*_2113=== PAUSE TestGlobMatch/*_2114=== RUN TestGlobMatch/*_anything2115=== PAUSE TestGlobMatch/*_anything2116=== RUN TestGlobMatch/foo*_foo2117=== PAUSE TestGlobMatch/foo*_foo2118=== RUN TestGlobMatch/foo*_foobar2119=== PAUSE TestGlobMatch/foo*_foobar2120=== RUN TestGlobMatch/foo*_bar2121=== PAUSE TestGlobMatch/foo*_bar2122=== RUN TestGlobMatch/*bar_bar2123=== PAUSE TestGlobMatch/*bar_bar2124=== RUN TestGlobMatch/*bar_foobar2125=== PAUSE TestGlobMatch/*bar_foobar2126=== RUN TestGlobMatch/*bar_foo2127=== PAUSE TestGlobMatch/*bar_foo2128=== RUN TestGlobMatch/foo*bar_foobar2129=== PAUSE TestGlobMatch/foo*bar_foobar2130=== RUN TestGlobMatch/foo*bar_foo123bar2131=== PAUSE TestGlobMatch/foo*bar_foo123bar2132=== RUN TestGlobMatch/foo*bar_foobarbaz2133=== PAUSE TestGlobMatch/foo*bar_foobarbaz2134=== RUN TestGlobMatch/*/*_foo/bar2135=== PAUSE TestGlobMatch/*/*_foo/bar2136=== RUN TestGlobMatch/*/*_foo2137=== PAUSE TestGlobMatch/*/*_foo2138=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2139=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2140=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02141=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02142=== RUN TestGlobMatch/refs/*/main_refs/heads/main2143=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2144=== RUN TestGlobMatch/fo?_foo2145=== PAUSE TestGlobMatch/fo?_foo2146=== RUN TestGlobMatch/fo?_fo2147=== PAUSE TestGlobMatch/fo?_fo2148=== RUN TestGlobMatch/fo?_fooo2149=== PAUSE TestGlobMatch/fo?_fooo2150=== RUN TestGlobMatch/?oo_foo2151=== PAUSE TestGlobMatch/?oo_foo2152=== RUN TestGlobMatch/?oo_boo2153=== PAUSE TestGlobMatch/?oo_boo2154=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2155=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2156=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2157=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2158=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2159--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2160=== CONT TestNewValidator_KubernetesRequiresCA21612026/10/06 10:53:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54471/oidc2162--- PASS: TestScopes_Rules (0.09s)2163=== CONT TestValidateToken_WrongAudience21642026/10/06 10:53:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54473/oidc2165--- PASS: TestValidateToken_ValidToken (0.09s)2166=== CONT TestPins_TopLevelShorthand21672026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54475/oidc2168--- PASS: TestValidateToken_Expired (0.10s)2169=== CONT TestGlobMatch/foo_foo2170=== CONT TestGlobMatch/*/*_foo/bar2171=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/?oo_boo2174=== CONT TestGlobMatch/?oo_foo2175=== CONT TestGlobMatch/fo?_fooo2176=== CONT TestGlobMatch/fo?_fo2177=== CONT TestGlobMatch/fo?_foo2178=== CONT TestGlobMatch/refs/*/main_refs/heads/main2179=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02180=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2181=== CONT TestGlobMatch/*/*_foo2182=== CONT TestGlobMatch/foo*_foo2183=== CONT TestGlobMatch/foo*_bar2184=== CONT TestGlobMatch/foo*_foobar2185=== CONT TestGlobMatch/*bar_bar2186=== CONT TestGlobMatch/foo*bar_foobarbaz2187=== CONT TestGlobMatch/*bar_foo2188=== CONT TestGlobMatch/*bar_foobar2189=== CONT TestGlobMatch/foo*bar_foo123bar2190=== CONT TestGlobMatch/*_2191=== CONT TestGlobMatch/foo_bar2192=== CONT TestGlobMatch/foo*bar_foobar2193=== CONT TestGlobMatch/*_anything2194--- PASS: TestGlobMatch (0.00s)2195 --- PASS: TestGlobMatch/foo_foo (0.00s)2196 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2197 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/?oo_boo (0.00s)2200 --- PASS: TestGlobMatch/?oo_foo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2202 --- PASS: TestGlobMatch/fo?_fo (0.00s)2203 --- PASS: TestGlobMatch/fo?_foo (0.00s)2204 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2206 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2207 --- PASS: TestGlobMatch/*/*_foo (0.00s)2208 --- PASS: TestGlobMatch/foo*_foo (0.00s)2209 --- PASS: TestGlobMatch/foo*_bar (0.00s)2210 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2211 --- PASS: TestGlobMatch/*bar_bar (0.00s)2212 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2213 --- PASS: TestGlobMatch/*bar_foo (0.00s)2214 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2215 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2216 --- PASS: TestGlobMatch/*_ (0.00s)2217 --- PASS: TestGlobMatch/foo_bar (0.00s)2218 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2219 --- PASS: TestGlobMatch/*_anything (0.00s)22202026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54477/oidc2221--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)22222026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54479/oidc2223--- PASS: TestPins_TopLevelShorthand (0.02s)22242026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54482/oidc2225--- PASS: TestPins_ReservedForMatchingRule (0.11s)22262026/10/06 10:53:05 http: TLS handshake error from 127.0.0.1:54485: remote error: tls: bad certificate2227--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)22282026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54486/oidc2229--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)22302026/10/06 10:53:05 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322312026/10/06 10:53:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54488/oidc2232--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)22332026/10/06 10:53:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54491/oidc2234--- PASS: TestValidateToken_MultipleProviders (0.17s)22352026/10/06 10:53:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54481/oidc2236--- PASS: TestValidateToken_NoMatchingProvider (0.18s)22372026/10/06 10:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54496/oidc2238--- PASS: TestValidateToken_WrongAudience (0.10s)2239PASS2240Running hook tests...2241=== RUN TestSendPathsEmpty2242=== PAUSE TestSendPathsEmpty2243=== RUN TestQueueEnqueueAndFetch2244=== PAUSE TestQueueEnqueueAndFetch2245=== RUN TestQueueDeduplication2246=== PAUSE TestQueueDeduplication2247=== RUN TestQueueRemove2248=== PAUSE TestQueueRemove2249=== RUN TestQueueFetchBatchLimit2250=== PAUSE TestQueueFetchBatchLimit2251=== RUN TestQueueRetryMovesToBack2252=== PAUSE TestQueueRetryMovesToBack2253=== RUN TestQueueFetchRemoveLifecycle2254=== PAUSE TestQueueFetchRemoveLifecycle2255=== RUN TestQueueConcurrentWriters2256=== PAUSE TestQueueConcurrentWriters2257=== RUN TestQueueRemoveLargeClosure2258=== PAUSE TestQueueRemoveLargeClosure2259=== RUN TestServerClientIntegration2260=== PAUSE TestServerClientIntegration2261=== RUN TestServerQueueError2262=== PAUSE TestServerQueueError2263=== RUN TestGetListenerSocketActivation2264 server_test.go:210: === RUN TestGetListenerSocketActivation2265 --- PASS: TestGetListenerSocketActivation (0.00s)2266 PASS2267 2268--- PASS: TestGetListenerSocketActivation (0.01s)2269=== RUN TestDrainIsolatesPoisonPath2270=== PAUSE TestDrainIsolatesPoisonPath2271=== RUN TestRunNotBlockedByPoisonHead2272=== PAUSE TestRunNotBlockedByPoisonHead2273=== RUN TestDrainGivesUpWhenServerDown2274=== PAUSE TestDrainGivesUpWhenServerDown2275=== RUN TestFailedPathPrunedByLaterClosure2276=== PAUSE TestFailedPathPrunedByLaterClosure2277=== RUN TestWorkerUploadsAndRemoves2278=== PAUSE TestWorkerUploadsAndRemoves2279=== RUN TestWorkerSkipsGCdPaths2280=== PAUSE TestWorkerSkipsGCdPaths2281=== RUN TestWorkerPrunesClosureDeps2282=== PAUSE TestWorkerPrunesClosureDeps2283=== RUN TestDrainTimeout2284=== PAUSE TestDrainTimeout2285=== CONT TestSendPathsEmpty2286=== CONT TestServerQueueError2287--- PASS: TestSendPathsEmpty (0.00s)2288=== CONT TestServerClientIntegration2289=== CONT TestQueueRemoveLargeClosure2290=== CONT TestQueueConcurrentWriters2291=== CONT TestQueueFetchRemoveLifecycle2292=== CONT TestQueueRetryMovesToBack2293=== CONT TestQueueFetchBatchLimit2294=== CONT TestQueueRemove2295=== CONT TestQueueDeduplication2296=== CONT TestQueueEnqueueAndFetch22972026/10/06 10:53:05 ERROR Failed to queue paths error="permission denied" count=12298--- PASS: TestServerQueueError (0.00s)2299=== CONT TestWorkerPrunesClosureDeps2300--- PASS: TestServerClientIntegration (0.00s)2301=== CONT TestDrainTimeout2302--- PASS: TestQueueFetchBatchLimit (0.01s)2303=== CONT TestDrainGivesUpWhenServerDown23042026/10/06 10:53:05 INFO Uploading batch count=223052026/10/06 10:53:05 INFO Upload queue status pending=22306--- PASS: TestQueueEnqueueAndFetch (0.01s)2307=== CONT TestFailedPathPrunedByLaterClosure23082026/10/06 10:53:05 INFO Uploading batch count=12309--- PASS: TestQueueRetryMovesToBack (0.01s)2310=== CONT TestRunNotBlockedByPoisonHead2311--- PASS: TestQueueDeduplication (0.01s)2312=== CONT TestDrainIsolatesPoisonPath2313--- PASS: TestQueueRemove (0.01s)2314=== CONT TestWorkerUploadsAndRemoves2315--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2316=== CONT TestWorkerSkipsGCdPaths23172026/10/06 10:53:05 INFO Uploading batch count=123182026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=123192026/10/06 10:53:05 INFO Upload queue status pending=323202026/10/06 10:53:05 INFO Uploading batch count=123212026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=123222026/10/06 10:53:05 INFO Uploading batch count=123232026/10/06 10:53:05 INFO Uploading batch count=123242026/10/06 10:53:05 INFO Uploading batch count=223252026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=223262026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/a23272026/10/06 10:53:05 INFO Upload queue status pending=223282026/10/06 10:53:05 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-30484-2750109167/TestWorkerSkipsGCdPaths2095798897/002/nonexistent23292026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/b23302026/10/06 10:53:05 INFO Uploading batch count=123312026/10/06 10:53:05 INFO Uploading batch count=223322026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=223332026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/c23342026/10/06 10:53:05 INFO Uploading batch count=423352026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=423362026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/d23372026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainIsolatesPoisonPath1950513826/002/bbb23382026/10/06 10:53:05 INFO Upload queue status pending=223392026/10/06 10:53:05 INFO Uploading batch count=223402026/10/06 10:53:05 INFO Uploading batch count=223412026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=223422026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/e2343--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23442026/10/06 10:53:05 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-30484-2750109167/TestDrainGivesUpWhenServerDown1989610155/002/f23452026/10/06 10:53:05 INFO Uploading batch count=123462026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=123472026/10/06 10:53:05 ERROR Drain finished with paths left in queue remaining=1023482026/10/06 10:53:05 INFO Uploading batch count=123492026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=123502026/10/06 10:53:05 INFO Uploading batch count=123512026/10/06 10:53:05 ERROR Upload failed error="upload failed" count=123522026/10/06 10:53:05 ERROR Drain finished with paths left in queue remaining=12353--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2354--- PASS: TestDrainIsolatesPoisonPath (0.01s)2355--- PASS: TestWorkerPrunesClosureDeps (0.03s)2356--- PASS: TestWorkerSkipsGCdPaths (0.02s)2357--- PASS: TestWorkerUploadsAndRemoves (0.02s)2358--- PASS: TestQueueRemoveLargeClosure (0.04s)2359--- PASS: TestQueueConcurrentWriters (0.16s)23602026/10/06 10:53:05 ERROR Upload failed error="context deadline exceeded" count=223612026/10/06 10:53:05 ERROR Drain finished with paths left in queue remaining=42362--- PASS: TestDrainTimeout (0.21s)23632026/10/06 10:53:06 INFO Uploading batch count=123642026/10/06 10:53:06 INFO Uploading batch count=123652026/10/06 10:53:06 INFO Uploading batch count=123662026/10/06 10:53:06 ERROR Upload failed error="upload failed" count=123672026/10/06 10:53:06 INFO Uploading batch count=123682026/10/06 10:53:06 ERROR Upload failed error="upload failed" count=123692026/10/06 10:53:06 INFO Uploading batch count=123702026/10/06 10:53:06 ERROR Upload failed error="upload failed" count=123712026/10/06 10:53:06 INFO Uploading batch count=123722026/10/06 10:53:06 ERROR Upload failed error="upload failed" count=123732026/10/06 10:53:06 ERROR Drain finished with paths left in queue remaining=12374--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2375PASS2376Running signing tests...2377=== RUN TestExternalSigner2378=== PAUSE TestExternalSigner2379=== RUN TestExternalSignerWrongPublicKey2380=== PAUSE TestExternalSignerWrongPublicKey2381=== RUN TestExternalSignerErrors2382=== PAUSE TestExternalSignerErrors2383=== RUN TestExternalSignerRestartsAfterCrash2384=== PAUSE TestExternalSignerRestartsAfterCrash2385=== RUN TestExternalSignerProgramErrorKeepsProcess2386=== PAUSE TestExternalSignerProgramErrorKeepsProcess2387=== RUN TestExternalSignerClose2388=== PAUSE TestExternalSignerClose2389=== RUN TestExternalSignerRejectsInvalidPublicKey2390=== PAUSE TestExternalSignerRejectsInvalidPublicKey2391=== RUN TestExternalSignerCancellation2392=== PAUSE TestExternalSignerCancellation2393=== RUN TestGenerateFingerprint2394=== PAUSE TestGenerateFingerprint2395=== RUN TestParseSigningKey2396=== PAUSE TestParseSigningKey2397=== RUN TestSign2398=== PAUSE TestSign2399=== RUN TestSignBatch2400=== PAUSE TestSignBatch2401=== RUN TestNilKeyPublicKey2402=== PAUSE TestNilKeyPublicKey2403=== RUN TestSignErrors2404=== PAUSE TestSignErrors2405=== CONT TestExternalSigner2406=== CONT TestExternalSignerProgramErrorKeepsProcess2407=== CONT TestSignErrors2408=== CONT TestSign2409=== CONT TestNilKeyPublicKey2410--- PASS: TestNilKeyPublicKey (0.00s)2411=== CONT TestSignBatch2412=== CONT TestParseSigningKey2413=== CONT TestExternalSignerRejectsInvalidPublicKey2414=== RUN TestParseSigningKey/valid_32-byte_key2415=== PAUSE TestParseSigningKey/valid_32-byte_key2416=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2417=== RUN TestExternalSignerRejectsInvalidPublicKey/#002418=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2419=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002420=== CONT TestExternalSignerErrors2421=== CONT TestGenerateFingerprint2422=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2423=== RUN TestExternalSignerErrors/exit_at_startup2424=== PAUSE TestExternalSignerErrors/exit_at_startup2425=== RUN TestParseSigningKey/no_colon2426=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2427=== PAUSE TestParseSigningKey/no_colon2428=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2429=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2430=== RUN TestGenerateFingerprint/basic_with_references2431=== RUN TestExternalSignerErrors/wrong_shape2432=== PAUSE TestExternalSignerErrors/wrong_shape2433=== RUN TestExternalSignerErrors/missing_signatures2434=== RUN TestParseSigningKey/empty_name2435=== PAUSE TestParseSigningKey/empty_name2436=== RUN TestParseSigningKey/invalid_base642437=== CONT TestExternalSignerCancellation2438=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2439=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2440=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2441=== PAUSE TestGenerateFingerprint/basic_with_references2442=== RUN TestGenerateFingerprint/no_references2443=== PAUSE TestExternalSignerErrors/missing_signatures2444=== PAUSE TestParseSigningKey/invalid_base642445=== RUN TestExternalSignerErrors/wrong_signatures_shape2446=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2447=== RUN TestParseSigningKey/wrong_length2448=== PAUSE TestGenerateFingerprint/no_references2449=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2450=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2451=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2452--- PASS: TestSign (0.00s)2453=== PAUSE TestParseSigningKey/wrong_length2454=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2455=== CONT TestExternalSignerRestartsAfterCrash2456=== CONT TestExternalSignerClose2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2458=== RUN TestGenerateFingerprint/invalid_nar_hash_length2459=== RUN TestSignErrors/nil_key2460=== CONT TestExternalSignerWrongPublicKey2461=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2462=== RUN TestGenerateFingerprint/invalid_store_path_prefix2463=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2464=== RUN TestGenerateFingerprint/invalid_reference_prefix2465=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2466=== PAUSE TestSignErrors/nil_key2467=== RUN TestExternalSignerErrors/too_few_signatures2468=== PAUSE TestExternalSignerErrors/too_few_signatures2469=== RUN TestExternalSignerErrors/wrong_signature_name2470=== PAUSE TestExternalSignerErrors/wrong_signature_name2471=== RUN TestExternalSignerErrors/invalid_signature_base642472=== PAUSE TestExternalSignerErrors/invalid_signature_base642473=== RUN TestExternalSignerErrors/invalid_JSON2474=== PAUSE TestExternalSignerErrors/invalid_JSON2475=== CONT TestParseSigningKey/valid_32-byte_key2476--- PASS: TestSignBatch (0.00s)2477=== CONT TestExternalSignerRejectsInvalidPublicKey/#002478=== RUN TestExternalSignerErrors/null2479=== CONT TestParseSigningKey/empty_name2480=== PAUSE TestExternalSignerErrors/null2481=== RUN TestExternalSignerErrors/wrong_id2482=== CONT TestParseSigningKey/wrong_length2483=== PAUSE TestExternalSignerErrors/wrong_id2484=== CONT TestParseSigningKey/invalid_base642485=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2486=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2487=== CONT TestParseSigningKey/no_colon2488=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2489=== RUN TestExternalSignerErrors/unrequested_key2490--- PASS: TestParseSigningKey (0.00s)2491 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2492 --- PASS: TestParseSigningKey/empty_name (0.00s)2493 --- PASS: TestParseSigningKey/wrong_length (0.00s)2494 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2495 --- PASS: TestParseSigningKey/no_colon (0.00s)2496 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2497=== CONT TestGenerateFingerprint/invalid_nar_hash_length2498=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2499=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2500=== CONT TestGenerateFingerprint/no_references2501=== PAUSE TestExternalSignerErrors/unrequested_key2502=== RUN TestSignErrors/nil_narinfo2503=== PAUSE TestSignErrors/nil_narinfo2504=== CONT TestGenerateFingerprint/invalid_reference_prefix2505=== CONT TestGenerateFingerprint/basic_with_references2506=== RUN TestSignErrors/invalid_narinfo2507=== CONT TestGenerateFingerprint/invalid_store_path_prefix2508--- PASS: TestGenerateFingerprint (0.00s)2509 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2510 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2511 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2512 --- PASS: TestGenerateFingerprint/no_references (0.00s)2513 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2514 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2515 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2516=== RUN TestExternalSignerErrors/missing_signature_name2517=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2518=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2519=== PAUSE TestExternalSignerErrors/missing_signature_name2520--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2523 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2524 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2525 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2526=== PAUSE TestSignErrors/invalid_narinfo2527=== RUN TestExternalSignerErrors/exit_on_request2528=== RUN TestSignErrors/canceled2529=== PAUSE TestExternalSignerErrors/exit_on_request2530=== PAUSE TestSignErrors/canceled2531=== RUN TestExternalSignerErrors/null_signatures2532=== PAUSE TestExternalSignerErrors/null_signatures2533=== RUN TestExternalSignerErrors/wrong_signature_length2534=== PAUSE TestExternalSignerErrors/wrong_signature_length2535=== RUN TestExternalSignerErrors/program_error2536=== PAUSE TestExternalSignerErrors/program_error2537=== CONT TestSignErrors/nil_narinfo2538=== CONT TestExternalSignerErrors/exit_at_startup2539=== CONT TestSignErrors/nil_key2540=== CONT TestSignErrors/canceled2541=== CONT TestExternalSignerErrors/wrong_signature_name2542=== CONT TestSignErrors/invalid_narinfo2543=== CONT TestExternalSignerErrors/wrong_id2544=== CONT TestExternalSignerErrors/null2545--- PASS: TestSignErrors (0.00s)2546 --- PASS: TestSignErrors/nil_key (0.00s)2547 --- PASS: TestSignErrors/nil_narinfo (0.00s)2548 --- PASS: TestSignErrors/canceled (0.00s)2549 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2550--- PASS: TestExternalSigner (0.19s)2551=== CONT TestExternalSignerErrors/invalid_JSON2552--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.37s)2553=== CONT TestExternalSignerErrors/invalid_signature_base642554--- PASS: TestExternalSignerCancellation (0.56s)2555=== CONT TestExternalSignerErrors/null_signatures2556--- PASS: TestExternalSignerWrongPublicKey (0.73s)2557=== CONT TestExternalSignerErrors/exit_on_request2558--- PASS: TestExternalSignerClose (0.93s)2559=== CONT TestExternalSignerErrors/missing_signature_name2560--- PASS: TestExternalSignerRestartsAfterCrash (1.15s)2561=== CONT TestExternalSignerErrors/unrequested_key2562/nix/var/nix/builds/nix-30484-2750109167/TestExternalSignerRestartsAfterCrash543073199/001/sign program: line 7: /nix/var/nix/builds/nix-30484-2750109167/TestExternalSignerRestartsAfterCrash543073199/001/sign program.starts: No such file or directory2563=== CONT TestExternalSignerErrors/wrong_signatures_shape2564=== CONT TestExternalSignerErrors/too_few_signatures2565=== CONT TestExternalSignerErrors/missing_signatures2566=== CONT TestExternalSignerErrors/program_error2567=== CONT TestExternalSignerErrors/wrong_signature_length2568=== CONT TestExternalSignerErrors/wrong_shape2569--- PASS: TestExternalSignerErrors (0.00s)2570 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.32s)2571 --- PASS: TestExternalSignerErrors/null (1.51s)2572 --- PASS: TestExternalSignerErrors/exit_at_startup (1.69s)2573 --- PASS: TestExternalSignerErrors/wrong_id (1.88s)2574 --- PASS: TestExternalSignerErrors/invalid_JSON (1.88s)2575 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.89s)2576 --- PASS: TestExternalSignerErrors/null_signatures (1.89s)2577 --- PASS: TestExternalSignerErrors/exit_on_request (1.91s)2578 --- PASS: TestExternalSignerErrors/missing_signature_name (1.89s)2579 --- PASS: TestExternalSignerErrors/unrequested_key (1.86s)2580 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.88s)2581 --- PASS: TestExternalSignerErrors/too_few_signatures (1.88s)2582 --- PASS: TestExternalSignerErrors/missing_signatures (1.89s)2583 --- PASS: TestExternalSignerErrors/program_error (1.89s)2584 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.89s)2585 --- PASS: TestExternalSignerErrors/wrong_shape (1.89s)2586PASS2587Running OpenBao signer tests...2588=== RUN TestSign2589=== PAUSE TestSign2590=== RUN TestSignErrors2591=== PAUSE TestSignErrors2592=== RUN TestServe2593=== PAUSE TestServe2594=== RUN TestServeRejectsGarbage2595=== PAUSE TestServeRejectsGarbage2596=== CONT TestSign2597=== CONT TestServe2598=== CONT TestSignErrors2599=== RUN TestSignErrors/invalid_json2600=== CONT TestServeRejectsGarbage2601=== PAUSE TestSignErrors/invalid_json2602--- PASS: TestServeRejectsGarbage (0.00s)2603=== RUN TestSignErrors/no_prefix2604=== PAUSE TestSignErrors/no_prefix2605=== RUN TestSignErrors/invalid_base642606=== PAUSE TestSignErrors/invalid_base642607=== RUN TestSignErrors/http_error2608=== PAUSE TestSignErrors/http_error2609=== CONT TestSignErrors/invalid_json2610=== CONT TestSignErrors/invalid_base642611=== CONT TestSignErrors/http_error2612--- PASS: TestServe (0.00s)2613=== CONT TestSignErrors/no_prefix2614--- PASS: TestSign (0.00s)2615--- PASS: TestSignErrors (0.00s)2616 --- PASS: TestSignErrors/no_prefix (0.00s)2617 --- PASS: TestSignErrors/invalid_json (0.00s)2618 --- PASS: TestSignErrors/invalid_base64 (0.00s)2619 --- PASS: TestSignErrors/http_error (0.00s)2620PASS