niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #378
· 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.24s)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 TestScriptTokenScriptFails101=== CONT TestSetClientTLSErrors102=== CONT TestScriptTokenCachesUntilRefresh103=== CONT TestScriptTokenNoExpiryRerunsEveryCall104=== CONT TestFileTokenEmpty105=== CONT TestFileTokenMissing106=== CONT TestStaticToken107=== CONT TestFileTokenReadsAndCaches108=== CONT TestScriptTokenBadJSON109--- PASS: TestStaticToken (0.00s)110--- PASS: TestFileTokenEmpty (0.01s)111=== CONT TestScriptTokenEmptyToken112=== RUN TestSetClientTLSErrors/missing_cert_file113--- PASS: TestFileTokenMissing (0.01s)114=== CONT TestEncodeNixBase32115--- PASS: TestFileTokenReadsAndCaches (0.01s)116=== CONT TestResolveStorePath1172026/10/06 18:26:28 WARN Rate limiter enabled after throttle name=server-test rate=5118=== RUN TestEncodeNixBase32/test_string_hash119=== PAUSE TestSetClientTLSErrors/missing_cert_file1202026/10/06 18:26:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58444121=== PAUSE TestEncodeNixBase32/test_string_hash122=== RUN TestEncodeNixBase32/empty_input123=== PAUSE TestEncodeNixBase32/empty_input124=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess125=== RUN TestSetClientTLSErrors/missing_key_file126=== PAUSE TestSetClientTLSErrors/missing_key_file127=== RUN TestSetClientTLSErrors/missing_ca_file128=== PAUSE TestSetClientTLSErrors/missing_ca_file1292026/10/06 18:26:28 WARN Rate limiter enabled after throttle name=server-test rate=5130=== RUN TestSetClientTLSErrors/invalid_ca_file131=== PAUSE TestSetClientTLSErrors/invalid_ca_file132=== CONT TestRateLimiterFeedback133=== RUN TestRateLimiterFeedback/429_enables_limiter1342026/10/06 18:26:28 WARN Rate limiter backed off name=server-test rate=51352026/10/06 18:26:28 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:58444136=== CONT TestPathInfoCACompatibility137=== RUN TestPathInfoCACompatibility/null_ca_field138=== CONT TestParsePathInfoJSONMultiplePaths139=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths140--- PASS: TestDoServerRequestAttachesToken (0.01s)141=== PAUSE TestRateLimiterFeedback/429_enables_limiter142=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143--- PASS: TestScriptTokenScriptFails (0.01s)144--- PASS: TestResolveStorePath (0.00s)145=== RUN TestRateLimiterFeedback/503_enables_limiter146=== PAUSE TestPathInfoCACompatibility/null_ca_field147=== PAUSE TestRateLimiterFeedback/503_enables_limiter148=== RUN TestPathInfoCACompatibility/old_string_format_-_text149=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter150=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths151=== CONT TestParsePathInfoJSON152=== RUN TestParsePathInfoJSON/Nix_format153=== PAUSE TestParsePathInfoJSON/Nix_format154=== RUN TestParsePathInfoJSON/Lix_format155=== PAUSE TestParsePathInfoJSON/Lix_format156=== RUN TestParsePathInfoJSON/empty_input157=== PAUSE TestParsePathInfoJSON/empty_input158=== RUN TestParsePathInfoJSON/whitespace_only159=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text160=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive161=== PAUSE TestParsePathInfoJSON/whitespace_only162=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths163=== RUN TestParsePathInfoJSON/invalid_JSON164=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter165=== PAUSE TestParsePathInfoJSON/invalid_JSON166--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)167=== CONT TestPathInfoHashCompatibility168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive169=== CONT TestGetStorePathHash170=== RUN TestGetStorePathHash/valid_store_path171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== PAUSE TestGetStorePathHash/valid_store_path173=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)174=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter175=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter176=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon177=== CONT TestEncodeNixBase32WithRealHash178=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon179--- PASS: TestEncodeNixBase32WithRealHash (0.00s)180=== CONT TestStreamPushGivesUpOnDeadServer181=== CONT TestConvertHashToNix32182=== RUN TestConvertHashToNix32/SRI_format_to_Nix32183=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32184=== RUN TestGetStorePathHash/basename_without_hyphen_should_error185=== RUN TestConvertHashToNix32/already_Nix32_format186=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error187=== RUN TestPathInfoCACompatibility/new_structured_format_-_text188=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text189=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method190=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method191=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI192=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121942026/10/06 18:26:28 ERROR Upload failed error="connection refused" count=20195=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha5121962026/10/06 18:26:28 ERROR Server seems unavailable, giving up on batch untried=17197=== CONT TestSetClientTLSDoesNotMutateDefaultTransport198=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error199=== PAUSE TestConvertHashToNix32/already_Nix32_format200=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error201=== RUN TestConvertHashToNix32/invalid_format202=== CONT TestSetClientTLS203=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error204=== PAUSE TestConvertHashToNix32/invalid_format205=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error206=== CONT TestClientSignaturesByStorePath207--- PASS: TestClientSignaturesByStorePath (0.00s)208=== CONT TestStreamPushRequestLine209=== CONT TestStreamPushReportsSignatures210--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)211=== CONT TestStreamPushReportsEveryPath2122026/10/06 18:26:28 ERROR Upload failed error=boom count=1213--- PASS: TestStreamPushReportsEveryPath (0.00s)214=== CONT TestStreamPushIsolatesFailures2152026/10/06 18:26:28 ERROR Upload failed error="bad path" count=32162026/10/06 18:26:28 ERROR Upload failed error=boom count=1217--- PASS: TestStreamPushIsolatesFailures (0.00s)218=== CONT TestStreamPushBatchesUnderLoad219--- PASS: TestStreamPushReportsSignatures (0.00s)220=== CONT TestScriptTokenEmptyCommand221--- PASS: TestScriptTokenEmptyCommand (0.00s)222=== CONT TestShellSplitErrors223--- PASS: TestShellSplitErrors (0.00s)224=== CONT TestUploadMultipart_PartsInParallel225--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)226=== RUN TestSetClientTLS/rejects_connection_without_client_cert227=== CONT TestDumpPathWriterError228=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert229=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA230=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA231=== RUN TestSetClientTLS/preserves_debug_logging_transport232=== PAUSE TestSetClientTLS/preserves_debug_logging_transport233=== CONT TestDumpPathSingleFile234--- PASS: TestScriptTokenBadJSON (0.01s)235=== CONT TestDumpPathMatchesNix236--- PASS: TestScriptTokenEmptyToken (0.01s)237=== CONT TestUploadMultipart_SupersededByPeer238=== RUN TestUploadMultipart_SupersededByPeer/exists239=== PAUSE TestUploadMultipart_SupersededByPeer/exists240=== RUN TestUploadMultipart_SupersededByPeer/missing241=== PAUSE TestUploadMultipart_SupersededByPeer/missing242=== CONT TestPartSizeForNAR243=== RUN TestPartSizeForNAR/zero_stays_at_minimum244=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum245=== RUN TestPartSizeForNAR/small_stays_at_minimum246=== PAUSE TestPartSizeForNAR/small_stays_at_minimum247=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum248=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum249=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts250=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts251=== RUN TestPartSizeForNAR/1_TiB252=== PAUSE TestPartSizeForNAR/1_TiB253=== RUN TestPartSizeForNAR/5_TiB_S3_max_object254=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object255=== RUN TestPartSizeForNAR/capped_at_5_GiB256=== PAUSE TestPartSizeForNAR/capped_at_5_GiB257=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2582026/10/06 18:26:28 INFO Garbage collection started259--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)260=== CONT TestFilterOversizedClosures261=== RUN TestFilterOversizedClosures/no_limit_keeps_everything262=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything263=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped264=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped265=== RUN TestFilterOversizedClosures/all_closures_skipped266=== PAUSE TestFilterOversizedClosures/all_closures_skipped267=== CONT TestCaseHackSuffix268--- PASS: TestStreamPushRequestLine (0.02s)269=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2702026/10/06 18:26:28 INFO Garbage collection started2712026/10/06 18:26:28 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=02722026/10/06 18:26:28 WARN Garbage collection finished on another replica. Its statistics are not available here273--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)274=== CONT TestShellSplit275--- PASS: TestShellSplit (0.00s)276=== CONT TestRegisterUploadedObjectReusesConnections277--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestEncodeNixBase32/empty_input280--- PASS: TestEncodeNixBase32 (0.00s)281 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)282 --- PASS: TestEncodeNixBase32/empty_input (0.00s)283=== CONT TestSetClientTLSErrors/missing_cert_file284=== CONT TestSetClientTLSErrors/missing_ca_file285=== CONT TestSetClientTLSErrors/invalid_ca_file286=== CONT TestSetClientTLSErrors/missing_key_file287--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)288=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289=== CONT TestParsePathInfoJSON/Nix_format290=== CONT TestParsePathInfoJSON/invalid_JSON291=== CONT TestParsePathInfoJSON/whitespace_only292=== CONT TestParsePathInfoJSON/Lix_format293=== CONT TestRateLimiterFeedback/429_enables_limiter294--- PASS: TestSetClientTLSErrors (0.01s)295 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)296 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)297 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)298 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)299=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths300--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)301 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)302 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)303=== CONT TestRateLimiterFeedback/503_enables_limiter3042026/10/06 18:26:28 WARN Rate limiter enabled after throttle name=server-test rate=53052026/10/06 18:26:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:585243062026/10/06 18:26:28 WARN Rate limiter enabled after throttle name=server-test rate=53072026/10/06 18:26:28 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:585263082026/10/06 18:26:28 WARN Rate limiter backed off name=server-test rate=5309=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3102026/10/06 18:26:28 WARN Rate limiter backed off name=server-test rate=5311=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter312=== CONT TestParsePathInfoJSON/empty_input313--- PASS: TestParsePathInfoJSON (0.00s)314 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)315 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)316 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)317 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)318 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)319=== CONT TestPathInfoCACompatibility/null_ca_field320=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)321=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method322--- PASS: TestRateLimiterFeedback (0.00s)323 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)324 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)325 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)326 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)327=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive328=== CONT TestPathInfoCACompatibility/new_structured_format_-_text329=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512330=== CONT TestConvertHashToNix32/SRI_format_to_Nix32331=== CONT TestPathInfoCACompatibility/old_string_format_-_text332--- PASS: TestPathInfoCACompatibility (0.00s)333 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)334 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)336 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)338=== CONT TestGetStorePathHash/valid_store_path339=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error340=== CONT TestGetStorePathHash/basename_without_hyphen_should_error341=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error342--- PASS: TestGetStorePathHash (0.00s)343 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)344 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)345 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347=== CONT TestConvertHashToNix32/invalid_format348=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI349=== CONT TestConvertHashToNix32/already_Nix32_format350--- PASS: TestConvertHashToNix32 (0.00s)351 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)352 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)353 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)354=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon355--- PASS: TestPathInfoHashCompatibility (0.00s)356 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)357 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)358 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)359 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)360=== CONT TestSetClientTLS/rejects_connection_without_client_cert361=== CONT TestSetClientTLS/preserves_debug_logging_transport362=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA363=== CONT TestUploadMultipart_SupersededByPeer/exists364--- PASS: TestDumpPathWriterError (0.04s)365=== CONT TestPartSizeForNAR/zero_stays_at_minimum366=== CONT TestUploadMultipart_SupersededByPeer/missing367--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)368 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)369 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)370=== CONT TestPartSizeForNAR/capped_at_5_GiB371=== CONT TestPartSizeForNAR/5_TiB_S3_max_object372=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum373=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts374=== CONT TestPartSizeForNAR/small_stays_at_minimum375=== CONT TestFilterOversizedClosures/no_limit_keeps_everything376=== CONT TestFilterOversizedClosures/all_closures_skipped3772026/10/06 18:26:28 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=50378=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3792026/10/06 18:26:28 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=2000380=== CONT TestPartSizeForNAR/1_TiB381--- PASS: TestFilterOversizedClosures (0.00s)382 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)383 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)384 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)385--- PASS: TestPartSizeForNAR (0.00s)386 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)387 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)388 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)389 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)391 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)392 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)393--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3942026/10/06 18:26:28 http: TLS handshake error from 127.0.0.1:58532: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.04s)401--- PASS: TestDumpPathMatchesNix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.62s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld1".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-75043-2721225071/postgres3780467720/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-75043-2721225071/postgres3780467720/data -l logfile start4334342026-10-06 18:26:29.987 UTC [75083] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4352026-10-06 18:26:29.987 UTC [75083] LOG: listening on Unix socket "/nix/var/nix/builds/nix-75043-2721225071/postgres3780467720/.s.PGSQL.5432"4362026-10-06 18:26:29.989 UTC [75090] LOG: database system was shut down at 2026-10-06 18:26:29 UTC4372026-10-06 18:26:29.990 UTC [75091] FATAL: the database system is starting up438/nix/var/nix/builds/nix-75043-2721225071/postgres3780467720:5432 - rejecting connections4392026-10-06 18:26:29.990 UTC [75083] LOG: database system is ready to accept connections440/nix/var/nix/builds/nix-75043-2721225071/postgres3780467720:5432 - accepting connections441{"timestamp":"2026-10-06T18:26:30.244207Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b53915ab-3d8b-4bab-a193-960e0c21a003","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":9,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}442{"timestamp":"2026-10-06T18:26:30.350645Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6a15e748-75d1-4fca-bcf5-71e02a00d844","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}443{"timestamp":"2026-10-06T18:26:30.453794Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8d060ea1-66ba-44c1-a3fe-88c76550d3b2","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 18:26:30 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 18:26:31 INFO lead: released remote=192.0.2.1:12344912026/10/06 18:26:31 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 18:26:32 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.98s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 18:26:32 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 18:26:33.904 UTC [75126] FATAL: terminating connection due to administrator command5012026/10/06 18:26:34 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 18:26:35 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 18:26:35 INFO lead: released remote=192.0.2.1:12345042026/10/06 18:26:35 INFO lead: released remote=192.0.2.1:1234505--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)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 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6692026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 18:26:35 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 18:26:35 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 TestCompleteMultipartUnregistered699=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT700=== CONT TestService_verifyS3Integrity701=== CONT TestCreatePendingClosureRejectsOversizedNAR702=== CONT TestReadProxyRootRedirectsToIndexHTML703=== CONT TestReadProxyNarStreaming704=== CONT TestCacheConfigHandlerMaxNarSize705=== CONT TestService_AuthMiddleware706=== CONT TestDeduplicatedObjectsRecordedAsPending707=== CONT TestReadProxyConditionalGet7082026/10/06 18:26:35 INFO Received uploads request method=POST path=/api/pending_closures709--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)710=== CONT TestReadProxyNarinfo711--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)712=== CONT TestReadProxyContentNegotiation7132026/10/06 18:26:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7142026/10/06 18:26:35 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst715--- PASS: TestCompleteMultipartUnregistered (0.45s)716=== CONT TestReadProxyNarinfoAlreadyDecompressed717--- PASS: TestReadProxyNarStreaming (0.63s)718=== CONT TestClientSharedPathCommittedMidPush7192026/10/06 18:26:36 INFO Received uploads request method=POST path=/api/pending_closures720--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.95s)721=== CONT TestPushDedupSurvivesConcurrentGC7222026/10/06 18:26:36 INFO Received uploads request method=POST path=/api/pending_closures723--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.18s)724=== CONT TestGCMetrics7252026/10/06 18:26:36 INFO Received uploads request method=POST path=/api/pending_closures726--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.37s)727=== CONT TestGCBugBareHashReferences7282026/10/06 18:26:37 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>729--- PASS: TestReadProxyNarinfo (1.63s)730=== CONT TestGCAdvisoryLockBlocksConcurrentRun731--- PASS: TestReadProxyConditionalGet (1.82s)732=== CONT TestLeadEndsOnShutdown7332026/10/06 18:26:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7342026/10/06 18:26:37 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LjczOGM0NTM4LTJhYzktNGFkNy04OGQ4LTEzNWYzYTdhNmE5NngxNzkxMzExMTk2MzYwNzEzMDAw parts=107352026/10/06 18:26:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete7362026/10/06 18:26:37 INFO Completed upload id=17372026/10/06 18:26:37 INFO Received uploads request method=POST path=/api/pending_closures7382026/10/06 18:26:37 INFO Received uploads request method=POST path=/api/pending_closures7392026/10/06 18:26:37 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo7402026/10/06 18:26:37 WARN Found objects in DB but missing from S3, will re-upload count=1741--- PASS: TestService_verifyS3Integrity (2.02s)742=== CONT TestLeadIncumbentAnnouncesAtOnce7432026/10/06 18:26:37 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"744--- PASS: TestService_AuthMiddleware (2.04s)745=== CONT TestLeadElectsOneAndHandsOver746--- PASS: TestReadProxyContentNegotiation (2.27s)747=== CONT TestConnectWaitsForAPeerMigration748--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.95s)749=== CONT TestResolveDBConnectionString750=== RUN TestResolveDBConnectionString/flag_wins751=== PAUSE TestResolveDBConnectionString/flag_wins752=== RUN TestResolveDBConnectionString/file_when_flag_empty753=== PAUSE TestResolveDBConnectionString/file_when_flag_empty754=== RUN TestResolveDBConnectionString/missing_file_is_an_error755=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error756=== RUN TestResolveDBConnectionString/PGHOST_allows_empty757=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty758=== RUN TestResolveDBConnectionString/nothing_configured759=== PAUSE TestResolveDBConnectionString/nothing_configured760=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7612026/10/06 18:26:38 INFO Received uploads request method=POST path=/api/pending_closures7622026/10/06 18:26:38 INFO Aborted multipart uploads count=0 kept=07632026/10/06 18:26:38 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=07642026/10/06 18:26:38 INFO Vacuumed table table=pending_closures7652026/10/06 18:26:38 INFO Vacuumed table table=pending_objects7662026/10/06 18:26:38 INFO Vacuumed table table=multipart_uploads7672026/10/06 18:26:38 INFO Received push request method=POST path=/api/pushes7682026/10/06 18:26:38 INFO Aborted multipart uploads count=0 kept=07692026/10/06 18:26:38 WARN Force mode enabled - objects will be deleted immediately without grace period7702026/10/06 18:26:38 INFO Vacuumed table table=closures7712026/10/06 18:26:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07722026/10/06 18:26:38 INFO Vacuumed table table=pending_closures7732026/10/06 18:26:38 INFO Vacuumed table table=pending_objects7742026/10/06 18:26:38 INFO Vacuumed table table=multipart_uploads7752026/10/06 18:26:38 INFO Vacuumed table table=closures7762026/10/06 18:26:38 INFO Vacuumed table table=objects777--- PASS: TestGCMetrics (1.83s)778=== CONT TestClientFallsBackToClosures7792026/10/06 18:26:38 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)7802026/10/06 18:26:38 INFO Uploading 5y8zdhpax4880zkgqz7wmyda3n8c7s5k-shared-dep (136B)7812026/10/06 18:26:38 INFO Uploading 9vkkxbmmmigq1ngmrkbgqv1j58yznxyf-top (256B)7822026/10/06 18:26:38 INFO Vacuumed table table=objects7832026/10/06 18:26:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7842026/10/06 18:26:38 INFO Aborted multipart uploads count=0 kept=07852026/10/06 18:26:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7862026/10/06 18:26:38 WARN Failed to register uploaded object key=nar/1djk4hnwjqfc0xsjspnvijaw0w4frwrvryglfigxv65plif8jmg7.nar.zst error="server returned 404: 404 page not found\n"7872026/10/06 18:26:38 WARN Failed to register uploaded object key=5y8zdhpax4880zkgqz7wmyda3n8c7s5k.ls error="server returned 404: 404 page not found\n"7882026/10/06 18:26:38 WARN Failed to register uploaded object key=9vkkxbmmmigq1ngmrkbgqv1j58yznxyf.ls error="server returned 404: 404 page not found\n"7892026/10/06 18:26:38 INFO Signed narinfos id=1 count=27902026/10/06 18:26:38 INFO Uploading 2 narinfos7912026/10/06 18:26:38 WARN Force mode enabled - objects will be deleted immediately without grace period7922026/10/06 18:26:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07932026/10/06 18:26:38 INFO Vacuumed table table=pending_closures7942026/10/06 18:26:38 INFO Received complete push request method=POST path=/api/pushes/1/complete7952026/10/06 18:26:38 WARN Failed to register uploaded object key=5y8zdhpax4880zkgqz7wmyda3n8c7s5k.narinfo error="server returned 404: 404 page not found\n"7962026/10/06 18:26:38 INFO Vacuumed table table=pending_objects7972026/10/06 18:26:38 WARN Failed to register uploaded object key=9vkkxbmmmigq1ngmrkbgqv1j58yznxyf.narinfo error="server returned 404: 404 page not found\n"7982026/10/06 18:26:38 INFO Vacuumed table table=multipart_uploads7992026/10/06 18:26:38 INFO Vacuumed table table=closures8002026/10/06 18:26:38 INFO Vacuumed table table=objects8012026/10/06 18:26:38 INFO Completed push id=1802--- PASS: TestPushDedupSurvivesConcurrentGC (2.10s)803=== CONT TestClientPushesUseOnePush8042026/10/06 18:26:38 INFO Upload complete. (126ms)805=== NAME TestClientSharedPathCommittedMidPush806 client_integration_test.go:680: Retrieved narinfo from S3:807 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientSharedPathCommittedMidPush2521638705/001/store/5y8zdhpax4880zkgqz7wmyda3n8c7s5k-shared-dep808 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst809 Compression: zstd810 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82811 NarSize: 136812 References: 813 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n814 client_integration_test.go:680: Retrieved narinfo from S3:815 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientSharedPathCommittedMidPush2521638705/001/store/9vkkxbmmmigq1ngmrkbgqv1j58yznxyf-top816 URL: nar/1djk4hnwjqfc0xsjspnvijaw0w4frwrvryglfigxv65plif8jmg7.nar.zst817 Compression: zstd818 NarHash: sha256:1djk4hnwjqfc0xsjspnvijaw0w4frwrvryglfigxv65plif8jmg7819 NarSize: 256820 References: /nix/var/nix/builds/nix-75043-2721225071/TestClientSharedPathCommittedMidPush2521638705/001/store/5y8zdhpax4880zkgqz7wmyda3n8c7s5k-shared-dep821 CA: text:sha256:13d2yj972j338k72qvg0hriw40grcq95042c755jlhcqpk2d2aib822--- PASS: TestClientSharedPathCommittedMidPush (2.49s)823=== CONT TestPinProtectsFromGC8242026/10/06 18:26:38 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"825--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.79s)826=== CONT TestCompletedNarNotReofferedAcrossClosures827--- PASS: TestGCBugBareHashReferences (2.09s)828=== CONT TestService_createPendingClosureHandler8292026/10/06 18:26:39 INFO lead: acquired remote=192.0.2.1:12348302026/10/06 18:26:39 INFO lead: acquired remote=192.0.2.1:12348312026/10/06 18:26:39 INFO lead: released remote=192.0.2.1:1234832--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.70s)833=== CONT TestService_cleanupPendingClosuresHandler8342026/10/06 18:26:39 INFO lead: acquired remote=192.0.2.1:1234835=== NAME TestPinProtectsFromGC836 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-75043-2721225071/TestPinProtectsFromGC1615766461/001/store/6d3g74ldjqa60mgrg20zdz8b6604smrj-pinned-file.txt837 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-75043-2721225071/TestPinProtectsFromGC1615766461/001/store/jmdjpyir3fs54wnz89ayv6vm210spaxb-unpinned-file.txt8382026/10/06 18:26:40 INFO lead: released remote=192.0.2.1:1234839--- PASS: TestLeadEndsOnShutdown (2.79s)840=== CONT TestUploadHandlersRejectOversizedBody841=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart842=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart843=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts844=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts845=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure846=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure847=== CONT TestUploadHandlersRejectInvalidKeys848=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info849=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info850=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal851=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal852=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key853=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key854=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key855=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key856=== CONT TestIsValidUploadKey857=== RUN TestIsValidUploadKey/narinfo858=== PAUSE TestIsValidUploadKey/narinfo859=== RUN TestIsValidUploadKey/nar_zst860=== PAUSE TestIsValidUploadKey/nar_zst861=== RUN TestIsValidUploadKey/nar_xz862=== PAUSE TestIsValidUploadKey/nar_xz863=== RUN TestIsValidUploadKey/nar_plain864=== PAUSE TestIsValidUploadKey/nar_plain865=== RUN TestIsValidUploadKey/listing866=== PAUSE TestIsValidUploadKey/listing867=== RUN TestIsValidUploadKey/build_log868=== PAUSE TestIsValidUploadKey/build_log869=== RUN TestIsValidUploadKey/build_log_home-manager_file870=== PAUSE TestIsValidUploadKey/build_log_home-manager_file871=== RUN TestIsValidUploadKey/build_log_plus_in_name872=== PAUSE TestIsValidUploadKey/build_log_plus_in_name873=== RUN TestIsValidUploadKey/build_log_question_mark874=== PAUSE TestIsValidUploadKey/build_log_question_mark875=== RUN TestIsValidUploadKey/build_log_equals876=== PAUSE TestIsValidUploadKey/build_log_equals877=== RUN TestIsValidUploadKey/realisation878=== PAUSE TestIsValidUploadKey/realisation879=== RUN TestIsValidUploadKey/realisation_plus_in_output880=== PAUSE TestIsValidUploadKey/realisation_plus_in_output881=== RUN TestIsValidUploadKey/nix-cache-info882=== PAUSE TestIsValidUploadKey/nix-cache-info883=== RUN TestIsValidUploadKey/index.html884=== PAUSE TestIsValidUploadKey/index.html885=== RUN TestIsValidUploadKey/narinfo_key,_nar_type886=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type887=== RUN TestIsValidUploadKey/nar_key,_narinfo_type888=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type889=== RUN TestIsValidUploadKey/listing_key,_narinfo_type890=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type891=== RUN TestIsValidUploadKey/traversal892=== PAUSE TestIsValidUploadKey/traversal893=== RUN TestIsValidUploadKey/traversal_nar894=== PAUSE TestIsValidUploadKey/traversal_nar895=== RUN TestIsValidUploadKey/absolute896=== PAUSE TestIsValidUploadKey/absolute897=== RUN TestIsValidUploadKey/empty_key898=== PAUSE TestIsValidUploadKey/empty_key899=== RUN TestIsValidUploadKey/unknown_type900=== PAUSE TestIsValidUploadKey/unknown_type901=== CONT TestPendingClosureWriteTimeout902=== RUN TestPendingClosureWriteTimeout/empty903=== PAUSE TestPendingClosureWriteTimeout/empty904=== RUN TestPendingClosureWriteTimeout/400_objects905=== PAUSE TestPendingClosureWriteTimeout/400_objects906=== RUN TestPendingClosureWriteTimeout/670k_objects907=== PAUSE TestPendingClosureWriteTimeout/670k_objects908=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline909=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline910=== CONT TestProxyWriteTimeout911=== RUN TestProxyWriteTimeout/narinfo912=== PAUSE TestProxyWriteTimeout/narinfo913=== RUN TestProxyWriteTimeout/1_GiB_nar914=== PAUSE TestProxyWriteTimeout/1_GiB_nar915=== RUN TestProxyWriteTimeout/10_GiB_nar916=== PAUSE TestProxyWriteTimeout/10_GiB_nar917=== RUN TestProxyWriteTimeout/unknown_size918=== PAUSE TestProxyWriteTimeout/unknown_size919=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9202026/10/06 18:26:40 INFO Received push request method=POST path=/api/pushes9212026/10/06 18:26:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9222026/10/06 18:26:40 INFO Uploading 6d3g74ldjqa60mgrg20zdz8b6604smrj-pinned-file.txt (128B)9232026/10/06 18:26:40 WARN Failed to register uploaded object key=6d3g74ldjqa60mgrg20zdz8b6604smrj.ls error="server returned 404: 404 page not found\n"9242026/10/06 18:26:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9252026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9262026/10/06 18:26:40 INFO Signed narinfos id=1 count=19272026/10/06 18:26:40 INFO Uploading 1 narinfos9282026/10/06 18:26:40 INFO Received complete push request method=POST path=/api/pushes/1/complete9292026/10/06 18:26:40 WARN Failed to register uploaded object key=6d3g74ldjqa60mgrg20zdz8b6604smrj.narinfo error="server returned 404: 404 page not found\n"9302026/10/06 18:26:40 INFO Completed push id=19312026/10/06 18:26:40 INFO Upload complete. (96ms)932--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.36s)933=== CONT TestSkippedUploadsHandler9342026/10/06 18:26:40 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000935--- PASS: TestSkippedUploadsHandler (0.00s)936=== CONT TestParseSize937--- PASS: TestParseSize (0.00s)938=== CONT TestService_Rustfstest9392026/10/06 18:26:40 INFO Received push request method=POST path=/api/pushes9402026/10/06 18:26:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9412026/10/06 18:26:40 INFO Uploading jmdjpyir3fs54wnz89ayv6vm210spaxb-unpinned-file.txt (128B)9422026/10/06 18:26:40 WARN Failed to register uploaded object key=jmdjpyir3fs54wnz89ayv6vm210spaxb.ls error="server returned 404: 404 page not found\n"9432026/10/06 18:26:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9442026/10/06 18:26:40 INFO Signed narinfos id=2 count=19452026/10/06 18:26:40 INFO Uploading 1 narinfos9462026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9472026/10/06 18:26:40 INFO Received complete push request method=POST path=/api/pushes/2/complete9482026/10/06 18:26:40 WARN Failed to register uploaded object key=jmdjpyir3fs54wnz89ayv6vm210spaxb.narinfo error="server returned 404: 404 page not found\n"9492026/10/06 18:26:40 INFO Completed push id=29502026/10/06 18:26:40 INFO Upload complete. (79ms)9512026/10/06 18:26:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures9522026/10/06 18:26:40 INFO Garbage collection started9532026/10/06 18:26:40 INFO Aborted multipart uploads count=0 kept=09542026/10/06 18:26:40 WARN Force mode enabled - objects will be deleted immediately without grace period9552026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/06 18:26:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9582026/10/06 18:26:40 INFO Uploading yx1valch2axrb7n413ihi5q21m7naddl-shared-dep (136B)9592026/10/06 18:26:40 INFO Uploading 7mmwlpj2ffr1fxz243q47jicyiv1qsg7-a (248B)9602026/10/06 18:26:40 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=09612026/10/06 18:26:40 WARN Failed to register uploaded object key=yx1valch2axrb7n413ihi5q21m7naddl.ls error="server returned 404: 404 page not found\n"9622026/10/06 18:26:40 WARN Failed to register uploaded object key=1nr1k9ng3p9lqzzgm5wzv68v1hq59z4y.ls error="server returned 404: 404 page not found\n"9632026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9642026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/116mayvxgs8wsl9m39l99y0clq29z5f1w0d54szmzjjyr0q2fg3r.nar.zst error="server returned 404: 404 page not found\n"9652026/10/06 18:26:40 WARN Failed to register uploaded object key=7mmwlpj2ffr1fxz243q47jicyiv1qsg7.ls error="server returned 404: 404 page not found\n"9662026/10/06 18:26:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9672026/10/06 18:26:40 INFO Signed narinfos id=1 count=29682026/10/06 18:26:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9692026/10/06 18:26:40 INFO Signed narinfos id=2 count=29702026/10/06 18:26:40 INFO Uploading 4 narinfos9712026/10/06 18:26:40 WARN Failed to register uploaded object key=yx1valch2axrb7n413ihi5q21m7naddl.narinfo error="server returned 404: 404 page not found\n"9722026/10/06 18:26:40 INFO Vacuumed table table=pending_closures9732026/10/06 18:26:40 WARN Failed to register uploaded object key=1nr1k9ng3p9lqzzgm5wzv68v1hq59z4y.narinfo error="server returned 404: 404 page not found\n"9742026/10/06 18:26:40 WARN Failed to register uploaded object key=7mmwlpj2ffr1fxz243q47jicyiv1qsg7.narinfo error="server returned 404: 404 page not found\n"9752026/10/06 18:26:40 INFO Vacuumed table table=pending_objects9762026/10/06 18:26:40 INFO Vacuumed table table=multipart_uploads9772026/10/06 18:26:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9782026/10/06 18:26:40 WARN Failed to register uploaded object key=yx1valch2axrb7n413ihi5q21m7naddl.narinfo error="server returned 404: 404 page not found\n"9792026/10/06 18:26:40 INFO Vacuumed table table=closures9802026/10/06 18:26:40 INFO Vacuumed table table=objects9812026/10/06 18:26:40 INFO Completed upload id=19822026/10/06 18:26:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9832026/10/06 18:26:40 INFO Completed upload id=29842026/10/06 18:26:40 INFO Upload complete. (101ms)985=== NAME TestClientFallsBackToClosures986 client_pushes_test.go:112: Retrieved narinfo from S3:987 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientFallsBackToClosures3459535940/001/store/yx1valch2axrb7n413ihi5q21m7naddl-shared-dep988 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst989 Compression: zstd990 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82991 NarSize: 136992 References: 993 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n994 client_pushes_test.go:112: Retrieved narinfo from S3:995 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientFallsBackToClosures3459535940/001/store/7mmwlpj2ffr1fxz243q47jicyiv1qsg7-a996 URL: nar/116mayvxgs8wsl9m39l99y0clq29z5f1w0d54szmzjjyr0q2fg3r.nar.zst997 Compression: zstd998 NarHash: sha256:116mayvxgs8wsl9m39l99y0clq29z5f1w0d54szmzjjyr0q2fg3r999 NarSize: 2481000 References: /nix/var/nix/builds/nix-75043-2721225071/TestClientFallsBackToClosures3459535940/001/store/yx1valch2axrb7n413ihi5q21m7naddl-shared-dep1001 CA: text:sha256:1s0vmxlyd8ivcrl6mm4kfb598kg098x39yqqwb0xd9ylfjsjms6g1002 client_pushes_test.go:112: Retrieved narinfo from S3:1003 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientFallsBackToClosures3459535940/001/store/1nr1k9ng3p9lqzzgm5wzv68v1hq59z4y-b1004 URL: nar/116mayvxgs8wsl9m39l99y0clq29z5f1w0d54szmzjjyr0q2fg3r.nar.zst1005 Compression: zstd1006 NarHash: sha256:116mayvxgs8wsl9m39l99y0clq29z5f1w0d54szmzjjyr0q2fg3r1007 NarSize: 2481008 References: /nix/var/nix/builds/nix-75043-2721225071/TestClientFallsBackToClosures3459535940/001/store/yx1valch2axrb7n413ihi5q21m7naddl-shared-dep1009 CA: text:sha256:1s0vmxlyd8ivcrl6mm4kfb598kg098x39yqqwb0xd9ylfjsjms6g10102026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures1011--- PASS: TestClientFallsBackToClosures (1.96s)1012=== CONT TestPresignedUploadRegisteredBeforeCommit10132026/10/06 18:26:40 INFO Received push request method=POST path=/api/pushes10142026/10/06 18:26:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10152026/10/06 18:26:40 INFO Uploading zm01a0iv4l5ybk03npv1jwgnip6vcn0r-b (248B)10162026/10/06 18:26:40 INFO Uploading 5n1bpv4d2i68rb9jgsjxs3n1d64np92i-shared-dep (136B)10172026/10/06 18:26:40 WARN Failed to register uploaded object key=5n1bpv4d2i68rb9jgsjxs3n1d64np92i.ls error="server returned 404: 404 page not found\n"10182026/10/06 18:26:40 WARN Failed to register uploaded object key=z5xpadzf07xf3450zsamilh692h07myq.ls error="server returned 404: 404 page not found\n"10192026/10/06 18:26:40 WARN Failed to register uploaded object key=zm01a0iv4l5ybk03npv1jwgnip6vcn0r.ls error="server returned 404: 404 page not found\n"10202026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10212026/10/06 18:26:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/06 18:26:40 WARN Failed to register uploaded object key=nar/14j6d77wydr10a47xbv42avmqd0260y021sv3b7hb6mmyml7gfzm.nar.zst error="server returned 404: 404 page not found\n"10232026/10/06 18:26:40 INFO Signed narinfos id=1 count=310242026/10/06 18:26:40 INFO Uploading 3 narinfos10252026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures10262026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures10272026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures10282026/10/06 18:26:40 WARN Failed to register uploaded object key=5n1bpv4d2i68rb9jgsjxs3n1d64np92i.narinfo error="server returned 404: 404 page not found\n"10292026/10/06 18:26:40 WARN Failed to register uploaded object key=z5xpadzf07xf3450zsamilh692h07myq.narinfo error="server returned 404: 404 page not found\n"10302026/10/06 18:26:40 INFO Received complete push request method=POST path=/api/pushes/1/complete10312026/10/06 18:26:40 WARN Failed to register uploaded object key=zm01a0iv4l5ybk03npv1jwgnip6vcn0r.narinfo error="server returned 404: 404 page not found\n"10322026/10/06 18:26:40 INFO lead: released remote=192.0.2.1:123410332026/10/06 18:26:40 INFO Completed push id=110342026/10/06 18:26:40 INFO Upload complete. (103ms)1035=== NAME TestClientPushesUseOnePush1036 client_pushes_test.go:97: Retrieved narinfo from S3:1037 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientPushesUseOnePush3997845755/001/store/5n1bpv4d2i68rb9jgsjxs3n1d64np92i-shared-dep1038 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1039 Compression: zstd1040 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821041 NarSize: 1361042 References: 1043 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1044 client_pushes_test.go:97: Retrieved narinfo from S3:1045 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientPushesUseOnePush3997845755/001/store/z5xpadzf07xf3450zsamilh692h07myq-a1046 URL: nar/14j6d77wydr10a47xbv42avmqd0260y021sv3b7hb6mmyml7gfzm.nar.zst1047 Compression: zstd1048 NarHash: sha256:14j6d77wydr10a47xbv42avmqd0260y021sv3b7hb6mmyml7gfzm1049 NarSize: 2481050 References: /nix/var/nix/builds/nix-75043-2721225071/TestClientPushesUseOnePush3997845755/001/store/5n1bpv4d2i68rb9jgsjxs3n1d64np92i-shared-dep1051 CA: text:sha256:1z0jv5njjylrxj4g2kz6c817djvwia8hxdlm74rjwf7q516bl8qj1052 client_pushes_test.go:97: Retrieved narinfo from S3:1053 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientPushesUseOnePush3997845755/001/store/zm01a0iv4l5ybk03npv1jwgnip6vcn0r-b1054 URL: nar/14j6d77wydr10a47xbv42avmqd0260y021sv3b7hb6mmyml7gfzm.nar.zst1055 Compression: zstd1056 NarHash: sha256:14j6d77wydr10a47xbv42avmqd0260y021sv3b7hb6mmyml7gfzm1057 NarSize: 2481058 References: /nix/var/nix/builds/nix-75043-2721225071/TestClientPushesUseOnePush3997845755/001/store/5n1bpv4d2i68rb9jgsjxs3n1d64np92i-shared-dep1059 CA: text:sha256:1z0jv5njjylrxj4g2kz6c817djvwia8hxdlm74rjwf7q516bl8qj10602026/10/06 18:26:40 INFO lead: acquired remote=192.0.2.1:12341061--- PASS: TestClientPushesUseOnePush (2.15s)1062=== CONT TestReadProxyHead10632026/10/06 18:26:40 INFO Received cleanup request method=DELETE path=/api/pending_closures10642026/10/06 18:26:40 INFO Aborted multipart uploads count=0 kept=010652026/10/06 18:26:40 INFO Received uploads request method=POST path=/api/pending_closures10662026/10/06 18:26:40 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/10/06 18:26:40 INFO Aborted multipart uploads count=1 kept=010682026/10/06 18:26:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10692026-10-06 18:26:40.948 UTC [75237] ERROR: Closure does not exist: id=110702026-10-06 18:26:40.948 UTC [75237] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE10712026-10-06 18:26:40.948 UTC [75237] STATEMENT: -- name: CommitPendingClosure :exec1072 SELECT commit_pending_closure($1::bigint)1073 1074--- PASS: TestService_cleanupPendingClosuresHandler (1.69s)1075=== CONT TestReadProxyOutlastsServerWriteTimeout10762026/10/06 18:26:41 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/06 18:26:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10782026/10/06 18:26:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10792026/10/06 18:26:41 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LjNhMTk3ZjU3LWViNzMtNGIxOS1hY2RiLTJhMzEwYjg4NGQ1ZXgxNzkxMzExMjAwNTA3MTYyMDAw parts=1210802026/10/06 18:26:41 INFO Received uploads request method=POST path=/api/pending_closures1081--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.82s)10822026/10/06 18:26:41 INFO lead: released remote=192.0.2.1:12341083=== CONT TestPush_CompleteCommitsEveryRoot1084--- PASS: TestLeadElectsOneAndHandsOver (4.20s)1085=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10862026/10/06 18:26:41 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LjQ2MzZkOGE0LTdlMjItNGI5MC1iZWQ3LTQyYzQzNmRhOWJhZXgxNzkxMzExMjAwNjgwMzAxMDAw parts=1010872026/10/06 18:26:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10882026/10/06 18:26:41 INFO Completed upload id=110892026/10/06 18:26:41 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010902026/10/06 18:26:41 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/06 18:26:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures10922026/10/06 18:26:41 INFO Aborted multipart uploads count=0 kept=010932026/10/06 18:26:41 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=010942026/10/06 18:26:41 INFO Vacuumed table table=pending_closures10952026/10/06 18:26:41 INFO Vacuumed table table=pending_objects10962026/10/06 18:26:41 INFO Vacuumed table table=multipart_uploads10972026/10/06 18:26:41 INFO Vacuumed table table=closures1098--- PASS: TestService_Rustfstest (1.63s)1099=== CONT TestRedundantMultipartUpload11002026/10/06 18:26:41 INFO Vacuumed table table=objects11012026/10/06 18:26:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001102--- PASS: TestService_createPendingClosureHandler (3.00s)1103=== CONT TestPush_SignsNarinfosOfItsPendingObjects11042026/10/06 18:26:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/10/06 18:26:42 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/06 18:26:42 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11072026/10/06 18:26:42 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.87s)1109=== CONT TestPush_RejectsBadRequests11102026/10/06 18:26:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011112026/10/06 18:26:42 INFO Received create pin request method=POST path=/api/pins/myapp11122026/10/06 18:26:42 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-75043-2721225071/TestPinProtectsFromGC1615766461/001/store/6d3g74ldjqa60mgrg20zdz8b6604smrj-pinned-file.txt narinfo_key=6d3g74ldjqa60mgrg20zdz8b6604smrj.narinfo11132026/10/06 18:26:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures11142026/10/06 18:26:42 INFO Garbage collection started11152026/10/06 18:26:42 INFO Aborted multipart uploads count=0 kept=011162026/10/06 18:26:42 WARN Force mode enabled - objects will be deleted immediately without grace period11172026/10/06 18:26:42 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=011182026/10/06 18:26:42 INFO Vacuumed table table=pending_closures11192026/10/06 18:26:42 INFO Vacuumed table table=pending_objects11202026/10/06 18:26:42 INFO Vacuumed table table=multipart_uploads11212026/10/06 18:26:42 INFO Vacuumed table table=closures11222026/10/06 18:26:42 INFO Vacuumed table table=objects1123--- PASS: TestReadProxyHead (1.95s)1124=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11252026/10/06 18:26:43 INFO Received push request method=POST path=/api/pushes11262026/10/06 18:26:43 INFO Received complete push request method=POST path=/api/pushes/1/complete11272026/10/06 18:26:43 INFO Completed push id=11128--- PASS: TestPush_CompleteCommitsEveryRoot (1.98s)1129=== CONT TestPush_RepeatedRootCommitsOnce11302026/10/06 18:26:43 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/06 18:26:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026/10/06 18:26:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LmU0ZGQ2YjVkLWRhYzUtNGU4OS04ZTFhLWVlZDNhNDlmMTAwMHgxNzkxMzExMjAzOTI5MjgzMDAw11332026/10/06 18:26:44 INFO Received push request method=POST path=/api/pushes11342026/10/06 18:26:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LmU0ZGQ2YjVkLWRhYzUtNGU4OS04ZTFhLWVlZDNhNDlmMTAwMHgxNzkxMzExMjAzOTI5MjgzMDAw parts=11135--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.45s)1136=== CONT TestReadProxyInvalidPath11372026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11382026/10/06 18:26:44 INFO Signed narinfos id=1 count=111392026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11402026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11412026/10/06 18:26:44 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11422026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11432026/10/06 18:26:44 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11442026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11452026/10/06 18:26:44 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111462026/10/06 18:26:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11472026/10/06 18:26:44 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1148--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.31s)1149=== CONT TestProxyHeadersOnlyTrustedOnSocket1150--- PASS: TestConnectWaitsForAPeerMigration (6.53s)1151=== CONT TestIsValidCachePath1152=== RUN TestIsValidCachePath/narinfo1153=== PAUSE TestIsValidCachePath/narinfo1154=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1155=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1156=== RUN TestIsValidCachePath/nar_zst1157=== PAUSE TestIsValidCachePath/nar_zst1158=== RUN TestIsValidCachePath/nar_xz1159=== PAUSE TestIsValidCachePath/nar_xz1160=== RUN TestIsValidCachePath/nar_bz21161=== PAUSE TestIsValidCachePath/nar_bz21162=== RUN TestIsValidCachePath/nar_uncompressed1163=== PAUSE TestIsValidCachePath/nar_uncompressed1164=== RUN TestIsValidCachePath/ls1165=== PAUSE TestIsValidCachePath/ls1166=== RUN TestIsValidCachePath/log1167=== PAUSE TestIsValidCachePath/log1168=== RUN TestIsValidCachePath/realisation1169=== PAUSE TestIsValidCachePath/realisation1170=== RUN TestIsValidCachePath/nix-cache-info1171=== PAUSE TestIsValidCachePath/nix-cache-info1172=== RUN TestIsValidCachePath/index.html1173=== PAUSE TestIsValidCachePath/index.html1174=== RUN TestIsValidCachePath/traversal_parent1175=== PAUSE TestIsValidCachePath/traversal_parent1176=== RUN TestIsValidCachePath/traversal_in_middle1177=== PAUSE TestIsValidCachePath/traversal_in_middle1178=== RUN TestIsValidCachePath/invalid_char_e1179=== PAUSE TestIsValidCachePath/invalid_char_e1180=== RUN TestIsValidCachePath/invalid_char_u1181=== PAUSE TestIsValidCachePath/invalid_char_u1182=== RUN TestIsValidCachePath/random_path1183=== PAUSE TestIsValidCachePath/random_path1184=== RUN TestIsValidCachePath/empty1185=== PAUSE TestIsValidCachePath/empty1186=== RUN TestIsValidCachePath/leading_slash1187=== PAUSE TestIsValidCachePath/leading_slash1188=== RUN TestIsValidCachePath/wrong_extension1189=== PAUSE TestIsValidCachePath/wrong_extension1190=== RUN TestIsValidCachePath/short_hash1191=== PAUSE TestIsValidCachePath/short_hash1192=== CONT TestParseSingleRange1193=== RUN TestParseSingleRange/none1194=== PAUSE TestParseSingleRange/none1195=== RUN TestParseSingleRange/unknown_unit1196=== PAUSE TestParseSingleRange/unknown_unit1197=== RUN TestParseSingleRange/multi-range_ignored1198=== PAUSE TestParseSingleRange/multi-range_ignored1199=== RUN TestParseSingleRange/malformed_no_dash1200=== PAUSE TestParseSingleRange/malformed_no_dash1201=== RUN TestParseSingleRange/malformed_both_empty1202=== PAUSE TestParseSingleRange/malformed_both_empty1203=== RUN TestParseSingleRange/malformed_end_before_start1204=== PAUSE TestParseSingleRange/malformed_end_before_start1205=== RUN TestParseSingleRange/closed1206=== PAUSE TestParseSingleRange/closed1207=== RUN TestParseSingleRange/open-ended1208=== PAUSE TestParseSingleRange/open-ended1209=== RUN TestParseSingleRange/end_clamped_to_size1210=== PAUSE TestParseSingleRange/end_clamped_to_size1211=== RUN TestParseSingleRange/suffix1212=== PAUSE TestParseSingleRange/suffix1213=== RUN TestParseSingleRange/suffix_exceeds_size1214=== PAUSE TestParseSingleRange/suffix_exceeds_size1215=== RUN TestParseSingleRange/single_byte1216=== PAUSE TestParseSingleRange/single_byte1217=== RUN TestParseSingleRange/start_past_EOF1218=== PAUSE TestParseSingleRange/start_past_EOF1219=== RUN TestParseSingleRange/start_far_past_EOF1220=== PAUSE TestParseSingleRange/start_far_past_EOF1221=== CONT TestCacheConfigHandler1222=== RUN TestCacheConfigHandler/full_config,_no_issuer1223=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1224=== RUN TestCacheConfigHandler/no_cache_url_configured1225=== PAUSE TestCacheConfigHandler/no_cache_url_configured1226=== RUN TestCacheConfigHandler/no_signing_keys1227=== PAUSE TestCacheConfigHandler/no_signing_keys1228=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1229=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1230=== CONT TestClientWithDependencies1231=== NAME TestPinProtectsFromGC1232 client_integration_test.go:840: Pin successfully protected closure from garbage collection12332026/10/06 18:26:44 INFO Received uploads request method=POST path=/api/pending_closures1234--- PASS: TestPinProtectsFromGC (5.82s)1235=== CONT TestClientMultipleUploads12362026/10/06 18:26:44 INFO Received uploads request method=POST path=/api/pending_closures1237=== RUN TestPush_RejectsBadRequests/no_objects1238=== PAUSE TestPush_RejectsBadRequests/no_objects1239=== RUN TestPush_RejectsBadRequests/bad_root1240=== PAUSE TestPush_RejectsBadRequests/bad_root1241=== RUN TestPush_RejectsBadRequests/root_not_in_objects1242=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1243=== RUN TestPush_RejectsBadRequests/no_roots1244=== PAUSE TestPush_RejectsBadRequests/no_roots1245=== CONT TestClientIntegration12462026/10/06 18:26:44 INFO Received push request method=POST path=/api/pushes12472026/10/06 18:26:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12482026/10/06 18:26:45 INFO Completed push id=112492026/10/06 18:26:45 INFO Received push request method=POST path=/api/pushes12502026/10/06 18:26:45 INFO Aborted multipart uploads count=0 kept=012512026/10/06 18:26:45 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/06 18:26:45 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=012532026/10/06 18:26:45 INFO Vacuumed table table=pending_closures12542026/10/06 18:26:45 INFO Vacuumed table table=pending_objects12552026/10/06 18:26:45 INFO Vacuumed table table=multipart_uploads12562026/10/06 18:26:45 INFO Vacuumed table table=closures12572026/10/06 18:26:45 INFO Vacuumed table table=objects12582026/10/06 18:26:45 INFO Received complete push request method=POST path=/api/pushes/2/complete12592026/10/06 18:26:45 INFO Completed push id=21260--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.55s)1261=== CONT TestClientErrorHandling1262=== RUN TestClientErrorHandling/InvalidStorePath1263=== PAUSE TestClientErrorHandling/InvalidStorePath1264=== RUN TestClientErrorHandling/InvalidAuthToken1265=== PAUSE TestClientErrorHandling/InvalidAuthToken1266=== RUN TestClientErrorHandling/ServerNotAvailable1267=== PAUSE TestClientErrorHandling/ServerNotAvailable1268=== CONT TestClientCADerivations12692026/10/06 18:26:45 INFO Received push request method=POST path=/api/pushes12702026/10/06 18:26:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12712026/10/06 18:26:45 INFO Completed push id=11272--- PASS: TestPush_RepeatedRootCommitsOnce (2.00s)1273=== CONT TestCacheStatsHandler12742026/10/06 18:26:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12752026/10/06 18:26:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LmEwOGI3ZmE5LWI1NWYtNGE2Ni04N2UzLWFhNDBmMTJkYzkwZXgxNzkxMzExMjA0NDY3MjYzMDAw parts=121276--- PASS: TestReadProxyInvalidPath (1.72s)1277=== CONT TestGCEndsOnShutdown1278=== RUN TestGCEndsOnShutdown/before_the_run1279=== PAUSE TestGCEndsOnShutdown/before_the_run1280=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1281=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1282=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1283=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1284=== CONT TestGenerateLandingPage12852026/10/06 18:26:45 INFO Received uploads request method=POST path=/api/pending_closures1286--- PASS: TestGenerateLandingPage (0.00s)1287=== CONT TestService_readinessHandler12882026/10/06 18:26:45 INFO Received uploads request method=POST path=/api/pending_closures12892026/10/06 18:26:46 INFO Starting HTTP server address=/nix/var/nix/builds/nix-75043-2721225071/TestProxyHeadersOnlyTrustedOnSocket776980887/001/proxy.sock12902026/10/06 18:26:46 INFO Starting HTTP server address=127.0.0.1:5875012912026/10/06 18:26:46 WARN mTLS auth: subject not in bound subjects subject="CN=someone"12922026/10/06 18:26:46 INFO Shutdown signal received, draining in-flight requests timeout=10s1293--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.91s)1294=== CONT TestService_healthCheckHandler12952026/10/06 18:26:46 WARN Rate limiter enabled after throttle name=s3-test rate=512962026/10/06 18:26:46 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1297=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1298 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101299 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001300--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.15s)1301=== CONT TestGracefulShutdownDrainsInflight13022026/10/06 18:26:46 INFO Starting HTTP server address=127.0.0.1:5875813032026/10/06 18:26:46 INFO Shutdown signal received, draining in-flight requests timeout=10s1304--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1305=== CONT TestGCTaskStore_Fail1306--- PASS: TestGCTaskStore_Fail (0.00s)1307=== CONT TestGCTaskStore_PhaseUpdates1308--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1309=== CONT TestGCTaskStore_CompletedAllowsNewTask1310--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1311=== CONT TestGCTaskStore_GetReturnsLatest1312--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1313=== CONT TestGCTaskStore_GetEmpty1314--- PASS: TestGCTaskStore_GetEmpty (0.00s)1315=== CONT TestGCTaskStore_ConflictDifferentParams1316--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1317=== CONT TestGCTaskStore_DeduplicateSameParams1318--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1319=== CONT TestGCTaskStore_StartNew1320--- PASS: TestGCTaskStore_StartNew (0.00s)1321=== CONT TestSweepSkipsRowsLockedByPush1322=== NAME TestClientIntegration1323 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-75043-2721225071/TestClientIntegration3255012311/002/store/n9x5x9a06qzb2agwzrni9m2drz3dpczh-test-file.txt1324=== NAME TestClientWithDependencies1325 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-75043-2721225071/TestClientWithDependencies1646758759/001/store/xsk127a4f4yx3qks69x0hgp41srrsvag-test-script1326 client_integration_test.go:615: Found 1 dependencies (including self)13272026/10/06 18:26:46 INFO Received push request method=POST path=/api/pushes13282026/10/06 18:26:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13292026/10/06 18:26:46 INFO Uploading n9x5x9a06qzb2agwzrni9m2drz3dpczh-test-file.txt (152B)13302026/10/06 18:26:46 WARN Failed to register uploaded object key=n9x5x9a06qzb2agwzrni9m2drz3dpczh.ls error="server returned 404: 404 page not found\n"13312026/10/06 18:26:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13322026/10/06 18:26:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13332026/10/06 18:26:46 INFO Signed narinfos id=1 count=113342026/10/06 18:26:46 INFO Uploading 1 narinfos13352026/10/06 18:26:46 INFO Received push request method=POST path=/api/pushes13362026/10/06 18:26:46 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/06 18:26:46 WARN Failed to register uploaded object key=n9x5x9a06qzb2agwzrni9m2drz3dpczh.narinfo error="server returned 404: 404 page not found\n"13382026/10/06 18:26:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13392026/10/06 18:26:46 INFO Uploading xsk127a4f4yx3qks69x0hgp41srrsvag-test-script (136B)13402026/10/06 18:26:46 INFO Completed push id=113412026/10/06 18:26:46 INFO Upload complete. (132ms)13422026/10/06 18:26:46 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13432026/10/06 18:26:46 WARN Failed to register uploaded object key=xsk127a4f4yx3qks69x0hgp41srrsvag.ls error="server returned 404: 404 page not found\n"1344=== NAME TestClientMultipleUploads1345 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-75043-2721225071/TestClientMultipleUploads3986033100/001/store/cicm8hvy2m085r28fx2m0kl32jhrydak-test-file-0.txt13462026/10/06 18:26:46 WARN Failed to register uploaded object key=log/l1fi5kqws72rpfpxqncxlr9qdfpq6gka-test-script.drv error="server returned 404: 404 page not found\n"13472026/10/06 18:26:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13482026/10/06 18:26:46 INFO All 1 paths already cached13492026/10/06 18:26:46 INFO Signed narinfos id=1 count=113502026/10/06 18:26:46 INFO Uploading 1 narinfos1351=== NAME TestClientIntegration1352 client_integration_test.go:312: Retrieved narinfo from S3:1353 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientIntegration3255012311/002/store/n9x5x9a06qzb2agwzrni9m2drz3dpczh-test-file.txt1354 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1355 Compression: zstd1356 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11357 NarSize: 1521358 References: 1359 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11360 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1361 client_integration_test.go:313: Decompressed .ls content (64 bytes):1362 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1363 client_integration_test.go:316: Testing garbage collection...13642026/10/06 18:26:47 INFO Received complete push request method=POST path=/api/pushes/1/complete13652026/10/06 18:26:47 WARN Failed to register uploaded object key=xsk127a4f4yx3qks69x0hgp41srrsvag.narinfo error="server returned 404: 404 page not found\n"13662026/10/06 18:26:47 INFO Completed push id=113672026/10/06 18:26:47 INFO Upload complete. (142ms)1368=== NAME TestClientWithDependencies1369 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-75043-2721225071/TestClientWithDependencies1646758759/001/store) requires matching store prefix13702026/10/06 18:26:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures13712026/10/06 18:26:47 INFO Garbage collection started13722026/10/06 18:26:47 INFO Aborted multipart uploads count=0 kept=013732026/10/06 18:26:47 WARN Force mode enabled - objects will be deleted immediately without grace period1374=== NAME TestClientMultipleUploads1375 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-75043-2721225071/TestClientMultipleUploads3986033100/001/store/lki3bsn2pvqds8zlv4vrp534s2i3skkf-test-file-1.txt1376--- PASS: TestClientWithDependencies (2.75s)1377=== CONT TestCommitRacingPendingCleanupKeepsObjects13782026/10/06 18:26: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=013792026/10/06 18:26:47 INFO Vacuumed table table=pending_closures1380=== NAME TestClientMultipleUploads1381 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-75043-2721225071/TestClientMultipleUploads3986033100/001/store/rxrcn65i5f2y44j73ynqdsxf74k48qf1-test-file-2.txt1382--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.20s)1383=== CONT TestPushWaitsForSweepHoldingRow13842026/10/06 18:26:47 INFO Vacuumed table table=pending_objects13852026/10/06 18:26:47 INFO Vacuumed table table=multipart_uploads13862026/10/06 18:26:47 INFO Vacuumed table table=closures13872026/10/06 18:26:47 INFO Vacuumed table table=objects13882026/10/06 18:26:47 INFO Received push request method=POST path=/api/pushes13892026/10/06 18:26:47 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13902026/10/06 18:26:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13912026/10/06 18:26:47 INFO Uploading rxrcn65i5f2y44j73ynqdsxf74k48qf1-test-file-2.txt (160B)13922026/10/06 18:26:47 INFO Uploading cicm8hvy2m085r28fx2m0kl32jhrydak-test-file-0.txt (160B)13932026/10/06 18:26:47 INFO Uploading lki3bsn2pvqds8zlv4vrp534s2i3skkf-test-file-1.txt (160B)13942026/10/06 18:26:47 WARN Failed to register uploaded object key=cicm8hvy2m085r28fx2m0kl32jhrydak.ls error="server returned 404: 404 page not found\n"13952026/10/06 18:26:47 WARN Failed to register uploaded object key=lki3bsn2pvqds8zlv4vrp534s2i3skkf.ls error="server returned 404: 404 page not found\n"13962026/10/06 18:26:47 WARN Failed to register uploaded object key=rxrcn65i5f2y44j73ynqdsxf74k48qf1.ls error="server returned 404: 404 page not found\n"13972026/10/06 18:26:47 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13982026/10/06 18:26:47 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13992026/10/06 18:26:47 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14002026/10/06 18:26:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14012026/10/06 18:26:47 INFO Signed narinfos id=1 count=314022026/10/06 18:26:47 INFO Uploading 3 narinfos14032026/10/06 18:26:47 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LjBmOWY1Mzc1LTUzN2MtNDU3OC05MDJiLWY4ZGE5ODFjYWMzZHgxNzkxMzExMjA1OTg3NTU2MDAw error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14042026/10/06 18:26:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmVjMGVhNzAtOWExMy00OWUzLTllODYtZWJmMTE5ZDJmM2Q2LjU3M2FlYThiLWY4MGEtNDc1ZS05ZGZjLTA5MzE5N2VhMWI4NXgxNzkxMzExMjA1OTUyMDAyMDAw parts=1214052026/10/06 18:26:47 INFO Received cleanup request method=DELETE path=/api/pending_closures14062026/10/06 18:26:47 INFO Aborted multipart uploads count=1 kept=014072026/10/06 18:26:47 WARN Failed to register uploaded object key=cicm8hvy2m085r28fx2m0kl32jhrydak.narinfo error="server returned 404: 404 page not found\n"14082026/10/06 18:26:47 WARN Failed to register uploaded object key=lki3bsn2pvqds8zlv4vrp534s2i3skkf.narinfo error="server returned 404: 404 page not found\n"1409--- PASS: TestRedundantMultipartUpload (5.37s)1410=== CONT TestSweepRechecksPendingAfterLocking14112026/10/06 18:26:47 INFO Received complete push request method=POST path=/api/pushes/1/complete14122026/10/06 18:26:47 WARN Failed to register uploaded object key=rxrcn65i5f2y44j73ynqdsxf74k48qf1.narinfo error="server returned 404: 404 page not found\n"14132026/10/06 18:26:47 INFO Completed push id=114142026/10/06 18:26:47 INFO Upload complete. (148ms)1415=== NAME TestClientMultipleUploads1416 client_integration_test.go:369: Uploaded 3 paths in 181.554875ms1417=== CONT TestGetExistingObjectsLocksRows1418--- PASS: TestClientMultipleUploads (2.89s)1419=== NAME TestClientCADerivations1420 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-75043-2721225071/TestClientCADerivations1768071649/001/store/xwywqjdyw0wwc92nswc4hvl08h5d035s-ca-test1421--- PASS: TestCacheStatsHandler (1.83s)1422=== CONT TestRegisterCompletedObjectNeedsPendingRow1423=== NAME TestClientCADerivations1424 client_ca_test.go:139: Found 1 dependencies (including self)14252026/10/06 18:26:47 WARN readiness check failed error="closed pool"1426--- PASS: TestService_readinessHandler (1.75s)1427=== CONT TestReadProxyRangeRequest14282026/10/06 18:26:47 INFO Received push request method=POST path=/api/pushes14292026/10/06 18:26:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14302026/10/06 18:26:47 INFO Uploading xwywqjdyw0wwc92nswc4hvl08h5d035s-ca-test (144B)14312026/10/06 18:26:47 WARN Failed to register uploaded object key=xwywqjdyw0wwc92nswc4hvl08h5d035s.ls error="server returned 404: 404 page not found\n"14322026/10/06 18:26:47 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14332026/10/06 18:26:47 WARN Failed to register uploaded object key=log/qi4ph7qs334vmf6b71j43w6nh4wmaz1k-ca-test.drv error="server returned 404: 404 page not found\n"14342026/10/06 18:26:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14352026/10/06 18:26:47 INFO Signed narinfos id=1 count=114362026/10/06 18:26:47 INFO Uploading 1 narinfos14372026/10/06 18:26:47 INFO Received complete push request method=POST path=/api/pushes/1/complete14382026/10/06 18:26:47 WARN Failed to register uploaded object key=xwywqjdyw0wwc92nswc4hvl08h5d035s.narinfo error="server returned 404: 404 page not found\n"14392026/10/06 18:26:47 INFO Completed push id=114402026/10/06 18:26:47 INFO Upload complete. (163ms)1441=== NAME TestClientCADerivations1442 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestClientCADerivations1768071649/001/store/xwywqjdyw0wwc92nswc4hvl08h5d035s-ca-test1443 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1444 Compression: zstd1445 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1446 NarSize: 1441447 References: 1448 Deriver: /nix/var/nix/builds/nix-75043-2721225071/TestClientCADerivations1768071649/001/store/qi4ph7qs334vmf6b71j43w6nh4wmaz1k-ca-test.drv1449 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1450 client_ca_test.go:185: Checking for realisation files in S3...1451 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1452 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1453 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket46?endpoint=http://localhost:58541®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-75043-2721225071/TestClientCADerivations1768071649/001/store'1454 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11455--- PASS: TestService_healthCheckHandler (1.67s)1456=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1457--- PASS: TestClientCADerivations (2.70s)1458=== CONT TestReadRedirectUsesPublicS3URL14592026/10/06 18:26:48 INFO Aborted multipart uploads count=0 kept=014602026/10/06 18:26:48 WARN Force mode enabled - objects will be deleted immediately without grace period14612026/10/06 18:26:48 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=014622026/10/06 18:26:48 INFO Vacuumed table table=pending_closures14632026/10/06 18:26:48 INFO Vacuumed table table=pending_objects14642026/10/06 18:26:48 INFO Vacuumed table table=multipart_uploads14652026/10/06 18:26:48 INFO Vacuumed table table=closures14662026/10/06 18:26:48 INFO Vacuumed table table=objects14672026/10/06 18:26:48 INFO Aborted multipart uploads count=0 kept=014682026/10/06 18:26:48 WARN Force mode enabled - objects will be deleted immediately without grace period14692026/10/06 18:26:48 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=014702026/10/06 18:26:48 INFO Vacuumed table table=pending_closures14712026/10/06 18:26:48 INFO Vacuumed table table=pending_objects14722026/10/06 18:26:48 INFO Vacuumed table table=multipart_uploads14732026/10/06 18:26:48 INFO Vacuumed table table=closures14742026/10/06 18:26:48 INFO Vacuumed table table=objects1475--- PASS: TestSweepSkipsRowsLockedByPush (1.77s)1476=== CONT TestReadProxy40414772026/10/06 18:26:48 INFO Received uploads request method=POST path=/api/pending_closures14782026/10/06 18:26:48 INFO Aborted multipart uploads count=0 kept=014792026/10/06 18:26:48 WARN Force mode enabled - objects will be deleted immediately without grace period14802026/10/06 18:26:48 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=014812026/10/06 18:26:48 INFO Vacuumed table table=pending_closures14822026/10/06 18:26:48 INFO Vacuumed table table=pending_objects14832026/10/06 18:26:48 INFO Vacuumed table table=multipart_uploads14842026/10/06 18:26:48 INFO Vacuumed table table=closures14852026/10/06 18:26:48 INFO Vacuumed table table=objects1486--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.63s)1487=== CONT TestPendingCleanupUsesOneCutoff1488--- PASS: TestPushWaitsForSweepHoldingRow (1.72s)1489=== CONT TestPresentNotReportedWhileGCDeletesClosure14902026/10/06 18:26:48 INFO Aborted multipart uploads count=0 kept=014912026/10/06 18:26:48 WARN Force mode enabled - objects will be deleted immediately without grace period14922026/10/06 18:26:48 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=014932026/10/06 18:26:48 INFO Vacuumed table table=pending_closures14942026/10/06 18:26:48 INFO Vacuumed table table=pending_objects14952026/10/06 18:26:48 INFO Vacuumed table table=multipart_uploads14962026/10/06 18:26:48 INFO Vacuumed table table=closures14972026/10/06 18:26:48 INFO Vacuumed table table=objects1498--- PASS: TestSweepRechecksPendingAfterLocking (1.65s)1499=== CONT TestPresentReportsOnlyClosureRoots15002026/10/06 18:26:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01501=== NAME TestClientIntegration1502 client_integration_test.go:323: Objects in database after GC:1503 client_integration_test.go:323: Successfully deleted all objects with GC --force1504--- PASS: TestClientIntegration (4.40s)1505=== CONT TestCreatePin_ReservedPins1506--- PASS: TestGetExistingObjectsLocksRows (1.71s)1507=== CONT TestOrphanedObjectsGCStressTest1508--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.66s)1509=== CONT TestOrphanedObjectsGC15102026/10/06 18:26:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58836/oidc1511--- PASS: TestReadProxyRangeRequest (1.70s)1512=== CONT TestObjectStatsTrigger15132026/10/06 18:26:49 INFO Received push request method=POST path=/api/pushes1514--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.77s)1515=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1516--- PASS: TestReadRedirectUsesPublicS3URL (1.85s)1517=== CONT TestFailedS3DeleteKeepsTombstone1518--- PASS: TestReadProxy404 (1.90s)1519=== CONT TestForceGCDuringPushOffersSweptObject1520=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1521=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1522=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1523=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1524=== CONT TestReadRedirectNar15252026/10/06 18:26:50 INFO Received uploads request method=POST path=/api/pending_closures15262026/10/06 18:26:50 INFO Received uploads request method=POST path=/api/pending_closures15272026/10/06 18:26:50 INFO Received cleanup request method=DELETE path=/api/pending_closures1528--- PASS: TestPresentReportsOnlyClosureRoots (1.92s)1529=== CONT TestReadRedirectKeepsNarinfoProxied1530--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.25s)1531=== CONT TestService_AuthMiddleware_OIDC15322026/10/06 18:26:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58866/oidc15332026/10/06 18:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15342026/10/06 18:26:51 WARN Refused reserved pin name=worker-x86_64-linux15352026/10/06 18:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15362026/10/06 18:26:51 INFO Received create pin request method=POST path=/api/pins/my-app15372026/10/06 18:26:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1538--- PASS: TestCreatePin_ReservedPins (2.18s)1539=== CONT TestService_ReadScope_PublicByDefault1540--- PASS: TestObjectStatsTrigger (2.26s)1541=== CONT TestService_RequireScope_OIDC15422026/10/06 18:26:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58877/oidc15432026/10/06 18:26:51 INFO Received uploads request method=POST path=/api/pending_closures1544=== NAME TestOrphanedObjectsGC1545 orphaned_objects_gc_test.go:290: GC Test Summary:1546 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1547 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1548 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1549 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1550 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1551--- PASS: TestOrphanedObjectsGC (2.78s)1552=== CONT TestTombstonedObjectOfferedWithoutWaiting15532026/10/06 18:26:52 INFO Received uploads request method=POST path=/api/pending_closures1554--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.46s)1555=== CONT TestGCSweepDeliversEachKeyOnce15562026/10/06 18:26:52 INFO Aborted multipart uploads count=0 kept=015572026/10/06 18:26:52 WARN Force mode enabled - objects will be deleted immediately without grace period15582026/10/06 18:26:52 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15592026/10/06 18:26:52 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1560--- PASS: TestFailedS3DeleteKeepsTombstone (2.46s)1561=== CONT TestGCSweepSkipsPendingObjects1562--- PASS: TestReadRedirectNar (2.26s)1563=== CONT TestReadProxyDisabled1564--- PASS: TestReadRedirectKeepsNarinfoProxied (1.78s)1565=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1566=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1567=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1568=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1569=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1570=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1571=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1572=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1573=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1574=== CONT TestService_ReadAuthMiddleware1575--- PASS: TestService_ReadScope_PublicByDefault (2.12s)1576=== CONT TestService_AuthMiddleware_MTLSProxyHeader1577=== RUN TestService_RequireScope_OIDC/builder_may_write1578=== PAUSE TestService_RequireScope_OIDC/builder_may_write1579=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1580=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1581=== RUN TestService_RequireScope_OIDC/ops_may_admin1582=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1583=== RUN TestService_RequireScope_OIDC/ops_may_not_write1584=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1585=== RUN TestService_RequireScope_OIDC/reader_may_not_write1586=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1587=== RUN TestService_RequireScope_OIDC/static_token_may_admin1588=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1589=== RUN TestService_RequireScope_OIDC/static_token_may_write1590=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1591=== RUN TestService_RequireScope_OIDC/reader_may_read1592=== PAUSE TestService_RequireScope_OIDC/reader_may_read1593=== RUN TestService_RequireScope_OIDC/writer_implies_read1594=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1595=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1596=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1597=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1598=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1599=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1600=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1601=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1602=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1603=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1604=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1605=== CONT TestServerTLSConfig1606=== RUN TestServerTLSConfig/no_client_CA1607=== PAUSE TestServerTLSConfig/no_client_CA1608=== RUN TestServerTLSConfig/missing_CA_file1609=== PAUSE TestServerTLSConfig/missing_CA_file1610=== RUN TestServerTLSConfig/not_a_PEM_file1611=== PAUSE TestServerTLSConfig/not_a_PEM_file1612=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16132026/10/06 18:26:54 INFO Received uploads request method=POST path=/api/pending_closures1614--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.13s)1615=== CONT TestMultipartCleanup16162026/10/06 18:26:54 INFO Aborted multipart uploads count=0 kept=016172026/10/06 18:26:54 WARN Force mode enabled - objects will be deleted immediately without grace period16182026/10/06 18:26:54 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=016192026/10/06 18:26:54 INFO Vacuumed table table=pending_closures16202026/10/06 18:26:54 INFO Vacuumed table table=pending_objects16212026/10/06 18:26:54 INFO Vacuumed table table=multipart_uploads16222026/10/06 18:26:54 INFO Vacuumed table table=closures16232026/10/06 18:26:54 INFO Vacuumed table table=objects1624--- PASS: TestGCSweepDeliversEachKeyOnce (2.45s)1625=== CONT TestMetricsInventory16262026/10/06 18:26:54 INFO Received uploads request method=POST path=/api/pending_closures16272026/10/06 18:26:54 INFO Aborted multipart uploads count=0 kept=016282026/10/06 18:26:54 WARN Force mode enabled - objects will be deleted immediately without grace period16292026/10/06 18:26:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016302026/10/06 18:26:54 INFO Vacuumed table table=pending_closures16312026/10/06 18:26:54 INFO Vacuumed table table=pending_objects16322026/10/06 18:26:54 INFO Vacuumed table table=multipart_uploads16332026/10/06 18:26:54 INFO Vacuumed table table=closures16342026/10/06 18:26:54 INFO Vacuumed table table=objects1635--- PASS: TestGCSweepSkipsPendingObjects (2.63s)1636=== CONT TestService_NativeMTLS1637--- PASS: TestReadProxyDisabled (2.64s)1638=== CONT TestNARDeduplicationMetadataUploadBug16392026/10/06 18:26:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16402026/10/06 18:26:55 WARN mTLS auth: bound subjects configured but subject DN unavailable16412026/10/06 18:26:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1642--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.58s)1643=== CONT TestConcurrentPresentSharingKeysDoNotDeadlock1644--- PASS: TestService_ReadAuthMiddleware (2.50s)1645=== CONT TestResolveDBConnectionString/flag_wins1646=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1647=== CONT TestResolveDBConnectionString/nothing_configured1648=== CONT TestResolveDBConnectionString/file_when_flag_empty1649=== CONT TestResolveDBConnectionString/missing_file_is_an_error1650=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16512026/10/06 18:26:55 INFO Received complete multipart upload request method=POST path=/1652--- PASS: TestResolveDBConnectionString (0.02s)1653 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1654 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1655 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1656 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1657 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1658=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16592026/10/06 18:26:55 INFO Received uploads request method=POST path=/1660--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.51s)1661=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16622026/10/06 18:26:55 INFO Received request for more parts method=POST path=/1663=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16642026/10/06 18:26:55 INFO Received uploads request method=POST path=/1665=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16662026/10/06 18:26:55 INFO Received complete multipart upload request method=POST path=/1667=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16682026/10/06 18:26:55 INFO Received request for more parts method=POST path=/1669=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16702026/10/06 18:26:55 INFO Received uploads request method=POST path=/1671--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1672 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1673 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1674 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1675 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1676=== CONT TestIsValidUploadKey/narinfo1677=== CONT TestIsValidUploadKey/realisation_plus_in_output1678=== CONT TestIsValidUploadKey/unknown_type1679=== CONT TestIsValidUploadKey/empty_key1680=== CONT TestIsValidUploadKey/absolute1681=== CONT TestIsValidUploadKey/traversal_nar1682=== CONT TestIsValidUploadKey/traversal1683=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1684=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1685=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1686=== CONT TestIsValidUploadKey/index.html1687=== CONT TestIsValidUploadKey/nix-cache-info1688=== CONT TestIsValidUploadKey/build_log_home-manager_file1689=== CONT TestIsValidUploadKey/nar_plain1690=== CONT TestIsValidUploadKey/realisation1691=== CONT TestIsValidUploadKey/build_log1692=== CONT TestIsValidUploadKey/build_log_equals1693=== CONT TestIsValidUploadKey/listing1694=== CONT TestIsValidUploadKey/build_log_question_mark1695=== CONT TestIsValidUploadKey/nar_zst1696=== CONT TestIsValidUploadKey/nar_xz1697=== CONT TestPendingClosureWriteTimeout/empty1698=== CONT TestPendingClosureWriteTimeout/670k_objects1699=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1700=== CONT TestPendingClosureWriteTimeout/400_objects1701--- PASS: TestUploadHandlersRejectOversizedBody (0.02s)1702 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1703 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1704 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1705=== CONT TestProxyWriteTimeout/narinfo1706=== CONT TestIsValidUploadKey/build_log_plus_in_name1707=== CONT TestProxyWriteTimeout/10_GiB_nar1708=== CONT TestProxyWriteTimeout/unknown_size1709=== CONT TestProxyWriteTimeout/1_GiB_nar1710=== CONT TestIsValidCachePath/narinfo1711=== CONT TestIsValidCachePath/index.html1712=== CONT TestIsValidCachePath/nix-cache-info1713=== CONT TestIsValidCachePath/realisation1714=== CONT TestIsValidCachePath/log1715=== CONT TestIsValidCachePath/ls1716--- PASS: TestIsValidUploadKey (0.00s)1717 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1718 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1719 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1720 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1721 --- PASS: TestIsValidUploadKey/absolute (0.00s)1722 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1723 --- PASS: TestIsValidUploadKey/traversal (0.00s)1724 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1725 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1726 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1727 --- PASS: TestIsValidUploadKey/index.html (0.00s)1728 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1729 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1730 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1731 --- PASS: TestIsValidUploadKey/realisation (0.00s)1732 --- PASS: TestIsValidUploadKey/build_log (0.00s)1733 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1734 --- PASS: TestIsValidUploadKey/listing (0.00s)1735 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1736 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1737 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1738 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1739=== CONT TestIsValidCachePath/nar_uncompressed1740=== CONT TestIsValidCachePath/nar_bz21741=== CONT TestIsValidCachePath/nar_xz1742=== CONT TestIsValidCachePath/nar_zst1743=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1744=== CONT TestIsValidCachePath/empty1745=== CONT TestIsValidCachePath/traversal_parent1746=== CONT TestIsValidCachePath/random_path1747=== CONT TestIsValidCachePath/invalid_char_u1748=== CONT TestIsValidCachePath/invalid_char_e1749=== CONT TestIsValidCachePath/traversal_in_middle1750--- PASS: TestProxyWriteTimeout (0.00s)1751 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1752 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1753 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1754 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1755=== CONT TestIsValidCachePath/wrong_extension1756=== CONT TestIsValidCachePath/short_hash1757=== CONT TestIsValidCachePath/leading_slash1758=== CONT TestParseSingleRange/none1759--- PASS: TestIsValidCachePath (0.00s)1760 --- PASS: TestIsValidCachePath/narinfo (0.00s)1761 --- PASS: TestIsValidCachePath/index.html (0.00s)1762 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1763 --- PASS: TestIsValidCachePath/realisation (0.00s)1764 --- PASS: TestIsValidCachePath/log (0.00s)1765 --- PASS: TestIsValidCachePath/ls (0.00s)1766 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1767 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1768 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1769 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1770 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1771 --- PASS: TestIsValidCachePath/empty (0.00s)1772 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1773 --- PASS: TestIsValidCachePath/random_path (0.00s)1774 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1775 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1776 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1777 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1778 --- PASS: TestIsValidCachePath/short_hash (0.00s)1779 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1780=== CONT TestParseSingleRange/open-ended1781=== CONT TestParseSingleRange/start_far_past_EOF1782=== CONT TestParseSingleRange/start_past_EOF1783=== CONT TestParseSingleRange/single_byte1784=== CONT TestParseSingleRange/suffix_exceeds_size1785=== CONT TestParseSingleRange/suffix1786=== CONT TestParseSingleRange/end_clamped_to_size1787=== CONT TestParseSingleRange/closed1788=== CONT TestParseSingleRange/malformed_end_before_start1789=== CONT TestParseSingleRange/multi-range_ignored1790=== CONT TestParseSingleRange/malformed_no_dash1791=== CONT TestParseSingleRange/unknown_unit1792=== CONT TestParseSingleRange/malformed_both_empty1793--- PASS: TestParseSingleRange (0.00s)1794 --- PASS: TestParseSingleRange/none (0.00s)1795 --- PASS: TestParseSingleRange/open-ended (0.00s)1796 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1797 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1798 --- PASS: TestParseSingleRange/single_byte (0.00s)1799 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1800 --- PASS: TestParseSingleRange/suffix (0.00s)1801 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1802 --- PASS: TestParseSingleRange/closed (0.00s)1803 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1804 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1805 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1806 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1807 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1808=== CONT TestCacheConfigHandler/full_config,_no_issuer1809=== CONT TestCacheConfigHandler/no_signing_keys1810=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1811=== CONT TestCacheConfigHandler/no_cache_url_configured1812--- PASS: TestCacheConfigHandler (0.00s)1813 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1814 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1815 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1816 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1817=== CONT TestPush_RejectsBadRequests/no_objects18182026/10/06 18:26:55 INFO Received push request method=POST path=/api/pushes1819=== CONT TestPush_RejectsBadRequests/root_not_in_objects18202026/10/06 18:26:55 INFO Received push request method=POST path=/api/pushes1821=== CONT TestPush_RejectsBadRequests/no_roots18222026/10/06 18:26:55 INFO Received push request method=POST path=/api/pushes1823=== CONT TestPush_RejectsBadRequests/bad_root18242026/10/06 18:26:55 INFO Received push request method=POST path=/api/pushes1825=== CONT TestClientErrorHandling/InvalidStorePath1826--- PASS: TestPush_RejectsBadRequests (2.30s)1827 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1828 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1829 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1830 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1831=== NAME TestOrphanedObjectsGCStressTest1832 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1833 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18342026/10/06 18:26:56 INFO Received uploads request method=POST path=/api/pending_closures1835--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.58s)1836=== CONT TestClientErrorHandling/ServerNotAvailable18372026/10/06 18:26:56 INFO Aborted multipart uploads count=1 kept=018382026/10/06 18:26:56 INFO Received cleanup request method=DELETE path=/api/pending_closures18392026/10/06 18:26:56 INFO Aborted multipart uploads count=1 kept=01840--- PASS: TestPendingCleanupUsesOneCutoff (7.80s)1841=== CONT TestClientErrorHandling/InvalidAuthToken18422026/10/06 18:26:56 INFO Received uploads request method=POST path=/api/pending_closures18432026/10/06 18:26:56 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/present18442026/10/06 18:26:56 INFO Received cleanup request method=DELETE path=/api/pending_closures18452026/10/06 18:26:56 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18462026/10/06 18:26:56 INFO Aborted multipart uploads count=0 kept=118472026/10/06 18:26:56 INFO Received cleanup request method=DELETE path=/api/pending_closures18482026/10/06 18:26:56 INFO Aborted multipart uploads count=1 kept=01849--- PASS: TestMultipartCleanup (2.76s)1850=== CONT TestGCEndsOnShutdown/before_the_run18512026/10/06 18:26:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.820466ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1852--- PASS: TestMetricsInventory (2.51s)1853=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18542026/10/06 18:26:57 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=392.376057ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18552026/10/06 18:26:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18562026/10/06 18:26:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1857--- PASS: TestService_NativeMTLS (2.57s)1858=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18592026/10/06 18:26:57 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=820.286969ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1860=== NAME TestNARDeduplicationMetadataUploadBug1861 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-75043-2721225071/TestNARDeduplicationMetadataUploadBug644019762/001/store/xa0xjkrns8573zsx8qw5vg11ijkcyqya-file1.txt18622026/10/06 18:26:58 INFO Received push request method=POST path=/api/pushes18632026/10/06 18:26:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18642026/10/06 18:26:58 INFO Uploading xa0xjkrns8573zsx8qw5vg11ijkcyqya-file1.txt (160B)18652026/10/06 18:26:58 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18662026/10/06 18:26:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18672026/10/06 18:26:58 INFO Signed narinfos id=1 count=118682026/10/06 18:26:58 INFO Uploading 1 narinfos18692026/10/06 18:26:58 WARN Failed to register uploaded object key=xa0xjkrns8573zsx8qw5vg11ijkcyqya.ls error="server returned 404: 404 page not found\n"18702026/10/06 18:26:58 INFO Received complete push request method=POST path=/api/pushes/1/complete18712026/10/06 18:26:58 WARN Failed to register uploaded object key=xa0xjkrns8573zsx8qw5vg11ijkcyqya.narinfo error="server returned 404: 404 page not found\n"18722026/10/06 18:26:58 INFO Completed push id=118732026/10/06 18:26:58 INFO Upload complete. (157ms)1874 metadata_upload_test.go:54: Retrieved narinfo from S3:1875 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestNARDeduplicationMetadataUploadBug644019762/001/store/xa0xjkrns8573zsx8qw5vg11ijkcyqya-file1.txt1876 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1877 Compression: zstd1878 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1879 NarSize: 1601880 References: 1881 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1882 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1883 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1884 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18852026/10/06 18:26:58 INFO Received uploads request method=POST path=/api/pending_closures1886 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-75043-2721225071/TestNARDeduplicationMetadataUploadBug644019762/001/store/6jbpis2ybjqg1gx6qv9jacl33wpxghhd-file2.txt18872026/10/06 18:26:58 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.526865008s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18882026/10/06 18:26:58 INFO Received push request method=POST path=/api/pushes18892026/10/06 18:26:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18902026/10/06 18:26:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18912026/10/06 18:26:58 INFO Signed narinfos id=2 count=118922026/10/06 18:26:58 WARN Failed to register uploaded object key=6jbpis2ybjqg1gx6qv9jacl33wpxghhd.ls error="server returned 404: 404 page not found\n"18932026/10/06 18:26:58 INFO Uploading 1 narinfos18942026/10/06 18:26:58 INFO Received complete push request method=POST path=/api/pushes/2/complete18952026/10/06 18:26:58 WARN Failed to register uploaded object key=6jbpis2ybjqg1gx6qv9jacl33wpxghhd.narinfo error="server returned 404: 404 page not found\n"18962026/10/06 18:26:58 INFO Completed push id=218972026/10/06 18:26:58 INFO Upload complete. (120ms)1898 metadata_upload_test.go:76: Retrieved narinfo from S3:1899 StorePath: /nix/var/nix/builds/nix-75043-2721225071/TestNARDeduplicationMetadataUploadBug644019762/001/store/6jbpis2ybjqg1gx6qv9jacl33wpxghhd-file2.txt1900 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1901 Compression: zstd1902 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1903 NarSize: 1601904 References: 1905 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1906 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1907 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1908 {"version":1,"root":{"type":"regular","size":44}}1909--- PASS: TestNARDeduplicationMetadataUploadBug (3.56s)1910=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1911=== NAME TestOrphanedObjectsGCStressTest1912 orphaned_objects_gc_test.go:509: Stress test completed successfully:1913 orphaned_objects_gc_test.go:510: - Active objects preserved: 201914 orphaned_objects_gc_test.go:511: - Objects deleted: 2101915 orphaned_objects_gc_test.go:512: - Total GC'd: 2101916--- PASS: TestOrphanedObjectsGCStressTest (9.56s)1917=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1918=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1919=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19202026/10/06 18:26:58 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]1921=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19222026/10/06 18:26:58 WARN Authentication failed token_preview=eyJhbGciOi...3sLXrvbJjA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1923=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1924=== CONT TestService_RequireScope_OIDC/builder_may_write1925=== CONT TestService_RequireScope_OIDC/reader_may_read1926=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1927=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1928=== CONT TestService_RequireScope_OIDC/writer_implies_read1929=== CONT TestService_RequireScope_OIDC/ops_may_admin1930=== CONT TestService_RequireScope_OIDC/reader_may_not_write1931=== CONT TestService_RequireScope_OIDC/ops_may_not_write1932=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1933=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19342026/10/06 18:26:58 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]1935=== CONT TestService_RequireScope_OIDC/static_token_may_admin1936=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1937=== CONT TestService_RequireScope_OIDC/static_token_may_write1938=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1939=== CONT TestServerTLSConfig/no_client_CA1940=== CONT TestServerTLSConfig/not_a_PEM_file1941--- PASS: TestService_AuthMiddleware_OIDC (1.99s)1942 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1943 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1944 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1945 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1946--- PASS: TestService_RequireScope_OIDC (2.19s)1947 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1961=== CONT TestServerTLSConfig/missing_CA_file1962--- PASS: TestServerTLSConfig (0.00s)1963 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1964 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1965 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1966--- PASS: TestPendingClosureWriteTimeout (0.00s)1967 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1968 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1969 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1970 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.12s)19712026/10/06 18:26:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19722026/10/06 18:26:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19732026/10/06 18:26:59 INFO Aborted multipart uploads count=0 kept=019742026/10/06 18:26:59 WARN Force mode enabled - objects will be deleted immediately without grace period19752026-10-06 18:26:59.387 UTC [75639] ERROR: canceling statement due to user request19762026-10-06 18:26:59.387 UTC [75639] STATEMENT: -- name: MarkStaleObjects :execrows1977 WITH RECURSIVE ct AS (1978 SELECT timezone('UTC', now()) AS now1979 ),1980 closure_reach AS (1981 -- Start with all closure keys1982 SELECT o.key, o.refs1983 FROM objects o1984 INNER JOIN closures c ON o.key = c.key1985 UNION1986 -- Recursively add all referenced objects1987 SELECT o.key, o.refs1988 FROM objects o1989 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1990 ),1991 reachable_objects AS (1992 SELECT DISTINCT key FROM closure_reach1993 ),1994 stale_objects AS (1995 SELECT o.key1996 FROM objects AS o, ct1997 WHERE1998 NOT EXISTS (1999 SELECT 12000 FROM reachable_objects ro2001 WHERE ro.key = o.key2002 )2003 AND NOT EXISTS (2004 SELECT 12005 FROM pending_objects AS po2006 WHERE po.key = o.key2007 )2008 AND o.deleted_at IS NULL -- Only mark fresh objects2009 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2010 FOR UPDATE2011 )2012 UPDATE objects2013 SET2014 deleted_at = ct.now,2015 first_deleted_at = COALESCE(first_deleted_at, ct.now)2016 FROM stale_objects, ct2017 WHERE objects.key = stale_objects.key2018 20192026/10/06 18:26:59 INFO Aborted multipart uploads count=0 kept=020202026/10/06 18:26:59 WARN Force mode enabled - objects will be deleted immediately without grace period20212026/10/06 18:26:59 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58541/bucket92/?delete=\": context canceled"2022--- PASS: TestGCEndsOnShutdown (0.00s)2023 --- PASS: TestGCEndsOnShutdown/before_the_run (2.30s)2024 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.32s)2025 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.16s)20262026/10/06 18:26:59 INFO Received uploads request method=POST path=/api/pending_closures20272026/10/06 18:26:59 INFO Aborted multipart uploads count=0 kept=020282026/10/06 18:26:59 WARN Force mode enabled - objects will be deleted immediately without grace period20292026/10/06 18:26:59 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=020302026/10/06 18:26:59 INFO Vacuumed table table=pending_closures20312026/10/06 18:26:59 INFO Vacuumed table table=pending_objects20322026/10/06 18:26:59 INFO Vacuumed table table=multipart_uploads20332026/10/06 18:26:59 INFO Vacuumed table table=closures20342026/10/06 18:26:59 INFO Vacuumed table table=objects20352026/10/06 18:26:59 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-config20362026/10/06 18:26:59 INFO Received uploads request method=POST path=/api/pending_closures20372026/10/06 18:26:59 INFO Aborted multipart uploads count=0 kept=020382026/10/06 18:26:59 WARN Force mode enabled - objects will be deleted immediately without grace period20392026/10/06 18:26:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020402026/10/06 18:27:00 INFO Vacuumed table table=pending_closures20412026/10/06 18:27:00 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.323674ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20422026/10/06 18:27:00 INFO Vacuumed table table=pending_objects20432026/10/06 18:27:00 INFO Vacuumed table table=multipart_uploads20442026/10/06 18:27:00 INFO Vacuumed table table=closures20452026/10/06 18:27:00 INFO Vacuumed table table=objects2046--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2047 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (1.35s)2048 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (1.40s)2049--- PASS: TestConcurrentPresentSharingKeysDoNotDeadlock (4.89s)20502026/10/06 18:27:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=363.705345ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20512026/10/06 18:27:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=879.030237ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20522026/10/06 18:27:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.682962511s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20532026/10/06 18:27:03 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"20542026/10/06 18:27:03 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-config20552026/10/06 18:27:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.649773ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20562026/10/06 18:27:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.265ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20572026/10/06 18:27:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=823.715906ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20582026/10/06 18:27:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.529063068s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20592026/10/06 18:27:06 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_closures20602026/10/06 18:27:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.765519ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20612026/10/06 18:27:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=370.201889ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20622026/10/06 18:27:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=803.996795ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20632026/10/06 18:27:07 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.538531217s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2064--- PASS: TestClientErrorHandling (0.00s)2065 --- PASS: TestClientErrorHandling/InvalidStorePath (2.73s)2066 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.61s)2067 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.83s)2068PASS2069{"timestamp":"2026-10-06T18:27:09.263253Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58598","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}20702026-10-06 18:27:09.433 UTC [75083] LOG: received smart shutdown request20712026-10-06 18:27:09.434 UTC [75083] LOG: background worker "logical replication launcher" (PID 75094) exited with exit code 120722026-10-06 18:27:09.440 UTC [75088] LOG: shutting down20732026-10-06 18:27:09.440 UTC [75088] LOG: checkpoint starting: shutdown immediate20742026-10-06 18:27:10.806 UTC [75088] LOG: checkpoint complete: wrote 12932 buffers (78.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.755 s, sync=0.544 s, total=1.367 s; sync files=32011, longest=0.001 s, average=0.001 s; distance=460976 kB, estimate=460976 kB; lsn=0/1D9B9290, redo lsn=0/1D9B929020752026-10-06 18:27:10.813 UTC [75083] 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 TestValidateToken_ValidToken2120=== CONT TestGlobMatch2121=== RUN TestGlobMatch/foo_foo2122=== PAUSE TestGlobMatch/foo_foo2123=== RUN TestGlobMatch/foo_bar2124=== PAUSE TestGlobMatch/foo_bar2125=== RUN TestGlobMatch/*_2126=== PAUSE TestGlobMatch/*_2127=== RUN TestGlobMatch/*_anything2128=== PAUSE TestGlobMatch/*_anything2129=== RUN TestGlobMatch/foo*_foo2130=== PAUSE TestGlobMatch/foo*_foo2131=== RUN TestGlobMatch/foo*_foobar2132=== PAUSE TestGlobMatch/foo*_foobar2133=== RUN TestGlobMatch/foo*_bar2134=== PAUSE TestGlobMatch/foo*_bar2135=== RUN TestGlobMatch/*bar_bar2136=== PAUSE TestGlobMatch/*bar_bar2137=== CONT TestPins_ConfigValidation2138=== RUN TestGlobMatch/*bar_foobar2139=== PAUSE TestGlobMatch/*bar_foobar2140=== RUN TestGlobMatch/*bar_foo2141=== PAUSE TestGlobMatch/*bar_foo2142=== RUN TestGlobMatch/foo*bar_foobar2143=== PAUSE TestGlobMatch/foo*bar_foobar2144=== RUN TestGlobMatch/foo*bar_foo123bar2145=== PAUSE TestGlobMatch/foo*bar_foo123bar2146=== RUN TestGlobMatch/foo*bar_foobarbaz2147=== PAUSE TestGlobMatch/foo*bar_foobarbaz2148=== RUN TestGlobMatch/*/*_foo/bar2149=== PAUSE TestGlobMatch/*/*_foo/bar2150=== RUN TestGlobMatch/*/*_foo2151=== PAUSE TestGlobMatch/*/*_foo2152=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2153=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2154=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02155=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02156=== RUN TestGlobMatch/refs/*/main_refs/heads/main2157=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2158=== RUN TestGlobMatch/fo?_foo2159=== PAUSE TestGlobMatch/fo?_foo2160=== RUN TestGlobMatch/fo?_fo2161=== PAUSE TestGlobMatch/fo?_fo2162=== RUN TestGlobMatch/fo?_fooo2163=== PAUSE TestGlobMatch/fo?_fooo2164=== RUN TestGlobMatch/?oo_foo2165=== PAUSE TestGlobMatch/?oo_foo2166=== RUN TestGlobMatch/?oo_boo2167=== PAUSE TestGlobMatch/?oo_boo2168=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2169=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2170=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2171=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== CONT TestValidateToken_MultipleProviders2173--- PASS: TestPins_ConfigValidation (0.00s)2174=== CONT TestValidateToken_WrongAudience2175=== CONT TestValidateToken_BoundClaimsMismatch2176=== CONT TestPins_ReservedForMatchingRule2177=== CONT TestPins_TopLevelShorthand21782026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59022/oidc2179--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2180=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21812026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59025/oidc2182--- PASS: TestValidateToken_ValidToken (0.07s)2183=== CONT TestScopes_Rules21842026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59027/oidc21852026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59029/oidc2186--- PASS: TestValidateToken_WrongAudience (0.08s)2187=== CONT TestScopes_ConfigValidation2188--- PASS: TestPins_TopLevelShorthand (0.07s)2189=== CONT TestNewValidator_KubernetesRequiresCA2190--- PASS: TestScopes_ConfigValidation (0.00s)2191=== CONT TestScopes_LegacyProviderDefaultsToWrite21922026/10/06 18:27:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59024/oidc2193--- PASS: TestValidateToken_NoMatchingProvider (0.08s)2194=== CONT TestGlobMatch/foo_foo2195=== CONT TestGlobMatch/*/*_foo/bar2196=== CONT TestGlobMatch/fo?_fo2197=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2198=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2199=== CONT TestGlobMatch/?oo_boo2200=== CONT TestGlobMatch/?oo_foo2201=== CONT TestGlobMatch/fo?_fooo2202=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02203=== CONT TestGlobMatch/fo?_foo2204=== CONT TestGlobMatch/refs/*/main_refs/heads/main2205=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2206=== CONT TestGlobMatch/*/*_foo2207=== CONT TestGlobMatch/*bar_bar2208=== CONT TestGlobMatch/foo*bar_foobarbaz2209=== CONT TestGlobMatch/foo*bar_foo123bar2210=== CONT TestGlobMatch/foo*bar_foobar2211=== CONT TestGlobMatch/*bar_foo2212=== CONT TestGlobMatch/*bar_foobar2213=== CONT TestGlobMatch/foo*_foo2214=== CONT TestGlobMatch/foo*_bar2215=== CONT TestGlobMatch/foo*_foobar2216=== CONT TestGlobMatch/*_2217=== CONT TestGlobMatch/*_anything2218=== CONT TestGlobMatch/foo_bar2219--- PASS: TestGlobMatch (0.00s)2220 --- PASS: TestGlobMatch/foo_foo (0.00s)2221 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2222 --- PASS: TestGlobMatch/fo?_fo (0.00s)2223 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2224 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2225 --- PASS: TestGlobMatch/?oo_boo (0.00s)2226 --- PASS: TestGlobMatch/?oo_foo (0.00s)2227 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2228 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2229 --- PASS: TestGlobMatch/fo?_foo (0.00s)2230 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2231 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2232 --- PASS: TestGlobMatch/*/*_foo (0.00s)2233 --- PASS: TestGlobMatch/*bar_bar (0.00s)2234 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2235 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2236 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2237 --- PASS: TestGlobMatch/*bar_foo (0.00s)2238 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2239 --- PASS: TestGlobMatch/foo*_foo (0.00s)2240 --- PASS: TestGlobMatch/foo*_bar (0.00s)2241 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2242 --- PASS: TestGlobMatch/*_ (0.00s)2243 --- PASS: TestGlobMatch/*_anything (0.00s)2244 --- PASS: TestGlobMatch/foo_bar (0.00s)22452026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59033/oidc22462026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59035/oidc2247--- PASS: TestPins_ReservedForMatchingRule (0.08s)2248--- PASS: TestValidateToken_Expired (0.09s)22492026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59037/oidc2250--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)22512026/10/06 18:27:12 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232252--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)22532026/10/06 18:27:12 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:590422254--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)22552026/10/06 18:27:12 http: TLS handshake error from 127.0.0.1:59045: remote error: tls: bad certificate2256--- PASS: TestNewValidator_KubernetesRequiresCA (0.04s)22572026/10/06 18:27:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59041/oidc22582026/10/06 18:27:12 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59046/oidc2259--- PASS: TestValidateToken_MultipleProviders (0.13s)22602026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59049/oidc2261--- PASS: TestScopes_Rules (0.10s)22622026/10/06 18:27:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59051/oidc2263--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.13s)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.01s)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 TestServerQueueError2312=== CONT TestWorkerUploadsAndRemoves2313--- PASS: TestSendPathsEmpty (0.00s)2314=== CONT TestServerClientIntegration2315=== CONT TestQueueRemoveLargeClosure2316=== CONT TestQueueConcurrentWriters2317=== CONT TestQueueFetchRemoveLifecycle2318=== CONT TestQueueRetryMovesToBack2319=== CONT TestQueueFetchBatchLimit2320=== CONT TestQueueRemove2321=== CONT TestQueueDeduplication23222026/10/06 18:27:12 ERROR Failed to queue paths error="permission denied" count=12323--- PASS: TestServerQueueError (0.00s)2324=== CONT TestQueueEnqueueAndFetch2325--- PASS: TestServerClientIntegration (0.00s)2326=== CONT TestDrainGivesUpWhenServerDown2327--- PASS: TestQueueFetchBatchLimit (0.01s)2328=== CONT TestFailedPathPrunedByLaterClosure23292026/10/06 18:27:12 INFO Uploading batch count=223302026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=223312026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/a23322026/10/06 18:27:12 INFO Upload queue status pending=223332026/10/06 18:27:12 INFO Uploading batch count=223342026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/b2335--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2336=== CONT TestWorkerPrunesClosureDeps2337--- PASS: TestQueueRemove (0.01s)2338=== CONT TestDrainTimeout2339--- PASS: TestQueueDeduplication (0.01s)2340=== CONT TestWorkerSkipsGCdPaths23412026/10/06 18:27:12 INFO Uploading batch count=223422026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=223432026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/c23442026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/d2345--- PASS: TestQueueEnqueueAndFetch (0.01s)2346=== CONT TestRunNotBlockedByPoisonHead2347--- PASS: TestQueueRetryMovesToBack (0.01s)2348=== CONT TestDrainIsolatesPoisonPath23492026/10/06 18:27:12 INFO Uploading batch count=223502026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=223512026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/e23522026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainGivesUpWhenServerDown2554516320/002/f23532026/10/06 18:27:12 ERROR Drain finished with paths left in queue remaining=1023542026/10/06 18:27:12 INFO Uploading batch count=123552026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=123562026/10/06 18:27:12 INFO Uploading batch count=123572026/10/06 18:27:12 INFO Upload queue status pending=223582026/10/06 18:27:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-75043-2721225071/TestWorkerSkipsGCdPaths2077237403/002/nonexistent23592026/10/06 18:27:12 INFO Uploading batch count=123602026/10/06 18:27:12 INFO Uploading batch count=123612026/10/06 18:27:12 INFO Upload queue status pending=323622026/10/06 18:27:12 INFO Uploading batch count=123632026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=123642026/10/06 18:27:12 INFO Uploading batch count=223652026/10/06 18:27:12 INFO Upload queue status pending=223662026/10/06 18:27:12 INFO Uploading batch count=123672026/10/06 18:27:12 INFO Uploading batch count=423682026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=42369--- PASS: TestDrainGivesUpWhenServerDown (0.01s)23702026/10/06 18:27:12 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-75043-2721225071/TestDrainIsolatesPoisonPath1464121615/002/bbb23712026/10/06 18:27:12 INFO Uploading batch count=123722026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=12373--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23742026/10/06 18:27:12 INFO Uploading batch count=123752026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=123762026/10/06 18:27:12 INFO Uploading batch count=123772026/10/06 18:27:12 ERROR Upload failed error="upload failed" count=123782026/10/06 18:27:12 ERROR Drain finished with paths left in queue remaining=12379--- PASS: TestDrainIsolatesPoisonPath (0.01s)2380--- PASS: TestWorkerUploadsAndRemoves (0.03s)2381--- PASS: TestWorkerSkipsGCdPaths (0.02s)2382--- PASS: TestWorkerPrunesClosureDeps (0.03s)2383--- PASS: TestQueueRemoveLargeClosure (0.04s)2384--- PASS: TestQueueConcurrentWriters (0.16s)23852026/10/06 18:27:13 ERROR Upload failed error="context deadline exceeded" count=223862026/10/06 18:27:13 ERROR Drain finished with paths left in queue remaining=42387--- PASS: TestDrainTimeout (0.21s)23882026/10/06 18:27:13 INFO Uploading batch count=123892026/10/06 18:27:13 INFO Uploading batch count=123902026/10/06 18:27:13 INFO Uploading batch count=123912026/10/06 18:27:13 ERROR Upload failed error="upload failed" count=123922026/10/06 18:27:13 INFO Uploading batch count=123932026/10/06 18:27:13 ERROR Upload failed error="upload failed" count=123942026/10/06 18:27:13 INFO Uploading batch count=123952026/10/06 18:27:13 ERROR Upload failed error="upload failed" count=123962026/10/06 18:27:13 INFO Uploading batch count=123972026/10/06 18:27:13 ERROR Upload failed error="upload failed" count=123982026/10/06 18:27:13 ERROR Drain finished with paths left in queue remaining=12399--- PASS: TestRunNotBlockedByPoisonHead (1.07s)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 TestSignBatch2433=== CONT TestSignErrors2434=== CONT TestExternalSignerRejectsInvalidPublicKey2435=== RUN TestExternalSignerRejectsInvalidPublicKey/#002436=== CONT TestExternalSignerProgramErrorKeepsProcess2437=== CONT TestExternalSignerClose2438=== CONT TestExternalSignerErrors2439=== RUN TestExternalSignerErrors/exit_at_startup2440=== PAUSE TestExternalSignerErrors/exit_at_startup2441=== RUN TestExternalSignerErrors/exit_on_request2442=== PAUSE TestExternalSignerErrors/exit_on_request2443=== RUN TestExternalSignerErrors/null2444=== PAUSE TestExternalSignerErrors/null2445=== RUN TestExternalSignerErrors/missing_signatures2446=== PAUSE TestExternalSignerErrors/missing_signatures2447=== RUN TestExternalSignerErrors/wrong_signatures_shape2448=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2449=== RUN TestExternalSignerErrors/too_few_signatures2450=== PAUSE TestExternalSignerErrors/too_few_signatures2451=== CONT TestExternalSignerRestartsAfterCrash2452=== RUN TestExternalSignerErrors/unrequested_key2453=== PAUSE TestExternalSignerErrors/unrequested_key2454=== RUN TestExternalSignerErrors/wrong_shape2455=== PAUSE TestExternalSignerErrors/wrong_shape2456=== RUN TestExternalSignerErrors/invalid_signature_base642457=== PAUSE TestExternalSignerErrors/invalid_signature_base642458=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002459=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2460=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2461=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2462=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2463=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2464=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2465=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2466=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2467=== RUN TestExternalSignerErrors/wrong_id2468=== PAUSE TestExternalSignerErrors/wrong_id2469=== CONT TestExternalSignerWrongPublicKey2470=== RUN TestExternalSignerErrors/null_signatures2471=== PAUSE TestExternalSignerErrors/null_signatures2472=== RUN TestExternalSignerErrors/missing_signature_name2473=== PAUSE TestExternalSignerErrors/missing_signature_name2474=== CONT TestNilKeyPublicKey2475--- PASS: TestNilKeyPublicKey (0.00s)2476=== RUN TestExternalSignerErrors/wrong_signature_length2477=== CONT TestParseSigningKey2478=== RUN TestParseSigningKey/valid_32-byte_key2479=== PAUSE TestExternalSignerErrors/wrong_signature_length2480=== PAUSE TestParseSigningKey/valid_32-byte_key2481=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2482=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2483=== RUN TestParseSigningKey/no_colon2484=== RUN TestExternalSignerErrors/program_error2485=== PAUSE TestParseSigningKey/no_colon2486=== RUN TestParseSigningKey/empty_name2487=== PAUSE TestExternalSignerErrors/program_error2488=== PAUSE TestParseSigningKey/empty_name2489=== RUN TestExternalSignerErrors/invalid_JSON2490=== PAUSE TestExternalSignerErrors/invalid_JSON2491=== RUN TestExternalSignerErrors/wrong_signature_name2492=== PAUSE TestExternalSignerErrors/wrong_signature_name2493=== RUN TestParseSigningKey/invalid_base642494=== PAUSE TestParseSigningKey/invalid_base642495=== CONT TestSign2496=== RUN TestParseSigningKey/wrong_length2497=== PAUSE TestParseSigningKey/wrong_length2498=== CONT TestGenerateFingerprint2499=== RUN TestGenerateFingerprint/basic_with_references2500=== PAUSE TestGenerateFingerprint/basic_with_references2501=== RUN TestGenerateFingerprint/no_references2502=== PAUSE TestGenerateFingerprint/no_references2503=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2504=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2505=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2506=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2507=== RUN TestGenerateFingerprint/invalid_nar_hash_length2508=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2509=== RUN TestGenerateFingerprint/invalid_store_path_prefix2510=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2511=== RUN TestGenerateFingerprint/invalid_reference_prefix2512=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2513=== CONT TestExternalSignerRejectsInvalidPublicKey/#002514=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2515=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2516=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2517=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2518--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2519 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2520 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2521 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2522 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2523 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2524=== CONT TestExternalSignerErrors/exit_at_startup2525=== 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/too_few_signatures2534--- PASS: TestSign (0.00s)2535=== CONT TestExternalSignerErrors/invalid_signature_base642536--- PASS: TestSignBatch (0.01s)2537=== CONT TestExternalSignerErrors/wrong_shape2538--- PASS: TestExternalSignerCancellation (0.23s)2539=== CONT TestExternalSignerErrors/unrequested_key2540--- PASS: TestExternalSignerClose (0.40s)2541=== CONT TestExternalSignerErrors/missing_signatures2542--- PASS: TestExternalSigner (0.60s)2543=== CONT TestExternalSignerErrors/wrong_signatures_shape2544--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.77s)2545=== CONT TestExternalSignerErrors/program_error2546--- PASS: TestExternalSignerRestartsAfterCrash (0.98s)2547=== CONT TestExternalSignerErrors/wrong_id2548--- PASS: TestExternalSignerWrongPublicKey (1.15s)2549=== CONT TestExternalSignerErrors/wrong_signature_length2550=== CONT TestExternalSignerErrors/missing_signature_name2551=== CONT TestExternalSignerErrors/null_signatures2552=== CONT TestExternalSignerErrors/null2553=== CONT TestExternalSignerErrors/wrong_signature_name2554=== CONT TestExternalSignerErrors/invalid_JSON2555=== CONT TestExternalSignerErrors/exit_on_request2556=== CONT TestParseSigningKey/valid_32-byte_key2557=== CONT TestParseSigningKey/empty_name2558=== CONT TestParseSigningKey/wrong_length2559=== CONT TestParseSigningKey/invalid_base642560=== CONT TestParseSigningKey/no_colon2561=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2562--- PASS: TestParseSigningKey (0.00s)2563 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2564 --- PASS: TestParseSigningKey/empty_name (0.00s)2565 --- PASS: TestParseSigningKey/wrong_length (0.00s)2566 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2567 --- PASS: TestParseSigningKey/no_colon (0.00s)2568 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2569=== CONT TestGenerateFingerprint/basic_with_references2570=== CONT TestGenerateFingerprint/invalid_reference_prefix2571=== CONT TestGenerateFingerprint/invalid_store_path_prefix2572=== CONT TestGenerateFingerprint/invalid_nar_hash_length2573=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2574=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2575=== CONT TestGenerateFingerprint/no_references2576--- PASS: TestGenerateFingerprint (0.00s)2577 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2578 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2579 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2580 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2581 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2582 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2583 --- PASS: TestGenerateFingerprint/no_references (0.00s)2584=== CONT TestSignErrors/nil_key2585=== CONT TestSignErrors/invalid_narinfo2586=== CONT TestSignErrors/canceled2587=== CONT TestSignErrors/nil_narinfo2588--- PASS: TestSignErrors (0.00s)2589 --- PASS: TestSignErrors/nil_key (0.00s)2590 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2591 --- PASS: TestSignErrors/canceled (0.00s)2592 --- PASS: TestSignErrors/nil_narinfo (0.00s)2593--- PASS: TestExternalSignerErrors (0.00s)2594 --- PASS: TestExternalSignerErrors/too_few_signatures (1.33s)2595 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.51s)2596 --- PASS: TestExternalSignerErrors/wrong_shape (1.70s)2597 --- PASS: TestExternalSignerErrors/exit_at_startup (1.89s)2598 --- PASS: TestExternalSignerErrors/unrequested_key (1.85s)2599 --- PASS: TestExternalSignerErrors/missing_signatures (1.86s)2600 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.84s)2601 --- PASS: TestExternalSignerErrors/program_error (1.86s)2602 --- PASS: TestExternalSignerErrors/wrong_id (1.84s)2603 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.85s)2604 --- PASS: TestExternalSignerErrors/missing_signature_name (1.86s)2605 --- PASS: TestExternalSignerErrors/null_signatures (1.86s)2606 --- PASS: TestExternalSignerErrors/null (1.86s)2607 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.87s)2608 --- PASS: TestExternalSignerErrors/invalid_JSON (1.87s)2609 --- PASS: TestExternalSignerErrors/exit_on_request (1.87s)2610PASS2611Running OpenBao signer tests...2612=== RUN TestSign2613=== PAUSE TestSign2614=== RUN TestSignErrors2615=== PAUSE TestSignErrors2616=== RUN TestServe2617=== PAUSE TestServe2618=== RUN TestServeRejectsGarbage2619=== PAUSE TestServeRejectsGarbage2620=== CONT TestSign2621=== CONT TestServeRejectsGarbage2622=== CONT TestServe2623--- PASS: TestServeRejectsGarbage (0.00s)2624=== CONT TestSignErrors2625=== RUN TestSignErrors/http_error2626=== PAUSE TestSignErrors/http_error2627=== RUN TestSignErrors/invalid_json2628=== PAUSE TestSignErrors/invalid_json2629=== RUN TestSignErrors/no_prefix2630=== PAUSE TestSignErrors/no_prefix2631=== RUN TestSignErrors/invalid_base642632=== PAUSE TestSignErrors/invalid_base642633=== CONT TestSignErrors/http_error2634=== CONT TestSignErrors/no_prefix2635=== CONT TestSignErrors/invalid_base642636=== CONT TestSignErrors/invalid_json2637--- PASS: TestServe (0.00s)2638--- PASS: TestSign (0.00s)2639--- PASS: TestSignErrors (0.00s)2640 --- PASS: TestSignErrors/invalid_json (0.00s)2641 --- PASS: TestSignErrors/http_error (0.00s)2642 --- PASS: TestSignErrors/no_prefix (0.00s)2643 --- PASS: TestSignErrors/invalid_base64 (0.00s)2644PASS