niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #379
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.26s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestSetClientTLSErrors101=== CONT TestScriptTokenNoExpiryRerunsEveryCall102=== CONT TestFileTokenEmpty103=== CONT TestFileTokenMissing104=== CONT TestFileTokenReadsAndCaches105--- PASS: TestFileTokenMissing (0.00s)106=== CONT TestSetClientTLSDoesNotMutateDefaultTransport107=== CONT TestStaticToken108--- PASS: TestStaticToken (0.00s)109=== CONT TestSetClientTLS110=== CONT TestStreamPushGivesUpOnDeadServer111=== CONT TestScriptTokenCachesUntilRefresh112=== CONT TestScriptTokenEmptyCommand113=== CONT TestClientSignaturesByStorePath114--- PASS: TestFileTokenEmpty (0.00s)115--- PASS: TestScriptTokenEmptyCommand (0.00s)116--- PASS: TestClientSignaturesByStorePath (0.00s)1172026/10/06 19:58:23 WARN Rate limiter enabled after throttle name=server-test rate=5118=== CONT TestScriptTokenScriptFails1192026/10/06 19:58:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61743120--- PASS: TestFileTokenReadsAndCaches (0.00s)1212026/10/06 19:58:23 ERROR Upload failed error="connection refused" count=201222026/10/06 19:58:23 ERROR Server seems unavailable, giving up on batch untried=17123=== CONT TestStreamPushReportsSignatures124--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)125=== RUN TestSetClientTLSErrors/missing_cert_file126--- PASS: TestDoServerRequestAttachesToken (0.01s)127=== CONT TestStreamPushRequestLine128=== CONT TestScriptTokenBadJSON129=== PAUSE TestSetClientTLSErrors/missing_cert_file130=== RUN TestSetClientTLSErrors/missing_key_file1312026/10/06 19:58:23 ERROR Upload failed error=boom count=1132=== PAUSE TestSetClientTLSErrors/missing_key_file133=== RUN TestSetClientTLSErrors/missing_ca_file134--- PASS: TestStreamPushReportsSignatures (0.00s)135=== PAUSE TestSetClientTLSErrors/missing_ca_file136=== RUN TestSetClientTLSErrors/invalid_ca_file137=== PAUSE TestSetClientTLSErrors/invalid_ca_file138=== CONT TestScriptTokenEmptyToken1392026/10/06 19:58:23 ERROR Upload failed error=boom count=1140=== CONT TestEncodeNixBase32141=== RUN TestEncodeNixBase32/test_string_hash142=== PAUSE TestEncodeNixBase32/test_string_hash143=== RUN TestEncodeNixBase32/empty_input144=== PAUSE TestEncodeNixBase32/empty_input145=== CONT TestResolveStorePath146--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)147=== CONT TestUploadMultipart_PartsInParallel1482026/10/06 19:58:23 WARN Rate limiter backed off name=server-test rate=51492026/10/06 19:58:23 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61743150--- PASS: TestResolveStorePath (0.00s)151=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1522026/10/06 19:58:23 WARN Rate limiter enabled after throttle name=server-test rate=5153=== RUN TestSetClientTLS/rejects_connection_without_client_cert154--- PASS: TestScriptTokenScriptFails (0.01s)155=== CONT TestDumpPathWriterError156=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert157=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA158=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA159=== CONT TestRateLimiterFeedback160=== RUN TestRateLimiterFeedback/429_enables_limiter161=== PAUSE TestRateLimiterFeedback/429_enables_limiter162=== RUN TestRateLimiterFeedback/503_enables_limiter163--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)164=== RUN TestSetClientTLS/preserves_debug_logging_transport165=== PAUSE TestRateLimiterFeedback/503_enables_limiter166=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter167=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter168=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter169=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter170=== CONT TestDumpPathSingleFile171=== PAUSE TestSetClientTLS/preserves_debug_logging_transport172=== CONT TestPathInfoCACompatibility173=== RUN TestPathInfoCACompatibility/null_ca_field174=== PAUSE TestPathInfoCACompatibility/null_ca_field175=== RUN TestPathInfoCACompatibility/old_string_format_-_text176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text177=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive178=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive179=== RUN TestPathInfoCACompatibility/new_structured_format_-_text180=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text181=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method182=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method183=== CONT TestDumpPathMatchesNix184--- PASS: TestScriptTokenBadJSON (0.01s)185=== CONT TestParsePathInfoJSONMultiplePaths186--- PASS: TestScriptTokenEmptyToken (0.01s)187=== CONT TestUploadMultipart_SupersededByPeer188=== RUN TestUploadMultipart_SupersededByPeer/exists189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== RUN TestUploadMultipart_SupersededByPeer/missing191=== PAUSE TestUploadMultipart_SupersededByPeer/missing192=== CONT TestParsePathInfoJSON193=== RUN TestParsePathInfoJSON/Nix_format194=== PAUSE TestParsePathInfoJSON/Nix_format195=== RUN TestParsePathInfoJSON/Lix_format196=== PAUSE TestParsePathInfoJSON/Lix_format197=== RUN TestParsePathInfoJSON/empty_input198=== PAUSE TestParsePathInfoJSON/empty_input199=== RUN TestParsePathInfoJSON/whitespace_only200=== PAUSE TestParsePathInfoJSON/whitespace_only201=== RUN TestParsePathInfoJSON/invalid_JSON202=== PAUSE TestParsePathInfoJSON/invalid_JSON203=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths204=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths205=== CONT TestPathInfoHashCompatibility206=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)207=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)208=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon209=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths210=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon211=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI212=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI213=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512214=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths215=== CONT TestPartSizeForNAR216=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512217=== CONT TestGetStorePathHash218=== RUN TestGetStorePathHash/valid_store_path219=== RUN TestPartSizeForNAR/zero_stays_at_minimum220=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum221=== RUN TestPartSizeForNAR/small_stays_at_minimum222=== PAUSE TestPartSizeForNAR/small_stays_at_minimum223=== PAUSE TestGetStorePathHash/valid_store_path224=== RUN TestGetStorePathHash/basename_without_hyphen_should_error225=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error226=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum227=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error228=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum229=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error230=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error231=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error232=== CONT TestStreamPushReportsEveryPath233=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts234=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts235=== RUN TestPartSizeForNAR/1_TiB236=== PAUSE TestPartSizeForNAR/1_TiB237=== RUN TestPartSizeForNAR/5_TiB_S3_max_object238=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object239=== RUN TestPartSizeForNAR/capped_at_5_GiB240=== PAUSE TestPartSizeForNAR/capped_at_5_GiB241=== CONT TestShellSplitErrors242--- PASS: TestShellSplitErrors (0.00s)243=== CONT TestEncodeNixBase32WithRealHash244--- PASS: TestEncodeNixBase32WithRealHash (0.00s)245=== CONT TestShellSplit246--- PASS: TestShellSplit (0.00s)247=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun248--- PASS: TestStreamPushReportsEveryPath (0.00s)249=== CONT TestConvertHashToNix32250=== RUN TestConvertHashToNix32/SRI_format_to_Nix32251=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32252=== RUN TestConvertHashToNix32/already_Nix32_format253=== PAUSE TestConvertHashToNix32/already_Nix32_format254=== RUN TestConvertHashToNix32/invalid_format255=== PAUSE TestConvertHashToNix32/invalid_format256=== CONT TestFilterOversizedClosures257=== RUN TestFilterOversizedClosures/no_limit_keeps_everything258=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything259=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped260=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped261=== RUN TestFilterOversizedClosures/all_closures_skipped262=== PAUSE TestFilterOversizedClosures/all_closures_skipped263=== CONT TestCaseHackSuffix2642026/10/06 19:58:23 INFO Garbage collection started265--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)266=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica267--- PASS: TestStreamPushRequestLine (0.02s)268=== CONT TestRegisterUploadedObjectReusesConnections2692026/10/06 19:58:23 INFO Garbage collection started2702026/10/06 19:58:23 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=02712026/10/06 19:58:23 WARN Garbage collection finished on another replica. Its statistics are not available here272--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)273=== CONT TestStreamPushIsolatesFailures2742026/10/06 19:58:23 ERROR Upload failed error="bad path" count=3275--- PASS: TestStreamPushIsolatesFailures (0.00s)276=== CONT TestStreamPushBatchesUnderLoad277--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)278=== CONT TestSetClientTLSErrors/missing_cert_file279=== CONT TestSetClientTLSErrors/invalid_ca_file280=== CONT TestSetClientTLSErrors/missing_ca_file281=== CONT TestSetClientTLSErrors/missing_key_file282=== CONT TestEncodeNixBase32/test_string_hash283=== CONT TestEncodeNixBase32/empty_input284--- PASS: TestEncodeNixBase32 (0.00s)285 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)286 --- PASS: TestEncodeNixBase32/empty_input (0.00s)287=== CONT TestRateLimiterFeedback/429_enables_limiter288--- PASS: TestSetClientTLSErrors (0.01s)289 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)290 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)291 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)292 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)2932026/10/06 19:58:23 WARN Rate limiter enabled after throttle name=server-test rate=52942026/10/06 19:58:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:61823295--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)296=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2972026/10/06 19:58:23 WARN Rate limiter backed off name=server-test rate=5298=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter299=== CONT TestRateLimiterFeedback/503_enables_limiter300=== CONT TestSetClientTLS/rejects_connection_without_client_cert3012026/10/06 19:58:23 WARN Rate limiter enabled after throttle name=server-test rate=53022026/10/06 19:58:23 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:618283032026/10/06 19:58:23 WARN Rate limiter backed off name=server-test rate=5304--- PASS: TestRateLimiterFeedback (0.00s)305 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)306 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)307 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)308 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)309=== CONT TestPathInfoCACompatibility/null_ca_field310=== CONT TestSetClientTLS/preserves_debug_logging_transport311--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)312=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA313=== CONT TestPathInfoCACompatibility/new_structured_format_-_text314=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method315=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive316=== CONT TestPathInfoCACompatibility/old_string_format_-_text317--- PASS: TestPathInfoCACompatibility (0.00s)318 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)319 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)320 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)321 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)322 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)323=== CONT TestUploadMultipart_SupersededByPeer/exists324=== CONT TestUploadMultipart_SupersededByPeer/missing325=== CONT TestParsePathInfoJSON/Nix_format326=== CONT TestParsePathInfoJSON/invalid_JSON327=== CONT TestParsePathInfoJSON/whitespace_only328=== CONT TestParsePathInfoJSON/empty_input329=== CONT TestParsePathInfoJSON/Lix_format330--- PASS: TestParsePathInfoJSON (0.00s)331 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)336=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths337=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths338--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)339 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)340 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)341=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)342=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512343=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI344=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon345--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)347 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)348=== CONT TestGetStorePathHash/valid_store_path349=== CONT TestGetStorePathHash/basename_without_hyphen_should_error350=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error351=== CONT TestPartSizeForNAR/zero_stays_at_minimum352--- PASS: TestPathInfoHashCompatibility (0.00s)353 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)355 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)356 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)357=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error358--- PASS: TestGetStorePathHash (0.00s)359 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)360 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)361 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)362 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)363=== CONT TestPartSizeForNAR/1_TiB364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/small_stays_at_minimum368=== CONT TestConvertHashToNix32/SRI_format_to_Nix32369=== CONT TestConvertHashToNix32/invalid_format370=== CONT TestConvertHashToNix32/already_Nix32_format371--- PASS: TestConvertHashToNix32 (0.00s)372 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)373 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)374 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)375=== CONT TestFilterOversizedClosures/all_closures_skipped376=== CONT TestPartSizeForNAR/capped_at_5_GiB377--- PASS: TestPartSizeForNAR (0.00s)378 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)380 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)381 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)383 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)384 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)385=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3862026/10/06 19:58:23 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=50387=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3882026/10/06 19:58:23 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=2000389--- PASS: TestFilterOversizedClosures (0.00s)390 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)391 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)392 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)393--- PASS: TestDumpPathWriterError (0.05s)3942026/10/06 19:58:23 http: TLS handshake error from 127.0.0.1:61831: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestDumpPathSingleFile (0.10s)400--- PASS: TestCaseHackSuffix (0.09s)401--- PASS: TestStreamPushBatchesUnderLoad (0.10s)402--- PASS: TestDumpPathMatchesNix (0.12s)403--- PASS: TestUploadMultipart_PartsInParallel (0.61s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld13".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-57467-1694855006/postgres456849672/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-57467-1694855006/postgres456849672/data -l logfile start4334342026-10-06 19:58:27.438 UTC [57954] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-06 19:58:27.439 UTC [57954] LOG: listening on Unix socket "/nix/var/nix/builds/nix-57467-1694855006/postgres456849672/.s.PGSQL.5432"4362026-10-06 19:58:27.446 UTC [57962] LOG: database system was shut down at 2026-10-06 19:58:27 UTC4372026-10-06 19:58:27.447 UTC [57963] FATAL: the database system is starting up438/nix/var/nix/builds/nix-57467-1694855006/postgres456849672:5432 - rejecting connections4392026-10-06 19:58:27.448 UTC [57954] LOG: database system is ready to accept connections440/nix/var/nix/builds/nix-57467-1694855006/postgres456849672:5432 - accepting connections441{"timestamp":"2026-10-06T19:58:27.702391Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6b8b3acd-8b14-4c12-8621-a3e50db43a15","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":8,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}442{"timestamp":"2026-10-06T19:58:27.817435Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"20e84520-b99e-4054-bc7b-60f532e6dfd2","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(10)"}443{"timestamp":"2026-10-06T19:58:27.920868Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"86a6f3ba-0f0f-4e5f-9350-e578940c3faa","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}444=== RUN TestService_AuthMiddleware445=== PAUSE TestService_AuthMiddleware446=== RUN TestService_AuthMiddleware_MTLSProxyHeader447=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader448=== RUN TestService_AuthMiddleware_MTLSBoundSubjects449=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects450=== RUN TestService_ReadAuthMiddleware451=== PAUSE TestService_ReadAuthMiddleware452=== RUN TestService_AuthMiddleware_OIDC453=== PAUSE TestService_AuthMiddleware_OIDC454=== RUN TestService_RequireScope_OIDC455=== PAUSE TestService_RequireScope_OIDC456=== RUN TestService_ReadScope_PublicByDefault457=== PAUSE TestService_ReadScope_PublicByDefault458=== RUN TestCacheConfigHandler459=== PAUSE TestCacheConfigHandler460=== RUN TestCacheStatsHandler461=== PAUSE TestCacheStatsHandler462=== RUN TestClientCADerivations463=== PAUSE TestClientCADerivations464=== RUN TestClientErrorHandling465=== PAUSE TestClientErrorHandling466=== RUN TestClientIntegration467=== PAUSE TestClientIntegration468=== RUN TestClientMultipleUploads469=== PAUSE TestClientMultipleUploads470=== RUN TestClientWithDependencies471=== PAUSE TestClientWithDependencies472=== RUN TestClientSharedPathCommittedMidPush473=== PAUSE TestClientSharedPathCommittedMidPush474=== RUN TestPinProtectsFromGC475=== PAUSE TestPinProtectsFromGC476=== RUN TestClientPushesUseOnePush477=== PAUSE TestClientPushesUseOnePush478=== RUN TestClientFallsBackToClosures479=== PAUSE TestClientFallsBackToClosures480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 19:58:28 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 19:58:28 INFO lead: released remote=192.0.2.1:12344912026/10/06 19:58:28 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 19:58:30 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (2.03s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 19:58:30 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 19:58:31.624 UTC [58066] FATAL: terminating connection due to administrator command5012026/10/06 19:58:31 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 19:58:32 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 19:58:32 INFO lead: released remote=192.0.2.1:12345042026/10/06 19:58:33 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.97s)506=== RUN TestGCAdvisoryLockBlocksConcurrentRun507=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun508=== RUN TestGCBugBareHashReferences509=== PAUSE TestGCBugBareHashReferences510=== RUN TestGCMetrics511=== PAUSE TestGCMetrics512=== RUN TestPushDedupSurvivesConcurrentGC513=== PAUSE TestPushDedupSurvivesConcurrentGC514=== RUN TestDeduplicatedObjectsRecordedAsPending515=== PAUSE TestDeduplicatedObjectsRecordedAsPending516=== RUN TestGCSweepSkipsPendingObjects517=== PAUSE TestGCSweepSkipsPendingObjects518=== RUN TestTombstonedObjectOfferedWithoutWaiting519=== PAUSE TestTombstonedObjectOfferedWithoutWaiting520=== RUN TestGCSweepDeliversEachKeyOnce521=== PAUSE TestGCSweepDeliversEachKeyOnce522=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection524=== RUN TestForceGCDuringPushOffersSweptObject525=== PAUSE TestForceGCDuringPushOffersSweptObject526=== RUN TestFailedS3DeleteKeepsTombstone527=== PAUSE TestFailedS3DeleteKeepsTombstone528=== RUN TestSweepSkipsRowsLockedByPush529=== PAUSE TestSweepSkipsRowsLockedByPush530=== RUN TestRegisterCompletedObjectNeedsPendingRow531=== PAUSE TestRegisterCompletedObjectNeedsPendingRow532=== RUN TestGetExistingObjectsLocksRows533=== PAUSE TestGetExistingObjectsLocksRows534=== RUN TestSweepRechecksPendingAfterLocking535=== PAUSE TestSweepRechecksPendingAfterLocking536=== RUN TestPushWaitsForSweepHoldingRow537=== PAUSE TestPushWaitsForSweepHoldingRow538=== RUN TestCommitRacingPendingCleanupKeepsObjects539=== PAUSE TestCommitRacingPendingCleanupKeepsObjects540=== RUN TestGCEndsOnShutdown541=== PAUSE TestGCEndsOnShutdown542=== RUN TestGCTaskStore_StartNew543=== PAUSE TestGCTaskStore_StartNew544=== RUN TestGCTaskStore_DeduplicateSameParams545=== PAUSE TestGCTaskStore_DeduplicateSameParams546=== RUN TestGCTaskStore_ConflictDifferentParams547=== PAUSE TestGCTaskStore_ConflictDifferentParams548=== RUN TestGCTaskStore_GetEmpty549=== PAUSE TestGCTaskStore_GetEmpty550=== RUN TestGCTaskStore_GetReturnsLatest551=== PAUSE TestGCTaskStore_GetReturnsLatest552=== RUN TestGCTaskStore_CompletedAllowsNewTask553=== PAUSE TestGCTaskStore_CompletedAllowsNewTask554=== RUN TestGCTaskStore_PhaseUpdates555=== PAUSE TestGCTaskStore_PhaseUpdates556=== RUN TestGCTaskStore_Fail557=== PAUSE TestGCTaskStore_Fail558=== RUN TestGracefulShutdownDrainsInflight559=== PAUSE TestGracefulShutdownDrainsInflight560=== RUN TestService_healthCheckHandler561=== PAUSE TestService_healthCheckHandler562=== RUN TestService_readinessHandler563=== PAUSE TestService_readinessHandler564=== RUN TestGenerateLandingPage565=== PAUSE TestGenerateLandingPage566=== RUN TestCacheConfigHandlerMaxNarSize567=== PAUSE TestCacheConfigHandlerMaxNarSize568=== RUN TestCreatePendingClosureRejectsOversizedNAR569=== PAUSE TestCreatePendingClosureRejectsOversizedNAR570=== RUN TestNARDeduplicationMetadataUploadBug571=== PAUSE TestNARDeduplicationMetadataUploadBug572=== RUN TestMetricsInventory573=== PAUSE TestMetricsInventory574=== RUN TestService_NativeMTLS575=== PAUSE TestService_NativeMTLS576=== RUN TestServerTLSConfig577=== PAUSE TestServerTLSConfig578=== RUN TestMultipartCleanup579=== PAUSE TestMultipartCleanup580=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded582=== RUN TestPendingCleanupUsesOneCutoff583=== PAUSE TestPendingCleanupUsesOneCutoff584=== RUN TestObjectStatsTrigger585=== PAUSE TestObjectStatsTrigger586=== RUN TestOrphanedObjectsGC587=== PAUSE TestOrphanedObjectsGC588=== RUN TestOrphanedObjectsGCStressTest589=== PAUSE TestOrphanedObjectsGCStressTest590=== RUN TestCreatePin_ReservedPins591=== PAUSE TestCreatePin_ReservedPins592=== RUN TestPresentReportsOnlyClosureRoots593=== PAUSE TestPresentReportsOnlyClosureRoots594=== RUN TestPresentNotReportedWhileGCDeletesClosure595=== PAUSE TestPresentNotReportedWhileGCDeletesClosure596=== RUN TestConcurrentPresentSharingKeysDoNotDeadlock597=== PAUSE TestConcurrentPresentSharingKeysDoNotDeadlock598=== RUN TestParseSingleRange599=== PAUSE TestParseSingleRange600=== RUN TestProxyHeadersOnlyTrustedOnSocket601=== PAUSE TestProxyHeadersOnlyTrustedOnSocket602=== RUN TestIsValidCachePath603=== PAUSE TestIsValidCachePath604=== RUN TestReadProxyNarinfo605=== PAUSE TestReadProxyNarinfo606=== RUN TestReadProxyNarinfoAlreadyDecompressed607=== PAUSE TestReadProxyNarinfoAlreadyDecompressed608=== RUN TestReadProxyContentNegotiation609=== PAUSE TestReadProxyContentNegotiation610=== RUN TestReadProxyNarStreaming611=== PAUSE TestReadProxyNarStreaming612=== RUN TestReadProxy404613=== PAUSE TestReadProxy404614=== RUN TestReadProxyInvalidPath615=== PAUSE TestReadProxyInvalidPath616=== RUN TestReadProxyHead617=== PAUSE TestReadProxyHead618=== RUN TestReadProxyOutlastsServerWriteTimeout619=== PAUSE TestReadProxyOutlastsServerWriteTimeout620=== RUN TestReadProxyConditionalGet621=== PAUSE TestReadProxyConditionalGet622=== RUN TestReadProxyRootRedirectsToIndexHTML623=== PAUSE TestReadProxyRootRedirectsToIndexHTML624=== RUN TestReadProxyDisabled625=== PAUSE TestReadProxyDisabled626=== RUN TestReadRedirectNar627=== PAUSE TestReadRedirectNar628=== RUN TestReadRedirectKeepsNarinfoProxied629=== PAUSE TestReadRedirectKeepsNarinfoProxied630=== RUN TestReadProxyRangeRequest631=== PAUSE TestReadProxyRangeRequest632=== RUN TestReadRedirectUsesPublicS3URL633=== PAUSE TestReadRedirectUsesPublicS3URL634=== RUN TestPush_OverlappingRootsStoreOneRowPerKey635=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey636=== RUN TestPush_CompleteCommitsEveryRoot637=== PAUSE TestPush_CompleteCommitsEveryRoot638=== RUN TestPush_RepeatedRootCommitsOnce639=== PAUSE TestPush_RepeatedRootCommitsOnce640=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit641=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit642=== RUN TestPush_RejectsBadRequests643=== PAUSE TestPush_RejectsBadRequests644=== RUN TestPush_SignsNarinfosOfItsPendingObjects645=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects646=== RUN TestRedundantMultipartUpload647=== PAUSE TestRedundantMultipartUpload648=== RUN TestCompleteMultipartUpload_ErrorButObjectExists649=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists650=== RUN TestCompletedNarNotReofferedAcrossClosures651=== PAUSE TestCompletedNarNotReofferedAcrossClosures652=== RUN TestPresignedUploadRegisteredBeforeCommit653=== PAUSE TestPresignedUploadRegisteredBeforeCommit654=== RUN TestService_Rustfstest655=== PAUSE TestService_Rustfstest656=== RUN TestParseSize657=== PAUSE TestParseSize658=== RUN TestSkippedUploadsHandler659=== PAUSE TestSkippedUploadsHandler660=== RUN TestSystemdListenerNotActivated661--- PASS: TestSystemdListenerNotActivated (0.00s)662=== RUN TestWatchdogBeatsWhenHealthy663--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)664=== RUN TestWatchdogSkipsWhenUnhealthy6652026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 19:58:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"675--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)676=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle677=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle678=== RUN TestProxyWriteTimeout679=== PAUSE TestProxyWriteTimeout680=== RUN TestPendingClosureWriteTimeout681=== PAUSE TestPendingClosureWriteTimeout682=== RUN TestIsValidUploadKey683=== PAUSE TestIsValidUploadKey684=== RUN TestUploadHandlersRejectInvalidKeys685=== PAUSE TestUploadHandlersRejectInvalidKeys686=== RUN TestUploadHandlersRejectOversizedBody687=== PAUSE TestUploadHandlersRejectOversizedBody688=== RUN TestService_cleanupPendingClosuresHandler689=== PAUSE TestService_cleanupPendingClosuresHandler690=== RUN TestService_createPendingClosureHandler691=== PAUSE TestService_createPendingClosureHandler692=== RUN TestService_verifyS3Integrity693=== PAUSE TestService_verifyS3Integrity694=== RUN TestCompleteMultipartUnregistered695=== PAUSE TestCompleteMultipartUnregistered696=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT697=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT698=== CONT TestReadRedirectNar699=== CONT TestService_AuthMiddleware700=== CONT TestService_Rustfstest701=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit702=== CONT TestPresignedUploadRegisteredBeforeCommit703=== CONT TestGCTaskStore_StartNew704--- PASS: TestGCTaskStore_StartNew (0.00s)705=== CONT TestReadProxyDisabled706=== CONT TestLeadElectsOneAndHandsOver707=== CONT TestConnectWaitsForAPeerMigration708=== CONT TestPush_RepeatedRootCommitsOnce709=== CONT TestReadProxyRootRedirectsToIndexHTML7102026/10/06 19:58:33 INFO Received push request method=POST path=/api/pushes7112026/10/06 19:58:33 INFO Received complete push request method=POST path=/api/pushes/1/complete7122026/10/06 19:58:33 INFO Completed push id=1713--- PASS: TestPush_RepeatedRootCommitsOnce (0.50s)714=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT7152026/10/06 19:58:33 INFO Received push request method=POST path=/api/pushes7162026/10/06 19:58:33 INFO Received complete push request method=POST path=/api/pushes/1/complete7172026/10/06 19:58:33 INFO Completed push id=17182026/10/06 19:58:33 INFO Received push request method=POST path=/api/pushes7192026/10/06 19:58:34 INFO Aborted multipart uploads count=0 kept=07202026/10/06 19:58:34 WARN Force mode enabled - objects will be deleted immediately without grace period721--- PASS: TestService_Rustfstest (0.82s)722=== CONT TestCompleteMultipartUnregistered7232026/10/06 19:58:34 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=07242026/10/06 19:58:34 INFO Vacuumed table table=pending_closures7252026/10/06 19:58:34 INFO Vacuumed table table=pending_objects7262026/10/06 19:58:34 INFO Vacuumed table table=multipart_uploads7272026/10/06 19:58:34 INFO Vacuumed table table=closures7282026/10/06 19:58:34 INFO Vacuumed table table=objects7292026/10/06 19:58:34 INFO Received complete push request method=POST path=/api/pushes/2/complete7302026/10/06 19:58:34 INFO Completed push id=2731--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.90s)732=== CONT TestService_verifyS3Integrity733--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.06s)734=== CONT TestService_createPendingClosureHandler735--- PASS: TestReadProxyDisabled (1.20s)736=== CONT TestService_cleanupPendingClosuresHandler7372026/10/06 19:58:34 INFO lead: acquired remote=192.0.2.1:12347382026/10/06 19:58:34 INFO Received uploads request method=POST path=/api/pending_closures7392026/10/06 19:58:34 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7402026/10/06 19:58:34 INFO Received uploads request method=POST path=/api/pending_closures741--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.62s)742=== CONT TestUploadHandlersRejectOversizedBody743=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts744=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts745=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure746=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure747=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart748=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart749=== CONT TestUploadHandlersRejectInvalidKeys750=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info751=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info752=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal753=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal754=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key755=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key756=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key757=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key758=== CONT TestIsValidUploadKey759=== RUN TestIsValidUploadKey/narinfo760=== PAUSE TestIsValidUploadKey/narinfo761=== RUN TestIsValidUploadKey/nar_zst762=== PAUSE TestIsValidUploadKey/nar_zst763=== RUN TestIsValidUploadKey/nar_xz764=== PAUSE TestIsValidUploadKey/nar_xz765=== RUN TestIsValidUploadKey/nar_plain766=== PAUSE TestIsValidUploadKey/nar_plain767=== RUN TestIsValidUploadKey/listing768=== PAUSE TestIsValidUploadKey/listing769=== RUN TestIsValidUploadKey/build_log770=== PAUSE TestIsValidUploadKey/build_log771=== RUN TestIsValidUploadKey/build_log_home-manager_file772=== PAUSE TestIsValidUploadKey/build_log_home-manager_file773=== RUN TestIsValidUploadKey/build_log_plus_in_name774=== PAUSE TestIsValidUploadKey/build_log_plus_in_name775=== RUN TestIsValidUploadKey/build_log_question_mark776=== PAUSE TestIsValidUploadKey/build_log_question_mark777=== RUN TestIsValidUploadKey/build_log_equals778=== PAUSE TestIsValidUploadKey/build_log_equals779=== RUN TestIsValidUploadKey/realisation780=== PAUSE TestIsValidUploadKey/realisation781=== RUN TestIsValidUploadKey/realisation_plus_in_output782=== PAUSE TestIsValidUploadKey/realisation_plus_in_output783=== RUN TestIsValidUploadKey/nix-cache-info784=== PAUSE TestIsValidUploadKey/nix-cache-info785=== RUN TestIsValidUploadKey/index.html786=== PAUSE TestIsValidUploadKey/index.html787=== RUN TestIsValidUploadKey/narinfo_key,_nar_type788=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type789=== RUN TestIsValidUploadKey/nar_key,_narinfo_type790=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type791=== RUN TestIsValidUploadKey/listing_key,_narinfo_type792=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type793=== RUN TestIsValidUploadKey/traversal794=== PAUSE TestIsValidUploadKey/traversal795=== RUN TestIsValidUploadKey/traversal_nar796=== PAUSE TestIsValidUploadKey/traversal_nar797=== RUN TestIsValidUploadKey/absolute798=== PAUSE TestIsValidUploadKey/absolute799=== RUN TestIsValidUploadKey/empty_key800=== PAUSE TestIsValidUploadKey/empty_key801=== RUN TestIsValidUploadKey/unknown_type802=== PAUSE TestIsValidUploadKey/unknown_type803=== CONT TestPendingClosureWriteTimeout804=== RUN TestPendingClosureWriteTimeout/empty805=== PAUSE TestPendingClosureWriteTimeout/empty806=== RUN TestPendingClosureWriteTimeout/400_objects807=== PAUSE TestPendingClosureWriteTimeout/400_objects808=== RUN TestPendingClosureWriteTimeout/670k_objects809=== PAUSE TestPendingClosureWriteTimeout/670k_objects810=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline811=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline812=== CONT TestProxyWriteTimeout813=== RUN TestProxyWriteTimeout/narinfo814=== PAUSE TestProxyWriteTimeout/narinfo815=== RUN TestProxyWriteTimeout/1_GiB_nar816=== PAUSE TestProxyWriteTimeout/1_GiB_nar817=== RUN TestProxyWriteTimeout/10_GiB_nar818=== PAUSE TestProxyWriteTimeout/10_GiB_nar819=== RUN TestProxyWriteTimeout/unknown_size820=== PAUSE TestProxyWriteTimeout/unknown_size821=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8222026/10/06 19:58:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"823--- PASS: TestService_AuthMiddleware (1.73s)824=== CONT TestSkippedUploadsHandler8252026/10/06 19:58:34 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000826--- PASS: TestSkippedUploadsHandler (0.00s)827=== CONT TestParseSize828--- PASS: TestParseSize (0.00s)829=== CONT TestPendingCleanupUsesOneCutoff830--- PASS: TestReadRedirectNar (1.90s)831=== CONT TestReadProxyConditionalGet8322026/10/06 19:58:35 INFO Received uploads request method=POST path=/api/pending_closures833--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.64s)834=== CONT TestReadProxyOutlastsServerWriteTimeout8352026/10/06 19:58:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8362026/10/06 19:58:35 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst837--- PASS: TestCompleteMultipartUnregistered (1.42s)838=== CONT TestReadProxyHead8392026/10/06 19:58:35 INFO Received uploads request method=POST path=/api/pending_closures8402026/10/06 19:58:35 INFO lead: released remote=192.0.2.1:12348412026/10/06 19:58:35 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/06 19:58:35 INFO Received uploads request method=POST path=/api/pending_closures8432026/10/06 19:58:35 INFO Received uploads request method=POST path=/api/pending_closures8442026/10/06 19:58:35 INFO lead: acquired remote=192.0.2.1:12348452026/10/06 19:58:36 INFO Received cleanup request method=DELETE path=/api/pending_closures8462026/10/06 19:58:36 INFO Aborted multipart uploads count=0 kept=08472026/10/06 19:58:36 INFO Received uploads request method=POST path=/api/pending_closures8482026/10/06 19:58:36 INFO Received cleanup request method=DELETE path=/api/pending_closures8492026/10/06 19:58:36 INFO Aborted multipart uploads count=1 kept=08502026/10/06 19:58:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8512026-10-06 19:58:36.264 UTC [58534] ERROR: Closure does not exist: id=18522026-10-06 19:58:36.264 UTC [58534] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8532026-10-06 19:58:36.264 UTC [58534] STATEMENT: -- name: CommitPendingClosure :exec854 SELECT commit_pending_closure($1::bigint)855 856--- PASS: TestService_cleanupPendingClosuresHandler (1.81s)857=== CONT TestReadProxyInvalidPath8582026/10/06 19:58:36 INFO Received uploads request method=POST path=/api/pending_closures8592026/10/06 19:58:36 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/06 19:58:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8612026/10/06 19:58:36 INFO Received uploads request method=POST path=/api/pending_closures8622026/10/06 19:58:36 INFO Received cleanup request method=DELETE path=/api/pending_closures8632026/10/06 19:58:36 INFO lead: released remote=192.0.2.1:1234864--- PASS: TestLeadElectsOneAndHandsOver (3.72s)865=== CONT TestReadProxy4048662026/10/06 19:58:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8672026/10/06 19:58:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLmY5ZmFjYjA3LWZjODUtNGU0ZC1hYjBkLTNhNzBiNzM1YjczZXgxNzkxMzE2NzE1NzEyMzA1MDAw parts=108682026/10/06 19:58:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8692026/10/06 19:58:37 INFO Completed upload id=18702026/10/06 19:58:37 INFO Received uploads request method=POST path=/api/pending_closures8712026/10/06 19:58:37 INFO Received uploads request method=POST path=/api/pending_closures8722026/10/06 19:58:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8732026/10/06 19:58:37 WARN Found objects in DB but missing from S3, will re-upload count=1874--- PASS: TestService_verifyS3Integrity (2.94s)875=== CONT TestReadProxyNarStreaming876--- PASS: TestReadProxyConditionalGet (1.99s)877=== CONT TestReadProxyContentNegotiation8782026/10/06 19:58:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8792026/10/06 19:58:37 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLjRkNDRjZDJmLWY5MjMtNGVlNC1iNDA5LTU0OGNkYWFhZDVhM3gxNzkxMzE2NzE1OTIwMDUxMDAw parts=108802026/10/06 19:58:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8812026/10/06 19:58:37 INFO Completed upload id=18822026/10/06 19:58:37 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000008832026/10/06 19:58:37 INFO Received uploads request method=POST path=/api/pending_closures8842026/10/06 19:58:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures8852026/10/06 19:58:37 INFO Aborted multipart uploads count=0 kept=08862026/10/06 19:58:37 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=08872026/10/06 19:58:37 INFO Vacuumed table table=pending_closures8882026/10/06 19:58:37 INFO Vacuumed table table=pending_objects8892026/10/06 19:58:37 INFO Vacuumed table table=multipart_uploads8902026/10/06 19:58:37 INFO Vacuumed table table=closures8912026/10/06 19:58:37 INFO Vacuumed table table=objects8922026/10/06 19:58:37 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000893--- PASS: TestService_createPendingClosureHandler (3.15s)894=== CONT TestReadProxyNarinfoAlreadyDecompressed895--- PASS: TestReadProxyHead (2.10s)896=== CONT TestReadProxyNarinfo897--- PASS: TestReadProxyInvalidPath (1.59s)898=== CONT TestIsValidCachePath899=== RUN TestIsValidCachePath/narinfo900=== PAUSE TestIsValidCachePath/narinfo901=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars902=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars903=== RUN TestIsValidCachePath/nar_zst904=== PAUSE TestIsValidCachePath/nar_zst905=== RUN TestIsValidCachePath/nar_xz906=== PAUSE TestIsValidCachePath/nar_xz907=== RUN TestIsValidCachePath/nar_bz2908=== PAUSE TestIsValidCachePath/nar_bz2909=== RUN TestIsValidCachePath/nar_uncompressed910=== PAUSE TestIsValidCachePath/nar_uncompressed911=== RUN TestIsValidCachePath/ls912=== PAUSE TestIsValidCachePath/ls913=== RUN TestIsValidCachePath/log914=== PAUSE TestIsValidCachePath/log915=== RUN TestIsValidCachePath/realisation916=== PAUSE TestIsValidCachePath/realisation917=== RUN TestIsValidCachePath/nix-cache-info918=== PAUSE TestIsValidCachePath/nix-cache-info919=== RUN TestIsValidCachePath/index.html920=== PAUSE TestIsValidCachePath/index.html921=== RUN TestIsValidCachePath/traversal_parent922=== PAUSE TestIsValidCachePath/traversal_parent923=== RUN TestIsValidCachePath/traversal_in_middle924=== PAUSE TestIsValidCachePath/traversal_in_middle925=== RUN TestIsValidCachePath/invalid_char_e926=== PAUSE TestIsValidCachePath/invalid_char_e927=== RUN TestIsValidCachePath/invalid_char_u928=== PAUSE TestIsValidCachePath/invalid_char_u929=== RUN TestIsValidCachePath/random_path930=== PAUSE TestIsValidCachePath/random_path931=== RUN TestIsValidCachePath/empty932=== PAUSE TestIsValidCachePath/empty933=== RUN TestIsValidCachePath/leading_slash934=== PAUSE TestIsValidCachePath/leading_slash935=== RUN TestIsValidCachePath/wrong_extension936=== PAUSE TestIsValidCachePath/wrong_extension937=== RUN TestIsValidCachePath/short_hash938=== PAUSE TestIsValidCachePath/short_hash939=== CONT TestProxyHeadersOnlyTrustedOnSocket940--- PASS: TestReadProxy404 (1.22s)941=== CONT TestParseSingleRange942=== RUN TestParseSingleRange/none943=== PAUSE TestParseSingleRange/none944=== RUN TestParseSingleRange/unknown_unit945=== PAUSE TestParseSingleRange/unknown_unit946=== RUN TestParseSingleRange/multi-range_ignored947=== PAUSE TestParseSingleRange/multi-range_ignored948=== RUN TestParseSingleRange/malformed_no_dash949=== PAUSE TestParseSingleRange/malformed_no_dash950=== RUN TestParseSingleRange/malformed_both_empty951=== PAUSE TestParseSingleRange/malformed_both_empty952=== RUN TestParseSingleRange/malformed_end_before_start953=== PAUSE TestParseSingleRange/malformed_end_before_start954=== RUN TestParseSingleRange/closed955=== PAUSE TestParseSingleRange/closed956=== RUN TestParseSingleRange/open-ended957=== PAUSE TestParseSingleRange/open-ended958=== RUN TestParseSingleRange/end_clamped_to_size959=== PAUSE TestParseSingleRange/end_clamped_to_size960=== RUN TestParseSingleRange/suffix961=== PAUSE TestParseSingleRange/suffix962=== RUN TestParseSingleRange/suffix_exceeds_size963=== PAUSE TestParseSingleRange/suffix_exceeds_size964=== RUN TestParseSingleRange/single_byte965=== PAUSE TestParseSingleRange/single_byte966=== RUN TestParseSingleRange/start_past_EOF967=== PAUSE TestParseSingleRange/start_past_EOF968=== RUN TestParseSingleRange/start_far_past_EOF969=== PAUSE TestParseSingleRange/start_far_past_EOF970=== CONT TestConcurrentPresentSharingKeysDoNotDeadlock971--- PASS: TestReadProxyNarStreaming (1.22s)972=== CONT TestPresentNotReportedWhileGCDeletesClosure973--- PASS: TestReadProxyContentNegotiation (1.39s)974=== CONT TestPresentReportsOnlyClosureRoots975--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.20s)976=== CONT TestResolveDBConnectionString977=== RUN TestResolveDBConnectionString/flag_wins978=== PAUSE TestResolveDBConnectionString/flag_wins979=== RUN TestResolveDBConnectionString/file_when_flag_empty980=== PAUSE TestResolveDBConnectionString/file_when_flag_empty981=== RUN TestResolveDBConnectionString/missing_file_is_an_error982=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error983=== RUN TestResolveDBConnectionString/PGHOST_allows_empty984=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty985=== RUN TestResolveDBConnectionString/nothing_configured986=== PAUSE TestResolveDBConnectionString/nothing_configured987=== CONT TestCreatePin_ReservedPins988--- PASS: TestConnectWaitsForAPeerMigration (5.58s)989=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9902026/10/06 19:58:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61962/oidc9912026/10/06 19:58:38 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>992--- PASS: TestReadProxyNarinfo (1.27s)993=== CONT TestOrphanedObjectsGCStressTest9942026/10/06 19:58:39 INFO Starting HTTP server address=127.0.0.1:619649952026/10/06 19:58:39 INFO Starting HTTP server address=/nix/var/nix/builds/nix-57467-1694855006/TestProxyHeadersOnlyTrustedOnSocket1890006974/001/proxy.sock9962026/10/06 19:58:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9972026/10/06 19:58:39 INFO Shutdown signal received, draining in-flight requests timeout=10s998--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.18s)999=== CONT TestOrphanedObjectsGC10002026/10/06 19:58:39 WARN Rate limiter enabled after throttle name=s3-test rate=510012026/10/06 19:58:39 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1002=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1003 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101004 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001005--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.82s)1006=== CONT TestObjectStatsTrigger1007--- PASS: TestPresentReportsOnlyClosureRoots (1.49s)1008=== CONT TestService_readinessHandler1009--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.83s)1010=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10112026/10/06 19:58:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10122026/10/06 19:58:40 WARN Refused reserved pin name=worker-x86_64-linux10132026/10/06 19:58:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10142026/10/06 19:58:40 INFO Received create pin request method=POST path=/api/pins/my-app10152026/10/06 19:58:40 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1016--- PASS: TestCreatePin_ReservedPins (1.87s)1017=== CONT TestMultipartCleanup1018--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.23s)1019=== CONT TestServerTLSConfig1020=== RUN TestServerTLSConfig/no_client_CA1021=== PAUSE TestServerTLSConfig/no_client_CA1022=== RUN TestServerTLSConfig/missing_CA_file1023=== PAUSE TestServerTLSConfig/missing_CA_file1024=== RUN TestServerTLSConfig/not_a_PEM_file1025=== PAUSE TestServerTLSConfig/not_a_PEM_file1026=== CONT TestClientFallsBackToClosures1027=== NAME TestOrphanedObjectsGC1028 orphaned_objects_gc_test.go:290: GC Test Summary:1029 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1030 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1031 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1032 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1033 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1034--- PASS: TestOrphanedObjectsGC (2.67s)1035=== CONT TestService_NativeMTLS1036--- PASS: TestObjectStatsTrigger (2.03s)1037=== CONT TestClientPushesUseOnePush1038--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.21s)1039=== CONT TestMetricsInventory10402026/10/06 19:58:42 WARN readiness check failed error="closed pool"1041--- PASS: TestService_readinessHandler (2.03s)1042=== CONT TestPinProtectsFromGC10432026/10/06 19:58:42 INFO Received uploads request method=POST path=/api/pending_closures1044--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.24s)1045=== CONT TestNARDeduplicationMetadataUploadBug10462026/10/06 19:58:42 INFO Received uploads request method=POST path=/api/pending_closures10472026/10/06 19:58:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10482026/10/06 19:58:42 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10492026/10/06 19:58:42 INFO Aborted multipart uploads count=0 kept=110502026/10/06 19:58:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10512026/10/06 19:58:42 INFO Aborted multipart uploads count=1 kept=01052--- PASS: TestMultipartCleanup (2.33s)1053=== CONT TestClientSharedPathCommittedMidPush10542026/10/06 19:58:42 INFO Aborted multipart uploads count=1 kept=010552026/10/06 19:58:42 INFO Received cleanup request method=DELETE path=/api/pending_closures10562026/10/06 19:58:42 INFO Aborted multipart uploads count=1 kept=01057--- PASS: TestPendingCleanupUsesOneCutoff (7.99s)1058=== CONT TestCreatePendingClosureRejectsOversizedNAR10592026/10/06 19:58:42 INFO Received uploads request method=POST path=/api/pending_closures1060--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1061=== CONT TestCacheConfigHandlerMaxNarSize1062--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1063=== CONT TestGenerateLandingPage1064--- PASS: TestGenerateLandingPage (0.00s)1065=== CONT TestGCTaskStore_CompletedAllowsNewTask1066--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1067=== CONT TestClientWithDependencies10682026/10/06 19:58:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10692026/10/06 19:58:43 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1070--- PASS: TestService_NativeMTLS (2.20s)1071=== CONT TestService_healthCheckHandler10722026/10/06 19:58:44 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/06 19:58:44 INFO Received uploads request method=POST path=/api/pending_closures10742026/10/06 19:58:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10752026/10/06 19:58:44 INFO Uploading xiviv85i7y0nmslbngqidpaq7h3bbdm0-b (248B)10762026/10/06 19:58:44 INFO Uploading fdzjmxizn0hadmqzd4wms3avq3wan7dh-shared-dep (136B)10772026/10/06 19:58:44 WARN Failed to register uploaded object key=xiviv85i7y0nmslbngqidpaq7h3bbdm0.ls error="server returned 404: 404 page not found\n"10782026/10/06 19:58:44 WARN Failed to register uploaded object key=nar/1rzyk6awq477j3k50g9hpppj9jgv8z7y5pxgl7dxjzx99y8q7172.nar.zst error="server returned 404: 404 page not found\n"10792026/10/06 19:58:44 WARN Failed to register uploaded object key=fdzjmxizn0hadmqzd4wms3avq3wan7dh.ls error="server returned 404: 404 page not found\n"10802026/10/06 19:58:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10812026/10/06 19:58:44 WARN Failed to register uploaded object key=p6wp94yyrmglcvhcms4lch7m1h8h4n8g.ls error="server returned 404: 404 page not found\n"10822026/10/06 19:58:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10832026/10/06 19:58:44 INFO Signed narinfos id=2 count=210842026/10/06 19:58:44 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10852026/10/06 19:58:44 INFO Signed narinfos id=1 count=210862026/10/06 19:58:44 INFO Uploading 4 narinfos10872026/10/06 19:58:44 WARN Failed to register uploaded object key=p6wp94yyrmglcvhcms4lch7m1h8h4n8g.narinfo error="server returned 404: 404 page not found\n"10882026/10/06 19:58:44 WARN Failed to register uploaded object key=xiviv85i7y0nmslbngqidpaq7h3bbdm0.narinfo error="server returned 404: 404 page not found\n"10892026/10/06 19:58:44 WARN Failed to register uploaded object key=fdzjmxizn0hadmqzd4wms3avq3wan7dh.narinfo error="server returned 404: 404 page not found\n"10902026/10/06 19:58:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10912026/10/06 19:58:44 WARN Failed to register uploaded object key=fdzjmxizn0hadmqzd4wms3avq3wan7dh.narinfo error="server returned 404: 404 page not found\n"10922026/10/06 19:58:44 INFO Completed upload id=110932026/10/06 19:58:44 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10942026/10/06 19:58:44 INFO Completed upload id=210952026/10/06 19:58:44 INFO Upload complete. (287ms)1096=== NAME TestClientFallsBackToClosures1097 client_pushes_test.go:112: Retrieved narinfo from S3:1098 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientFallsBackToClosures3526896840/001/store/fdzjmxizn0hadmqzd4wms3avq3wan7dh-shared-dep1099 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1100 Compression: zstd1101 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821102 NarSize: 1361103 References: 1104 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1105 client_pushes_test.go:112: Retrieved narinfo from S3:1106 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientFallsBackToClosures3526896840/001/store/p6wp94yyrmglcvhcms4lch7m1h8h4n8g-a1107 URL: nar/1rzyk6awq477j3k50g9hpppj9jgv8z7y5pxgl7dxjzx99y8q7172.nar.zst1108 Compression: zstd1109 NarHash: sha256:1rzyk6awq477j3k50g9hpppj9jgv8z7y5pxgl7dxjzx99y8q71721110 NarSize: 2481111 References: /nix/var/nix/builds/nix-57467-1694855006/TestClientFallsBackToClosures3526896840/001/store/fdzjmxizn0hadmqzd4wms3avq3wan7dh-shared-dep1112 CA: text:sha256:1mh7vr092xni14kv946z1ib2bg30jw56j7w6y7dcq8cvjbf5c1z51113 client_pushes_test.go:112: Retrieved narinfo from S3:1114 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientFallsBackToClosures3526896840/001/store/xiviv85i7y0nmslbngqidpaq7h3bbdm0-b1115 URL: nar/1rzyk6awq477j3k50g9hpppj9jgv8z7y5pxgl7dxjzx99y8q7172.nar.zst1116 Compression: zstd1117 NarHash: sha256:1rzyk6awq477j3k50g9hpppj9jgv8z7y5pxgl7dxjzx99y8q71721118 NarSize: 2481119 References: /nix/var/nix/builds/nix-57467-1694855006/TestClientFallsBackToClosures3526896840/001/store/fdzjmxizn0hadmqzd4wms3avq3wan7dh-shared-dep1120 CA: text:sha256:1mh7vr092xni14kv946z1ib2bg30jw56j7w6y7dcq8cvjbf5c1z51121--- PASS: TestClientFallsBackToClosures (2.85s)1122=== CONT TestClientMultipleUploads1123--- PASS: TestMetricsInventory (2.43s)1124=== CONT TestGracefulShutdownDrainsInflight11252026/10/06 19:58:44 INFO Starting HTTP server address=127.0.0.1:6202611262026/10/06 19:58:44 INFO Shutdown signal received, draining in-flight requests timeout=10s1127--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1128=== CONT TestClientIntegration11292026/10/06 19:58:44 INFO Received push request method=POST path=/api/pushes11302026/10/06 19:58:44 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11312026/10/06 19:58:44 INFO Uploading pz46j3nk7sxs2n1shl7ngp36gwd72m9r-b (248B)11322026/10/06 19:58:44 INFO Uploading vjizsigy7f8r9vnnlx2mynhwrkr3mrgg-shared-dep (136B)11332026/10/06 19:58:44 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11342026/10/06 19:58:44 WARN Failed to register uploaded object key=vjizsigy7f8r9vnnlx2mynhwrkr3mrgg.ls error="server returned 404: 404 page not found\n"11352026/10/06 19:58:44 WARN Failed to register uploaded object key=7ypr028qaipdn8r2d2s1mh9s4y8y48q3.ls error="server returned 404: 404 page not found\n"11362026/10/06 19:58:44 WARN Failed to register uploaded object key=pz46j3nk7sxs2n1shl7ngp36gwd72m9r.ls error="server returned 404: 404 page not found\n"11372026/10/06 19:58:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11382026/10/06 19:58:44 WARN Failed to register uploaded object key=nar/1xhyqmd6cidyagldiacmp4pd9ycbb9f5v6j2xzjpm0ajcfbvrngi.nar.zst error="server returned 404: 404 page not found\n"11392026/10/06 19:58:44 INFO Signed narinfos id=1 count=311402026/10/06 19:58:44 INFO Uploading 3 narinfos11412026/10/06 19:58:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11422026/10/06 19:58:44 WARN Failed to register uploaded object key=pz46j3nk7sxs2n1shl7ngp36gwd72m9r.narinfo error="server returned 404: 404 page not found\n"11432026/10/06 19:58:44 WARN Failed to register uploaded object key=7ypr028qaipdn8r2d2s1mh9s4y8y48q3.narinfo error="server returned 404: 404 page not found\n"11442026/10/06 19:58:44 WARN Failed to register uploaded object key=vjizsigy7f8r9vnnlx2mynhwrkr3mrgg.narinfo error="server returned 404: 404 page not found\n"11452026/10/06 19:58:44 INFO Completed push id=11146=== NAME TestPinProtectsFromGC1147 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-57467-1694855006/TestPinProtectsFromGC2305041296/001/store/vd47n37pkzm27sh1hjj4r340d1xfggs5-pinned-file.txt11482026/10/06 19:58:44 INFO Upload complete. (284ms)1149 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-57467-1694855006/TestPinProtectsFromGC2305041296/001/store/6vhv38pgnxj9ldv6pqy76vm1990p979p-unpinned-file.txt1150=== NAME TestClientPushesUseOnePush1151 client_pushes_test.go:97: Retrieved narinfo from S3:1152 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientPushesUseOnePush3030071246/001/store/vjizsigy7f8r9vnnlx2mynhwrkr3mrgg-shared-dep1153 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1154 Compression: zstd1155 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821156 NarSize: 1361157 References: 1158 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1159 client_pushes_test.go:97: Retrieved narinfo from S3:1160 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientPushesUseOnePush3030071246/001/store/7ypr028qaipdn8r2d2s1mh9s4y8y48q3-a1161 URL: nar/1xhyqmd6cidyagldiacmp4pd9ycbb9f5v6j2xzjpm0ajcfbvrngi.nar.zst1162 Compression: zstd1163 NarHash: sha256:1xhyqmd6cidyagldiacmp4pd9ycbb9f5v6j2xzjpm0ajcfbvrngi1164 NarSize: 2481165 References: /nix/var/nix/builds/nix-57467-1694855006/TestClientPushesUseOnePush3030071246/001/store/vjizsigy7f8r9vnnlx2mynhwrkr3mrgg-shared-dep1166 CA: text:sha256:0br1b5blz21ryqfarsvapfi8g6npgp1bbcdp0b8r3ykz28n08gm91167 client_pushes_test.go:97: Retrieved narinfo from S3:1168 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientPushesUseOnePush3030071246/001/store/pz46j3nk7sxs2n1shl7ngp36gwd72m9r-b1169 URL: nar/1xhyqmd6cidyagldiacmp4pd9ycbb9f5v6j2xzjpm0ajcfbvrngi.nar.zst1170 Compression: zstd1171 NarHash: sha256:1xhyqmd6cidyagldiacmp4pd9ycbb9f5v6j2xzjpm0ajcfbvrngi1172 NarSize: 2481173 References: /nix/var/nix/builds/nix-57467-1694855006/TestClientPushesUseOnePush3030071246/001/store/vjizsigy7f8r9vnnlx2mynhwrkr3mrgg-shared-dep1174 CA: text:sha256:0br1b5blz21ryqfarsvapfi8g6npgp1bbcdp0b8r3ykz28n08gm91175--- PASS: TestClientPushesUseOnePush (2.99s)1176=== CONT TestGCTaskStore_Fail1177--- PASS: TestGCTaskStore_Fail (0.00s)1178=== CONT TestClientErrorHandling1179=== RUN TestClientErrorHandling/InvalidStorePath1180=== PAUSE TestClientErrorHandling/InvalidStorePath1181=== RUN TestClientErrorHandling/InvalidAuthToken1182=== PAUSE TestClientErrorHandling/InvalidAuthToken1183=== RUN TestClientErrorHandling/ServerNotAvailable1184=== PAUSE TestClientErrorHandling/ServerNotAvailable1185=== CONT TestGCTaskStore_PhaseUpdates1186--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1187=== CONT TestClientCADerivations1188=== NAME TestNARDeduplicationMetadataUploadBug1189 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-57467-1694855006/TestNARDeduplicationMetadataUploadBug31130497/001/store/hx3j8xn6vsl4dlszr5yhwcsqh6k02ryz-file1.txt11902026/10/06 19:58:45 INFO Received push request method=POST path=/api/pushes11912026/10/06 19:58:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11922026/10/06 19:58:45 INFO Uploading vd47n37pkzm27sh1hjj4r340d1xfggs5-pinned-file.txt (128B)11932026/10/06 19:58:45 WARN Failed to register uploaded object key=vd47n37pkzm27sh1hjj4r340d1xfggs5.ls error="server returned 404: 404 page not found\n"11942026/10/06 19:58:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11952026/10/06 19:58:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11962026/10/06 19:58:45 INFO Signed narinfos id=1 count=111972026/10/06 19:58:45 INFO Uploading 1 narinfos11982026/10/06 19:58:45 INFO Received complete push request method=POST path=/api/pushes/1/complete11992026/10/06 19:58:45 WARN Failed to register uploaded object key=vd47n37pkzm27sh1hjj4r340d1xfggs5.narinfo error="server returned 404: 404 page not found\n"12002026/10/06 19:58:45 INFO Completed push id=112012026/10/06 19:58:45 INFO Upload complete. (281ms)12022026/10/06 19:58:45 INFO Received push request method=POST path=/api/pushes12032026/10/06 19:58:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12042026/10/06 19:58:45 INFO Uploading hx3j8xn6vsl4dlszr5yhwcsqh6k02ryz-file1.txt (160B)12052026/10/06 19:58:45 WARN Failed to register uploaded object key=hx3j8xn6vsl4dlszr5yhwcsqh6k02ryz.ls error="server returned 404: 404 page not found\n"12062026/10/06 19:58:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12072026/10/06 19:58:45 INFO Signed narinfos id=1 count=112082026/10/06 19:58:45 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12092026/10/06 19:58:45 INFO Uploading 1 narinfos12102026/10/06 19:58:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12112026/10/06 19:58:45 WARN Failed to register uploaded object key=hx3j8xn6vsl4dlszr5yhwcsqh6k02ryz.narinfo error="server returned 404: 404 page not found\n"12122026/10/06 19:58:45 INFO Completed push id=112132026/10/06 19:58:45 INFO Upload complete. (216ms)1214 metadata_upload_test.go:54: Retrieved narinfo from S3:1215 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestNARDeduplicationMetadataUploadBug31130497/001/store/hx3j8xn6vsl4dlszr5yhwcsqh6k02ryz-file1.txt1216 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1217 Compression: zstd1218 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1219 NarSize: 1601220 References: 1221 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1222 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1223 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1224 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1225=== NAME TestOrphanedObjectsGCStressTest1226 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains12272026/10/06 19:58:45 INFO Received push request method=POST path=/api/pushes12282026/10/06 19:58:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12292026/10/06 19:58:45 INFO Uploading 6vhv38pgnxj9ldv6pqy76vm1990p979p-unpinned-file.txt (128B)1230 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion12312026/10/06 19:58:45 WARN Failed to register uploaded object key=6vhv38pgnxj9ldv6pqy76vm1990p979p.ls error="server returned 404: 404 page not found\n"12322026/10/06 19:58:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12332026/10/06 19:58:45 INFO Signed narinfos id=2 count=112342026/10/06 19:58:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12352026/10/06 19:58:45 INFO Uploading 1 narinfos1236--- PASS: TestService_healthCheckHandler (1.64s)1237=== CONT TestService_RequireScope_OIDC12382026/10/06 19:58:45 INFO Received complete push request method=POST path=/api/pushes/2/complete12392026/10/06 19:58:45 WARN Failed to register uploaded object key=6vhv38pgnxj9ldv6pqy76vm1990p979p.narinfo error="server returned 404: 404 page not found\n"1240=== NAME TestNARDeduplicationMetadataUploadBug1241 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-57467-1694855006/TestNARDeduplicationMetadataUploadBug31130497/001/store/zivvhj3mmkbk5m33scl4v60i5vl8m96p-file2.txt12422026/10/06 19:58:45 INFO Completed push id=212432026/10/06 19:58:45 INFO Upload complete. (212ms)12442026/10/06 19:58:45 INFO Received push request method=POST path=/api/pushes12452026/10/06 19:58:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62070/oidc12462026/10/06 19:58:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12472026/10/06 19:58:45 INFO Uploading i1qjha8kc2jsb267j4kk8c18n3ywkfcq-shared-dep (136B)12482026/10/06 19:58:45 INFO Uploading xsgi2xpvf2smrgbc7gpg3zrrbhz58vg9-top (256B)12492026/10/06 19:58:45 WARN Failed to register uploaded object key=xsgi2xpvf2smrgbc7gpg3zrrbhz58vg9.ls error="server returned 404: 404 page not found\n"12502026/10/06 19:58:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12512026/10/06 19:58:45 WARN Failed to register uploaded object key=nar/1xmqcg8iagb22ln45kyfbknhx5hj0klnkrfvd2h1graa7qf2fx5i.nar.zst error="server returned 404: 404 page not found\n"12522026/10/06 19:58:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12532026/10/06 19:58:45 WARN Failed to register uploaded object key=i1qjha8kc2jsb267j4kk8c18n3ywkfcq.ls error="server returned 404: 404 page not found\n"12542026/10/06 19:58:45 INFO Signed narinfos id=1 count=212552026/10/06 19:58:45 INFO Uploading 2 narinfos12562026/10/06 19:58:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12572026/10/06 19:58:45 WARN Failed to register uploaded object key=i1qjha8kc2jsb267j4kk8c18n3ywkfcq.narinfo error="server returned 404: 404 page not found\n"12582026/10/06 19:58:45 WARN Failed to register uploaded object key=xsgi2xpvf2smrgbc7gpg3zrrbhz58vg9.narinfo error="server returned 404: 404 page not found\n"12592026/10/06 19:58:45 INFO Completed push id=112602026/10/06 19:58:45 INFO Upload complete. (207ms)1261=== NAME TestClientSharedPathCommittedMidPush1262 client_integration_test.go:680: Retrieved narinfo from S3:1263 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientSharedPathCommittedMidPush4076255260/001/store/i1qjha8kc2jsb267j4kk8c18n3ywkfcq-shared-dep1264 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1265 Compression: zstd1266 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821267 NarSize: 1361268 References: 1269 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1270 client_integration_test.go:680: Retrieved narinfo from S3:1271 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientSharedPathCommittedMidPush4076255260/001/store/xsgi2xpvf2smrgbc7gpg3zrrbhz58vg9-top1272 URL: nar/1xmqcg8iagb22ln45kyfbknhx5hj0klnkrfvd2h1graa7qf2fx5i.nar.zst1273 Compression: zstd1274 NarHash: sha256:1xmqcg8iagb22ln45kyfbknhx5hj0klnkrfvd2h1graa7qf2fx5i1275 NarSize: 2561276 References: /nix/var/nix/builds/nix-57467-1694855006/TestClientSharedPathCommittedMidPush4076255260/001/store/i1qjha8kc2jsb267j4kk8c18n3ywkfcq-shared-dep1277 CA: text:sha256:094n8afqckkfh0cajk5x3pl3ybq395m30rvq4f154mi7jrfp5a2g1278--- PASS: TestClientSharedPathCommittedMidPush (2.81s)1279=== CONT TestCacheStatsHandler12802026/10/06 19:58:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures12812026/10/06 19:58:45 INFO Garbage collection started12822026/10/06 19:58:45 INFO Aborted multipart uploads count=0 kept=012832026/10/06 19:58:45 WARN Force mode enabled - objects will be deleted immediately without grace period12842026/10/06 19:58:45 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=012852026/10/06 19:58:45 INFO Vacuumed table table=pending_closures12862026/10/06 19:58:45 INFO Vacuumed table table=pending_objects12872026/10/06 19:58:45 INFO Vacuumed table table=multipart_uploads12882026/10/06 19:58:45 INFO Vacuumed table table=closures12892026/10/06 19:58:45 INFO Vacuumed table table=objects12902026/10/06 19:58:45 INFO Received push request method=POST path=/api/pushes12912026/10/06 19:58:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12922026/10/06 19:58:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12932026/10/06 19:58:45 INFO Signed narinfos id=2 count=112942026/10/06 19:58:45 INFO Uploading 1 narinfos12952026/10/06 19:58:45 WARN Failed to register uploaded object key=zivvhj3mmkbk5m33scl4v60i5vl8m96p.ls error="server returned 404: 404 page not found\n"12962026/10/06 19:58:45 INFO Received complete push request method=POST path=/api/pushes/2/complete12972026/10/06 19:58:45 WARN Failed to register uploaded object key=zivvhj3mmkbk5m33scl4v60i5vl8m96p.narinfo error="server returned 404: 404 page not found\n"12982026/10/06 19:58:45 INFO Completed push id=212992026/10/06 19:58:45 INFO Upload complete. (265ms)1300=== NAME TestNARDeduplicationMetadataUploadBug1301 metadata_upload_test.go:76: Retrieved narinfo from S3:1302 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestNARDeduplicationMetadataUploadBug31130497/001/store/zivvhj3mmkbk5m33scl4v60i5vl8m96p-file2.txt1303 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1304 Compression: zstd1305 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1306 NarSize: 1601307 References: 1308 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1309 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1310 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1311 {"version":1,"root":{"type":"regular","size":44}}1312--- PASS: TestNARDeduplicationMetadataUploadBug (3.59s)1313=== CONT TestCacheConfigHandler1314=== RUN TestCacheConfigHandler/full_config,_no_issuer1315=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1316=== RUN TestCacheConfigHandler/no_cache_url_configured1317=== PAUSE TestCacheConfigHandler/no_cache_url_configured1318=== RUN TestCacheConfigHandler/no_signing_keys1319=== PAUSE TestCacheConfigHandler/no_signing_keys1320=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1321=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1322=== CONT TestService_ReadScope_PublicByDefault1323=== NAME TestClientMultipleUploads1324 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-57467-1694855006/TestClientMultipleUploads53221289/001/store/z96ymhlyx1sqgn54y0l6r447nw65yb63-test-file-0.txt1325 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-57467-1694855006/TestClientMultipleUploads53221289/001/store/zwg288j352bq3j0pi213a359bbn8cx4a-test-file-1.txt1326=== NAME TestClientIntegration1327 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-57467-1694855006/TestClientIntegration1778330408/002/store/9s4whigxanlwmdz34sgmv3kz4lqs0na4-test-file.txt1328=== NAME TestClientMultipleUploads1329 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-57467-1694855006/TestClientMultipleUploads53221289/001/store/gi62cw33fd21g2n0xbb0vb6i7vp50wrg-test-file-2.txt1330=== RUN TestService_RequireScope_OIDC/builder_may_write1331=== PAUSE TestService_RequireScope_OIDC/builder_may_write1332=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1333=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1334=== RUN TestService_RequireScope_OIDC/ops_may_admin1335=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1336=== RUN TestService_RequireScope_OIDC/ops_may_not_write1337=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1338=== RUN TestService_RequireScope_OIDC/reader_may_not_write1339=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1340=== RUN TestService_RequireScope_OIDC/static_token_may_admin1341=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1342=== RUN TestService_RequireScope_OIDC/static_token_may_write1343=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1344=== RUN TestService_RequireScope_OIDC/reader_may_read1345=== PAUSE TestService_RequireScope_OIDC/reader_may_read1346=== RUN TestService_RequireScope_OIDC/writer_implies_read1347=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1348=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1349=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1350=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1351=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1352=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1353=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1354=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1355=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1356=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1357=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1358=== CONT TestService_AuthMiddleware_OIDC13592026/10/06 19:58:46 INFO Received push request method=POST path=/api/pushes13602026/10/06 19:58:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13612026/10/06 19:58:46 INFO Uploading 9s4whigxanlwmdz34sgmv3kz4lqs0na4-test-file.txt (152B)13622026/10/06 19:58:46 WARN Failed to register uploaded object key=9s4whigxanlwmdz34sgmv3kz4lqs0na4.ls error="server returned 404: 404 page not found\n"13632026/10/06 19:58:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13642026/10/06 19:58:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13652026/10/06 19:58:46 INFO Signed narinfos id=1 count=113662026/10/06 19:58:46 INFO Uploading 1 narinfos13672026/10/06 19:58:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13682026/10/06 19:58:46 WARN Failed to register uploaded object key=9s4whigxanlwmdz34sgmv3kz4lqs0na4.narinfo error="server returned 404: 404 page not found\n"13692026/10/06 19:58:46 INFO Completed push id=113702026/10/06 19:58:46 INFO Upload complete. (202ms)1371--- PASS: TestCacheStatsHandler (0.95s)1372=== CONT TestGCTaskStore_GetEmpty1373--- PASS: TestGCTaskStore_GetEmpty (0.00s)1374=== CONT TestService_ReadAuthMiddleware13752026/10/06 19:58:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62108/oidc13762026/10/06 19:58:46 INFO Received push request method=POST path=/api/pushes13772026/10/06 19:58:46 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13782026/10/06 19:58:46 INFO Uploading z96ymhlyx1sqgn54y0l6r447nw65yb63-test-file-0.txt (160B)13792026/10/06 19:58:46 INFO Uploading zwg288j352bq3j0pi213a359bbn8cx4a-test-file-1.txt (160B)13802026/10/06 19:58:46 INFO Uploading gi62cw33fd21g2n0xbb0vb6i7vp50wrg-test-file-2.txt (160B)13812026/10/06 19:58:46 WARN Failed to register uploaded object key=zwg288j352bq3j0pi213a359bbn8cx4a.ls error="server returned 404: 404 page not found\n"13822026/10/06 19:58:46 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13832026/10/06 19:58:46 WARN Failed to register uploaded object key=gi62cw33fd21g2n0xbb0vb6i7vp50wrg.ls error="server returned 404: 404 page not found\n"13842026/10/06 19:58:46 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13852026/10/06 19:58:46 WARN Failed to register uploaded object key=z96ymhlyx1sqgn54y0l6r447nw65yb63.ls error="server returned 404: 404 page not found\n"13862026/10/06 19:58:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13872026/10/06 19:58:46 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13882026/10/06 19:58:46 INFO Signed narinfos id=1 count=313892026/10/06 19:58:46 INFO Uploading 3 narinfos13902026/10/06 19:58:46 WARN Failed to register uploaded object key=zwg288j352bq3j0pi213a359bbn8cx4a.narinfo error="server returned 404: 404 page not found\n"13912026/10/06 19:58:46 WARN Failed to register uploaded object key=gi62cw33fd21g2n0xbb0vb6i7vp50wrg.narinfo error="server returned 404: 404 page not found\n"13922026/10/06 19:58:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13932026/10/06 19:58:46 WARN Failed to register uploaded object key=z96ymhlyx1sqgn54y0l6r447nw65yb63.narinfo error="server returned 404: 404 page not found\n"13942026/10/06 19:58:46 INFO Completed push id=113952026/10/06 19:58:46 INFO Upload complete. (170ms)1396=== NAME TestClientMultipleUploads1397 client_integration_test.go:369: Uploaded 3 paths in 270.432417ms13982026/10/06 19:58:46 INFO All 1 paths already cached1399=== NAME TestClientIntegration1400 client_integration_test.go:312: Retrieved narinfo from S3:1401 StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientIntegration1778330408/002/store/9s4whigxanlwmdz34sgmv3kz4lqs0na4-test-file.txt1402 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1403 Compression: zstd1404 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11405 NarSize: 1521406 References: 1407 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11408 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1409 client_integration_test.go:313: Decompressed .ls content (64 bytes):1410 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1411 client_integration_test.go:316: Testing garbage collection...1412=== NAME TestClientWithDependencies1413 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-57467-1694855006/TestClientWithDependencies473492656/001/store/piljd9ahpp1izfc1x8z3703a4s5171x1-test-script1414--- PASS: TestClientMultipleUploads (2.29s)1415=== CONT TestGCTaskStore_GetReturnsLatest1416--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1417=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1418--- PASS: TestService_ReadScope_PublicByDefault (0.89s)1419=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection14202026/10/06 19:58:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures14212026/10/06 19:58:46 INFO Garbage collection started14222026/10/06 19:58:46 INFO Aborted multipart uploads count=0 kept=014232026/10/06 19:58:46 WARN Force mode enabled - objects will be deleted immediately without grace period14242026/10/06 19:58:47 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=014252026/10/06 19:58:47 INFO Vacuumed table table=pending_closures1426=== NAME TestClientWithDependencies1427 client_integration_test.go:615: Found 1 dependencies (including self)1428=== NAME TestOrphanedObjectsGCStressTest1429 orphaned_objects_gc_test.go:509: Stress test completed successfully:1430 orphaned_objects_gc_test.go:510: - Active objects preserved: 201431 orphaned_objects_gc_test.go:511: - Objects deleted: 2101432 orphaned_objects_gc_test.go:512: - Total GC'd: 2101433--- PASS: TestOrphanedObjectsGCStressTest (8.18s)1434=== CONT TestService_AuthMiddleware_MTLSProxyHeader14352026/10/06 19:58:47 INFO Vacuumed table table=pending_objects14362026/10/06 19:58:47 INFO Vacuumed table table=multipart_uploads14372026/10/06 19:58:47 INFO Vacuumed table table=closures14382026/10/06 19:58:47 INFO Vacuumed table table=objects14392026/10/06 19:58:47 INFO Received push request method=POST path=/api/pushes14402026/10/06 19:58:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14412026/10/06 19:58:47 INFO Uploading piljd9ahpp1izfc1x8z3703a4s5171x1-test-script (136B)14422026/10/06 19:58:47 WARN Failed to register uploaded object key=piljd9ahpp1izfc1x8z3703a4s5171x1.ls error="server returned 404: 404 page not found\n"14432026/10/06 19:58:47 WARN Failed to register uploaded object key=log/s9w2fj06q805l0qiidiq93sgbzr3hrgr-test-script.drv error="server returned 404: 404 page not found\n"14442026/10/06 19:58:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14452026/10/06 19:58:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14462026/10/06 19:58:47 INFO Signed narinfos id=1 count=114472026/10/06 19:58:47 INFO Uploading 1 narinfos14482026/10/06 19:58:47 INFO Received complete push request method=POST path=/api/pushes/1/complete14492026/10/06 19:58:47 WARN Failed to register uploaded object key=piljd9ahpp1izfc1x8z3703a4s5171x1.narinfo error="server returned 404: 404 page not found\n"14502026/10/06 19:58:47 INFO Completed push id=114512026/10/06 19:58:47 INFO Upload complete. (262ms)1452=== NAME TestClientWithDependencies1453 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-57467-1694855006/TestClientWithDependencies473492656/001/store) requires matching store prefix1454--- PASS: TestClientWithDependencies (4.57s)1455=== CONT TestGCEndsOnShutdown1456=== RUN TestGCEndsOnShutdown/before_the_run1457=== PAUSE TestGCEndsOnShutdown/before_the_run1458=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1459=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1460=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1461=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1462=== CONT TestCommitRacingPendingCleanupKeepsObjects1463=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1464=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1465=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1466=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1467=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1468=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1469=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1470=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1471=== CONT TestPushDedupSurvivesConcurrentGC14722026/10/06 19:58:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01473=== NAME TestClientCADerivations1474 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-57467-1694855006/TestClientCADerivations354086258/001/store/v4a50jjkdqifgwppxpcsfz5lmmc7pglm-ca-test14752026/10/06 19:58:47 INFO Received create pin request method=POST path=/api/pins/myapp14762026/10/06 19:58:47 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-57467-1694855006/TestPinProtectsFromGC2305041296/001/store/vd47n37pkzm27sh1hjj4r340d1xfggs5-pinned-file.txt narinfo_key=vd47n37pkzm27sh1hjj4r340d1xfggs5.narinfo14772026/10/06 19:58:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures14782026/10/06 19:58:47 INFO Garbage collection started14792026/10/06 19:58:47 INFO Aborted multipart uploads count=0 kept=014802026/10/06 19:58:47 WARN Force mode enabled - objects will be deleted immediately without grace period14812026/10/06 19:58:47 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=014822026/10/06 19:58:47 INFO Vacuumed table table=pending_closures14832026/10/06 19:58:47 INFO Vacuumed table table=pending_objects14842026/10/06 19:58:47 INFO Vacuumed table table=multipart_uploads14852026/10/06 19:58:47 INFO Vacuumed table table=closures14862026/10/06 19:58:47 INFO Vacuumed table table=objects1487 client_ca_test.go:139: Found 1 dependencies (including self)1488--- PASS: TestService_ReadAuthMiddleware (1.21s)1489=== CONT TestPushWaitsForSweepHoldingRow14902026/10/06 19:58:48 INFO Received push request method=POST path=/api/pushes14912026/10/06 19:58:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14922026/10/06 19:58:48 WARN mTLS auth: bound subjects configured but subject DN unavailable14932026/10/06 19:58:48 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1494--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.32s)1495=== CONT TestGCSweepDeliversEachKeyOnce14962026/10/06 19:58:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14972026/10/06 19:58:48 INFO Uploading v4a50jjkdqifgwppxpcsfz5lmmc7pglm-ca-test (144B)14982026/10/06 19:58:48 WARN Failed to register uploaded object key=v4a50jjkdqifgwppxpcsfz5lmmc7pglm.ls error="server returned 404: 404 page not found\n"14992026/10/06 19:58:48 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"15002026/10/06 19:58:48 WARN Failed to register uploaded object key=log/acjn3z6lmlxs45axv2g82ikvdcrr8hvl-ca-test.drv error="server returned 404: 404 page not found\n"15012026/10/06 19:58:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15022026/10/06 19:58:48 INFO Signed narinfos id=1 count=115032026/10/06 19:58:48 INFO Uploading 1 narinfos15042026/10/06 19:58:48 INFO Received complete push request method=POST path=/api/pushes/1/complete15052026/10/06 19:58:48 WARN Failed to register uploaded object key=v4a50jjkdqifgwppxpcsfz5lmmc7pglm.narinfo error="server returned 404: 404 page not found\n"15062026/10/06 19:58:48 INFO Completed push id=115072026/10/06 19:58:48 INFO Upload complete. (297ms)1508=== NAME TestClientCADerivations1509 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-57467-1694855006/TestClientCADerivations354086258/001/store/v4a50jjkdqifgwppxpcsfz5lmmc7pglm-ca-test1510 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1511 Compression: zstd1512 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1513 NarSize: 1441514 References: 1515 Deriver: /nix/var/nix/builds/nix-57467-1694855006/TestClientCADerivations354086258/001/store/acjn3z6lmlxs45axv2g82ikvdcrr8hvl-ca-test.drv1516 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1517 client_ca_test.go:185: Checking for realisation files in S3...1518 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1519 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1520 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket51?endpoint=http://localhost:61840®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-57467-1694855006/TestClientCADerivations354086258/001/store'1521 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115222026/10/06 19:58:48 INFO Received uploads request method=POST path=/api/pending_closures1523--- PASS: TestClientCADerivations (3.65s)1524=== CONT TestSweepRechecksPendingAfterLocking1525--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.76s)1526=== CONT TestTombstonedObjectOfferedWithoutWaiting1527--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.58s)1528=== CONT TestGetExistingObjectsLocksRows15292026/10/06 19:58:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01530=== NAME TestClientIntegration1531 client_integration_test.go:323: Objects in database after GC:1532 client_integration_test.go:323: Successfully deleted all objects with GC --force1533--- PASS: TestClientIntegration (4.46s)1534=== CONT TestGCSweepSkipsPendingObjects15352026/10/06 19:58:49 INFO Received uploads request method=POST path=/api/pending_closures15362026/10/06 19:58:49 INFO Aborted multipart uploads count=0 kept=015372026/10/06 19:58:49 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=015382026/10/06 19:58:49 INFO Vacuumed table table=pending_closures15392026/10/06 19:58:49 INFO Vacuumed table table=pending_objects15402026/10/06 19:58:49 INFO Vacuumed table table=multipart_uploads15412026/10/06 19:58:49 INFO Vacuumed table table=closures15422026/10/06 19:58:49 INFO Vacuumed table table=objects15432026/10/06 19:58:49 INFO Aborted multipart uploads count=0 kept=015442026/10/06 19:58:49 WARN Force mode enabled - objects will be deleted immediately without grace period15452026/10/06 19:58:49 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=015462026/10/06 19:58:49 INFO Vacuumed table table=pending_closures15472026/10/06 19:58:49 INFO Vacuumed table table=pending_objects15482026/10/06 19:58:49 INFO Vacuumed table table=multipart_uploads15492026/10/06 19:58:49 INFO Vacuumed table table=closures15502026/10/06 19:58:49 INFO Vacuumed table table=objects1551--- PASS: TestPushDedupSurvivesConcurrentGC (1.88s)1552=== CONT TestRegisterCompletedObjectNeedsPendingRow15532026/10/06 19:58:49 INFO Aborted multipart uploads count=0 kept=015542026/10/06 19:58:49 WARN Force mode enabled - objects will be deleted immediately without grace period15552026/10/06 19:58:49 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=015562026/10/06 19:58:49 INFO Vacuumed table table=pending_closures15572026/10/06 19:58:49 INFO Vacuumed table table=pending_objects15582026/10/06 19:58:49 INFO Vacuumed table table=multipart_uploads15592026/10/06 19:58:49 INFO Vacuumed table table=closures15602026/10/06 19:58:49 INFO Vacuumed table table=objects1561--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.01s)1562=== CONT TestSweepSkipsRowsLockedByPush1563=== NAME TestPinProtectsFromGC1564 client_integration_test.go:840: Pin successfully protected closure from garbage collection15652026/10/06 19:58:49 INFO Received uploads request method=POST path=/api/pending_closures1566--- PASS: TestPinProtectsFromGC (7.69s)1567=== CONT TestDeduplicatedObjectsRecordedAsPending15682026/10/06 19:58:50 INFO Aborted multipart uploads count=0 kept=015692026/10/06 19:58:50 WARN Force mode enabled - objects will be deleted immediately without grace period15702026/10/06 19:58:50 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=015712026/10/06 19:58:50 INFO Vacuumed table table=pending_closures15722026/10/06 19:58:50 INFO Vacuumed table table=pending_objects15732026/10/06 19:58:50 INFO Vacuumed table table=multipart_uploads15742026/10/06 19:58:50 INFO Vacuumed table table=closures15752026/10/06 19:58:50 INFO Vacuumed table table=objects1576--- PASS: TestGCSweepDeliversEachKeyOnce (2.11s)1577=== CONT TestFailedS3DeleteKeepsTombstone1578--- PASS: TestPushWaitsForSweepHoldingRow (2.39s)1579=== CONT TestGCAdvisoryLockBlocksConcurrentRun15802026/10/06 19:58:50 INFO Aborted multipart uploads count=0 kept=015812026/10/06 19:58:50 WARN Force mode enabled - objects will be deleted immediately without grace period15822026/10/06 19:58:50 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 19:58:50 INFO Vacuumed table table=pending_closures15842026/10/06 19:58:50 INFO Vacuumed table table=pending_objects15852026/10/06 19:58:50 INFO Vacuumed table table=multipart_uploads15862026/10/06 19:58:50 INFO Vacuumed table table=closures15872026/10/06 19:58:50 INFO Vacuumed table table=objects1588--- PASS: TestSweepRechecksPendingAfterLocking (2.12s)1589=== CONT TestForceGCDuringPushOffersSweptObject1590=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1591=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1592=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1593=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1594=== CONT TestGCMetrics15952026/10/06 19:58:50 INFO Received uploads request method=POST path=/api/pending_closures1596--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.02s)1597=== CONT TestLeadEndsOnShutdown1598--- PASS: TestGetExistingObjectsLocksRows (2.28s)1599=== CONT TestGCBugBareHashReferences1600--- PASS: TestConcurrentPresentSharingKeysDoNotDeadlock (12.81s)1601=== CONT TestLeadIncumbentAnnouncesAtOnce16022026/10/06 19:58:51 INFO Received uploads request method=POST path=/api/pending_closures16032026/10/06 19:58:51 INFO Aborted multipart uploads count=0 kept=016042026/10/06 19:58:51 WARN Force mode enabled - objects will be deleted immediately without grace period16052026/10/06 19:58:51 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=016062026/10/06 19:58:51 INFO Vacuumed table table=pending_closures16072026/10/06 19:58:51 INFO Vacuumed table table=pending_objects16082026/10/06 19:58:51 INFO Vacuumed table table=multipart_uploads16092026/10/06 19:58:51 INFO Vacuumed table table=closures16102026/10/06 19:58:51 INFO Vacuumed table table=objects1611--- PASS: TestGCSweepSkipsPendingObjects (2.39s)1612=== CONT TestReadRedirectUsesPublicS3URL1613--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.09s)1614=== CONT TestPush_CompleteCommitsEveryRoot16152026/10/06 19:58:51 INFO Aborted multipart uploads count=0 kept=016162026/10/06 19:58:51 WARN Force mode enabled - objects will be deleted immediately without grace period16172026/10/06 19:58:51 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=016182026/10/06 19:58:51 INFO Vacuumed table table=pending_closures16192026/10/06 19:58:51 INFO Vacuumed table table=pending_objects16202026/10/06 19:58:51 INFO Vacuumed table table=multipart_uploads16212026/10/06 19:58:51 INFO Vacuumed table table=closures16222026/10/06 19:58:51 INFO Vacuumed table table=objects16232026/10/06 19:58:51 INFO Aborted multipart uploads count=0 kept=016242026/10/06 19:58:51 WARN Force mode enabled - objects will be deleted immediately without grace period16252026/10/06 19:58:51 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=016262026/10/06 19:58:51 INFO Vacuumed table table=pending_closures16272026/10/06 19:58:51 INFO Vacuumed table table=pending_objects16282026/10/06 19:58:51 INFO Vacuumed table table=multipart_uploads16292026/10/06 19:58:51 INFO Vacuumed table table=closures16302026/10/06 19:58:51 INFO Vacuumed table table=objects1631--- PASS: TestSweepSkipsRowsLockedByPush (2.38s)1632=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16332026/10/06 19:58:52 INFO Received uploads request method=POST path=/api/pending_closures1634--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.45s)1635=== CONT TestRedundantMultipartUpload16362026/10/06 19:58:52 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld13 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1637--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.34s)1638=== CONT TestPush_SignsNarinfosOfItsPendingObjects16392026/10/06 19:58:52 INFO Received uploads request method=POST path=/api/pending_closures16402026/10/06 19:58:52 INFO Aborted multipart uploads count=0 kept=016412026/10/06 19:58:52 WARN Force mode enabled - objects will be deleted immediately without grace period16422026/10/06 19:58:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16432026/10/06 19:58:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1644--- PASS: TestFailedS3DeleteKeepsTombstone (2.80s)1645=== CONT TestCompletedNarNotReofferedAcrossClosures16462026/10/06 19:58:53 INFO Aborted multipart uploads count=0 kept=016472026/10/06 19:58:53 WARN Force mode enabled - objects will be deleted immediately without grace period16482026/10/06 19:58:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016492026/10/06 19:58:53 INFO Vacuumed table table=pending_closures16502026/10/06 19:58:53 INFO Vacuumed table table=pending_objects16512026/10/06 19:58:53 INFO Vacuumed table table=multipart_uploads16522026/10/06 19:58:53 INFO Vacuumed table table=closures16532026/10/06 19:58:53 INFO Vacuumed table table=objects1654--- PASS: TestGCMetrics (2.67s)1655=== CONT TestGCTaskStore_ConflictDifferentParams1656--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1657=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16582026/10/06 19:58:53 INFO lead: acquired remote=192.0.2.1:123416592026/10/06 19:58:53 INFO lead: acquired remote=192.0.2.1:123416602026/10/06 19:58:53 INFO lead: released remote=192.0.2.1:12341661--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.84s)1662=== CONT TestReadProxyRangeRequest1663--- PASS: TestGCBugBareHashReferences (3.01s)1664=== CONT TestPush_RejectsBadRequests1665--- PASS: TestReadRedirectUsesPublicS3URL (2.69s)1666=== CONT TestGCTaskStore_DeduplicateSameParams1667--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1668=== CONT TestReadRedirectKeepsNarinfoProxied16692026/10/06 19:58:54 INFO Received push request method=POST path=/api/pushes16702026/10/06 19:58:54 INFO Received complete push request method=POST path=/api/pushes/1/complete16712026/10/06 19:58:54 INFO Completed push id=11672--- PASS: TestPush_CompleteCommitsEveryRoot (2.81s)1673=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16742026/10/06 19:58:54 INFO Received request for more parts method=POST path=/1675=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16762026/10/06 19:58:54 INFO Received uploads request method=POST path=/1677=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16782026/10/06 19:58:54 INFO Received complete multipart upload request method=POST path=/1679=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16802026/10/06 19:58:54 INFO Received uploads request method=POST path=/16812026/10/06 19:58:54 INFO Received push request method=POST path=/api/pushes16822026/10/06 19:58:54 INFO lead: released remote=192.0.2.1:12341683--- PASS: TestLeadEndsOnShutdown (3.85s)1684=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16852026/10/06 19:58:54 INFO Received complete multipart upload request method=POST path=/1686=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16872026/10/06 19:58:54 INFO Received request for more parts method=POST path=/1688=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16892026/10/06 19:58:54 INFO Received uploads request method=POST path=/1690=== CONT TestIsValidUploadKey/narinfo1691=== CONT TestIsValidUploadKey/traversal_nar1692=== CONT TestIsValidUploadKey/traversal1693=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1694=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1695=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1696--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1697 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1698 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1699 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1700 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1701=== CONT TestIsValidUploadKey/index.html1702=== CONT TestIsValidUploadKey/nix-cache-info1703=== CONT TestIsValidUploadKey/realisation_plus_in_output1704=== CONT TestIsValidUploadKey/realisation1705=== CONT TestIsValidUploadKey/build_log_equals1706=== CONT TestIsValidUploadKey/build_log_question_mark1707=== CONT TestIsValidUploadKey/build_log_plus_in_name1708=== CONT TestIsValidUploadKey/build_log_home-manager_file1709=== CONT TestIsValidUploadKey/build_log1710=== CONT TestIsValidUploadKey/listing1711=== CONT TestIsValidUploadKey/nar_plain1712=== CONT TestIsValidUploadKey/nar_xz1713=== CONT TestIsValidUploadKey/nar_zst1714=== CONT TestIsValidUploadKey/unknown_type1715=== CONT TestIsValidUploadKey/absolute1716=== CONT TestIsValidUploadKey/empty_key1717--- PASS: TestIsValidUploadKey (0.00s)1718 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1719 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1720 --- PASS: TestIsValidUploadKey/traversal (0.00s)1721 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1722 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1723 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1724 --- PASS: TestIsValidUploadKey/index.html (0.00s)1725 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1726 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1727 --- PASS: TestIsValidUploadKey/realisation (0.00s)1728 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1729 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1730 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1731 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log (0.00s)1733 --- PASS: TestIsValidUploadKey/listing (0.00s)1734 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1735 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1736 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1737 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1738 --- PASS: TestIsValidUploadKey/absolute (0.00s)1739 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1740=== CONT TestPendingClosureWriteTimeout/empty1741=== CONT TestPendingClosureWriteTimeout/670k_objects1742=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1743--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.59s)1744=== CONT TestPendingClosureWriteTimeout/400_objects1745=== CONT TestProxyWriteTimeout/narinfo1746=== CONT TestProxyWriteTimeout/10_GiB_nar1747=== CONT TestProxyWriteTimeout/unknown_size1748=== CONT TestProxyWriteTimeout/1_GiB_nar1749--- PASS: TestProxyWriteTimeout (0.00s)1750 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1751 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1752 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1753 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1754=== CONT TestIsValidCachePath/narinfo1755=== CONT TestIsValidCachePath/index.html1756=== CONT TestIsValidCachePath/nix-cache-info1757=== CONT TestIsValidCachePath/realisation1758=== CONT TestIsValidCachePath/log1759=== CONT TestIsValidCachePath/ls1760=== CONT TestIsValidCachePath/nar_uncompressed1761=== CONT TestIsValidCachePath/nar_bz21762=== CONT TestIsValidCachePath/nar_xz1763=== CONT TestIsValidCachePath/nar_zst1764=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1765=== CONT TestIsValidCachePath/traversal_parent1766=== CONT TestIsValidCachePath/empty1767=== CONT TestIsValidCachePath/random_path1768=== CONT TestIsValidCachePath/invalid_char_u1769=== CONT TestIsValidCachePath/invalid_char_e1770=== CONT TestIsValidCachePath/traversal_in_middle1771=== CONT TestIsValidCachePath/wrong_extension1772=== CONT TestIsValidCachePath/short_hash1773=== CONT TestIsValidCachePath/leading_slash1774--- PASS: TestIsValidCachePath (0.00s)1775 --- PASS: TestIsValidCachePath/narinfo (0.00s)1776 --- PASS: TestIsValidCachePath/index.html (0.00s)1777 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1778 --- PASS: TestIsValidCachePath/realisation (0.00s)1779 --- PASS: TestIsValidCachePath/log (0.00s)1780 --- PASS: TestIsValidCachePath/ls (0.00s)1781 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1782 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1783 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1784 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1785 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1786 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1787 --- PASS: TestIsValidCachePath/empty (0.00s)1788 --- PASS: TestIsValidCachePath/random_path (0.00s)1789 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1790 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1791 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1792 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1793 --- PASS: TestIsValidCachePath/short_hash (0.00s)1794 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1795=== CONT TestParseSingleRange/none1796=== CONT TestParseSingleRange/open-ended1797=== CONT TestParseSingleRange/start_far_past_EOF1798=== CONT TestParseSingleRange/start_past_EOF1799=== CONT TestParseSingleRange/single_byte1800=== CONT TestParseSingleRange/suffix_exceeds_size1801=== CONT TestParseSingleRange/suffix1802=== CONT TestParseSingleRange/end_clamped_to_size1803=== CONT TestParseSingleRange/malformed_both_empty1804=== CONT TestParseSingleRange/closed1805=== CONT TestParseSingleRange/malformed_end_before_start1806=== CONT TestParseSingleRange/multi-range_ignored1807=== CONT TestParseSingleRange/malformed_no_dash1808=== CONT TestParseSingleRange/unknown_unit1809--- PASS: TestParseSingleRange (0.00s)1810 --- PASS: TestParseSingleRange/none (0.00s)1811 --- PASS: TestParseSingleRange/open-ended (0.00s)1812 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1813 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1814 --- PASS: TestParseSingleRange/single_byte (0.00s)1815 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1816 --- PASS: TestParseSingleRange/suffix (0.00s)1817 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1818 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1819 --- PASS: TestParseSingleRange/closed (0.00s)1820 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1821 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1822 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1823 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1824=== CONT TestResolveDBConnectionString/flag_wins1825=== CONT TestResolveDBConnectionString/missing_file_is_an_error1826=== CONT TestResolveDBConnectionString/file_when_flag_empty1827=== CONT TestResolveDBConnectionString/nothing_configured1828=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1829--- PASS: TestResolveDBConnectionString (0.00s)1830 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1831 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1832 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1833 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1834 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1835=== CONT TestServerTLSConfig/no_client_CA1836=== CONT TestServerTLSConfig/not_a_PEM_file1837=== CONT TestServerTLSConfig/missing_CA_file1838--- PASS: TestServerTLSConfig (0.00s)1839 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1840 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1841 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1842=== CONT TestClientErrorHandling/InvalidStorePath18432026/10/06 19:58:54 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/06 19:58:54 INFO Received uploads request method=POST path=/api/pending_closures18452026/10/06 19:58:54 INFO Received push request method=POST path=/api/pushes18462026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18472026/10/06 19:58:55 INFO Signed narinfos id=1 count=118482026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18492026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18502026/10/06 19:58:55 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"18512026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18522026/10/06 19:58:55 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"18532026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18542026/10/06 19:58:55 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=118552026/10/06 19:58:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18562026/10/06 19:58:55 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1857--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.47s)1858=== CONT TestClientErrorHandling/ServerNotAvailable18592026/10/06 19:58:55 INFO Received uploads request method=POST path=/api/pending_closures18602026/10/06 19:58:55 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/present18612026/10/06 19:58:55 INFO Received uploads request method=POST path=/api/pending_closures18622026/10/06 19:58:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.01166ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18632026/10/06 19:58:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.057523ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1864--- PASS: TestReadProxyRangeRequest (1.98s)1865=== CONT TestClientErrorHandling/InvalidAuthToken18662026/10/06 19:58:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18672026/10/06 19:58:55 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLmRmZTBjNDgxLTRlYmUtNDg2Ny04ZWQyLWFmYjIyMDY3ZDc0ZHgxNzkxMzE2NzM1NTI3MDM0MDAw18682026/10/06 19:58:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLmRmZTBjNDgxLTRlYmUtNDg2Ny04ZWQyLWFmYjIyMDY3ZDc0ZHgxNzkxMzE2NzM1NTI3MDM0MDAw parts=11869--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.70s)1870=== CONT TestCacheConfigHandler/full_config,_no_issuer1871=== CONT TestCacheConfigHandler/no_signing_keys1872=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1873=== CONT TestCacheConfigHandler/no_cache_url_configured1874--- PASS: TestCacheConfigHandler (0.00s)1875 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1876 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1877 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1878 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1879=== CONT TestService_RequireScope_OIDC/builder_may_write1880=== CONT TestService_RequireScope_OIDC/reader_may_read1881=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1882=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18832026/10/06 19:58:55 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]1884=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1885=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1886=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1887=== CONT TestService_RequireScope_OIDC/writer_implies_read1888=== CONT TestService_RequireScope_OIDC/reader_may_not_write1889=== CONT TestService_RequireScope_OIDC/static_token_may_write1890=== CONT TestService_RequireScope_OIDC/static_token_may_admin1891=== CONT TestService_RequireScope_OIDC/ops_may_admin1892=== CONT TestService_RequireScope_OIDC/ops_may_not_write1893=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1894=== CONT TestGCEndsOnShutdown/before_the_run1895--- PASS: TestService_RequireScope_OIDC (0.95s)1896 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1901 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1902 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1903 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1904 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1905 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1906 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1907 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1908 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1909 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1910=== RUN TestPush_RejectsBadRequests/bad_root1911=== PAUSE TestPush_RejectsBadRequests/bad_root1912=== RUN TestPush_RejectsBadRequests/root_not_in_objects1913=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1914=== RUN TestPush_RejectsBadRequests/no_roots1915=== PAUSE TestPush_RejectsBadRequests/no_roots1916=== RUN TestPush_RejectsBadRequests/no_objects1917=== PAUSE TestPush_RejectsBadRequests/no_objects1918=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19192026/10/06 19:58:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=844.029669ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19202026/10/06 19:58:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19212026/10/06 19:58:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLjM1ODVkYzQ4LTEyZWUtNDE2Yi04NzY3LTYwNDZlYjllNzFiNXgxNzkxMzE2NzM0Njc3OTAxMDAw parts=1219222026/10/06 19:58:56 INFO Received uploads request method=POST path=/api/pending_closures1923--- PASS: TestReadRedirectKeepsNarinfoProxied (2.37s)1924=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19252026/10/06 19:58:56 INFO Received uploads request method=POST path=/api/pending_closures1926--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1927 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1928 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1929 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (2.28s)1930=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1931=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19322026/10/06 19:58:56 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]1933=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1934=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19352026/10/06 19:58:56 WARN Authentication failed token_preview=eyJhbGciOi...ImxvtVn7gw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1936=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1937--- PASS: TestService_AuthMiddleware_OIDC (1.11s)1938 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1939 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1940 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19422026/10/06 19:58:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19432026/10/06 19:58:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.700946525s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1944=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19452026/10/06 19:58:56 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLjI5NTU1NzQ3LTYxNTEtNDcxNS05M2FjLWNkODJjZjU2ODFkNHgxNzkxMzE2NzM1MjQxMzIzMDAw parts=1219462026/10/06 19:58:56 INFO Received uploads request method=POST path=/api/pending_closures1947--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.98s)1948=== CONT TestPush_RejectsBadRequests/bad_root19492026/10/06 19:58:56 INFO Received push request method=POST path=/api/pushes1950=== CONT TestPush_RejectsBadRequests/no_roots19512026/10/06 19:58:56 INFO Received push request method=POST path=/api/pushes1952=== CONT TestPush_RejectsBadRequests/no_objects19532026/10/06 19:58:56 INFO Received push request method=POST path=/api/pushes1954=== CONT TestPush_RejectsBadRequests/root_not_in_objects19552026/10/06 19:58:56 INFO Received push request method=POST path=/api/pushes1956--- PASS: TestPush_RejectsBadRequests (2.18s)1957 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1958 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1959 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1960 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)19612026/10/06 19:58:57 INFO Received uploads request method=POST path=/api/pending_closures19622026/10/06 19:58:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19632026/10/06 19:58:57 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLmU1YjgxMGFiLWFkYWQtNGZlMy04MzgwLTQ2N2IwYjNmNzA0NngxNzkxMzE2NzM2NDkwNjUyMDAw error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19642026/10/06 19:58:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTEwYTNiZGMtYWI0Ni00NDVkLTlhY2MtMjRjZGI0M2JkNDEyLjAyNDdlOTdkLWNkOWItNDUxMy1hMDI0LWE3OGJlZjI0MWM3ZngxNzkxMzE2NzM2NDU1NDk2MDAw parts=1219652026/10/06 19:58:57 INFO Received cleanup request method=DELETE path=/api/pending_closures19662026/10/06 19:58:57 INFO Aborted multipart uploads count=1 kept=01967--- PASS: TestRedundantMultipartUpload (5.73s)1968--- PASS: TestPendingClosureWriteTimeout (0.00s)1969 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1970 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1971 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1972 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.54s)19732026/10/06 19:58:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19742026/10/06 19:58:58 INFO Aborted multipart uploads count=0 kept=019752026/10/06 19:58:58 WARN Force mode enabled - objects will be deleted immediately without grace period19762026-10-06 19:58:58.146 UTC [60294] ERROR: canceling statement due to user request19772026-10-06 19:58:58.146 UTC [60294] STATEMENT: -- name: MarkStaleObjects :execrows1978 WITH RECURSIVE ct AS (1979 SELECT timezone('UTC', now()) AS now1980 ),1981 closure_reach AS (1982 -- Start with all closure keys1983 SELECT o.key, o.refs1984 FROM objects o1985 INNER JOIN closures c ON o.key = c.key1986 UNION1987 -- Recursively add all referenced objects1988 SELECT o.key, o.refs1989 FROM objects o1990 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1991 ),1992 reachable_objects AS (1993 SELECT DISTINCT key FROM closure_reach1994 ),1995 stale_objects AS (1996 SELECT o.key1997 FROM objects AS o, ct1998 WHERE1999 NOT EXISTS (2000 SELECT 12001 FROM reachable_objects ro2002 WHERE ro.key = o.key2003 )2004 AND NOT EXISTS (2005 SELECT 12006 FROM pending_objects AS po2007 WHERE po.key = o.key2008 )2009 AND o.deleted_at IS NULL -- Only mark fresh objects2010 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2011 FOR UPDATE2012 )2013 UPDATE objects2014 SET2015 deleted_at = ct.now,2016 first_deleted_at = COALESCE(first_deleted_at, ct.now)2017 FROM stale_objects, ct2018 WHERE objects.key = stale_objects.key2019 20202026/10/06 19:58:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20212026/10/06 19:58:58 INFO Aborted multipart uploads count=0 kept=020222026/10/06 19:58:58 WARN Force mode enabled - objects will be deleted immediately without grace period20232026/10/06 19:58:58 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:61840/bucket92/?delete=\": context canceled"2024--- PASS: TestGCEndsOnShutdown (0.00s)2025 --- PASS: TestGCEndsOnShutdown/before_the_run (2.06s)2026 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.05s)2027 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.83s)20282026/10/06 19:58:58 INFO Received uploads request method=POST path=/api/pending_closures20292026/10/06 19:58:58 INFO Aborted multipart uploads count=0 kept=020302026/10/06 19:58:58 WARN Force mode enabled - objects will be deleted immediately without grace period20312026/10/06 19:58:58 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=020322026/10/06 19:58:58 INFO Vacuumed table table=pending_closures20332026/10/06 19:58:58 INFO Vacuumed table table=pending_objects20342026/10/06 19:58:58 INFO Vacuumed table table=multipart_uploads20352026/10/06 19:58:58 INFO Vacuumed table table=closures20362026/10/06 19:58:58 INFO Vacuumed table table=objects20372026/10/06 19:58:58 INFO Received uploads request method=POST path=/api/pending_closures20382026/10/06 19:58:58 INFO Aborted multipart uploads count=0 kept=020392026/10/06 19:58:58 WARN Force mode enabled - objects will be deleted immediately without grace period20402026/10/06 19:58:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020412026/10/06 19:58:58 INFO Vacuumed table table=pending_closures20422026/10/06 19:58:58 INFO Vacuumed table table=pending_objects20432026/10/06 19:58:58 INFO Vacuumed table table=multipart_uploads20442026/10/06 19:58:58 INFO Vacuumed table table=closures20452026/10/06 19:58:58 INFO Vacuumed table table=objects2046--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2047 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.86s)2048 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.76s)20492026/10/06 19:58:58 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-config20502026/10/06 19:58:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.178411ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20512026/10/06 19:58:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=406.265058ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/06 19:58:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=750.099044ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/06 19:59:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.614533073s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20542026/10/06 19:59:01 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"20552026/10/06 19:59:01 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-config20562026/10/06 19:59:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=185.598629ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/06 19:59:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.904791ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/06 19:59:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.153695ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20592026/10/06 19:59:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.505052555s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20602026/10/06 19:59:04 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_closures20612026/10/06 19:59:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=210.448381ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20622026/10/06 19:59:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=428.366528ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20632026/10/06 19:59:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=828.160737ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20642026/10/06 19:59:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.70190392s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2065--- PASS: TestClientErrorHandling (0.00s)2066 --- PASS: TestClientErrorHandling/InvalidStorePath (2.44s)2067 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.39s)2068 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.16s)2069PASS20702026-10-06 19:59:08.690 UTC [57954] LOG: received smart shutdown request20712026-10-06 19:59:08.691 UTC [57954] LOG: background worker "logical replication launcher" (PID 57966) exited with exit code 120722026-10-06 19:59:08.702 UTC [57960] LOG: shutting down20732026-10-06 19:59:08.702 UTC [57960] LOG: checkpoint starting: shutdown immediate20742026-10-06 19:59:15.080 UTC [57960] LOG: checkpoint complete: wrote 12851 buffers (78.4%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.976 s, sync=5.354 s, total=6.378 s; sync files=32010, longest=0.109 s, average=0.001 s; distance=461095 kB, estimate=461095 kB; lsn=0/1D9D6DF8, redo lsn=0/1D9D6DF820752026-10-06 19:59:15.091 UTC [57954] LOG: database system is shut down2076Running OIDC tests...2077=== RUN TestAudienceForIssuer2078=== PAUSE TestAudienceForIssuer2079=== RUN TestGlobMatch2080=== PAUSE TestGlobMatch2081=== RUN TestValidateToken_ValidToken2082=== PAUSE TestValidateToken_ValidToken2083=== RUN TestValidateToken_WrongAudience2084=== PAUSE TestValidateToken_WrongAudience2085=== RUN TestValidateToken_Expired2086=== PAUSE TestValidateToken_Expired2087=== RUN TestValidateToken_BoundClaimsMismatch2088=== PAUSE TestValidateToken_BoundClaimsMismatch2089=== RUN TestValidateToken_BoundSubjectMismatch2090=== PAUSE TestValidateToken_BoundSubjectMismatch2091=== RUN TestValidateToken_MultipleProviders2092=== PAUSE TestValidateToken_MultipleProviders2093=== RUN TestValidateToken_NoMatchingProvider2094=== PAUSE TestValidateToken_NoMatchingProvider2095=== RUN TestValidateToken_KubernetesServiceAccount2096=== PAUSE TestValidateToken_KubernetesServiceAccount2097=== RUN TestNewValidator_KubernetesRequiresCA2098=== PAUSE TestNewValidator_KubernetesRequiresCA2099=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2100=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2101=== RUN TestPins_ReservedForMatchingRule2102=== PAUSE TestPins_ReservedForMatchingRule2103=== RUN TestPins_TopLevelShorthand2104=== PAUSE TestPins_TopLevelShorthand2105=== RUN TestPins_ConfigValidation2106=== PAUSE TestPins_ConfigValidation2107=== RUN TestScopes_LegacyProviderDefaultsToWrite2108=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2109=== RUN TestScopes_Rules2110=== PAUSE TestScopes_Rules2111=== RUN TestScopes_ConfigValidation2112=== PAUSE TestScopes_ConfigValidation2113=== CONT TestAudienceForIssuer2114--- PASS: TestAudienceForIssuer (0.00s)2115=== CONT TestValidateToken_NoMatchingProvider2116=== CONT TestValidateToken_Expired2117=== CONT TestValidateToken_KubernetesServiceAccount2118=== CONT TestValidateToken_BoundSubjectMismatch2119=== CONT TestPins_ConfigValidation2120=== CONT TestValidateToken_ValidToken2121=== CONT TestValidateToken_WrongAudience2122=== CONT TestGlobMatch2123=== RUN TestGlobMatch/foo_foo2124=== PAUSE TestGlobMatch/foo_foo2125=== CONT TestPins_ReservedForMatchingRule2126=== RUN TestGlobMatch/foo_bar2127=== PAUSE TestGlobMatch/foo_bar2128=== RUN TestGlobMatch/*_2129=== PAUSE TestGlobMatch/*_2130=== RUN TestGlobMatch/*_anything2131=== PAUSE TestGlobMatch/*_anything2132=== CONT TestScopes_Rules2133=== RUN TestGlobMatch/foo*_foo2134=== PAUSE TestGlobMatch/foo*_foo2135=== RUN TestGlobMatch/foo*_foobar2136=== PAUSE TestGlobMatch/foo*_foobar2137=== RUN TestGlobMatch/foo*_bar2138=== PAUSE TestGlobMatch/foo*_bar2139=== RUN TestGlobMatch/*bar_bar2140=== PAUSE TestGlobMatch/*bar_bar2141=== RUN TestGlobMatch/*bar_foobar2142=== PAUSE TestGlobMatch/*bar_foobar2143=== RUN TestGlobMatch/*bar_foo2144=== PAUSE TestGlobMatch/*bar_foo2145=== RUN TestGlobMatch/foo*bar_foobar2146=== PAUSE TestGlobMatch/foo*bar_foobar2147=== RUN TestGlobMatch/foo*bar_foo123bar2148=== PAUSE TestGlobMatch/foo*bar_foo123bar2149=== RUN TestGlobMatch/foo*bar_foobarbaz2150=== PAUSE TestGlobMatch/foo*bar_foobarbaz2151=== RUN TestGlobMatch/*/*_foo/bar2152=== PAUSE TestGlobMatch/*/*_foo/bar2153=== RUN TestGlobMatch/*/*_foo2154=== PAUSE TestGlobMatch/*/*_foo2155=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2156=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2157=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02158=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02159=== RUN TestGlobMatch/refs/*/main_refs/heads/main2160=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2161=== RUN TestGlobMatch/fo?_foo2162=== PAUSE TestGlobMatch/fo?_foo2163=== RUN TestGlobMatch/fo?_fo2164=== PAUSE TestGlobMatch/fo?_fo2165=== RUN TestGlobMatch/fo?_fooo2166=== PAUSE TestGlobMatch/fo?_fooo2167=== RUN TestGlobMatch/?oo_foo2168=== PAUSE TestGlobMatch/?oo_foo2169=== RUN TestGlobMatch/?oo_boo2170=== PAUSE TestGlobMatch/?oo_boo2171=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2172=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2173=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2174=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2175=== CONT TestScopes_ConfigValidation2176--- PASS: TestScopes_ConfigValidation (0.00s)2177=== CONT TestValidateToken_BoundClaimsMismatch2178--- PASS: TestPins_ConfigValidation (0.00s)2179=== CONT TestPins_TopLevelShorthand21802026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62314/oidc21812026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62315/oidc21822026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62318/oidc2183--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2184=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2185--- PASS: TestValidateToken_BoundSubjectMismatch (0.06s)2186=== CONT TestValidateToken_MultipleProviders2187--- PASS: TestScopes_Rules (0.06s)2188=== CONT TestNewValidator_KubernetesRequiresCA21892026/10/06 19:59:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232190--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.20s)2191=== CONT TestScopes_LegacyProviderDefaultsToWrite21922026/10/06 19:59:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:623222193--- PASS: TestValidateToken_KubernetesServiceAccount (0.28s)2194=== CONT TestGlobMatch/foo_foo2195=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2196=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2197=== CONT TestGlobMatch/?oo_boo2198=== CONT TestGlobMatch/?oo_foo2199=== CONT TestGlobMatch/fo?_fooo2200=== CONT TestGlobMatch/fo?_fo2201=== CONT TestGlobMatch/fo?_foo2202=== CONT TestGlobMatch/refs/*/main_refs/heads/main2203=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02204=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2205=== CONT TestGlobMatch/*/*_foo2206=== CONT TestGlobMatch/*/*_foo/bar2207=== CONT TestGlobMatch/foo*bar_foobarbaz2208=== CONT TestGlobMatch/foo*bar_foo123bar2209=== CONT TestGlobMatch/foo*bar_foobar2210=== CONT TestGlobMatch/*bar_foo2211=== CONT TestGlobMatch/*bar_foobar2212=== CONT TestGlobMatch/*bar_bar2213=== CONT TestGlobMatch/foo*_bar2214=== CONT TestGlobMatch/foo*_foobar2215=== CONT TestGlobMatch/foo*_foo2216=== CONT TestGlobMatch/*_anything2217=== CONT TestGlobMatch/*_2218=== CONT TestGlobMatch/foo_bar2219--- PASS: TestGlobMatch (0.00s)2220 --- PASS: TestGlobMatch/foo_foo (0.00s)2221 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2222 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2223 --- PASS: TestGlobMatch/?oo_boo (0.00s)2224 --- PASS: TestGlobMatch/?oo_foo (0.00s)2225 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2226 --- PASS: TestGlobMatch/fo?_fo (0.00s)2227 --- PASS: TestGlobMatch/fo?_foo (0.00s)2228 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2229 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2230 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2231 --- PASS: TestGlobMatch/*/*_foo (0.00s)2232 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2233 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2234 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2235 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2236 --- PASS: TestGlobMatch/*bar_foo (0.00s)2237 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2238 --- PASS: TestGlobMatch/*bar_bar (0.00s)2239 --- PASS: TestGlobMatch/foo*_bar (0.00s)2240 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2241 --- PASS: TestGlobMatch/foo*_foo (0.00s)2242 --- PASS: TestGlobMatch/*_anything (0.00s)2243 --- PASS: TestGlobMatch/*_ (0.00s)2244 --- PASS: TestGlobMatch/foo_bar (0.00s)22452026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62324/oidc2246--- PASS: TestPins_TopLevelShorthand (0.44s)22472026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62328/oidc2248--- PASS: TestValidateToken_WrongAudience (0.45s)22492026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62332/oidc2250--- PASS: TestValidateToken_ValidToken (0.60s)22512026/10/06 19:59:20 http: TLS handshake error from 127.0.0.1:62331: remote error: tls: bad certificate2252--- PASS: TestNewValidator_KubernetesRequiresCA (0.54s)22532026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62334/oidc2254--- PASS: TestValidateToken_Expired (0.65s)22552026/10/06 19:59:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62327/oidc2256--- PASS: TestValidateToken_NoMatchingProvider (0.67s)22572026/10/06 19:59:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62338/oidc2258--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.44s)22592026/10/06 19:59:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62340/oidc2260--- PASS: TestPins_ReservedForMatchingRule (1.08s)22612026/10/06 19:59:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62326/oidc22622026/10/06 19:59:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62342/oidc2263--- PASS: TestValidateToken_MultipleProviders (1.07s)2264PASS2265Running hook tests...2266=== RUN TestSendPathsEmpty2267=== PAUSE TestSendPathsEmpty2268=== RUN TestQueueEnqueueAndFetch2269=== PAUSE TestQueueEnqueueAndFetch2270=== RUN TestQueueDeduplication2271=== PAUSE TestQueueDeduplication2272=== RUN TestQueueRemove2273=== PAUSE TestQueueRemove2274=== RUN TestQueueFetchBatchLimit2275=== PAUSE TestQueueFetchBatchLimit2276=== RUN TestQueueRetryMovesToBack2277=== PAUSE TestQueueRetryMovesToBack2278=== RUN TestQueueFetchRemoveLifecycle2279=== PAUSE TestQueueFetchRemoveLifecycle2280=== RUN TestQueueConcurrentWriters2281=== PAUSE TestQueueConcurrentWriters2282=== RUN TestQueueRemoveLargeClosure2283=== PAUSE TestQueueRemoveLargeClosure2284=== RUN TestServerClientIntegration2285=== PAUSE TestServerClientIntegration2286=== RUN TestServerQueueError2287=== PAUSE TestServerQueueError2288=== RUN TestGetListenerSocketActivation2289 server_test.go:210: === RUN TestGetListenerSocketActivation2290 --- PASS: TestGetListenerSocketActivation (0.00s)2291 PASS2292 2293--- PASS: TestGetListenerSocketActivation (0.02s)2294=== RUN TestDrainIsolatesPoisonPath2295=== PAUSE TestDrainIsolatesPoisonPath2296=== RUN TestRunNotBlockedByPoisonHead2297=== PAUSE TestRunNotBlockedByPoisonHead2298=== RUN TestDrainGivesUpWhenServerDown2299=== PAUSE TestDrainGivesUpWhenServerDown2300=== RUN TestFailedPathPrunedByLaterClosure2301=== PAUSE TestFailedPathPrunedByLaterClosure2302=== RUN TestWorkerUploadsAndRemoves2303=== PAUSE TestWorkerUploadsAndRemoves2304=== RUN TestWorkerSkipsGCdPaths2305=== PAUSE TestWorkerSkipsGCdPaths2306=== RUN TestWorkerPrunesClosureDeps2307=== PAUSE TestWorkerPrunesClosureDeps2308=== RUN TestDrainTimeout2309=== PAUSE TestDrainTimeout2310=== CONT TestSendPathsEmpty2311=== CONT TestRunNotBlockedByPoisonHead2312=== CONT TestWorkerSkipsGCdPaths2313=== CONT TestDrainTimeout2314=== CONT TestWorkerPrunesClosureDeps2315=== CONT TestServerClientIntegration2316=== CONT TestDrainIsolatesPoisonPath2317=== CONT TestServerQueueError2318--- PASS: TestSendPathsEmpty (0.00s)2319=== CONT TestQueueRemoveLargeClosure2320=== CONT TestQueueRetryMovesToBack2321=== CONT TestQueueFetchRemoveLifecycle23222026/10/06 19:59:21 ERROR Failed to queue paths error="permission denied" count=12323--- PASS: TestServerQueueError (0.00s)2324=== CONT TestQueueConcurrentWriters2325--- PASS: TestServerClientIntegration (0.00s)2326=== CONT TestFailedPathPrunedByLaterClosure23272026/10/06 19:59:21 INFO Upload queue status pending=223282026/10/06 19:59:21 INFO Upload queue status pending=223292026/10/06 19:59:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-57467-1694855006/TestWorkerSkipsGCdPaths2146012996/002/nonexistent23302026/10/06 19:59:21 INFO Uploading batch count=423312026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=423322026/10/06 19:59:21 INFO Uploading batch count=123332026/10/06 19:59:21 INFO Uploading batch count=123342026/10/06 19:59:21 INFO Uploading batch count=123352026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=123362026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainIsolatesPoisonPath2596231811/002/bbb23372026/10/06 19:59:21 INFO Upload queue status pending=323382026/10/06 19:59:21 INFO Uploading batch count=22339--- PASS: TestQueueFetchRemoveLifecycle (0.01s)23402026/10/06 19:59:21 INFO Uploading batch count=12341=== CONT TestWorkerUploadsAndRemoves23422026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=12343--- PASS: TestQueueRetryMovesToBack (0.01s)2344=== CONT TestDrainGivesUpWhenServerDown23452026/10/06 19:59:21 INFO Uploading batch count=123462026/10/06 19:59:21 INFO Uploading batch count=123472026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=123482026/10/06 19:59:21 INFO Uploading batch count=123492026/10/06 19:59:21 INFO Uploading batch count=123502026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=123512026/10/06 19:59:21 INFO Uploading batch count=123522026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=123532026/10/06 19:59:21 ERROR Drain finished with paths left in queue remaining=12354--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2355=== CONT TestQueueRemove23562026/10/06 19:59:21 INFO Upload queue status pending=223572026/10/06 19:59:21 INFO Uploading batch count=22358--- PASS: TestDrainIsolatesPoisonPath (0.02s)2359=== CONT TestQueueFetchBatchLimit23602026/10/06 19:59:21 INFO Uploading batch count=223612026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=223622026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/a23632026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/b23642026/10/06 19:59:21 INFO Uploading batch count=223652026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=223662026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/c23672026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/d23682026/10/06 19:59:21 INFO Uploading batch count=223692026/10/06 19:59:21 ERROR Upload failed error="upload failed" count=223702026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/e2371--- PASS: TestQueueRemove (0.00s)2372=== CONT TestQueueDeduplication23732026/10/06 19:59:21 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-57467-1694855006/TestDrainGivesUpWhenServerDown3060085968/002/f23742026/10/06 19:59:21 ERROR Drain finished with paths left in queue remaining=102375--- PASS: TestQueueFetchBatchLimit (0.00s)2376=== CONT TestQueueEnqueueAndFetch2377--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2378--- PASS: TestQueueDeduplication (0.00s)2379--- PASS: TestQueueEnqueueAndFetch (0.00s)2380--- PASS: TestWorkerSkipsGCdPaths (0.03s)2381--- PASS: TestWorkerPrunesClosureDeps (0.03s)2382--- PASS: TestWorkerUploadsAndRemoves (0.02s)2383--- PASS: TestQueueRemoveLargeClosure (0.06s)2384--- PASS: TestQueueConcurrentWriters (0.15s)23852026/10/06 19:59:21 ERROR Upload failed error="context deadline exceeded" count=223862026/10/06 19:59:21 ERROR Drain finished with paths left in queue remaining=42387--- PASS: TestDrainTimeout (0.21s)23882026/10/06 19:59:22 INFO Uploading batch count=123892026/10/06 19:59:22 INFO Uploading batch count=123902026/10/06 19:59:22 INFO Uploading batch count=123912026/10/06 19:59:22 ERROR Upload failed error="upload failed" count=123922026/10/06 19:59:22 INFO Uploading batch count=123932026/10/06 19:59:22 ERROR Upload failed error="upload failed" count=123942026/10/06 19:59:22 INFO Uploading batch count=123952026/10/06 19:59:22 ERROR Upload failed error="upload failed" count=123962026/10/06 19:59:22 INFO Uploading batch count=123972026/10/06 19:59:22 ERROR Upload failed error="upload failed" count=123982026/10/06 19:59:22 ERROR Drain finished with paths left in queue remaining=12399--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2400PASS2401Running signing tests...2402=== RUN TestExternalSigner2403=== PAUSE TestExternalSigner2404=== RUN TestExternalSignerWrongPublicKey2405=== PAUSE TestExternalSignerWrongPublicKey2406=== RUN TestExternalSignerErrors2407=== PAUSE TestExternalSignerErrors2408=== RUN TestExternalSignerRestartsAfterCrash2409=== PAUSE TestExternalSignerRestartsAfterCrash2410=== RUN TestExternalSignerProgramErrorKeepsProcess2411=== PAUSE TestExternalSignerProgramErrorKeepsProcess2412=== RUN TestExternalSignerClose2413=== PAUSE TestExternalSignerClose2414=== RUN TestExternalSignerRejectsInvalidPublicKey2415=== PAUSE TestExternalSignerRejectsInvalidPublicKey2416=== RUN TestExternalSignerCancellation2417=== PAUSE TestExternalSignerCancellation2418=== RUN TestGenerateFingerprint2419=== PAUSE TestGenerateFingerprint2420=== RUN TestParseSigningKey2421=== PAUSE TestParseSigningKey2422=== RUN TestSign2423=== PAUSE TestSign2424=== RUN TestSignBatch2425=== PAUSE TestSignBatch2426=== RUN TestNilKeyPublicKey2427=== PAUSE TestNilKeyPublicKey2428=== RUN TestSignErrors2429=== PAUSE TestSignErrors2430=== CONT TestExternalSigner2431=== CONT TestExternalSignerCancellation2432=== CONT TestExternalSignerProgramErrorKeepsProcess2433=== CONT TestSignErrors2434=== CONT TestExternalSignerErrors2435=== RUN TestExternalSignerErrors/null2436=== CONT TestExternalSignerRejectsInvalidPublicKey2437=== PAUSE TestExternalSignerErrors/null2438=== CONT TestSign2439=== CONT TestNilKeyPublicKey2440=== RUN TestExternalSignerErrors/wrong_id2441--- PASS: TestNilKeyPublicKey (0.00s)2442=== CONT TestSignBatch2443=== CONT TestExternalSignerRestartsAfterCrash2444=== PAUSE TestExternalSignerErrors/wrong_id2445=== RUN TestExternalSignerErrors/program_error2446=== CONT TestExternalSignerClose2447=== RUN TestExternalSignerRejectsInvalidPublicKey/#002448=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002449=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2450=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2451=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2452=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2453=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2454=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2455=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2456=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2457=== CONT TestExternalSignerWrongPublicKey2458=== PAUSE TestExternalSignerErrors/program_error2459=== RUN TestExternalSignerErrors/exit_at_startup2460=== PAUSE TestExternalSignerErrors/exit_at_startup2461=== RUN TestExternalSignerErrors/invalid_JSON2462=== PAUSE TestExternalSignerErrors/invalid_JSON2463=== RUN TestExternalSignerErrors/null_signatures2464=== PAUSE TestExternalSignerErrors/null_signatures2465=== RUN TestExternalSignerErrors/missing_signature_name2466=== PAUSE TestExternalSignerErrors/missing_signature_name2467=== RUN TestExternalSignerErrors/exit_on_request2468=== PAUSE TestExternalSignerErrors/exit_on_request2469=== RUN TestExternalSignerErrors/wrong_shape2470=== PAUSE TestExternalSignerErrors/wrong_shape2471=== RUN TestExternalSignerErrors/too_few_signatures2472=== PAUSE TestExternalSignerErrors/too_few_signatures2473=== RUN TestExternalSignerErrors/wrong_signature_name2474=== PAUSE TestExternalSignerErrors/wrong_signature_name2475=== RUN TestExternalSignerErrors/wrong_signature_length2476=== PAUSE TestExternalSignerErrors/wrong_signature_length2477=== RUN TestExternalSignerErrors/missing_signatures2478=== PAUSE TestExternalSignerErrors/missing_signatures2479=== RUN TestExternalSignerErrors/wrong_signatures_shape2480=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2481=== RUN TestExternalSignerErrors/unrequested_key2482=== PAUSE TestExternalSignerErrors/unrequested_key2483=== RUN TestExternalSignerErrors/invalid_signature_base642484=== PAUSE TestExternalSignerErrors/invalid_signature_base642485=== CONT TestExternalSignerRejectsInvalidPublicKey/#002486=== CONT TestParseSigningKey2487=== RUN TestParseSigningKey/valid_32-byte_key2488=== PAUSE TestParseSigningKey/valid_32-byte_key2489=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2490=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2491=== RUN TestParseSigningKey/no_colon2492=== PAUSE TestParseSigningKey/no_colon2493=== RUN TestParseSigningKey/empty_name2494=== PAUSE TestParseSigningKey/empty_name2495=== RUN TestParseSigningKey/invalid_base642496=== PAUSE TestParseSigningKey/invalid_base642497=== RUN TestParseSigningKey/wrong_length2498=== PAUSE TestParseSigningKey/wrong_length2499=== CONT TestGenerateFingerprint2500=== RUN TestGenerateFingerprint/basic_with_references2501=== PAUSE TestGenerateFingerprint/basic_with_references2502=== RUN TestGenerateFingerprint/no_references2503=== PAUSE TestGenerateFingerprint/no_references2504=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2505=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2506=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2507=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2508=== RUN TestGenerateFingerprint/invalid_nar_hash_length2509=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2510=== RUN TestGenerateFingerprint/invalid_store_path_prefix2511=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2512=== RUN TestGenerateFingerprint/invalid_reference_prefix2513=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2514=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2515=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2516=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2517=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2518--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2523 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2524=== CONT TestExternalSignerErrors/null2525=== RUN TestSignErrors/nil_key2526=== PAUSE TestSignErrors/nil_key2527=== RUN TestSignErrors/nil_narinfo2528=== PAUSE TestSignErrors/nil_narinfo2529=== RUN TestSignErrors/invalid_narinfo2530=== PAUSE TestSignErrors/invalid_narinfo2531=== RUN TestSignErrors/canceled2532=== PAUSE TestSignErrors/canceled2533=== CONT TestExternalSignerErrors/wrong_shape2534--- PASS: TestSign (0.00s)2535=== CONT TestExternalSignerErrors/invalid_signature_base642536--- PASS: TestSignBatch (0.00s)2537=== CONT TestExternalSignerErrors/unrequested_key2538--- PASS: TestExternalSigner (0.53s)2539=== CONT TestExternalSignerErrors/wrong_signatures_shape2540--- PASS: TestExternalSignerRestartsAfterCrash (0.74s)2541=== CONT TestExternalSignerErrors/missing_signatures2542/nix/var/nix/builds/nix-57467-1694855006/TestExternalSignerRestartsAfterCrash2595260453/001/sign program: line 7: /nix/var/nix/builds/nix-57467-1694855006/TestExternalSignerRestartsAfterCrash2595260453/001/sign program.starts: No such file or directory2543--- PASS: TestExternalSignerClose (0.91s)2544=== CONT TestExternalSignerErrors/wrong_signature_length2545--- PASS: TestExternalSignerCancellation (1.12s)2546=== CONT TestExternalSignerErrors/wrong_signature_name2547--- PASS: TestExternalSignerProgramErrorKeepsProcess (1.30s)2548=== CONT TestExternalSignerErrors/too_few_signatures2549=== CONT TestExternalSignerErrors/invalid_JSON2550--- PASS: TestExternalSignerWrongPublicKey (1.69s)2551=== CONT TestExternalSignerErrors/exit_on_request2552=== CONT TestExternalSignerErrors/missing_signature_name2553=== CONT TestExternalSignerErrors/null_signatures2554=== CONT TestExternalSignerErrors/program_error2555=== CONT TestExternalSignerErrors/exit_at_startup2556=== CONT TestExternalSignerErrors/wrong_id2557=== CONT TestParseSigningKey/valid_32-byte_key2558=== CONT TestParseSigningKey/empty_name2559=== CONT TestParseSigningKey/no_colon2560=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2561=== CONT TestParseSigningKey/invalid_base642562=== CONT TestParseSigningKey/wrong_length2563--- PASS: TestParseSigningKey (0.00s)2564 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2565 --- PASS: TestParseSigningKey/empty_name (0.00s)2566 --- PASS: TestParseSigningKey/no_colon (0.00s)2567 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2568 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2569 --- PASS: TestParseSigningKey/wrong_length (0.00s)2570=== CONT TestGenerateFingerprint/basic_with_references2571=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2572=== CONT TestGenerateFingerprint/invalid_reference_prefix2573=== CONT TestGenerateFingerprint/invalid_store_path_prefix2574=== CONT TestGenerateFingerprint/invalid_nar_hash_length2575=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2576=== CONT TestGenerateFingerprint/no_references2577--- PASS: TestGenerateFingerprint (0.00s)2578 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2579 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2580 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2581 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2582 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2583 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2584 --- PASS: TestGenerateFingerprint/no_references (0.00s)2585=== CONT TestSignErrors/nil_key2586=== CONT TestSignErrors/canceled2587=== CONT TestSignErrors/nil_narinfo2588=== CONT TestSignErrors/invalid_narinfo2589--- PASS: TestSignErrors (0.00s)2590 --- PASS: TestSignErrors/nil_key (0.00s)2591 --- PASS: TestSignErrors/canceled (0.00s)2592 --- PASS: TestSignErrors/nil_narinfo (0.00s)2593 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2594--- PASS: TestExternalSignerErrors (0.00s)2595 --- PASS: TestExternalSignerErrors/null (1.50s)2596 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.89s)2597 --- PASS: TestExternalSignerErrors/wrong_shape (2.09s)2598 --- PASS: TestExternalSignerErrors/unrequested_key (2.29s)2599 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.98s)2600 --- PASS: TestExternalSignerErrors/missing_signatures (1.97s)2601 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.00s)2602 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.20s)2603 --- PASS: TestExternalSignerErrors/too_few_signatures (2.22s)2604 --- PASS: TestExternalSignerErrors/invalid_JSON (2.21s)2605 --- PASS: TestExternalSignerErrors/exit_on_request (2.22s)2606 --- PASS: TestExternalSignerErrors/missing_signature_name (2.22s)2607 --- PASS: TestExternalSignerErrors/null_signatures (2.77s)2608 --- PASS: TestExternalSignerErrors/program_error (2.76s)2609 --- PASS: TestExternalSignerErrors/exit_at_startup (2.74s)2610 --- PASS: TestExternalSignerErrors/wrong_id (2.73s)2611PASS2612Running OpenBao signer tests...2613=== RUN TestSign2614=== PAUSE TestSign2615=== RUN TestSignErrors2616=== PAUSE TestSignErrors2617=== RUN TestServe2618=== PAUSE TestServe2619=== RUN TestServeRejectsGarbage2620=== PAUSE TestServeRejectsGarbage2621=== CONT TestSign2622=== CONT TestServeRejectsGarbage2623=== CONT TestServe2624--- PASS: TestServeRejectsGarbage (0.00s)2625=== CONT TestSignErrors2626=== RUN TestSignErrors/http_error2627=== PAUSE TestSignErrors/http_error2628=== RUN TestSignErrors/invalid_json2629=== PAUSE TestSignErrors/invalid_json2630=== RUN TestSignErrors/no_prefix2631=== PAUSE TestSignErrors/no_prefix2632=== RUN TestSignErrors/invalid_base642633=== PAUSE TestSignErrors/invalid_base642634=== CONT TestSignErrors/http_error2635=== CONT TestSignErrors/no_prefix2636=== CONT TestSignErrors/invalid_base642637=== CONT TestSignErrors/invalid_json2638--- PASS: TestServe (0.00s)2639--- PASS: TestSign (0.00s)2640--- PASS: TestSignErrors (0.00s)2641 --- PASS: TestSignErrors/invalid_json (0.00s)2642 --- PASS: TestSignErrors/no_prefix (0.00s)2643 --- PASS: TestSignErrors/http_error (0.00s)2644 --- PASS: TestSignErrors/invalid_base64 (0.00s)2645PASS