niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #387
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestEncodeNixBase32101=== RUN TestEncodeNixBase32/test_string_hash102=== PAUSE TestEncodeNixBase32/test_string_hash103=== CONT TestResolveStorePath104=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess105=== CONT TestRateLimiterFeedback106=== RUN TestRateLimiterFeedback/429_enables_limiter107=== PAUSE TestRateLimiterFeedback/429_enables_limiter108=== RUN TestRateLimiterFeedback/503_enables_limiter109=== PAUSE TestRateLimiterFeedback/503_enables_limiter110=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter111=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter112=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter113=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter114=== CONT TestPathInfoCACompatibility115=== RUN TestPathInfoCACompatibility/null_ca_field116=== PAUSE TestPathInfoCACompatibility/null_ca_field117=== RUN TestPathInfoCACompatibility/old_string_format_-_text118=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text119=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive120=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive121=== RUN TestPathInfoCACompatibility/new_structured_format_-_text122=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text123=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method124=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method125=== CONT TestGetStorePathHash126=== RUN TestGetStorePathHash/valid_store_path127=== PAUSE TestGetStorePathHash/valid_store_path128=== RUN TestGetStorePathHash/basename_without_hyphen_should_error129=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error130=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error131=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error132=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error133=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error134=== CONT TestParsePathInfoJSONMultiplePaths135=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1382026/10/06 21:24:07 WARN Rate limiter enabled after throttle name=server-test rate=5139=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths140=== CONT TestEncodeNixBase32WithRealHash141--- PASS: TestEncodeNixBase32WithRealHash (0.00s)142=== CONT TestConvertHashToNix32143=== RUN TestConvertHashToNix32/SRI_format_to_Nix32144=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32145=== RUN TestConvertHashToNix32/already_Nix32_format146=== PAUSE TestConvertHashToNix32/already_Nix32_format147--- PASS: TestResolveStorePath (0.00s)148=== CONT TestDumpPathSingleFile149=== RUN TestConvertHashToNix32/invalid_format150=== PAUSE TestConvertHashToNix32/invalid_format151=== CONT TestPathInfoHashCompatibility152=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154=== RUN TestEncodeNixBase32/empty_input155=== CONT TestDumpPathMatchesNix156=== CONT TestUploadMultipart_PartsInParallel157=== CONT TestParsePathInfoJSON158=== RUN TestParsePathInfoJSON/Nix_format159=== CONT TestDumpPathWriterError160=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon161=== PAUSE TestEncodeNixBase32/empty_input162=== PAUSE TestParsePathInfoJSON/Nix_format163=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon165=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI166=== RUN TestParsePathInfoJSON/Lix_format167=== PAUSE TestParsePathInfoJSON/Lix_format168=== RUN TestParsePathInfoJSON/empty_input169=== PAUSE TestParsePathInfoJSON/empty_input170=== RUN TestParsePathInfoJSON/whitespace_only171=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI172=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512173=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512174=== PAUSE TestParsePathInfoJSON/whitespace_only175=== RUN TestParsePathInfoJSON/invalid_JSON176=== PAUSE TestParsePathInfoJSON/invalid_JSON177=== CONT TestFilterOversizedClosures178=== RUN TestFilterOversizedClosures/no_limit_keeps_everything179=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything180=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped181=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped182=== RUN TestFilterOversizedClosures/all_closures_skipped183=== PAUSE TestFilterOversizedClosures/all_closures_skipped184=== CONT TestCaseHackSuffix185=== CONT TestUploadMultipart_SupersededByPeer1862026/10/06 21:24:07 WARN Rate limiter enabled after throttle name=server-test rate=5187=== RUN TestUploadMultipart_SupersededByPeer/exists1882026/10/06 21:24:07 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52772189=== PAUSE TestUploadMultipart_SupersededByPeer/exists190=== RUN TestUploadMultipart_SupersededByPeer/missing191=== PAUSE TestUploadMultipart_SupersededByPeer/missing192=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica1932026/10/06 21:24:07 WARN Rate limiter backed off name=server-test rate=51942026/10/06 21:24:07 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:52772195--- PASS: TestDoServerRequestAttachesToken (0.01s)196=== CONT TestSetClientTLSErrors197--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)198=== CONT TestScriptTokenEmptyCommand199--- PASS: TestScriptTokenEmptyCommand (0.00s)200=== CONT TestScriptTokenScriptFails2012026/10/06 21:24:07 INFO Garbage collection started2022026/10/06 21:24:07 INFO Garbage collection started203=== RUN TestSetClientTLSErrors/missing_cert_file204=== PAUSE TestSetClientTLSErrors/missing_cert_file205=== RUN TestSetClientTLSErrors/missing_key_file206=== PAUSE TestSetClientTLSErrors/missing_key_file207=== RUN TestSetClientTLSErrors/missing_ca_file208=== PAUSE TestSetClientTLSErrors/missing_ca_file209=== RUN TestSetClientTLSErrors/invalid_ca_file210=== PAUSE TestSetClientTLSErrors/invalid_ca_file211=== CONT TestPartSizeForNAR212=== RUN TestPartSizeForNAR/zero_stays_at_minimum213=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum214=== RUN TestPartSizeForNAR/small_stays_at_minimum215=== PAUSE TestPartSizeForNAR/small_stays_at_minimum216=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum217=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum218=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts219=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts220=== RUN TestPartSizeForNAR/1_TiB221=== PAUSE TestPartSizeForNAR/1_TiB222=== RUN TestPartSizeForNAR/5_TiB_S3_max_object223=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object224=== RUN TestPartSizeForNAR/capped_at_5_GiB225=== PAUSE TestPartSizeForNAR/capped_at_5_GiB226=== CONT TestScriptTokenBadJSON2272026/10/06 21:24:07 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=0228--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)229=== CONT TestScriptTokenEmptyToken2302026/10/06 21:24:07 WARN Garbage collection finished on another replica. Its statistics are not available here231--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)232=== CONT TestStreamPushGivesUpOnDeadServer2332026/10/06 21:24:07 ERROR Upload failed error="connection refused" count=202342026/10/06 21:24:07 ERROR Server seems unavailable, giving up on batch untried=17235--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)236=== CONT TestScriptTokenCachesUntilRefresh237--- PASS: TestScriptTokenScriptFails (0.01s)238=== CONT TestSetClientTLSDoesNotMutateDefaultTransport239--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)240=== CONT TestScriptTokenNoExpiryRerunsEveryCall241--- PASS: TestScriptTokenEmptyToken (0.01s)242=== CONT TestSetClientTLS243--- PASS: TestScriptTokenBadJSON (0.01s)244=== CONT TestFileTokenEmpty245--- PASS: TestFileTokenEmpty (0.00s)246=== CONT TestClientSignaturesByStorePath247--- PASS: TestClientSignaturesByStorePath (0.00s)248=== CONT TestFileTokenMissing249--- PASS: TestFileTokenMissing (0.00s)250=== CONT TestStreamPushReportsSignatures2512026/10/06 21:24:07 ERROR Upload failed error=boom count=1252--- PASS: TestStreamPushReportsSignatures (0.00s)253=== CONT TestFileTokenReadsAndCaches254--- PASS: TestFileTokenReadsAndCaches (0.00s)255=== CONT TestStreamPushRequestLine2562026/10/06 21:24:07 ERROR Upload failed error=boom count=1257=== RUN TestSetClientTLS/rejects_connection_without_client_cert258=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert259=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA260=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA261=== RUN TestSetClientTLS/preserves_debug_logging_transport262=== PAUSE TestSetClientTLS/preserves_debug_logging_transport263=== CONT TestStaticToken264--- PASS: TestStaticToken (0.00s)265=== CONT TestRegisterUploadedObjectReusesConnections266--- PASS: TestStreamPushRequestLine (0.01s)267=== CONT TestStreamPushReportsEveryPath268--- PASS: TestStreamPushReportsEveryPath (0.00s)269=== CONT TestStreamPushIsolatesFailures2702026/10/06 21:24:07 ERROR Upload failed error="bad path" count=3271--- PASS: TestStreamPushIsolatesFailures (0.00s)272=== CONT TestStreamPushBatchesUnderLoad273--- PASS: TestDumpPathWriterError (0.04s)274=== CONT TestShellSplitErrors275--- PASS: TestShellSplitErrors (0.00s)276=== CONT TestShellSplit277--- PASS: TestShellSplit (0.00s)278=== CONT TestRateLimiterFeedback/429_enables_limiter2792026/10/06 21:24:07 WARN Rate limiter enabled after throttle name=server-test rate=52802026/10/06 21:24:07 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:528512812026/10/06 21:24:07 WARN Rate limiter backed off name=server-test rate=5282=== CONT TestPathInfoCACompatibility/null_ca_field283=== CONT TestGetStorePathHash/valid_store_path284=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter285=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter286=== CONT TestRateLimiterFeedback/503_enables_limiter2872026/10/06 21:24:07 WARN Rate limiter enabled after throttle name=server-test rate=52882026/10/06 21:24:07 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:52857289--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)2902026/10/06 21:24:07 WARN Rate limiter backed off name=server-test rate=5291=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths292--- PASS: TestRateLimiterFeedback (0.00s)293 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)294 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)295 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)296 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)297=== CONT TestPathInfoCACompatibility/old_string_format_-_text298=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method299=== CONT TestPathInfoCACompatibility/new_structured_format_-_text300=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive301=== CONT TestGetStorePathHash/basename_without_hyphen_should_error302=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error303=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305=== CONT TestConvertHashToNix32/SRI_format_to_Nix32306=== CONT TestConvertHashToNix32/invalid_format307=== CONT TestConvertHashToNix32/already_Nix32_format308=== CONT TestEncodeNixBase32/empty_input309=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)310=== CONT TestParsePathInfoJSON/Nix_format311--- PASS: TestPathInfoCACompatibility (0.00s)312 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)313 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)315 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)316 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)317=== CONT TestEncodeNixBase32/test_string_hash318=== CONT TestFilterOversizedClosures/no_limit_keeps_everything319=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512320=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon322=== CONT TestParsePathInfoJSON/Lix_format323--- PASS: TestGetStorePathHash (0.00s)324 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)325 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)326 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)327 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)328=== CONT TestParsePathInfoJSON/whitespace_only329=== CONT TestParsePathInfoJSON/invalid_JSON330--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)331 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)332 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)333=== CONT TestParsePathInfoJSON/empty_input334--- PASS: TestEncodeNixBase32 (0.00s)335 --- PASS: TestEncodeNixBase32/empty_input (0.00s)336 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)337=== CONT TestFilterOversizedClosures/all_closures_skipped338=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3392026/10/06 21:24:07 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=2000340--- PASS: TestPathInfoHashCompatibility (0.00s)341 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)342 --- PASS: TestPathInfoHashCompatibility/new_structured_f2026/10/06 21:24:07 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=50343ormat_with_sha512 (0.00s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)345 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)346=== CONT TestUploadMultipart_SupersededByPeer/exists347--- PASS: TestConvertHashToNix32 (0.00s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)350 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)351=== CONT TestUploadMultipart_SupersededByPeer/missing352--- PASS: TestFilterOversizedClosures (0.00s)353 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)354 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)355 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)356--- PASS: TestParsePathInfoJSON (0.00s)357 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)358 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)359 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)360 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)361 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)362=== CONT TestSetClientTLSErrors/missing_cert_file363--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)364 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)365 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)366=== CONT TestPartSizeForNAR/zero_stays_at_minimum367=== CONT TestSetClientTLSErrors/invalid_ca_file368=== CONT TestSetClientTLSErrors/missing_ca_file369--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)370=== CONT TestSetClientTLSErrors/missing_key_file371=== CONT TestPartSizeForNAR/1_TiB372=== CONT TestPartSizeForNAR/capped_at_5_GiB373=== CONT TestPartSizeForNAR/5_TiB_S3_max_object374=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum375=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts376=== CONT TestPartSizeForNAR/small_stays_at_minimum377--- PASS: TestPartSizeForNAR (0.00s)378 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)379 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)380 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)381 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)382 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)383 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)384 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)385=== CONT TestSetClientTLS/rejects_connection_without_client_cert386=== CONT TestSetClientTLS/preserves_debug_logging_transport387=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA388--- PASS: TestSetClientTLSErrors (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)390 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)391 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)392 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)393--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)394--- PASS: TestDumpPathSingleFile (0.06s)3952026/10/06 21:24:07 http: TLS handshake error from 127.0.0.1:52863: remote error: tls: bad certificate396--- PASS: TestCaseHackSuffix (0.05s)397--- PASS: TestSetClientTLS (0.00s)398 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)399 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)400 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)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-49089-2277871705/postgres1083827687/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-49089-2277871705/postgres1083827687/data -l logfile start433434/nix/var/nix/builds/nix-49089-2277871705/postgres1083827687:5432 - no response4352026-10-06 21:24:09.681 UTC [49126] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 21:24:09.681 UTC [49126] LOG: listening on Unix socket "/nix/var/nix/builds/nix-49089-2277871705/postgres1083827687/.s.PGSQL.5432"4372026-10-06 21:24:09.683 UTC [49133] LOG: database system was shut down at 2026-10-06 21:24:09 UTC4382026-10-06 21:24:09.684 UTC [49126] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-49089-2277871705/postgres1083827687:5432 - accepting connections440{"timestamp":"2026-10-06T21:24:09.899465Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7d19e18d-0b09-4fd4-921d-dcf883fd11d9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}441{"timestamp":"2026-10-06T21:24:10.003451Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"73c52846-73d4-4805-89cd-09152065c4ec","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestDeleteClosuresRacingPins479=== PAUSE TestDeleteClosuresRacingPins480=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock482=== RUN TestResolveDBConnectionString483=== PAUSE TestResolveDBConnectionString484=== RUN TestConnectWaitsForAPeerMigration485=== PAUSE TestConnectWaitsForAPeerMigration486=== RUN TestLeadElectsOneAndHandsOver487=== PAUSE TestLeadElectsOneAndHandsOver488=== RUN TestLeadIncumbentWinsAfterRestart4892026/10/06 21:24:10 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 21:24:10 INFO lead: released remote=192.0.2.1:12344912026/10/06 21:24:10 INFO lead: acquired remote=192.0.2.1:12344922026/10/06 21:24:11 INFO lead: released remote=192.0.2.1:1234493--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)494=== RUN TestLeadIncumbentAnnouncesAtOnce495=== PAUSE TestLeadIncumbentAnnouncesAtOnce496=== RUN TestLeadEndsOnShutdown497=== PAUSE TestLeadEndsOnShutdown498=== RUN TestLeadEndsWhenItsConnectionHangs4992026/10/06 21:24:12 INFO lead: acquired remote=192.0.2.1:12345002026-10-06 21:24:13.350 UTC [49168] FATAL: terminating connection due to administrator command5012026/10/06 21:24:13 INFO lead: acquired remote=192.0.2.1:12345022026/10/06 21:24:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"5032026/10/06 21:24:14 INFO lead: released remote=192.0.2.1:12345042026/10/06 21:24:14 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 TestPresentRefreshesOnlyStaleClosures595=== PAUSE TestPresentRefreshesOnlyStaleClosures596=== RUN TestPresentNotReportedWhileGCDeletesClosure597=== PAUSE TestPresentNotReportedWhileGCDeletesClosure598=== 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_CompleteWaitsForCleanupOfThePush641=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush642=== RUN TestPush_RootsAreLockedInByteOrder643=== PAUSE TestPush_RootsAreLockedInByteOrder644=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit645=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit646=== RUN TestPush_RejectsBadRequests647=== PAUSE TestPush_RejectsBadRequests648=== RUN TestPush_SignsNarinfosOfItsPendingObjects649=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects650=== RUN TestRedundantMultipartUpload651=== PAUSE TestRedundantMultipartUpload652=== RUN TestCompleteMultipartUpload_ErrorButObjectExists653=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists654=== RUN TestCompletedNarNotReofferedAcrossClosures655=== PAUSE TestCompletedNarNotReofferedAcrossClosures656=== RUN TestPresignedUploadRegisteredBeforeCommit657=== PAUSE TestPresignedUploadRegisteredBeforeCommit658=== RUN TestService_Rustfstest659=== PAUSE TestService_Rustfstest660=== RUN TestParseSize661=== PAUSE TestParseSize662=== RUN TestSkippedUploadsHandler663=== PAUSE TestSkippedUploadsHandler664=== RUN TestSystemdListenerNotActivated665--- PASS: TestSystemdListenerNotActivated (0.00s)666=== RUN TestWatchdogBeatsWhenHealthy667--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)668=== RUN TestWatchdogSkipsWhenUnhealthy6692026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6702026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6712026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6722026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6732026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6742026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6752026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6762026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6772026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6782026/10/06 21:24:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"679--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)680=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle681=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle682=== RUN TestProxyWriteTimeout683=== PAUSE TestProxyWriteTimeout684=== RUN TestPendingClosureWriteTimeout685=== PAUSE TestPendingClosureWriteTimeout686=== RUN TestIsValidUploadKey687=== PAUSE TestIsValidUploadKey688=== RUN TestUploadHandlersRejectInvalidKeys689=== PAUSE TestUploadHandlersRejectInvalidKeys690=== RUN TestUploadHandlersRejectOversizedBody691=== PAUSE TestUploadHandlersRejectOversizedBody692=== RUN TestService_cleanupPendingClosuresHandler693=== PAUSE TestService_cleanupPendingClosuresHandler694=== RUN TestService_createPendingClosureHandler695=== PAUSE TestService_createPendingClosureHandler696=== RUN TestService_verifyS3Integrity697=== PAUSE TestService_verifyS3Integrity698=== RUN TestCompleteMultipartUnregistered699=== PAUSE TestCompleteMultipartUnregistered700=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT701=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT702=== CONT TestPresentNotReportedWhileGCDeletesClosure703=== CONT TestGCBugBareHashReferences704=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh705=== CONT TestTombstonedObjectOfferedWithoutWaiting706=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh707=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale708=== CONT TestService_AuthMiddleware709=== CONT TestPresentRefreshesOnlyStaleClosures710=== CONT TestForceGCDuringPushOffersSweptObject711=== CONT TestService_readinessHandler712=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection713=== CONT TestGCSweepDeliversEachKeyOnce714=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale715=== CONT TestFailedS3DeleteKeepsTombstone716=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows717=== CONT TestPresentReportsOnlyClosureRoots718=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows719=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check720=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check721=== CONT TestCreatePin_ReservedPins7222026/10/06 21:24:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52888/oidc7232026/10/06 21:24:15 INFO Received uploads request method=POST path=/api/pending_closures7242026/10/06 21:24:15 INFO Received uploads request method=POST path=/api/pending_closures725--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)726=== CONT TestOrphanedObjectsGCStressTest7272026/10/06 21:24:15 INFO Aborted multipart uploads count=0 kept=07282026/10/06 21:24:15 WARN Force mode enabled - objects will be deleted immediately without grace period7292026/10/06 21:24:15 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."7302026/10/06 21:24:15 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."731--- PASS: TestFailedS3DeleteKeepsTombstone (0.64s)732=== CONT TestOrphanedObjectsGC7332026/10/06 21:24:15 INFO Aborted multipart uploads count=0 kept=07342026/10/06 21:24:15 WARN Force mode enabled - objects will be deleted immediately without grace period7352026/10/06 21:24:15 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=07362026/10/06 21:24:15 INFO Vacuumed table table=pending_closures7372026/10/06 21:24:15 INFO Vacuumed table table=pending_objects7382026/10/06 21:24:15 INFO Vacuumed table table=multipart_uploads7392026/10/06 21:24:15 INFO Vacuumed table table=closures7402026/10/06 21:24:15 INFO Vacuumed table table=objects741--- PASS: TestGCSweepDeliversEachKeyOnce (0.79s)742=== CONT TestObjectStatsTrigger7432026/10/06 21:24:15 INFO Received uploads request method=POST path=/api/pending_closures744--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.87s)745=== CONT TestPendingCleanupUsesOneCutoff7462026/10/06 21:24:15 WARN readiness check failed error="closed pool"747--- PASS: TestService_readinessHandler (0.95s)748=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded749--- PASS: TestPresentRefreshesOnlyStaleClosures (1.21s)750=== CONT TestMultipartCleanup751--- PASS: TestGCBugBareHashReferences (1.34s)752=== CONT TestServerTLSConfig753=== RUN TestServerTLSConfig/no_client_CA754=== PAUSE TestServerTLSConfig/no_client_CA755=== RUN TestServerTLSConfig/missing_CA_file756=== PAUSE TestServerTLSConfig/missing_CA_file757=== RUN TestServerTLSConfig/not_a_PEM_file758=== PAUSE TestServerTLSConfig/not_a_PEM_file759=== CONT TestService_NativeMTLS760--- PASS: TestPresentReportsOnlyClosureRoots (1.37s)761=== CONT TestMetricsInventory7622026/10/06 21:24:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"763--- PASS: TestService_AuthMiddleware (1.48s)764=== CONT TestNARDeduplicationMetadataUploadBug7652026/10/06 21:24:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7662026/10/06 21:24:16 WARN Refused reserved pin name=worker-x86_64-linux7672026/10/06 21:24:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7682026/10/06 21:24:16 INFO Received create pin request method=POST path=/api/pins/my-app7692026/10/06 21:24:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux770--- PASS: TestCreatePin_ReservedPins (1.62s)771=== CONT TestCreatePendingClosureRejectsOversizedNAR7722026/10/06 21:24:16 INFO Received uploads request method=POST path=/api/pending_closures773--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)774=== CONT TestCacheConfigHandlerMaxNarSize775--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)776=== CONT TestGenerateLandingPage777--- PASS: TestGenerateLandingPage (0.00s)778=== CONT TestClientWithDependencies779--- PASS: TestObjectStatsTrigger (1.38s)780=== CONT TestGCAdvisoryLockBlocksConcurrentRun7812026/10/06 21:24:17 INFO Received uploads request method=POST path=/api/pending_closures7822026/10/06 21:24:17 INFO Received uploads request method=POST path=/api/pending_closures7832026/10/06 21:24:17 INFO Received cleanup request method=DELETE path=/api/pending_closures7842026/10/06 21:24:17 INFO Received uploads request method=POST path=/api/pending_closures785--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.69s)786=== CONT TestLeadEndsOnShutdown787=== NAME TestOrphanedObjectsGC788 orphaned_objects_gc_test.go:287: GC Test Summary:789 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A790 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B791 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)792 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)793 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects794--- PASS: TestOrphanedObjectsGC (2.01s)795=== CONT TestLeadIncumbentAnnouncesAtOnce7962026/10/06 21:24:17 INFO Received uploads request method=POST path=/api/pending_closures7972026/10/06 21:24:18 INFO Received cleanup request method=DELETE path=/api/pending_closures7982026/10/06 21:24:18 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket18/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""7992026/10/06 21:24:18 INFO Aborted multipart uploads count=0 kept=18002026/10/06 21:24:18 INFO Received cleanup request method=DELETE path=/api/pending_closures8012026/10/06 21:24:18 INFO Aborted multipart uploads count=1 kept=08022026/10/06 21:24:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8032026/10/06 21:24:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"804--- PASS: TestService_NativeMTLS (1.81s)805=== CONT TestLeadElectsOneAndHandsOver806--- PASS: TestMultipartCleanup (1.95s)807=== CONT TestConnectWaitsForAPeerMigration808--- PASS: TestMetricsInventory (1.98s)809=== CONT TestResolveDBConnectionString810=== RUN TestResolveDBConnectionString/flag_wins811=== PAUSE TestResolveDBConnectionString/flag_wins812=== RUN TestResolveDBConnectionString/file_when_flag_empty813=== PAUSE TestResolveDBConnectionString/file_when_flag_empty814=== RUN TestResolveDBConnectionString/missing_file_is_an_error815=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error816=== RUN TestResolveDBConnectionString/PGHOST_allows_empty817=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty818=== RUN TestResolveDBConnectionString/nothing_configured819=== PAUSE TestResolveDBConnectionString/nothing_configured820=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock821=== NAME TestNARDeduplicationMetadataUploadBug822 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-49089-2277871705/TestNARDeduplicationMetadataUploadBug2262644746/001/store/si6a2dj9kw91ddfpfbay9g62k832w1qp-file1.txt8232026/10/06 21:24:18 INFO Received push request method=POST path=/api/pushes8242026/10/06 21:24:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8252026/10/06 21:24:18 INFO Uploading si6a2dj9kw91ddfpfbay9g62k832w1qp-file1.txt (160B)8262026/10/06 21:24:18 WARN Failed to register uploaded object key=si6a2dj9kw91ddfpfbay9g62k832w1qp.ls error="server returned 404: 404 page not found\n"8272026/10/06 21:24:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8282026/10/06 21:24:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"8292026/10/06 21:24:18 INFO Signed narinfos id=1 count=18302026/10/06 21:24:18 INFO Uploading 1 narinfos8312026/10/06 21:24:18 INFO Received complete push request method=POST path=/api/pushes/1/complete8322026/10/06 21:24:18 WARN Failed to register uploaded object key=si6a2dj9kw91ddfpfbay9g62k832w1qp.narinfo error="server returned 404: 404 page not found\n"8332026/10/06 21:24:18 INFO Completed push id=18342026/10/06 21:24:18 INFO Upload complete. (138ms)835 metadata_upload_test.go:54: Retrieved narinfo from S3:836 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestNARDeduplicationMetadataUploadBug2262644746/001/store/si6a2dj9kw91ddfpfbay9g62k832w1qp-file1.txt837 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst838 Compression: zstd839 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf840 NarSize: 160841 References: 842 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf843 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)844 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):845 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}846 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-49089-2277871705/TestNARDeduplicationMetadataUploadBug2262644746/001/store/z2p0h54ncr20i1n1a0b7p3q9iq7xmqw3-file2.txt8472026/10/06 21:24:18 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"848--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.80s)849=== CONT TestDeleteClosuresRacingPins850=== NAME TestClientWithDependencies851 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-49089-2277871705/TestClientWithDependencies3014067836/001/store/rsbxsrg149amhn6b4qf7ckd2ysi5jh68-test-script8522026/10/06 21:24:19 INFO Received push request method=POST path=/api/pushes8532026/10/06 21:24:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)854 client_integration_test.go:615: Found 1 dependencies (including self)8552026/10/06 21:24:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign8562026/10/06 21:24:19 INFO Signed narinfos id=2 count=18572026/10/06 21:24:19 INFO Uploading 1 narinfos8582026/10/06 21:24:19 WARN Failed to register uploaded object key=z2p0h54ncr20i1n1a0b7p3q9iq7xmqw3.ls error="server returned 404: 404 page not found\n"8592026/10/06 21:24:19 INFO Received complete push request method=POST path=/api/pushes/2/complete8602026/10/06 21:24:19 WARN Failed to register uploaded object key=z2p0h54ncr20i1n1a0b7p3q9iq7xmqw3.narinfo error="server returned 404: 404 page not found\n"8612026/10/06 21:24:19 INFO Completed push id=28622026/10/06 21:24:19 INFO Upload complete. (52ms)863=== NAME TestNARDeduplicationMetadataUploadBug864 metadata_upload_test.go:76: Retrieved narinfo from S3:865 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestNARDeduplicationMetadataUploadBug2262644746/001/store/z2p0h54ncr20i1n1a0b7p3q9iq7xmqw3-file2.txt866 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst867 Compression: zstd868 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf869 NarSize: 160870 References: 871 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf872 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)873 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):874 {"version":1,"root":{"type":"regular","size":44}}875=== CONT TestClientFallsBackToClosures876--- PASS: TestNARDeduplicationMetadataUploadBug (2.61s)8772026/10/06 21:24:19 INFO Received push request method=POST path=/api/pushes8782026/10/06 21:24:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8792026/10/06 21:24:19 INFO Uploading rsbxsrg149amhn6b4qf7ckd2ysi5jh68-test-script (136B)8802026/10/06 21:24:19 WARN Failed to register uploaded object key=rsbxsrg149amhn6b4qf7ckd2ysi5jh68.ls error="server returned 404: 404 page not found\n"8812026/10/06 21:24:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"8822026/10/06 21:24:19 WARN Failed to register uploaded object key=log/s4cfyqlcnycd4ix14s1g9isn49la2bmk-test-script.drv error="server returned 404: 404 page not found\n"8832026/10/06 21:24:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8842026/10/06 21:24:19 INFO Signed narinfos id=1 count=18852026/10/06 21:24:19 INFO Uploading 1 narinfos8862026/10/06 21:24:19 INFO Received complete push request method=POST path=/api/pushes/1/complete8872026/10/06 21:24:19 WARN Failed to register uploaded object key=rsbxsrg149amhn6b4qf7ckd2ysi5jh68.narinfo error="server returned 404: 404 page not found\n"8882026/10/06 21:24:19 INFO lead: acquired remote=192.0.2.1:12348892026/10/06 21:24:19 INFO Completed push id=18902026/10/06 21:24:19 INFO Upload complete. (146ms)891=== NAME TestClientWithDependencies892 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-49089-2277871705/TestClientWithDependencies3014067836/001/store) requires matching store prefix893--- PASS: TestClientWithDependencies (2.63s)894=== CONT TestClientPushesUseOnePush8952026/10/06 21:24:19 INFO lead: acquired remote=192.0.2.1:12348962026/10/06 21:24:19 INFO lead: released remote=192.0.2.1:1234897--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.74s)898=== CONT TestPinProtectsFromGC8992026/10/06 21:24:19 INFO lead: acquired remote=192.0.2.1:12349002026/10/06 21:24:20 INFO lead: released remote=192.0.2.1:1234901--- PASS: TestLeadEndsOnShutdown (2.62s)902=== CONT TestClientSharedPathCommittedMidPush903=== NAME TestOrphanedObjectsGCStressTest904 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains905 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion9062026/10/06 21:24:21 INFO lead: released remote=192.0.2.1:12349072026/10/06 21:24:21 INFO lead: acquired remote=192.0.2.1:1234908--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.89s)909=== CONT TestClientErrorHandling910=== RUN TestClientErrorHandling/InvalidStorePath911=== PAUSE TestClientErrorHandling/InvalidStorePath912=== RUN TestClientErrorHandling/InvalidAuthToken913=== PAUSE TestClientErrorHandling/InvalidAuthToken914=== RUN TestClientErrorHandling/ServerNotAvailable915=== PAUSE TestClientErrorHandling/ServerNotAvailable916=== CONT TestClientMultipleUploads9172026/10/06 21:24:21 INFO Received uploads request method=POST path=/api/pending_closures9182026/10/06 21:24:21 INFO Received uploads request method=POST path=/api/pending_closures9192026/10/06 21:24:21 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9202026/10/06 21:24:21 INFO Uploading p7b00v8iaq3al4di0638lp99yr8apd9b-a (248B)9212026/10/06 21:24:21 INFO Uploading 2gcjcqsgb6z65ybddlaapsl1yqxp0npg-shared-dep (136B)9222026/10/06 21:24:21 WARN Failed to register uploaded object key=ng10f5lwaasnhz55iah6080yjk0sklws.ls error="server returned 404: 404 page not found\n"9232026/10/06 21:24:21 WARN Failed to register uploaded object key=2gcjcqsgb6z65ybddlaapsl1yqxp0npg.ls error="server returned 404: 404 page not found\n"9242026/10/06 21:24:21 WARN Failed to register uploaded object key=p7b00v8iaq3al4di0638lp99yr8apd9b.ls error="server returned 404: 404 page not found\n"9252026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9262026/10/06 21:24:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9272026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/1bph5q6sbmw744d79s6qw3l24pq90y4h8adhpl1jkc3chxwr1gyw.nar.zst error="server returned 404: 404 page not found\n"9282026/10/06 21:24:21 INFO Signed narinfos id=1 count=29292026/10/06 21:24:21 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9302026/10/06 21:24:21 INFO Signed narinfos id=2 count=29312026/10/06 21:24:21 INFO Uploading 4 narinfos9322026/10/06 21:24:21 WARN Failed to register uploaded object key=p7b00v8iaq3al4di0638lp99yr8apd9b.narinfo error="server returned 404: 404 page not found\n"9332026/10/06 21:24:21 WARN Failed to register uploaded object key=2gcjcqsgb6z65ybddlaapsl1yqxp0npg.narinfo error="server returned 404: 404 page not found\n"9342026/10/06 21:24:21 WARN Failed to register uploaded object key=ng10f5lwaasnhz55iah6080yjk0sklws.narinfo error="server returned 404: 404 page not found\n"9352026/10/06 21:24:21 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9362026/10/06 21:24:21 WARN Failed to register uploaded object key=2gcjcqsgb6z65ybddlaapsl1yqxp0npg.narinfo error="server returned 404: 404 page not found\n"9372026/10/06 21:24:21 INFO Completed upload id=19382026/10/06 21:24:21 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9392026/10/06 21:24:21 INFO Completed upload id=29402026/10/06 21:24:21 INFO Upload complete. (153ms)941=== NAME TestClientFallsBackToClosures942 client_pushes_test.go:112: Retrieved narinfo from S3:943 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientFallsBackToClosures3022503382/001/store/2gcjcqsgb6z65ybddlaapsl1yqxp0npg-shared-dep944 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst945 Compression: zstd946 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82947 NarSize: 136948 References: 949 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n950 client_pushes_test.go:112: Retrieved narinfo from S3:951 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientFallsBackToClosures3022503382/001/store/p7b00v8iaq3al4di0638lp99yr8apd9b-a952 URL: nar/1bph5q6sbmw744d79s6qw3l24pq90y4h8adhpl1jkc3chxwr1gyw.nar.zst953 Compression: zstd954 NarHash: sha256:1bph5q6sbmw744d79s6qw3l24pq90y4h8adhpl1jkc3chxwr1gyw955 NarSize: 248956 References: /nix/var/nix/builds/nix-49089-2277871705/TestClientFallsBackToClosures3022503382/001/store/2gcjcqsgb6z65ybddlaapsl1yqxp0npg-shared-dep957 CA: text:sha256:0aadgqz56xpn4mfvl7pyfbhlwyys44igp8vbi2bsf5jwm11hxgw6958 client_pushes_test.go:112: Retrieved narinfo from S3:959 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientFallsBackToClosures3022503382/001/store/ng10f5lwaasnhz55iah6080yjk0sklws-b960 URL: nar/1bph5q6sbmw744d79s6qw3l24pq90y4h8adhpl1jkc3chxwr1gyw.nar.zst961 Compression: zstd962 NarHash: sha256:1bph5q6sbmw744d79s6qw3l24pq90y4h8adhpl1jkc3chxwr1gyw963 NarSize: 248964 References: /nix/var/nix/builds/nix-49089-2277871705/TestClientFallsBackToClosures3022503382/001/store/2gcjcqsgb6z65ybddlaapsl1yqxp0npg-shared-dep965 CA: text:sha256:0aadgqz56xpn4mfvl7pyfbhlwyys44igp8vbi2bsf5jwm11hxgw6966--- PASS: TestClientFallsBackToClosures (2.50s)967=== CONT TestClientIntegration9682026/10/06 21:24:21 INFO Received push request method=POST path=/api/pushes9692026/10/06 21:24:21 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9702026/10/06 21:24:21 INFO Uploading 6nv7ds3hiz8gpqaa3c016afpqdk81szm-b (248B)9712026/10/06 21:24:21 INFO Uploading dm9a8nvdry9w22ji3zsmxlpss9y4ww3w-shared-dep (136B)9722026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9732026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/1xvd2x3qavlmhdx1ynq9hbjmfgw5f5jzyv4gm0jk0rifwz4wpv28.nar.zst error="server returned 404: 404 page not found\n"9742026/10/06 21:24:21 WARN Failed to register uploaded object key=z6p0davwcmh4a5ja8ffp93qizwbp3ym5.ls error="server returned 404: 404 page not found\n"9752026/10/06 21:24:21 WARN Failed to register uploaded object key=6nv7ds3hiz8gpqaa3c016afpqdk81szm.ls error="server returned 404: 404 page not found\n"9762026/10/06 21:24:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9772026/10/06 21:24:21 WARN Failed to register uploaded object key=dm9a8nvdry9w22ji3zsmxlpss9y4ww3w.ls error="server returned 404: 404 page not found\n"9782026/10/06 21:24:21 INFO Signed narinfos id=1 count=39792026/10/06 21:24:21 INFO Uploading 3 narinfos980=== NAME TestPinProtectsFromGC981 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-49089-2277871705/TestPinProtectsFromGC1185818249/001/store/nv3lizsyih6c6h1p1w57w99scbqi9185-pinned-file.txt982 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-49089-2277871705/TestPinProtectsFromGC1185818249/001/store/bpmk5w8sx3q7km4m4nczwqn101ysvaki-unpinned-file.txt9832026/10/06 21:24:21 WARN Failed to register uploaded object key=6nv7ds3hiz8gpqaa3c016afpqdk81szm.narinfo error="server returned 404: 404 page not found\n"9842026/10/06 21:24:21 WARN Failed to register uploaded object key=z6p0davwcmh4a5ja8ffp93qizwbp3ym5.narinfo error="server returned 404: 404 page not found\n"9852026/10/06 21:24:21 INFO Received complete push request method=POST path=/api/pushes/1/complete9862026/10/06 21:24:21 WARN Failed to register uploaded object key=dm9a8nvdry9w22ji3zsmxlpss9y4ww3w.narinfo error="server returned 404: 404 page not found\n"9872026/10/06 21:24:21 INFO Completed push id=19882026/10/06 21:24:21 INFO Upload complete. (118ms)989=== NAME TestClientPushesUseOnePush990 client_pushes_test.go:97: Retrieved narinfo from S3:991 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientPushesUseOnePush1217143911/001/store/dm9a8nvdry9w22ji3zsmxlpss9y4ww3w-shared-dep992 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst993 Compression: zstd994 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82995 NarSize: 136996 References: 997 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n998 client_pushes_test.go:97: Retrieved narinfo from S3:999 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientPushesUseOnePush1217143911/001/store/z6p0davwcmh4a5ja8ffp93qizwbp3ym5-a1000 URL: nar/1xvd2x3qavlmhdx1ynq9hbjmfgw5f5jzyv4gm0jk0rifwz4wpv28.nar.zst1001 Compression: zstd1002 NarHash: sha256:1xvd2x3qavlmhdx1ynq9hbjmfgw5f5jzyv4gm0jk0rifwz4wpv281003 NarSize: 2481004 References: /nix/var/nix/builds/nix-49089-2277871705/TestClientPushesUseOnePush1217143911/001/store/dm9a8nvdry9w22ji3zsmxlpss9y4ww3w-shared-dep1005 CA: text:sha256:08935wg3hd5haz3j9mnyd9hqv4qi2i2gwhqnmpls7i4pam77rbcd1006 client_pushes_test.go:97: Retrieved narinfo from S3:1007 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientPushesUseOnePush1217143911/001/store/6nv7ds3hiz8gpqaa3c016afpqdk81szm-b1008 URL: nar/1xvd2x3qavlmhdx1ynq9hbjmfgw5f5jzyv4gm0jk0rifwz4wpv28.nar.zst1009 Compression: zstd1010 NarHash: sha256:1xvd2x3qavlmhdx1ynq9hbjmfgw5f5jzyv4gm0jk0rifwz4wpv281011 NarSize: 2481012 References: /nix/var/nix/builds/nix-49089-2277871705/TestClientPushesUseOnePush1217143911/001/store/dm9a8nvdry9w22ji3zsmxlpss9y4ww3w-shared-dep1013 CA: text:sha256:08935wg3hd5haz3j9mnyd9hqv4qi2i2gwhqnmpls7i4pam77rbcd1014--- PASS: TestClientPushesUseOnePush (2.44s)1015=== CONT TestGCTaskStore_DeduplicateSameParams1016--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1017=== CONT TestService_healthCheckHandler10182026/10/06 21:24:21 INFO Received push request method=POST path=/api/pushes10192026/10/06 21:24:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10202026/10/06 21:24:21 INFO Uploading nv3lizsyih6c6h1p1w57w99scbqi9185-pinned-file.txt (128B)10212026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10222026/10/06 21:24:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10232026/10/06 21:24:21 WARN Failed to register uploaded object key=nv3lizsyih6c6h1p1w57w99scbqi9185.ls error="server returned 404: 404 page not found\n"10242026/10/06 21:24:21 INFO Signed narinfos id=1 count=110252026/10/06 21:24:21 INFO Uploading 1 narinfos10262026/10/06 21:24:21 INFO Received complete push request method=POST path=/api/pushes/1/complete10272026/10/06 21:24:21 WARN Failed to register uploaded object key=nv3lizsyih6c6h1p1w57w99scbqi9185.narinfo error="server returned 404: 404 page not found\n"10282026/10/06 21:24:21 INFO Completed push id=110292026/10/06 21:24:21 INFO Upload complete. (115ms)10302026/10/06 21:24:21 INFO Received push request method=POST path=/api/pushes10312026/10/06 21:24:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10322026/10/06 21:24:21 INFO Uploading bpmk5w8sx3q7km4m4nczwqn101ysvaki-unpinned-file.txt (128B)10332026/10/06 21:24:21 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10342026/10/06 21:24:21 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10352026/10/06 21:24:21 WARN Failed to register uploaded object key=bpmk5w8sx3q7km4m4nczwqn101ysvaki.ls error="server returned 404: 404 page not found\n"10362026/10/06 21:24:21 INFO Signed narinfos id=2 count=110372026/10/06 21:24:21 INFO Uploading 1 narinfos10382026/10/06 21:24:21 INFO Received complete push request method=POST path=/api/pushes/2/complete10392026/10/06 21:24:21 WARN Failed to register uploaded object key=bpmk5w8sx3q7km4m4nczwqn101ysvaki.narinfo error="server returned 404: 404 page not found\n"10402026/10/06 21:24:21 INFO Completed push id=210412026/10/06 21:24:21 INFO Upload complete. (75ms)10422026/10/06 21:24:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures10432026/10/06 21:24:21 INFO Garbage collection started10442026/10/06 21:24:21 INFO Aborted multipart uploads count=0 kept=010452026/10/06 21:24:21 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/10/06 21:24:21 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=010472026/10/06 21:24:21 INFO Vacuumed table table=pending_closures10482026/10/06 21:24:22 INFO Vacuumed table table=pending_objects10492026/10/06 21:24:22 INFO Vacuumed table table=multipart_uploads10502026/10/06 21:24:22 INFO Vacuumed table table=closures10512026/10/06 21:24:22 INFO Vacuumed table table=objects10522026/10/06 21:24:22 INFO Received push request method=POST path=/api/pushes10532026/10/06 21:24:22 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10542026/10/06 21:24:22 INFO Uploading 4m8wf44kddpgssgihxa219vi95qcrnqi-top (256B)10552026/10/06 21:24:22 INFO Uploading f31js47bpryc62gl5d5mr6i98vz4rffi-shared-dep (136B)10562026/10/06 21:24:22 WARN Failed to register uploaded object key=f31js47bpryc62gl5d5mr6i98vz4rffi.ls error="server returned 404: 404 page not found\n"10572026/10/06 21:24:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10582026/10/06 21:24:22 WARN Failed to register uploaded object key=4m8wf44kddpgssgihxa219vi95qcrnqi.ls error="server returned 404: 404 page not found\n"10592026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/1psl7m5c1jyiklkdqv50wla3h7vbibwgkrlw30fdjbsl2kcrzlpc.nar.zst error="server returned 404: 404 page not found\n"10602026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10612026/10/06 21:24:22 INFO Signed narinfos id=1 count=210622026/10/06 21:24:22 INFO Uploading 2 narinfos10632026/10/06 21:24:22 WARN Failed to register uploaded object key=4m8wf44kddpgssgihxa219vi95qcrnqi.narinfo error="server returned 404: 404 page not found\n"10642026/10/06 21:24:22 INFO Received complete push request method=POST path=/api/pushes/1/complete10652026/10/06 21:24:22 WARN Failed to register uploaded object key=f31js47bpryc62gl5d5mr6i98vz4rffi.narinfo error="server returned 404: 404 page not found\n"10662026/10/06 21:24:22 INFO lead: released remote=192.0.2.1:12341067--- PASS: TestLeadElectsOneAndHandsOver (4.08s)1068=== CONT TestGracefulShutdownDrainsInflight10692026/10/06 21:24:22 INFO Starting HTTP server address=127.0.0.1:5304010702026/10/06 21:24:22 INFO Shutdown signal received, draining in-flight requests timeout=10s10712026/10/06 21:24:22 INFO Completed push id=110722026/10/06 21:24:22 INFO Upload complete. (79ms)1073=== NAME TestClientSharedPathCommittedMidPush1074 client_integration_test.go:680: Retrieved narinfo from S3:1075 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientSharedPathCommittedMidPush4033747099/001/store/f31js47bpryc62gl5d5mr6i98vz4rffi-shared-dep1076 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1077 Compression: zstd1078 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821079 NarSize: 1361080 References: 1081 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1082 client_integration_test.go:680: Retrieved narinfo from S3:1083 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientSharedPathCommittedMidPush4033747099/001/store/4m8wf44kddpgssgihxa219vi95qcrnqi-top1084 URL: nar/1psl7m5c1jyiklkdqv50wla3h7vbibwgkrlw30fdjbsl2kcrzlpc.nar.zst1085 Compression: zstd1086 NarHash: sha256:1psl7m5c1jyiklkdqv50wla3h7vbibwgkrlw30fdjbsl2kcrzlpc1087 NarSize: 2561088 References: /nix/var/nix/builds/nix-49089-2277871705/TestClientSharedPathCommittedMidPush4033747099/001/store/f31js47bpryc62gl5d5mr6i98vz4rffi-shared-dep1089 CA: text:sha256:073r30l33lasgvnaq6z5ri57zyr38cwmxwvadpb12nsd3sk6mfj41090--- PASS: TestClientSharedPathCommittedMidPush (2.01s)1091=== CONT TestGCTaskStore_Fail1092--- PASS: TestGCTaskStore_Fail (0.00s)1093=== CONT TestGCTaskStore_PhaseUpdates1094--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1095=== CONT TestGCTaskStore_CompletedAllowsNewTask1096--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1097=== CONT TestGCTaskStore_GetReturnsLatest1098--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1099=== CONT TestGCTaskStore_GetEmpty1100--- PASS: TestGCTaskStore_GetEmpty (0.00s)1101=== CONT TestGCTaskStore_ConflictDifferentParams1102--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1103=== CONT TestPush_CompleteWaitsForCleanupOfThePush1104--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1105=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1106=== NAME TestOrphanedObjectsGCStressTest1107 orphaned_objects_gc_test.go:503: Stress test completed successfully:1108 orphaned_objects_gc_test.go:504: - Active objects preserved: 201109 orphaned_objects_gc_test.go:505: - Objects deleted: 2101110 orphaned_objects_gc_test.go:506: - Total GC'd: 2101111--- PASS: TestOrphanedObjectsGCStressTest (6.88s)1112=== CONT TestCompleteMultipartUnregistered1113=== NAME TestClientMultipleUploads1114 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-49089-2277871705/TestClientMultipleUploads3298599272/001/store/i8ns45ij9b4s8dj5dls5jzsx8kpj7nhc-test-file-0.txt1115 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-49089-2277871705/TestClientMultipleUploads3298599272/001/store/mfsv3z5m32hycmiqlsyjsnz1h7hgsxzx-test-file-1.txt1116 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-49089-2277871705/TestClientMultipleUploads3298599272/001/store/n4njgp8k797fzyv0ly9phia9zgdqb4g6-test-file-2.txt1117=== NAME TestClientIntegration1118 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-49089-2277871705/TestClientIntegration1546856323/002/store/w4sc8xgn0ga8pa5pa3ahrrl54c9wcpha-test-file.txt1119--- PASS: TestService_healthCheckHandler (1.08s)1120=== CONT TestService_verifyS3Integrity11212026/10/06 21:24:22 INFO Received push request method=POST path=/api/pushes11222026/10/06 21:24:22 INFO Received push request method=POST path=/api/pushes11232026/10/06 21:24:22 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11242026/10/06 21:24:22 INFO Uploading i8ns45ij9b4s8dj5dls5jzsx8kpj7nhc-test-file-0.txt (160B)11252026/10/06 21:24:22 INFO Uploading mfsv3z5m32hycmiqlsyjsnz1h7hgsxzx-test-file-1.txt (160B)11262026/10/06 21:24:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11272026/10/06 21:24:22 INFO Uploading n4njgp8k797fzyv0ly9phia9zgdqb4g6-test-file-2.txt (160B)11282026/10/06 21:24:22 INFO Uploading w4sc8xgn0ga8pa5pa3ahrrl54c9wcpha-test-file.txt (152B)11292026/10/06 21:24:22 WARN Failed to register uploaded object key=i8ns45ij9b4s8dj5dls5jzsx8kpj7nhc.ls error="server returned 404: 404 page not found\n"11302026/10/06 21:24:22 WARN Failed to register uploaded object key=n4njgp8k797fzyv0ly9phia9zgdqb4g6.ls error="server returned 404: 404 page not found\n"11312026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11322026/10/06 21:24:22 WARN Failed to register uploaded object key=mfsv3z5m32hycmiqlsyjsnz1h7hgsxzx.ls error="server returned 404: 404 page not found\n"11332026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11342026/10/06 21:24:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11352026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11362026/10/06 21:24:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11372026/10/06 21:24:22 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11382026/10/06 21:24:22 WARN Failed to register uploaded object key=w4sc8xgn0ga8pa5pa3ahrrl54c9wcpha.ls error="server returned 404: 404 page not found\n"11392026/10/06 21:24:22 INFO Signed narinfos id=1 count=311402026/10/06 21:24:22 INFO Signed narinfos id=1 count=111412026/10/06 21:24:22 INFO Uploading 3 narinfos11422026/10/06 21:24:22 INFO Uploading 1 narinfos11432026/10/06 21:24:22 INFO Received complete push request method=POST path=/api/pushes/1/complete11442026/10/06 21:24:22 INFO Received complete push request method=POST path=/api/pushes/1/complete11452026/10/06 21:24:22 WARN Failed to register uploaded object key=mfsv3z5m32hycmiqlsyjsnz1h7hgsxzx.narinfo error="server returned 404: 404 page not found\n"11462026/10/06 21:24:22 WARN Failed to register uploaded object key=n4njgp8k797fzyv0ly9phia9zgdqb4g6.narinfo error="server returned 404: 404 page not found\n"11472026/10/06 21:24:22 WARN Failed to register uploaded object key=i8ns45ij9b4s8dj5dls5jzsx8kpj7nhc.narinfo error="server returned 404: 404 page not found\n"11482026/10/06 21:24:22 WARN Failed to register uploaded object key=w4sc8xgn0ga8pa5pa3ahrrl54c9wcpha.narinfo error="server returned 404: 404 page not found\n"11492026/10/06 21:24:22 INFO Completed push id=111502026/10/06 21:24:22 INFO Upload complete. (84ms)1151=== NAME TestClientMultipleUploads1152 client_integration_test.go:369: Uploaded 3 paths in 116.663792ms11532026/10/06 21:24:22 INFO Completed push id=111542026/10/06 21:24:22 INFO Upload complete. (81ms)1155--- PASS: TestClientMultipleUploads (1.61s)1156=== CONT TestService_createPendingClosureHandler11572026/10/06 21:24:22 INFO All 1 paths already cached1158=== NAME TestClientIntegration1159 client_integration_test.go:312: Retrieved narinfo from S3:1160 StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientIntegration1546856323/002/store/w4sc8xgn0ga8pa5pa3ahrrl54c9wcpha-test-file.txt1161 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1162 Compression: zstd1163 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11164 NarSize: 1521165 References: 1166 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11167 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1168 client_integration_test.go:313: Decompressed .ls content (64 bytes):1169 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1170 client_integration_test.go:316: Testing garbage collection...11712026/10/06 21:24:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures11722026/10/06 21:24:22 INFO Garbage collection started11732026/10/06 21:24:22 INFO Aborted multipart uploads count=0 kept=011742026/10/06 21:24:22 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/06 21:24:22 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=011762026/10/06 21:24:22 INFO Vacuumed table table=pending_closures11772026/10/06 21:24:22 INFO Vacuumed table table=pending_objects11782026/10/06 21:24:22 INFO Vacuumed table table=multipart_uploads11792026/10/06 21:24:22 INFO Vacuumed table table=closures11802026/10/06 21:24:22 INFO Vacuumed table table=objects11812026/10/06 21:24:23 INFO Received push request method=POST path=/api/pushes1182--- PASS: TestDeleteClosuresRacingPins (4.06s)1183=== CONT TestService_cleanupPendingClosuresHandler11842026/10/06 21:24:23 INFO Received uploads request method=POST path=/api/pending_closures1185--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.94s)1186=== CONT TestUploadHandlersRejectOversizedBody1187=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1188=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1189=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1190=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1191=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1192=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1193=== CONT TestUploadHandlersRejectInvalidKeys1194=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1195=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1196=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1197=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1198=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1199=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1200=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1201=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1202=== CONT TestIsValidUploadKey1203=== RUN TestIsValidUploadKey/narinfo1204=== PAUSE TestIsValidUploadKey/narinfo1205=== RUN TestIsValidUploadKey/nar_zst1206=== PAUSE TestIsValidUploadKey/nar_zst1207=== RUN TestIsValidUploadKey/nar_xz1208=== PAUSE TestIsValidUploadKey/nar_xz1209=== RUN TestIsValidUploadKey/nar_plain1210=== PAUSE TestIsValidUploadKey/nar_plain1211=== RUN TestIsValidUploadKey/listing1212=== PAUSE TestIsValidUploadKey/listing1213=== RUN TestIsValidUploadKey/build_log1214=== PAUSE TestIsValidUploadKey/build_log1215=== RUN TestIsValidUploadKey/build_log_home-manager_file1216=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1217=== RUN TestIsValidUploadKey/build_log_plus_in_name1218=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1219=== RUN TestIsValidUploadKey/build_log_question_mark1220=== PAUSE TestIsValidUploadKey/build_log_question_mark1221=== RUN TestIsValidUploadKey/build_log_equals1222=== PAUSE TestIsValidUploadKey/build_log_equals1223=== RUN TestIsValidUploadKey/realisation1224=== PAUSE TestIsValidUploadKey/realisation1225=== RUN TestIsValidUploadKey/realisation_plus_in_output1226=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1227=== RUN TestIsValidUploadKey/nix-cache-info1228=== PAUSE TestIsValidUploadKey/nix-cache-info1229=== RUN TestIsValidUploadKey/index.html1230=== PAUSE TestIsValidUploadKey/index.html1231=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1232=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1233=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1234=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1235=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1236=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1237=== RUN TestIsValidUploadKey/traversal1238=== PAUSE TestIsValidUploadKey/traversal1239=== RUN TestIsValidUploadKey/traversal_nar1240=== PAUSE TestIsValidUploadKey/traversal_nar1241=== RUN TestIsValidUploadKey/absolute1242=== PAUSE TestIsValidUploadKey/absolute1243=== RUN TestIsValidUploadKey/empty_key1244=== PAUSE TestIsValidUploadKey/empty_key1245=== RUN TestIsValidUploadKey/unknown_type1246=== PAUSE TestIsValidUploadKey/unknown_type1247=== CONT TestPendingClosureWriteTimeout1248=== RUN TestPendingClosureWriteTimeout/empty1249=== PAUSE TestPendingClosureWriteTimeout/empty1250=== RUN TestPendingClosureWriteTimeout/400_objects1251=== PAUSE TestPendingClosureWriteTimeout/400_objects1252=== RUN TestPendingClosureWriteTimeout/670k_objects1253=== PAUSE TestPendingClosureWriteTimeout/670k_objects1254=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1255=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1256=== CONT TestProxyWriteTimeout1257=== RUN TestProxyWriteTimeout/narinfo1258=== PAUSE TestProxyWriteTimeout/narinfo1259=== RUN TestProxyWriteTimeout/1_GiB_nar1260=== PAUSE TestProxyWriteTimeout/1_GiB_nar1261=== RUN TestProxyWriteTimeout/10_GiB_nar1262=== PAUSE TestProxyWriteTimeout/10_GiB_nar1263=== RUN TestProxyWriteTimeout/unknown_size1264=== PAUSE TestProxyWriteTimeout/unknown_size1265=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle12662026-10-06 21:24:23.376 UTC [49412] ERROR: Push does not exist: id=112672026-10-06 21:24:23.376 UTC [49412] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE12682026-10-06 21:24:23.376 UTC [49412] STATEMENT: SELECT commit_push($1)1269--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.13s)1270=== CONT TestSkippedUploadsHandler12712026/10/06 21:24:23 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001272--- PASS: TestSkippedUploadsHandler (0.00s)1273=== CONT TestParseSize1274--- PASS: TestParseSize (0.00s)1275=== CONT TestService_Rustfstest12762026/10/06 21:24:23 INFO Aborted multipart uploads count=1 kept=012772026/10/06 21:24:23 INFO Received cleanup request method=DELETE path=/api/pending_closures12782026/10/06 21:24:23 INFO Aborted multipart uploads count=1 kept=01279--- PASS: TestPendingCleanupUsesOneCutoff (7.60s)1280=== CONT TestPresignedUploadRegisteredBeforeCommit1281{"timestamp":"2026-10-06T21:24:23.580275Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":3,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}12822026/10/06 21:24:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12832026/10/06 21:24:23 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1284--- PASS: TestCompleteMultipartUnregistered (1.11s)1285=== CONT TestCompletedNarNotReofferedAcrossClosures12862026/10/06 21:24:23 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=012872026/10/06 21:24:23 INFO Received create pin request method=POST path=/api/pins/myapp12882026/10/06 21:24:23 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-49089-2277871705/TestPinProtectsFromGC1185818249/001/store/nv3lizsyih6c6h1p1w57w99scbqi9185-pinned-file.txt narinfo_key=nv3lizsyih6c6h1p1w57w99scbqi9185.narinfo12892026/10/06 21:24:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures12902026/10/06 21:24:23 INFO Garbage collection started12912026/10/06 21:24:23 INFO Aborted multipart uploads count=0 kept=012922026/10/06 21:24:23 WARN Force mode enabled - objects will be deleted immediately without grace period12932026/10/06 21:24:23 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=012942026/10/06 21:24:23 INFO Vacuumed table table=pending_closures12952026/10/06 21:24:23 INFO Vacuumed table table=pending_objects12962026/10/06 21:24:23 INFO Vacuumed table table=multipart_uploads12972026/10/06 21:24:23 INFO Vacuumed table table=closures12982026/10/06 21:24:23 INFO Vacuumed table table=objects12992026/10/06 21:24:23 INFO Received uploads request method=POST path=/api/pending_closures13002026/10/06 21:24:24 INFO Received uploads request method=POST path=/api/pending_closures13012026/10/06 21:24:24 INFO Received uploads request method=POST path=/api/pending_closures13022026/10/06 21:24:24 INFO Received uploads request method=POST path=/api/pending_closures13032026/10/06 21:24:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01304=== NAME TestClientIntegration1305 client_integration_test.go:323: Objects in database after GC:1306 client_integration_test.go:323: Successfully deleted all objects with GC --force1307--- PASS: TestClientIntegration (3.38s)1308=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13092026/10/06 21:24:24 INFO Received cleanup request method=DELETE path=/api/pending_closures13102026/10/06 21:24:24 INFO Aborted multipart uploads count=0 kept=013112026/10/06 21:24:24 INFO Received uploads request method=POST path=/api/pending_closures1312--- PASS: TestConnectWaitsForAPeerMigration (6.85s)1313=== CONT TestRedundantMultipartUpload13142026/10/06 21:24:25 INFO Received cleanup request method=DELETE path=/api/pending_closures13152026/10/06 21:24:25 INFO Aborted multipart uploads count=1 kept=013162026/10/06 21:24:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13172026-10-06 21:24:25.079 UTC [49424] ERROR: Closure does not exist: id=113182026-10-06 21:24:25.079 UTC [49424] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13192026-10-06 21:24:25.079 UTC [49424] STATEMENT: -- name: CommitPendingClosure :exec1320 SELECT commit_pending_closure($1::bigint)1321 1322--- PASS: TestService_cleanupPendingClosuresHandler (2.06s)1323=== CONT TestPush_SignsNarinfosOfItsPendingObjects13242026/10/06 21:24:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13252026/10/06 21:24:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLmJkMjRiY2JlLWU3YzEtNGRjOS05MjllLTAzM2IwN2MzMDM3MngxNzkxMzIxODY0MDI1NzM0MDAw parts=1013262026/10/06 21:24:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13272026/10/06 21:24:25 INFO Completed upload id=113282026/10/06 21:24:25 INFO Received uploads request method=POST path=/api/pending_closures13292026/10/06 21:24:25 INFO Received uploads request method=POST path=/api/pending_closures13302026/10/06 21:24:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13312026/10/06 21:24:25 WARN Found objects in DB but missing from S3, will re-upload count=11332--- PASS: TestService_verifyS3Integrity (2.77s)1333=== CONT TestPush_RejectsBadRequests13342026/10/06 21:24:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13352026/10/06 21:24:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLjhiMjg3MzAzLWZkY2UtNGVhNS1hZWE5LWJlMDkyNjRjODgyOHgxNzkxMzIxODY0MjU3MDQ1MDAw parts=1013362026/10/06 21:24:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13372026/10/06 21:24:25 INFO Completed upload id=113382026/10/06 21:24:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013392026/10/06 21:24:25 INFO Received uploads request method=POST path=/api/pending_closures13402026/10/06 21:24:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures13412026/10/06 21:24:25 INFO Aborted multipart uploads count=0 kept=013422026/10/06 21:24:25 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=013432026/10/06 21:24:25 INFO Received uploads request method=POST path=/api/pending_closures13442026/10/06 21:24:25 INFO Vacuumed table table=pending_closures13452026/10/06 21:24:25 INFO Vacuumed table table=pending_objects13462026/10/06 21:24:25 INFO Vacuumed table table=multipart_uploads13472026/10/06 21:24:25 INFO Vacuumed table table=closures1348=== NAME TestPinProtectsFromGC1349 client_integration_test.go:840: Pin successfully protected closure from garbage collection13502026/10/06 21:24:25 INFO Vacuumed table table=objects13512026/10/06 21:24:26 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001352--- PASS: TestService_createPendingClosureHandler (3.17s)1353=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1354--- PASS: TestService_Rustfstest (2.65s)1355=== CONT TestPush_RootsAreLockedInByteOrder1356--- PASS: TestPinProtectsFromGC (6.65s)1357=== CONT TestService_AuthMiddleware_OIDC13582026/10/06 21:24:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53106/oidc13592026/10/06 21:24:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13602026/10/06 21:24:26 INFO Received uploads request method=POST path=/api/pending_closures13612026/10/06 21:24:26 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13622026/10/06 21:24:26 INFO Received uploads request method=POST path=/api/pending_closures1363--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.83s)1364=== CONT TestService_ReadScope_PublicByDefault13652026/10/06 21:24:26 INFO Received uploads request method=POST path=/api/pending_closures13662026/10/06 21:24:26 INFO Received uploads request method=POST path=/api/pending_closures13672026/10/06 21:24:27 INFO Received push request method=POST path=/api/pushes13682026/10/06 21:24:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13692026/10/06 21:24:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLjFmZTQ0NTJkLTM4MTctNDBkNi04MWJhLTMwMjk4NjhkZTM5NXgxNzkxMzIxODY2OTM5NTgyMDAw13702026/10/06 21:24:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLjFmZTQ0NTJkLTM4MTctNDBkNi04MWJhLTMwMjk4NjhkZTM5NXgxNzkxMzIxODY2OTM5NTgyMDAw parts=11371--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.28s)1372=== CONT TestService_RequireScope_OIDC13732026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13742026/10/06 21:24:27 INFO Signed narinfos id=1 count=113752026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13772026/10/06 21:24:27 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"13782026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13792026/10/06 21:24:27 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"13802026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13812026/10/06 21:24:27 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113822026/10/06 21:24:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13832026/10/06 21:24:27 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1384--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.16s)1385=== CONT TestClientCADerivations13862026/10/06 21:24:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53116/oidc13872026/10/06 21:24:27 INFO Received uploads request method=POST path=/api/pending_closures13882026/10/06 21:24:27 INFO Received uploads request method=POST path=/api/pending_closures1389=== RUN TestPush_RejectsBadRequests/no_roots1390=== PAUSE TestPush_RejectsBadRequests/no_roots1391=== RUN TestPush_RejectsBadRequests/no_objects1392=== PAUSE TestPush_RejectsBadRequests/no_objects1393=== RUN TestPush_RejectsBadRequests/bad_root1394=== PAUSE TestPush_RejectsBadRequests/bad_root1395=== RUN TestPush_RejectsBadRequests/root_not_in_objects1396=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1397=== CONT TestReadProxyNarinfoAlreadyDecompressed13982026/10/06 21:24:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13992026/10/06 21:24:28 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLmE4ZTU1ZWY1LTk3MGYtNDFiMC04ODg5LTliMjg2MmM3M2ZkZHgxNzkxMzIxODY2NDg4MDM1MDAw parts=1214002026/10/06 21:24:28 INFO Received uploads request method=POST path=/api/pending_closures1401--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.55s)1402=== CONT TestReadProxyHead14032026/10/06 21:24:28 INFO Received push request method=POST path=/api/pushes14042026-10-06 21:24:28.379 UTC [49462] ERROR: could not obtain lock on row in relation "closures"14052026-10-06 21:24:28.379 UTC [49462] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14062026-10-06 21:24:28.380 UTC [49462] ERROR: could not obtain lock on row in relation "closures"14072026-10-06 21:24:28.380 UTC [49462] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14082026-10-06 21:24:28.380 UTC [49462] ERROR: could not obtain lock on row in relation "closures"14092026-10-06 21:24:28.380 UTC [49462] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14102026-10-06 21:24:28.380 UTC [49462] ERROR: could not obtain lock on row in relation "closures"14112026-10-06 21:24:28.380 UTC [49462] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14122026-10-06 21:24:28.380 UTC [49462] ERROR: could not obtain lock on row in relation "closures"14132026-10-06 21:24:28.380 UTC [49462] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1414--- PASS: TestPush_RootsAreLockedInByteOrder (2.36s)1415=== CONT TestReadProxyInvalidPath14162026/10/06 21:24:28 INFO Received push request method=POST path=/api/pushes14172026/10/06 21:24:28 INFO Received complete push request method=POST path=/api/pushes/1/complete14182026/10/06 21:24:28 INFO Completed push id=114192026/10/06 21:24:28 INFO Received push request method=POST path=/api/pushes14202026/10/06 21:24:28 INFO Aborted multipart uploads count=0 kept=014212026/10/06 21:24:28 WARN Force mode enabled - objects will be deleted immediately without grace period14222026/10/06 21:24:28 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=01423=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1424=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1425=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1426=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1427=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1428=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1429=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1430=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1431=== CONT TestReadProxyOutlastsServerWriteTimeout14322026/10/06 21:24:28 INFO Vacuumed table table=pending_closures14332026/10/06 21:24:28 INFO Vacuumed table table=pending_objects14342026/10/06 21:24:28 INFO Vacuumed table table=multipart_uploads14352026/10/06 21:24:28 INFO Vacuumed table table=closures14362026/10/06 21:24:28 INFO Vacuumed table table=objects14372026/10/06 21:24:28 INFO Received complete push request method=POST path=/api/pushes/2/complete14382026/10/06 21:24:28 INFO Completed push id=21439--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.85s)1440=== CONT TestReadProxy4041441--- PASS: TestService_ReadScope_PublicByDefault (2.67s)1442=== CONT TestReadProxyNarStreaming14432026/10/06 21:24:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14442026/10/06 21:24:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLjdlMTE4MjNiLTJjNTktNDZmNi1hNTc3LWZjN2ZjY2RjZGIzOXgxNzkxMzIxODY3NDIwMTMxMDAw parts=1214452026/10/06 21:24:29 INFO Received uploads request method=POST path=/api/pending_closures14462026/10/06 21:24:29 INFO Received uploads request method=POST path=/api/pending_closures1447=== RUN TestService_RequireScope_OIDC/builder_may_write1448=== PAUSE TestService_RequireScope_OIDC/builder_may_write1449=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1450=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1451=== RUN TestService_RequireScope_OIDC/ops_may_admin1452=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1453=== RUN TestService_RequireScope_OIDC/ops_may_not_write1454=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1455=== RUN TestService_RequireScope_OIDC/reader_may_not_write1456=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1457=== RUN TestService_RequireScope_OIDC/static_token_may_admin1458=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1459=== RUN TestService_RequireScope_OIDC/static_token_may_write1460=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1461=== RUN TestService_RequireScope_OIDC/reader_may_read1462=== PAUSE TestService_RequireScope_OIDC/reader_may_read1463=== RUN TestService_RequireScope_OIDC/writer_implies_read1464=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1465=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1466=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1467=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1468=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1469=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1470=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1471=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1472=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1473=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1474=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1475=== CONT TestPush_RepeatedRootCommitsOnce1476{"timestamp":"2026-10-06T21:24:29.891578Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":3,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}14772026/10/06 21:24:30 WARN Rate limiter enabled after throttle name=s3-test rate=514782026/10/06 21:24:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1479=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1480 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101481 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001482--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.98s)1483=== CONT TestReadProxyContentNegotiation1484=== NAME TestClientCADerivations1485 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-49089-2277871705/TestClientCADerivations3375779131/001/store/g6c7flm2l5xa85wy6169k2fi7zknls0v-ca-test1486 client_ca_test.go:139: Found 1 dependencies (including self)14872026/10/06 21:24:30 INFO Received push request method=POST path=/api/pushes1488--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.59s)1489=== CONT TestPush_CompleteCommitsEveryRoot14902026/10/06 21:24:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14912026/10/06 21:24:30 INFO Uploading g6c7flm2l5xa85wy6169k2fi7zknls0v-ca-test (144B)14922026/10/06 21:24:30 WARN Failed to register uploaded object key=g6c7flm2l5xa85wy6169k2fi7zknls0v.ls error="server returned 404: 404 page not found\n"14932026/10/06 21:24:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14942026/10/06 21:24:30 WARN Failed to register uploaded object key=log/8s10niy1r256sy2cby5d94p8f5xyw48v-ca-test.drv error="server returned 404: 404 page not found\n"14952026/10/06 21:24:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14962026/10/06 21:24:30 INFO Signed narinfos id=1 count=114972026/10/06 21:24:30 INFO Uploading 1 narinfos14982026/10/06 21:24:30 INFO Received complete push request method=POST path=/api/pushes/1/complete14992026/10/06 21:24:30 WARN Failed to register uploaded object key=g6c7flm2l5xa85wy6169k2fi7zknls0v.narinfo error="server returned 404: 404 page not found\n"15002026/10/06 21:24:30 INFO Completed push id=115012026/10/06 21:24:30 INFO Upload complete. (180ms)1502=== NAME TestClientCADerivations1503 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-49089-2277871705/TestClientCADerivations3375779131/001/store/g6c7flm2l5xa85wy6169k2fi7zknls0v-ca-test1504 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1505 Compression: zstd1506 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1507 NarSize: 1441508 References: 1509 Deriver: /nix/var/nix/builds/nix-49089-2277871705/TestClientCADerivations3375779131/001/store/8s10niy1r256sy2cby5d94p8f5xyw48v-ca-test.drv1510 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1511 client_ca_test.go:185: Checking for realisation files in S3...1512 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1513 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15142026/10/06 21:24:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15152026/10/06 21:24:30 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLmRmMDcyYmY4LWZhODUtNGZiMS05N2E5LTUxM2VhMzUzY2RmMHgxNzkxMzIxODY5MzI2ODI4MDAw error="Get \"http://127.0.0.1:1/bucket48/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15162026/10/06 21:24:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWUyOGE3OGYtNjIyMS00ZjRlLWEyNjAtMTRkNGNkZDBiMTgyLmExNTM5ZjcwLWE3NDMtNGE5OC04MzRjLTkxODk2ZmFmZGZjNXgxNzkxMzIxODY5MjUwMjMyMDAw parts=1215172026/10/06 21:24:30 INFO Received cleanup request method=DELETE path=/api/pending_closures15182026/10/06 21:24:30 INFO Aborted multipart uploads count=1 kept=01519--- PASS: TestRedundantMultipartUpload (5.75s)1520=== CONT TestReadRedirectKeepsNarinfoProxied1521=== NAME TestClientCADerivations1522 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket55?endpoint=http://localhost:52868®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-49089-2277871705/TestClientCADerivations3375779131/001/store'1523 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11524--- PASS: TestReadProxyHead (2.65s)1525=== CONT TestReadRedirectNar1526--- PASS: TestClientCADerivations (3.65s)1527=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1528--- PASS: TestReadProxyInvalidPath (2.61s)1529=== CONT TestReadProxyDisabled1530--- PASS: TestReadProxy404 (2.63s)1531=== CONT TestReadRedirectUsesPublicS3URL1532--- PASS: TestReadProxyNarStreaming (2.68s)1533=== CONT TestReadProxyRootRedirectsToIndexHTML15342026/10/06 21:24:31 INFO Received push request method=POST path=/api/pushes15352026/10/06 21:24:31 INFO Received complete push request method=POST path=/api/pushes/1/complete15362026/10/06 21:24:31 INFO Completed push id=11537--- PASS: TestPush_RepeatedRootCommitsOnce (2.22s)1538=== CONT TestReadProxyRangeRequest1539--- PASS: TestReadProxyContentNegotiation (2.08s)1540=== CONT TestReadProxyConditionalGet15412026/10/06 21:24:32 INFO Received push request method=POST path=/api/pushes15422026/10/06 21:24:32 INFO Received complete push request method=POST path=/api/pushes/1/complete15432026/10/06 21:24:32 INFO Completed push id=11544--- PASS: TestPush_CompleteCommitsEveryRoot (2.22s)1545=== CONT TestProxyHeadersOnlyTrustedOnSocket1546--- PASS: TestReadRedirectNar (2.14s)1547=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15482026/10/06 21:24:33 INFO Received push request method=POST path=/api/pushes1549--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.34s)1550=== CONT TestReadProxyNarinfo1551--- PASS: TestReadProxyDisabled (2.36s)1552=== CONT TestService_ReadAuthMiddleware1553--- PASS: TestReadRedirectKeepsNarinfoProxied (2.83s)1554=== CONT TestIsValidCachePath1555=== RUN TestIsValidCachePath/narinfo1556=== PAUSE TestIsValidCachePath/narinfo1557=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1558=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1559=== RUN TestIsValidCachePath/nar_zst1560=== PAUSE TestIsValidCachePath/nar_zst1561=== RUN TestIsValidCachePath/nar_xz1562=== PAUSE TestIsValidCachePath/nar_xz1563=== RUN TestIsValidCachePath/nar_bz21564=== PAUSE TestIsValidCachePath/nar_bz21565=== RUN TestIsValidCachePath/nar_uncompressed1566=== PAUSE TestIsValidCachePath/nar_uncompressed1567=== RUN TestIsValidCachePath/ls1568=== PAUSE TestIsValidCachePath/ls1569=== RUN TestIsValidCachePath/log1570=== PAUSE TestIsValidCachePath/log1571=== RUN TestIsValidCachePath/realisation1572=== PAUSE TestIsValidCachePath/realisation1573=== RUN TestIsValidCachePath/nix-cache-info1574=== PAUSE TestIsValidCachePath/nix-cache-info1575=== RUN TestIsValidCachePath/index.html1576=== PAUSE TestIsValidCachePath/index.html1577=== RUN TestIsValidCachePath/traversal_parent1578=== PAUSE TestIsValidCachePath/traversal_parent1579=== RUN TestIsValidCachePath/traversal_in_middle1580=== PAUSE TestIsValidCachePath/traversal_in_middle1581=== RUN TestIsValidCachePath/invalid_char_e1582=== PAUSE TestIsValidCachePath/invalid_char_e1583=== RUN TestIsValidCachePath/invalid_char_u1584=== PAUSE TestIsValidCachePath/invalid_char_u1585=== RUN TestIsValidCachePath/random_path1586=== PAUSE TestIsValidCachePath/random_path1587=== RUN TestIsValidCachePath/empty1588=== PAUSE TestIsValidCachePath/empty1589=== RUN TestIsValidCachePath/leading_slash1590=== PAUSE TestIsValidCachePath/leading_slash1591=== RUN TestIsValidCachePath/wrong_extension1592=== PAUSE TestIsValidCachePath/wrong_extension1593=== RUN TestIsValidCachePath/short_hash1594=== PAUSE TestIsValidCachePath/short_hash1595=== CONT TestCacheStatsHandler1596--- PASS: TestReadRedirectUsesPublicS3URL (2.31s)1597=== CONT TestSweepRechecksPendingAfterLocking1598--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.39s)1599=== CONT TestGCEndsOnShutdown1600=== RUN TestGCEndsOnShutdown/before_the_run1601=== PAUSE TestGCEndsOnShutdown/before_the_run1602=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1603=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1604=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1605=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1606=== CONT TestCommitRacingPendingCleanupKeepsObjects1607--- PASS: TestReadProxyRangeRequest (2.34s)1608=== CONT TestGCTaskStore_StartNew1609--- PASS: TestGCTaskStore_StartNew (0.00s)1610=== CONT TestPushWaitsForSweepHoldingRow1611--- PASS: TestReadProxyConditionalGet (2.30s)1612=== CONT TestService_AuthMiddleware_MTLSProxyHeader16132026/10/06 21:24:35 INFO Starting HTTP server address=127.0.0.1:5324316142026/10/06 21:24:35 INFO Starting HTTP server address=/nix/var/nix/builds/nix-49089-2277871705/TestProxyHeadersOnlyTrustedOnSocket908858594/001/proxy.sock16152026/10/06 21:24:35 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16162026/10/06 21:24:35 INFO Shutdown signal received, draining in-flight requests timeout=10s1617--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.24s)1618=== CONT TestParseSingleRange1619=== RUN TestParseSingleRange/none1620=== PAUSE TestParseSingleRange/none1621=== RUN TestParseSingleRange/unknown_unit1622=== PAUSE TestParseSingleRange/unknown_unit1623=== RUN TestParseSingleRange/multi-range_ignored1624=== PAUSE TestParseSingleRange/multi-range_ignored1625=== RUN TestParseSingleRange/malformed_no_dash1626=== PAUSE TestParseSingleRange/malformed_no_dash1627=== RUN TestParseSingleRange/malformed_both_empty1628=== PAUSE TestParseSingleRange/malformed_both_empty1629=== RUN TestParseSingleRange/malformed_end_before_start1630=== PAUSE TestParseSingleRange/malformed_end_before_start1631=== RUN TestParseSingleRange/closed1632=== PAUSE TestParseSingleRange/closed1633=== RUN TestParseSingleRange/open-ended1634=== PAUSE TestParseSingleRange/open-ended1635=== RUN TestParseSingleRange/end_clamped_to_size1636=== PAUSE TestParseSingleRange/end_clamped_to_size1637=== RUN TestParseSingleRange/suffix1638=== PAUSE TestParseSingleRange/suffix1639=== RUN TestParseSingleRange/suffix_exceeds_size1640=== PAUSE TestParseSingleRange/suffix_exceeds_size1641=== RUN TestParseSingleRange/single_byte1642=== PAUSE TestParseSingleRange/single_byte1643=== RUN TestParseSingleRange/start_past_EOF1644=== PAUSE TestParseSingleRange/start_past_EOF1645=== RUN TestParseSingleRange/start_far_past_EOF1646=== PAUSE TestParseSingleRange/start_far_past_EOF1647=== CONT TestRegisterCompletedObjectNeedsPendingRow16482026/10/06 21:24:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16492026/10/06 21:24:35 WARN mTLS auth: bound subjects configured but subject DN unavailable16502026/10/06 21:24:35 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1651--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.34s)1652=== CONT TestSweepSkipsRowsLockedByPush1653--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.73s)1654=== CONT TestGetExistingObjectsLocksRows16552026/10/06 21:24:35 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1656--- PASS: TestReadProxyNarinfo (2.35s)1657=== CONT TestGCSweepSkipsPendingObjects1658--- PASS: TestService_ReadAuthMiddleware (2.44s)1659=== CONT TestDeduplicatedObjectsRecordedAsPending1660--- PASS: TestCacheStatsHandler (2.58s)1661=== CONT TestPushDedupSurvivesConcurrentGC16622026/10/06 21:24:36 INFO Aborted multipart uploads count=0 kept=016632026/10/06 21:24:36 WARN Force mode enabled - objects will be deleted immediately without grace period16642026/10/06 21:24:36 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=016652026/10/06 21:24:36 INFO Vacuumed table table=pending_closures16662026/10/06 21:24:36 INFO Vacuumed table table=pending_objects16672026/10/06 21:24:36 INFO Vacuumed table table=multipart_uploads16682026/10/06 21:24:36 INFO Vacuumed table table=closures16692026/10/06 21:24:36 INFO Vacuumed table table=objects1670--- PASS: TestSweepRechecksPendingAfterLocking (2.75s)1671=== CONT TestCacheConfigHandler1672=== RUN TestCacheConfigHandler/full_config,_no_issuer1673=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1674=== RUN TestCacheConfigHandler/no_cache_url_configured1675=== PAUSE TestCacheConfigHandler/no_cache_url_configured1676=== RUN TestCacheConfigHandler/no_signing_keys1677=== PAUSE TestCacheConfigHandler/no_signing_keys1678=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1679=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1680=== CONT TestGCMetrics16812026/10/06 21:24:36 INFO Aborted multipart uploads count=0 kept=016822026/10/06 21:24:36 WARN Force mode enabled - objects will be deleted immediately without grace period16832026/10/06 21:24:36 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=016842026/10/06 21:24:36 INFO Vacuumed table table=pending_closures16852026/10/06 21:24:37 INFO Vacuumed table table=pending_objects16862026/10/06 21:24:37 INFO Vacuumed table table=multipart_uploads16872026/10/06 21:24:37 INFO Vacuumed table table=closures16882026/10/06 21:24:37 INFO Vacuumed table table=objects1689--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.07s)1690=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16912026/10/06 21:24:37 INFO Received uploads request method=POST path=/api/pending_closures1692{"timestamp":"2026-10-06T21:24:37.249335Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":3,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}1693--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.82s)1694=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1695--- PASS: TestPushWaitsForSweepHoldingRow (3.32s)1696=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1697--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.82s)1698=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16992026/10/06 21:24:38 INFO Aborted multipart uploads count=0 kept=017002026/10/06 21:24:38 WARN Force mode enabled - objects will be deleted immediately without grace period17012026/10/06 21:24: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=017022026/10/06 21:24:38 INFO Vacuumed table table=pending_closures17032026/10/06 21:24:38 INFO Vacuumed table table=pending_objects17042026/10/06 21:24:38 INFO Vacuumed table table=multipart_uploads17052026/10/06 21:24:38 INFO Vacuumed table table=closures17062026/10/06 21:24:38 INFO Vacuumed table table=objects17072026/10/06 21:24:38 INFO Aborted multipart uploads count=0 kept=017082026/10/06 21:24:38 WARN Force mode enabled - objects will be deleted immediately without grace period17092026/10/06 21:24:38 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=017102026/10/06 21:24:38 INFO Vacuumed table table=pending_closures17112026/10/06 21:24:38 INFO Vacuumed table table=pending_objects17122026/10/06 21:24:38 INFO Vacuumed table table=multipart_uploads17132026/10/06 21:24:38 INFO Vacuumed table table=closures17142026/10/06 21:24:38 INFO Vacuumed table table=objects1715--- PASS: TestSweepSkipsRowsLockedByPush (3.04s)1716=== CONT TestServerTLSConfig/no_client_CA1717=== CONT TestServerTLSConfig/missing_CA_file1718=== CONT TestServerTLSConfig/not_a_PEM_file1719=== CONT TestResolveDBConnectionString/flag_wins1720--- PASS: TestServerTLSConfig (0.00s)1721 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1722 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1723 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1724=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1725=== CONT TestResolveDBConnectionString/nothing_configured1726=== CONT TestResolveDBConnectionString/missing_file_is_an_error1727=== CONT TestResolveDBConnectionString/file_when_flag_empty1728=== CONT TestClientErrorHandling/InvalidStorePath1729--- PASS: TestResolveDBConnectionString (0.02s)1730 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1731 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1732 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1733 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1734 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1735--- PASS: TestGetExistingObjectsLocksRows (3.04s)1736=== CONT TestClientErrorHandling/ServerNotAvailable17372026/10/06 21:24:38 INFO Received uploads request method=POST path=/api/pending_closures17382026/10/06 21:24:38 INFO Aborted multipart uploads count=0 kept=017392026/10/06 21:24:38 WARN Force mode enabled - objects will be deleted immediately without grace period17402026/10/06 21:24: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=017412026/10/06 21:24:38 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/present17422026/10/06 21:24:38 INFO Vacuumed table table=pending_closures17432026/10/06 21:24:38 INFO Vacuumed table table=pending_objects17442026/10/06 21:24:38 INFO Vacuumed table table=multipart_uploads17452026/10/06 21:24:38 INFO Vacuumed table table=closures17462026/10/06 21:24:38 INFO Vacuumed table table=objects1747--- PASS: TestGCSweepSkipsPendingObjects (3.28s)1748=== CONT TestClientErrorHandling/InvalidAuthToken17492026/10/06 21:24:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.786379ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17502026/10/06 21:24:38 INFO Received uploads request method=POST path=/api/pending_closures1751--- PASS: TestDeduplicatedObjectsRecordedAsPending (3.17s)1752=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17532026/10/06 21:24:38 INFO Received request for more parts method=POST path=/1754=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17552026/10/06 21:24:38 INFO Received complete multipart upload request method=POST path=/1756=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17572026/10/06 21:24:39 INFO Received uploads request method=POST path=/17582026/10/06 21:24:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.233202ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1759--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1760 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)1761 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1762 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)1763=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17642026/10/06 21:24:39 INFO Received uploads request method=POST path=/17652026/10/06 21:24:39 INFO Received uploads request method=POST path=/api/pending_closures1766=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17672026/10/06 21:24:39 INFO Received complete multipart upload request method=POST path=/1768=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17692026/10/06 21:24:39 INFO Received request for more parts method=POST path=/1770=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17712026/10/06 21:24:39 INFO Received uploads request method=POST path=/1772--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1773 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1774 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1775 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1776 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1777=== CONT TestIsValidUploadKey/narinfo1778=== CONT TestIsValidUploadKey/realisation_plus_in_output1779=== CONT TestIsValidUploadKey/unknown_type1780=== CONT TestIsValidUploadKey/empty_key1781=== CONT TestIsValidUploadKey/absolute1782=== CONT TestIsValidUploadKey/traversal_nar1783=== CONT TestIsValidUploadKey/traversal1784=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1785=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1786=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1787=== CONT TestIsValidUploadKey/index.html1788=== CONT TestIsValidUploadKey/nix-cache-info1789=== CONT TestIsValidUploadKey/build_log_home-manager_file1790=== CONT TestIsValidUploadKey/realisation1791=== CONT TestIsValidUploadKey/build_log_equals1792=== CONT TestIsValidUploadKey/build_log_question_mark1793=== CONT TestIsValidUploadKey/build_log_plus_in_name1794=== CONT TestIsValidUploadKey/nar_plain1795=== CONT TestIsValidUploadKey/build_log1796=== CONT TestIsValidUploadKey/listing1797=== CONT TestIsValidUploadKey/nar_xz1798=== CONT TestIsValidUploadKey/nar_zst1799--- PASS: TestIsValidUploadKey (0.00s)1800 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1801 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1802 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1803 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1804 --- PASS: TestIsValidUploadKey/absolute (0.00s)1805 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1806 --- PASS: TestIsValidUploadKey/traversal (0.00s)1807 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1808 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1809 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1810 --- PASS: TestIsValidUploadKey/index.html (0.00s)1811 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1813 --- PASS: TestIsValidUploadKey/realisation (0.00s)1814 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1815 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1816 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1817 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1818 --- PASS: TestIsValidUploadKey/build_log (0.00s)1819 --- PASS: TestIsValidUploadKey/listing (0.00s)1820 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1821 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1822=== CONT TestPendingClosureWriteTimeout/empty1823=== CONT TestPendingClosureWriteTimeout/670k_objects1824=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18252026/10/06 21:24:39 INFO Aborted multipart uploads count=0 kept=018262026/10/06 21:24:39 WARN Force mode enabled - objects will be deleted immediately without grace period18272026/10/06 21:24:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018282026/10/06 21:24:39 INFO Vacuumed table table=pending_closures18292026/10/06 21:24:39 INFO Vacuumed table table=pending_objects18302026/10/06 21:24:39 INFO Vacuumed table table=multipart_uploads18312026/10/06 21:24:39 INFO Vacuumed table table=closures18322026/10/06 21:24:39 INFO Aborted multipart uploads count=0 kept=018332026/10/06 21:24:39 INFO Vacuumed table table=objects1834--- PASS: TestGCMetrics (2.83s)1835=== CONT TestPendingClosureWriteTimeout/400_objects1836=== CONT TestProxyWriteTimeout/narinfo1837=== CONT TestProxyWriteTimeout/10_GiB_nar1838=== CONT TestProxyWriteTimeout/unknown_size1839=== CONT TestProxyWriteTimeout/1_GiB_nar1840--- PASS: TestProxyWriteTimeout (0.00s)1841 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1842 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1843 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1844 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1845=== CONT TestPush_RejectsBadRequests/no_roots18462026/10/06 21:24:39 INFO Received push request method=POST path=/api/pushes1847=== CONT TestPush_RejectsBadRequests/bad_root18482026/10/06 21:24:39 INFO Received push request method=POST path=/api/pushes1849=== CONT TestPush_RejectsBadRequests/root_not_in_objects18502026/10/06 21:24:39 INFO Received push request method=POST path=/api/pushes1851=== CONT TestPush_RejectsBadRequests/no_objects18522026/10/06 21:24:39 INFO Received push request method=POST path=/api/pushes1853=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1854--- PASS: TestPush_RejectsBadRequests (2.49s)1855 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1856 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1857 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1858 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)18592026/10/06 21:24:39 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=01860=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18612026/10/06 21:24:39 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]1862=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1863=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18642026/10/06 21:24:39 WARN Authentication failed token_preview=eyJhbGciOi...4OqgY2WsKQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1865=== CONT TestService_RequireScope_OIDC/builder_may_write1866=== CONT TestService_RequireScope_OIDC/reader_may_read1867=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1868=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18692026/10/06 21:24:39 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]1870=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1871=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1872=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1873=== CONT TestService_RequireScope_OIDC/writer_implies_read1874=== CONT TestService_RequireScope_OIDC/reader_may_not_write1875=== CONT TestService_RequireScope_OIDC/static_token_may_write1876=== CONT TestService_RequireScope_OIDC/static_token_may_admin1877=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1878=== CONT TestService_RequireScope_OIDC/ops_may_not_write1879=== CONT TestService_RequireScope_OIDC/ops_may_admin1880=== CONT TestIsValidCachePath/narinfo1881=== CONT TestIsValidCachePath/index.html1882=== CONT TestIsValidCachePath/short_hash1883=== CONT TestIsValidCachePath/wrong_extension1884=== CONT TestIsValidCachePath/leading_slash1885=== CONT TestIsValidCachePath/empty1886=== CONT TestIsValidCachePath/random_path1887=== CONT TestIsValidCachePath/invalid_char_u1888=== CONT TestIsValidCachePath/invalid_char_e1889=== CONT TestIsValidCachePath/traversal_in_middle1890=== CONT TestIsValidCachePath/traversal_parent1891=== CONT TestIsValidCachePath/nar_uncompressed1892=== CONT TestIsValidCachePath/nix-cache-info1893=== CONT TestIsValidCachePath/realisation1894=== CONT TestIsValidCachePath/log1895=== CONT TestIsValidCachePath/ls1896=== CONT TestIsValidCachePath/nar_xz1897=== CONT TestIsValidCachePath/nar_bz21898=== CONT TestIsValidCachePath/nar_zst1899=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1900--- PASS: TestIsValidCachePath (0.00s)1901 --- PASS: TestIsValidCachePath/narinfo (0.00s)1902 --- PASS: TestIsValidCachePath/index.html (0.00s)1903 --- PASS: TestIsValidCachePath/short_hash (0.00s)1904 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1905 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1906 --- PASS: TestIsValidCachePath/empty (0.00s)1907 --- PASS: TestIsValidCachePath/random_path (0.00s)1908 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1909 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1910 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1911 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1912 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1913 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1914 --- PASS: TestIsValidCachePath/realisation (0.00s)1915 --- PASS: TestIsValidCachePath/log (0.00s)1916 --- PASS: TestIsValidCachePath/ls (0.00s)1917 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1918 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1919 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1920 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1921=== CONT TestGCEndsOnShutdown/before_the_run1922--- PASS: TestService_AuthMiddleware_OIDC (2.68s)1923 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1924 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1925 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1926 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1927--- PASS: TestService_RequireScope_OIDC (2.53s)1928 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)19422026/10/06 21:24:39 INFO Vacuumed table table=pending_closures19432026/10/06 21:24:39 INFO Vacuumed table table=pending_objects19442026/10/06 21:24:39 INFO Vacuumed table table=multipart_uploads19452026/10/06 21:24:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=789.723945ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19462026/10/06 21:24:39 INFO Vacuumed table table=closures19472026/10/06 21:24:39 INFO Vacuumed table table=objects19482026/10/06 21:24:39 INFO Aborted multipart uploads count=0 kept=019492026/10/06 21:24:39 WARN Force mode enabled - objects will be deleted immediately without grace period19502026/10/06 21:24:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019512026/10/06 21:24:39 INFO Vacuumed table table=pending_closures19522026/10/06 21:24:39 INFO Vacuumed table table=pending_objects19532026/10/06 21:24:39 INFO Vacuumed table table=multipart_uploads19542026/10/06 21:24:39 INFO Vacuumed table table=closures19552026/10/06 21:24:39 INFO Vacuumed table table=objects1956--- PASS: TestPushDedupSurvivesConcurrentGC (3.41s)1957=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1958=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19592026/10/06 21:24:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.718099877s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19602026/10/06 21:24:40 INFO Received uploads request method=POST path=/api/pending_closures19612026/10/06 21:24:40 INFO Aborted multipart uploads count=0 kept=019622026/10/06 21:24:40 WARN Force mode enabled - objects will be deleted immediately without grace period19632026/10/06 21:24:40 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=019642026/10/06 21:24:40 INFO Vacuumed table table=pending_closures19652026/10/06 21:24:40 INFO Vacuumed table table=pending_objects19662026/10/06 21:24:40 INFO Vacuumed table table=multipart_uploads19672026/10/06 21:24:40 INFO Vacuumed table table=closures19682026/10/06 21:24:40 INFO Vacuumed table table=objects1969--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1970 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (3.05s)1971 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (3.07s)1972=== CONT TestParseSingleRange/none1973=== CONT TestParseSingleRange/open-ended1974=== CONT TestParseSingleRange/start_far_past_EOF1975=== CONT TestParseSingleRange/start_past_EOF1976=== CONT TestParseSingleRange/single_byte1977=== CONT TestParseSingleRange/suffix_exceeds_size1978=== CONT TestParseSingleRange/suffix1979=== CONT TestParseSingleRange/end_clamped_to_size1980=== CONT TestParseSingleRange/malformed_both_empty1981=== CONT TestParseSingleRange/closed1982=== CONT TestParseSingleRange/malformed_end_before_start1983=== CONT TestParseSingleRange/multi-range_ignored1984=== CONT TestParseSingleRange/malformed_no_dash1985=== CONT TestParseSingleRange/unknown_unit1986--- PASS: TestParseSingleRange (0.00s)1987 --- PASS: TestParseSingleRange/none (0.00s)1988 --- PASS: TestParseSingleRange/open-ended (0.00s)1989 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1990 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1991 --- PASS: TestParseSingleRange/single_byte (0.00s)1992 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1993 --- PASS: TestParseSingleRange/suffix (0.00s)1994 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1995 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1996 --- PASS: TestParseSingleRange/closed (0.00s)1997 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1998 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1999 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2000 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2001=== CONT TestCacheConfigHandler/full_config,_no_issuer2002=== CONT TestCacheConfigHandler/no_signing_keys2003=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2004=== CONT TestCacheConfigHandler/no_cache_url_configured2005--- PASS: TestCacheConfigHandler (0.00s)2006 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2007 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2008 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2009 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)20102026/10/06 21:24:40 INFO Received uploads request method=POST path=/api/pending_closures20112026/10/06 21:24:40 INFO Aborted multipart uploads count=0 kept=020122026/10/06 21:24:40 WARN Force mode enabled - objects will be deleted immediately without grace period20132026/10/06 21:24:40 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=020142026/10/06 21:24:40 INFO Vacuumed table table=pending_closures20152026/10/06 21:24:40 INFO Vacuumed table table=pending_objects20162026/10/06 21:24:40 INFO Vacuumed table table=multipart_uploads20172026/10/06 21:24:40 INFO Vacuumed table table=closures20182026/10/06 21:24:40 INFO Vacuumed table table=objects2019--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2020 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.88s)2021 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (3.12s)20222026/10/06 21:24:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20232026/10/06 21:24:41 INFO Received uploads request method=POST path=/api/pending_closures20242026/10/06 21:24:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20252026/10/06 21:24:41 INFO Aborted multipart uploads count=0 kept=020262026/10/06 21:24:41 WARN Force mode enabled - objects will be deleted immediately without grace period20272026-10-06 21:24:41.791 UTC [49703] ERROR: canceling statement due to user request20282026-10-06 21:24:41.791 UTC [49703] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block20292026-10-06 21:24:41.791 UTC [49703] STATEMENT: -- name: MarkStaleObjects :execrows2030 WITH RECURSIVE ct AS (2031 SELECT timezone('UTC', now()) AS now2032 ),2033 closure_reach AS (2034 -- Start with all closure keys2035 SELECT o.key, o.refs2036 FROM objects o2037 INNER JOIN closures c ON o.key = c.key2038 UNION2039 -- Recursively add all referenced objects2040 SELECT o.key, o.refs2041 FROM objects o2042 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2043 ),2044 reachable_objects AS (2045 SELECT DISTINCT key FROM closure_reach2046 ),2047 stale_objects AS (2048 SELECT o.key2049 FROM objects AS o, ct2050 WHERE2051 NOT EXISTS (2052 SELECT 12053 FROM reachable_objects ro2054 WHERE ro.key = o.key2055 )2056 AND NOT EXISTS (2057 SELECT 12058 FROM pending_objects AS po2059 WHERE po.key = o.key2060 )2061 AND o.deleted_at IS NULL -- Only mark fresh objects2062 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2063 FOR UPDATE2064 )2065 UPDATE objects2066 SET2067 deleted_at = ct.now,2068 first_deleted_at = COALESCE(first_deleted_at, ct.now)2069 FROM stale_objects, ct2070 WHERE objects.key = stale_objects.key2071 20722026/10/06 21:24:42 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-config20732026/10/06 21:24:42 INFO Aborted multipart uploads count=0 kept=020742026/10/06 21:24:42 WARN Force mode enabled - objects will be deleted immediately without grace period20752026/10/06 21:24:42 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52868/bucket98/?delete=\": context canceled"2076--- PASS: TestGCEndsOnShutdown (0.00s)2077 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (2.22s)2078 --- PASS: TestGCEndsOnShutdown/before_the_run (2.54s)2079 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.92s)20802026/10/06 21:24:42 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.048193ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20812026/10/06 21:24:42 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.187302ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2082--- PASS: TestPendingClosureWriteTimeout (0.00s)2083 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2084 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2085 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2086 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.09s)20872026/10/06 21:24:42 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=801.356509ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20882026/10/06 21:24:43 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.489971453s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2089{"timestamp":"2026-10-06T21:24:44.545544Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":3,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}20902026/10/06 21:24:45 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"20912026/10/06 21:24:45 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-config20922026/10/06 21:24:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.102424ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20932026/10/06 21:24:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=366.629281ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20942026/10/06 21:24:45 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=732.716263ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20952026/10/06 21:24:46 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.650450689s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20962026/10/06 21:24:48 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_closures20972026/10/06 21:24:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=207.156339ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20982026/10/06 21:24:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=426.839819ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20992026/10/06 21:24:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=839.183756ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21002026/10/06 21:24:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.526338673s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2101{"timestamp":"2026-10-06T21:24:50.598701Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":3,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}2102--- PASS: TestClientErrorHandling (0.00s)2103 --- PASS: TestClientErrorHandling/InvalidStorePath (2.78s)2104 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.80s)2105 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)2106PASS2107{"timestamp":"2026-10-06T21:24:51.202046Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53098","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}21082026-10-06 21:24:51.355 UTC [49126] LOG: received smart shutdown request21092026-10-06 21:24:51.356 UTC [49126] LOG: background worker "logical replication launcher" (PID 49136) exited with exit code 121102026-10-06 21:24:51.359 UTC [49131] LOG: shutting down21112026-10-06 21:24:51.360 UTC [49131] LOG: checkpoint starting: shutdown immediate21122026-10-06 21:24:52.833 UTC [49131] LOG: checkpoint complete: wrote 12704 buffers (77.5%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.861 s, sync=0.563 s, total=1.474 s; sync files=33372, longest=0.001 s, average=0.001 s; distance=491971 kB, estimate=491971 kB; lsn=0/1F7FDE60, redo lsn=0/1F7FDE6021132026-10-06 21:24:52.839 UTC [49126] LOG: database system is shut down2114Running OIDC tests...2115=== RUN TestAudienceForIssuer2116=== PAUSE TestAudienceForIssuer2117=== RUN TestGlobMatch2118=== PAUSE TestGlobMatch2119=== RUN TestValidateToken_ValidToken2120=== PAUSE TestValidateToken_ValidToken2121=== RUN TestValidateToken_WrongAudience2122=== PAUSE TestValidateToken_WrongAudience2123=== RUN TestValidateToken_Expired2124=== PAUSE TestValidateToken_Expired2125=== RUN TestValidateToken_BoundClaimsMismatch2126=== PAUSE TestValidateToken_BoundClaimsMismatch2127=== RUN TestValidateToken_BoundSubjectMismatch2128=== PAUSE TestValidateToken_BoundSubjectMismatch2129=== RUN TestValidateToken_MultipleProviders2130=== PAUSE TestValidateToken_MultipleProviders2131=== RUN TestValidateToken_NoMatchingProvider2132=== PAUSE TestValidateToken_NoMatchingProvider2133=== RUN TestValidateToken_KubernetesServiceAccount2134=== PAUSE TestValidateToken_KubernetesServiceAccount2135=== RUN TestNewValidator_KubernetesRequiresCA2136=== PAUSE TestNewValidator_KubernetesRequiresCA2137=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2138=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2139=== RUN TestPins_ReservedForMatchingRule2140=== PAUSE TestPins_ReservedForMatchingRule2141=== RUN TestPins_TopLevelShorthand2142=== PAUSE TestPins_TopLevelShorthand2143=== RUN TestPins_ConfigValidation2144=== PAUSE TestPins_ConfigValidation2145=== RUN TestScopes_LegacyProviderDefaultsToWrite2146=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2147=== RUN TestScopes_Rules2148=== PAUSE TestScopes_Rules2149=== RUN TestScopes_ConfigValidation2150=== PAUSE TestScopes_ConfigValidation2151=== CONT TestAudienceForIssuer2152--- PASS: TestAudienceForIssuer (0.00s)2153=== CONT TestValidateToken_KubernetesServiceAccount2154=== CONT TestValidateToken_NoMatchingProvider2155=== CONT TestValidateToken_MultipleProviders2156=== CONT TestValidateToken_BoundSubjectMismatch2157=== CONT TestValidateToken_BoundClaimsMismatch2158=== CONT TestValidateToken_Expired2159=== CONT TestValidateToken_WrongAudience2160=== CONT TestValidateToken_ValidToken2161=== CONT TestGlobMatch2162=== RUN TestGlobMatch/foo_foo2163=== PAUSE TestGlobMatch/foo_foo2164=== RUN TestGlobMatch/foo_bar2165=== PAUSE TestGlobMatch/foo_bar2166=== RUN TestGlobMatch/*_2167=== PAUSE TestGlobMatch/*_2168=== RUN TestGlobMatch/*_anything2169=== PAUSE TestGlobMatch/*_anything2170=== CONT TestPins_ConfigValidation2171=== RUN TestGlobMatch/foo*_foo2172=== PAUSE TestGlobMatch/foo*_foo2173=== RUN TestGlobMatch/foo*_foobar2174=== PAUSE TestGlobMatch/foo*_foobar2175=== RUN TestGlobMatch/foo*_bar2176=== PAUSE TestGlobMatch/foo*_bar2177=== RUN TestGlobMatch/*bar_bar2178=== PAUSE TestGlobMatch/*bar_bar2179=== RUN TestGlobMatch/*bar_foobar2180=== PAUSE TestGlobMatch/*bar_foobar2181=== RUN TestGlobMatch/*bar_foo2182=== PAUSE TestGlobMatch/*bar_foo2183=== RUN TestGlobMatch/foo*bar_foobar2184=== PAUSE TestGlobMatch/foo*bar_foobar2185=== RUN TestGlobMatch/foo*bar_foo123bar2186=== PAUSE TestGlobMatch/foo*bar_foo123bar2187=== RUN TestGlobMatch/foo*bar_foobarbaz2188=== PAUSE TestGlobMatch/foo*bar_foobarbaz2189=== RUN TestGlobMatch/*/*_foo/bar2190=== PAUSE TestGlobMatch/*/*_foo/bar2191=== RUN TestGlobMatch/*/*_foo2192=== PAUSE TestGlobMatch/*/*_foo2193=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2194=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2195=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02196=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02197=== RUN TestGlobMatch/refs/*/main_refs/heads/main2198=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2199=== RUN TestGlobMatch/fo?_foo2200=== PAUSE TestGlobMatch/fo?_foo2201=== RUN TestGlobMatch/fo?_fo2202=== PAUSE TestGlobMatch/fo?_fo2203=== RUN TestGlobMatch/fo?_fooo2204=== PAUSE TestGlobMatch/fo?_fooo2205=== RUN TestGlobMatch/?oo_foo2206=== PAUSE TestGlobMatch/?oo_foo2207=== RUN TestGlobMatch/?oo_boo2208=== PAUSE TestGlobMatch/?oo_boo2209=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2210=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2211=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2212=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2213=== CONT TestPins_ReservedForMatchingRule2214--- PASS: TestPins_ConfigValidation (0.00s)2215=== CONT TestPins_TopLevelShorthand22162026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53356/oidc22172026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53355/oidc2218--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2219=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2220--- PASS: TestValidateToken_Expired (0.06s)2221=== CONT TestNewValidator_KubernetesRequiresCA22222026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53360/oidc22232026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53362/oidc2224--- PASS: TestValidateToken_WrongAudience (0.06s)2225=== CONT TestScopes_Rules2226--- PASS: TestValidateToken_ValidToken (0.06s)2227=== CONT TestScopes_ConfigValidation2228--- PASS: TestScopes_ConfigValidation (0.00s)2229=== CONT TestScopes_LegacyProviderDefaultsToWrite22302026/10/06 21:24:54 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5336422312026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53366/oidc2232--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)2233=== CONT TestGlobMatch/foo_foo2234=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2235=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2236=== CONT TestGlobMatch/?oo_boo2237=== CONT TestGlobMatch/?oo_foo2238=== CONT TestGlobMatch/fo?_fooo2239=== CONT TestGlobMatch/fo?_fo2240=== CONT TestGlobMatch/fo?_foo2241=== CONT TestGlobMatch/refs/*/main_refs/heads/main2242=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02243=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2244=== CONT TestGlobMatch/*/*_foo2245=== CONT TestGlobMatch/*/*_foo/bar2246=== CONT TestGlobMatch/foo*bar_foobarbaz2247=== CONT TestGlobMatch/foo*bar_foo123bar2248=== CONT TestGlobMatch/foo*bar_foobar2249=== CONT TestGlobMatch/*bar_foo2250=== CONT TestGlobMatch/*bar_foobar2251=== CONT TestGlobMatch/*bar_bar2252=== CONT TestGlobMatch/foo*_bar2253=== CONT TestGlobMatch/foo*_foobar2254=== CONT TestGlobMatch/foo*_foo2255=== CONT TestGlobMatch/*_anything2256=== CONT TestGlobMatch/*_2257=== CONT TestGlobMatch/foo_bar2258--- PASS: TestGlobMatch (0.00s)2259 --- PASS: TestGlobMatch/foo_foo (0.00s)2260 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2261 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2262 --- PASS: TestGlobMatch/?oo_boo (0.00s)2263 --- PASS: TestGlobMatch/?oo_foo (0.00s)2264 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2265 --- PASS: TestGlobMatch/fo?_fo (0.00s)2266 --- PASS: TestGlobMatch/fo?_foo (0.00s)2267 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2268 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2269 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2270 --- PASS: TestGlobMatch/*/*_foo (0.00s)2271 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2272 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2273 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2274 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2275 --- PASS: TestGlobMatch/*bar_foo (0.00s)2276 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2277 --- PASS: TestGlobMatch/*bar_bar (0.00s)2278 --- PASS: TestGlobMatch/foo*_bar (0.00s)2279 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2280 --- PASS: TestGlobMatch/foo*_foo (0.00s)2281 --- PASS: TestGlobMatch/*_anything (0.00s)2282 --- PASS: TestGlobMatch/*_ (0.00s)2283 --- PASS: TestGlobMatch/foo_bar (0.00s)2284--- PASS: TestPins_ReservedForMatchingRule (0.07s)22852026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53369/oidc22862026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53372/oidc2287--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)2288--- PASS: TestScopes_Rules (0.02s)22892026/10/06 21:24:54 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12322902026/10/06 21:24:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53359/oidc22912026/10/06 21:24:54 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:53376/oidc2292--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2293--- PASS: TestValidateToken_MultipleProviders (0.11s)22942026/10/06 21:24:54 http: TLS handshake error from 127.0.0.1:53383: remote error: tls: bad certificate2295--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)22962026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53384/oidc2297--- PASS: TestPins_TopLevelShorthand (0.12s)22982026/10/06 21:24:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53386/oidc2299--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)23002026/10/06 21:24:54 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53370/oidc2301--- PASS: TestValidateToken_NoMatchingProvider (0.16s)2302PASS2303Running hook tests...2304=== RUN TestSendPathsEmpty2305=== PAUSE TestSendPathsEmpty2306=== RUN TestQueueEnqueueAndFetch2307=== PAUSE TestQueueEnqueueAndFetch2308=== RUN TestQueueDeduplication2309=== PAUSE TestQueueDeduplication2310=== RUN TestQueueRemove2311=== PAUSE TestQueueRemove2312=== RUN TestQueueFetchBatchLimit2313=== PAUSE TestQueueFetchBatchLimit2314=== RUN TestQueueRetryMovesToBack2315=== PAUSE TestQueueRetryMovesToBack2316=== RUN TestQueueFetchRemoveLifecycle2317=== PAUSE TestQueueFetchRemoveLifecycle2318=== RUN TestQueueConcurrentWriters2319=== PAUSE TestQueueConcurrentWriters2320=== RUN TestQueueRemoveLargeClosure2321=== PAUSE TestQueueRemoveLargeClosure2322=== RUN TestServerClientIntegration2323=== PAUSE TestServerClientIntegration2324=== RUN TestServerQueueError2325=== PAUSE TestServerQueueError2326=== RUN TestGetListenerSocketActivation2327 server_test.go:210: === RUN TestGetListenerSocketActivation2328 --- PASS: TestGetListenerSocketActivation (0.00s)2329 PASS2330 2331--- PASS: TestGetListenerSocketActivation (0.01s)2332=== RUN TestDrainIsolatesPoisonPath2333=== PAUSE TestDrainIsolatesPoisonPath2334=== RUN TestRunNotBlockedByPoisonHead2335=== PAUSE TestRunNotBlockedByPoisonHead2336=== RUN TestDrainGivesUpWhenServerDown2337=== PAUSE TestDrainGivesUpWhenServerDown2338=== RUN TestFailedPathPrunedByLaterClosure2339=== PAUSE TestFailedPathPrunedByLaterClosure2340=== RUN TestWorkerUploadsAndRemoves2341=== PAUSE TestWorkerUploadsAndRemoves2342=== RUN TestWorkerSkipsGCdPaths2343=== PAUSE TestWorkerSkipsGCdPaths2344=== RUN TestWorkerPrunesClosureDeps2345=== PAUSE TestWorkerPrunesClosureDeps2346=== RUN TestDrainTimeout2347=== PAUSE TestDrainTimeout2348=== CONT TestSendPathsEmpty2349=== CONT TestServerQueueError2350--- PASS: TestSendPathsEmpty (0.00s)2351=== CONT TestQueueFetchBatchLimit2352=== CONT TestQueueRemove2353=== CONT TestQueueDeduplication2354=== CONT TestQueueEnqueueAndFetch2355=== CONT TestWorkerUploadsAndRemoves2356=== CONT TestDrainTimeout2357=== CONT TestWorkerPrunesClosureDeps2358=== CONT TestWorkerSkipsGCdPaths2359=== CONT TestQueueRetryMovesToBack23602026/10/06 21:24:54 ERROR Failed to queue paths error="permission denied" count=12361--- PASS: TestServerQueueError (0.00s)2362=== CONT TestDrainGivesUpWhenServerDown23632026/10/06 21:24:54 INFO Upload queue status pending=223642026/10/06 21:24:54 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-49089-2277871705/TestWorkerSkipsGCdPaths2794015146/002/nonexistent23652026/10/06 21:24:54 INFO Uploading batch count=123662026/10/06 21:24:54 INFO Uploading batch count=223672026/10/06 21:24:54 INFO Upload queue status pending=223682026/10/06 21:24:54 INFO Upload queue status pending=223692026/10/06 21:24:54 INFO Uploading batch count=223702026/10/06 21:24:54 INFO Uploading batch count=12371--- PASS: TestQueueRemove (0.01s)2372=== CONT TestFailedPathPrunedByLaterClosure23732026/10/06 21:24:54 INFO Uploading batch count=223742026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=223752026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/a2376--- PASS: TestQueueEnqueueAndFetch (0.01s)2377=== CONT TestServerClientIntegration23782026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/b23792026/10/06 21:24:54 INFO Uploading batch count=223802026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=223812026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/c2382--- PASS: TestQueueRetryMovesToBack (0.01s)2383=== CONT TestRunNotBlockedByPoisonHead2384--- PASS: TestQueueFetchBatchLimit (0.01s)2385=== CONT TestQueueRemoveLargeClosure23862026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/d2387--- PASS: TestQueueDeduplication (0.01s)2388=== CONT TestQueueConcurrentWriters23892026/10/06 21:24:54 INFO Uploading batch count=223902026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=223912026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/e2392--- PASS: TestServerClientIntegration (0.00s)2393=== CONT TestQueueFetchRemoveLifecycle23942026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainGivesUpWhenServerDown4076137139/002/f23952026/10/06 21:24:54 ERROR Drain finished with paths left in queue remaining=1023962026/10/06 21:24:54 INFO Uploading batch count=123972026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=123982026/10/06 21:24:54 INFO Uploading batch count=123992026/10/06 21:24:54 INFO Upload queue status pending=324002026/10/06 21:24:54 INFO Uploading batch count=124012026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=124022026/10/06 21:24:54 INFO Uploading batch count=12403--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2404=== CONT TestDrainIsolatesPoisonPath2405--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2406--- PASS: TestQueueFetchRemoveLifecycle (0.00s)24072026/10/06 21:24:54 INFO Uploading batch count=424082026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=424092026/10/06 21:24:54 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49089-2277871705/TestDrainIsolatesPoisonPath809370214/002/bbb24102026/10/06 21:24:54 INFO Uploading batch count=124112026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=124122026/10/06 21:24:54 INFO Uploading batch count=124132026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=124142026/10/06 21:24:54 INFO Uploading batch count=124152026/10/06 21:24:54 ERROR Upload failed error="upload failed" count=124162026/10/06 21:24:54 ERROR Drain finished with paths left in queue remaining=12417--- PASS: TestDrainIsolatesPoisonPath (0.00s)2418--- PASS: TestWorkerSkipsGCdPaths (0.03s)2419--- PASS: TestWorkerUploadsAndRemoves (0.03s)2420--- PASS: TestWorkerPrunesClosureDeps (0.03s)2421--- PASS: TestQueueRemoveLargeClosure (0.03s)2422--- PASS: TestQueueConcurrentWriters (0.12s)24232026/10/06 21:24:54 ERROR Upload failed error="context deadline exceeded" count=224242026/10/06 21:24:54 ERROR Drain finished with paths left in queue remaining=42425--- PASS: TestDrainTimeout (0.21s)24262026/10/06 21:24:55 INFO Uploading batch count=124272026/10/06 21:24:55 INFO Uploading batch count=124282026/10/06 21:24:55 INFO Uploading batch count=124292026/10/06 21:24:55 ERROR Upload failed error="upload failed" count=124302026/10/06 21:24:55 INFO Uploading batch count=124312026/10/06 21:24:55 ERROR Upload failed error="upload failed" count=124322026/10/06 21:24:55 INFO Uploading batch count=124332026/10/06 21:24:55 ERROR Upload failed error="upload failed" count=124342026/10/06 21:24:55 INFO Uploading batch count=124352026/10/06 21:24:55 ERROR Upload failed error="upload failed" count=124362026/10/06 21:24:55 ERROR Drain finished with paths left in queue remaining=12437--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2438PASS2439Running signing tests...2440=== RUN TestExternalSigner2441=== PAUSE TestExternalSigner2442=== RUN TestExternalSignerWrongPublicKey2443=== PAUSE TestExternalSignerWrongPublicKey2444=== RUN TestExternalSignerErrors2445=== PAUSE TestExternalSignerErrors2446=== RUN TestExternalSignerRestartsAfterCrash2447=== PAUSE TestExternalSignerRestartsAfterCrash2448=== RUN TestExternalSignerProgramErrorKeepsProcess2449=== PAUSE TestExternalSignerProgramErrorKeepsProcess2450=== RUN TestExternalSignerClose2451=== PAUSE TestExternalSignerClose2452=== RUN TestExternalSignerRejectsInvalidPublicKey2453=== PAUSE TestExternalSignerRejectsInvalidPublicKey2454=== RUN TestExternalSignerCancellation2455=== PAUSE TestExternalSignerCancellation2456=== RUN TestGenerateFingerprint2457=== PAUSE TestGenerateFingerprint2458=== RUN TestParseSigningKey2459=== PAUSE TestParseSigningKey2460=== RUN TestSign2461=== PAUSE TestSign2462=== RUN TestSignBatch2463=== PAUSE TestSignBatch2464=== RUN TestNilKeyPublicKey2465=== PAUSE TestNilKeyPublicKey2466=== RUN TestSignErrors2467=== PAUSE TestSignErrors2468=== CONT TestNilKeyPublicKey2469=== CONT TestSignErrors2470--- PASS: TestNilKeyPublicKey (0.00s)2471=== CONT TestExternalSignerProgramErrorKeepsProcess2472=== CONT TestExternalSignerClose2473=== CONT TestSignBatch2474=== CONT TestSign2475=== CONT TestParseSigningKey2476=== RUN TestParseSigningKey/valid_32-byte_key2477=== PAUSE TestParseSigningKey/valid_32-byte_key2478=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2479=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2480=== RUN TestParseSigningKey/no_colon2481=== PAUSE TestParseSigningKey/no_colon2482=== RUN TestParseSigningKey/empty_name2483=== PAUSE TestParseSigningKey/empty_name2484=== RUN TestParseSigningKey/invalid_base642485=== PAUSE TestParseSigningKey/invalid_base642486=== RUN TestParseSigningKey/wrong_length2487=== PAUSE TestParseSigningKey/wrong_length2488=== CONT TestGenerateFingerprint2489=== CONT TestExternalSignerCancellation2490=== CONT TestExternalSignerRejectsInvalidPublicKey2491=== RUN TestExternalSignerRejectsInvalidPublicKey/#002492=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002493=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2494=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2495=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2496=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2497=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2498=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2499=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2500=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2501=== CONT TestExternalSignerErrors2502=== CONT TestExternalSigner2503=== RUN TestExternalSignerErrors/wrong_signatures_shape2504=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2505=== RUN TestExternalSignerErrors/wrong_signature_length2506=== PAUSE TestExternalSignerErrors/wrong_signature_length2507=== RUN TestExternalSignerErrors/exit_on_request2508=== PAUSE TestExternalSignerErrors/exit_on_request2509=== RUN TestExternalSignerErrors/invalid_JSON2510=== PAUSE TestExternalSignerErrors/invalid_JSON2511=== RUN TestExternalSignerErrors/wrong_shape2512=== PAUSE TestExternalSignerErrors/wrong_shape2513=== RUN TestExternalSignerErrors/null2514=== PAUSE TestExternalSignerErrors/null2515=== RUN TestExternalSignerErrors/unrequested_key2516=== PAUSE TestExternalSignerErrors/unrequested_key2517=== RUN TestExternalSignerErrors/missing_signature_name2518=== PAUSE TestExternalSignerErrors/missing_signature_name2519=== RUN TestExternalSignerErrors/wrong_signature_name2520=== PAUSE TestExternalSignerErrors/wrong_signature_name2521=== RUN TestExternalSignerErrors/program_error2522=== PAUSE TestExternalSignerErrors/program_error2523=== RUN TestExternalSignerErrors/exit_at_startup2524=== PAUSE TestExternalSignerErrors/exit_at_startup2525=== RUN TestExternalSignerErrors/wrong_id2526=== PAUSE TestExternalSignerErrors/wrong_id2527=== RUN TestExternalSignerErrors/too_few_signatures2528=== PAUSE TestExternalSignerErrors/too_few_signatures2529=== RUN TestExternalSignerErrors/invalid_signature_base642530=== PAUSE TestExternalSignerErrors/invalid_signature_base642531=== RUN TestExternalSignerErrors/missing_signatures2532=== PAUSE TestExternalSignerErrors/missing_signatures2533=== RUN TestExternalSignerErrors/null_signatures2534=== PAUSE TestExternalSignerErrors/null_signatures2535=== CONT TestExternalSignerWrongPublicKey2536=== CONT TestExternalSignerRestartsAfterCrash2537=== RUN TestGenerateFingerprint/basic_with_references2538=== PAUSE TestGenerateFingerprint/basic_with_references2539=== RUN TestGenerateFingerprint/no_references2540=== PAUSE TestGenerateFingerprint/no_references2541=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2542=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2543=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2544=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2545=== RUN TestGenerateFingerprint/invalid_nar_hash_length2546=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2547=== RUN TestGenerateFingerprint/invalid_store_path_prefix2548=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2549=== RUN TestGenerateFingerprint/invalid_reference_prefix2550=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2551=== CONT TestParseSigningKey/valid_32-byte_key2552=== RUN TestSignErrors/nil_key2553=== PAUSE TestSignErrors/nil_key2554=== RUN TestSignErrors/nil_narinfo2555=== PAUSE TestSignErrors/nil_narinfo2556=== RUN TestSignErrors/invalid_narinfo2557=== PAUSE TestSignErrors/invalid_narinfo2558=== RUN TestSignErrors/canceled2559=== PAUSE TestSignErrors/canceled2560=== CONT TestParseSigningKey/wrong_length2561=== CONT TestParseSigningKey/invalid_base642562=== CONT TestParseSigningKey/empty_name2563=== CONT TestParseSigningKey/no_colon2564=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2565=== CONT TestExternalSignerRejectsInvalidPublicKey/#002566=== CONT TestExternalSignerErrors/wrong_signatures_shape2567--- PASS: TestParseSigningKey (0.00s)2568 --- PASS: TestParseSigningKey/wrong_length (0.00s)2569 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2570 --- PASS: TestParseSigningKey/empty_name (0.00s)2571 --- PASS: TestParseSigningKey/no_colon (0.00s)2572 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2573 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2574=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2575=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2576=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2577=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2578--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2579 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2580 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2581 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2582 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2583 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2584--- PASS: TestSign (0.00s)2585=== CONT TestExternalSignerErrors/null_signatures2586=== CONT TestExternalSignerErrors/too_few_signatures2587--- PASS: TestSignBatch (0.01s)2588=== CONT TestExternalSignerErrors/missing_signatures2589--- PASS: TestExternalSignerClose (0.09s)2590=== CONT TestExternalSignerErrors/invalid_signature_base642591--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.17s)2592=== CONT TestExternalSignerErrors/exit_at_startup2593--- PASS: TestExternalSignerCancellation (0.26s)2594=== CONT TestExternalSignerErrors/wrong_id2595--- PASS: TestExternalSigner (0.32s)2596=== CONT TestExternalSignerErrors/program_error2597--- PASS: TestExternalSignerWrongPublicKey (0.38s)2598=== CONT TestExternalSignerErrors/wrong_shape2599--- PASS: TestExternalSignerRestartsAfterCrash (0.47s)2600=== CONT TestExternalSignerErrors/missing_signature_name2601/nix/var/nix/builds/nix-49089-2277871705/TestExternalSignerRestartsAfterCrash1993941300/001/sign program: line 7: /nix/var/nix/builds/nix-49089-2277871705/TestExternalSignerRestartsAfterCrash1993941300/001/sign program.starts: No such file or directory2602=== CONT TestExternalSignerErrors/unrequested_key2603=== CONT TestExternalSignerErrors/null2604=== CONT TestExternalSignerErrors/exit_on_request2605=== CONT TestExternalSignerErrors/invalid_JSON2606=== CONT TestExternalSignerErrors/wrong_signature_length2607=== CONT TestExternalSignerErrors/wrong_signature_name2608=== CONT TestGenerateFingerprint/basic_with_references2609=== CONT TestGenerateFingerprint/invalid_reference_prefix2610=== CONT TestGenerateFingerprint/invalid_store_path_prefix2611=== CONT TestGenerateFingerprint/invalid_nar_hash_length2612=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2613=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2614=== CONT TestGenerateFingerprint/no_references2615--- PASS: TestGenerateFingerprint (0.00s)2616 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2617 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2618 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2619 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2620 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2621 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2622 --- PASS: TestGenerateFingerprint/no_references (0.00s)2623=== CONT TestSignErrors/nil_key2624=== CONT TestSignErrors/invalid_narinfo2625=== CONT TestSignErrors/canceled2626=== CONT TestSignErrors/nil_narinfo2627--- PASS: TestSignErrors (0.00s)2628 --- PASS: TestSignErrors/nil_key (0.00s)2629 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2630 --- PASS: TestSignErrors/canceled (0.00s)2631 --- PASS: TestSignErrors/nil_narinfo (0.00s)2632--- PASS: TestExternalSignerErrors (0.00s)2633 --- PASS: TestExternalSignerErrors/null_signatures (0.52s)2634 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.60s)2635 --- PASS: TestExternalSignerErrors/missing_signatures (0.67s)2636 --- PASS: TestExternalSignerErrors/too_few_signatures (0.74s)2637 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.72s)2638 --- PASS: TestExternalSignerErrors/exit_at_startup (0.72s)2639 --- PASS: TestExternalSignerErrors/wrong_id (0.70s)2640 --- PASS: TestExternalSignerErrors/program_error (0.71s)2641 --- PASS: TestExternalSignerErrors/wrong_shape (0.72s)2642 --- PASS: TestExternalSignerErrors/missing_signature_name (0.71s)2643 --- PASS: TestExternalSignerErrors/unrequested_key (0.72s)2644 --- PASS: TestExternalSignerErrors/null (0.72s)2645 --- PASS: TestExternalSignerErrors/exit_on_request (0.72s)2646 --- PASS: TestExternalSignerErrors/invalid_JSON (0.73s)2647 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.73s)2648 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.73s)2649PASS2650Running OpenBao signer tests...2651=== RUN TestSign2652=== PAUSE TestSign2653=== RUN TestSignErrors2654=== PAUSE TestSignErrors2655=== RUN TestServe2656=== PAUSE TestServe2657=== RUN TestServeRejectsGarbage2658=== PAUSE TestServeRejectsGarbage2659=== CONT TestSign2660=== CONT TestServeRejectsGarbage2661=== CONT TestSignErrors2662=== RUN TestSignErrors/http_error2663=== CONT TestServe2664=== PAUSE TestSignErrors/http_error2665=== RUN TestSignErrors/invalid_json2666=== PAUSE TestSignErrors/invalid_json2667=== RUN TestSignErrors/no_prefix2668=== PAUSE TestSignErrors/no_prefix2669=== RUN TestSignErrors/invalid_base642670=== PAUSE TestSignErrors/invalid_base642671=== CONT TestSignErrors/http_error2672--- PASS: TestServeRejectsGarbage (0.00s)2673=== CONT TestSignErrors/invalid_base642674=== CONT TestSignErrors/invalid_json2675=== CONT TestSignErrors/no_prefix2676--- PASS: TestServe (0.00s)2677--- PASS: TestSignErrors (0.00s)2678 --- PASS: TestSignErrors/http_error (0.00s)2679 --- PASS: TestSignErrors/invalid_json (0.00s)2680 --- PASS: TestSignErrors/no_prefix (0.00s)2681 --- PASS: TestSignErrors/invalid_base64 (0.00s)2682--- PASS: TestSign (0.00s)2683PASS