niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #370
· 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 TestParsePathInfoJSON101=== CONT TestParsePathInfoJSONMultiplePaths102=== CONT TestResolveStorePath103=== RUN TestParsePathInfoJSON/Nix_format104=== PAUSE TestParsePathInfoJSON/Nix_format105=== RUN TestParsePathInfoJSON/Lix_format106=== PAUSE TestParsePathInfoJSON/Lix_format107=== CONT TestEncodeNixBase32108=== CONT TestScriptTokenEmptyCommand109=== RUN TestParsePathInfoJSON/empty_input110=== PAUSE TestParsePathInfoJSON/empty_input111=== RUN TestParsePathInfoJSON/whitespace_only112=== PAUSE TestParsePathInfoJSON/whitespace_only113=== RUN TestParsePathInfoJSON/invalid_JSON114=== PAUSE TestParsePathInfoJSON/invalid_JSON115=== CONT TestParsePathInfoJSON/Nix_format116--- PASS: TestScriptTokenEmptyCommand (0.00s)117=== CONT TestScriptTokenScriptFails118=== CONT TestUploadMultipart_PartsInParallel119=== CONT TestDumpPathMatchesNix120=== CONT TestDumpPathWriterError121=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths122=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths123=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths124=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths125=== CONT TestUploadMultipart_SupersededByPeer126=== RUN TestEncodeNixBase32/test_string_hash127=== RUN TestUploadMultipart_SupersededByPeer/exists128=== PAUSE TestUploadMultipart_SupersededByPeer/exists129=== RUN TestUploadMultipart_SupersededByPeer/missing130=== PAUSE TestUploadMultipart_SupersededByPeer/missing131=== CONT TestPartSizeForNAR132=== PAUSE TestEncodeNixBase32/test_string_hash133=== RUN TestPartSizeForNAR/zero_stays_at_minimum134=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum135=== RUN TestPartSizeForNAR/small_stays_at_minimum136=== PAUSE TestPartSizeForNAR/small_stays_at_minimum137=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum138=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum139=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts140=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts141=== RUN TestPartSizeForNAR/1_TiB142=== PAUSE TestPartSizeForNAR/1_TiB143=== RUN TestPartSizeForNAR/5_TiB_S3_max_object144=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object145=== RUN TestPartSizeForNAR/capped_at_5_GiB146=== PAUSE TestPartSizeForNAR/capped_at_5_GiB147=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica148=== CONT TestFilterOversizedClosures149=== RUN TestFilterOversizedClosures/no_limit_keeps_everything150=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything151=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped152=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped153=== RUN TestEncodeNixBase32/empty_input154=== RUN TestFilterOversizedClosures/all_closures_skipped155--- PASS: TestResolveStorePath (0.00s)156=== CONT TestCaseHackSuffix157=== PAUSE TestFilterOversizedClosures/all_closures_skipped158=== PAUSE TestEncodeNixBase32/empty_input159=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun160--- PASS: TestScriptTokenScriptFails (0.01s)161=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess162=== CONT TestRateLimiterFeedback163=== RUN TestRateLimiterFeedback/429_enables_limiter164=== PAUSE TestRateLimiterFeedback/429_enables_limiter165=== RUN TestRateLimiterFeedback/503_enables_limiter166=== PAUSE TestRateLimiterFeedback/503_enables_limiter167=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter168=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter169=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter170=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter171=== CONT TestDumpPathSingleFile1722026/10/06 10:46:21 WARN Rate limiter enabled after throttle name=server-test rate=51732026/10/06 10:46:21 WARN Rate limiter enabled after throttle name=server-test rate=51742026/10/06 10:46:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:532311752026/10/06 10:46:21 INFO Garbage collection started1762026/10/06 10:46:21 INFO Garbage collection started177--- PASS: TestDoServerRequestAttachesToken (0.01s)178=== CONT TestPathInfoCACompatibility179=== RUN TestPathInfoCACompatibility/null_ca_field180=== PAUSE TestPathInfoCACompatibility/null_ca_field181=== RUN TestPathInfoCACompatibility/old_string_format_-_text182=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text183=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive184=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive185=== RUN TestPathInfoCACompatibility/new_structured_format_-_text186=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text187=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method188=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method189=== CONT TestParsePathInfoJSON/whitespace_only190=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1912026/10/06 10:46:21 WARN Rate limiter backed off name=server-test rate=5192=== CONT TestPathInfoHashCompatibility193=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)194=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)195=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon1972026/10/06 10:46:21 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:53231198=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI199=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI200=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512201=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512202=== CONT TestGetStorePathHash203=== RUN TestGetStorePathHash/valid_store_path204=== PAUSE TestGetStorePathHash/valid_store_path205=== RUN TestGetStorePathHash/basename_without_hyphen_should_error206=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error207=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error208=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error209=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error210=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error211=== CONT TestConvertHashToNix32212=== RUN TestConvertHashToNix32/SRI_format_to_Nix32213=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32214=== RUN TestConvertHashToNix32/already_Nix32_format215=== PAUSE TestConvertHashToNix32/already_Nix32_format216=== RUN TestConvertHashToNix32/invalid_format217=== PAUSE TestConvertHashToNix32/invalid_format218=== CONT TestEncodeNixBase32WithRealHash219--- PASS: TestEncodeNixBase32WithRealHash (0.00s)220=== CONT TestParsePathInfoJSON/invalid_JSON221=== CONT TestParsePathInfoJSON/empty_input222=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths223--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)224 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)225 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)226=== CONT TestUploadMultipart_SupersededByPeer/exists227--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)228=== CONT TestUploadMultipart_SupersededByPeer/missing229--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)230=== CONT TestFileTokenEmpty2312026/10/06 10:46:21 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=0232=== CONT TestScriptTokenEmptyToken233--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)234 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)235 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)236=== CONT TestScriptTokenBadJSON237=== CONT TestScriptTokenCachesUntilRefresh238--- PASS: TestFileTokenEmpty (0.00s)2392026/10/06 10:46:21 WARN Garbage collection finished on another replica. Its statistics are not available here240--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)241=== CONT TestScriptTokenNoExpiryRerunsEveryCall242--- PASS: TestScriptTokenEmptyToken (0.01s)243=== CONT TestFileTokenMissing244--- PASS: TestScriptTokenBadJSON (0.01s)245=== CONT TestFileTokenReadsAndCaches246--- PASS: TestFileTokenMissing (0.00s)247=== CONT TestParsePathInfoJSON/Lix_format248--- PASS: TestParsePathInfoJSON (0.00s)249 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)250 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)251 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)252 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)253 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)254=== CONT TestPartSizeForNAR/zero_stays_at_minimum255=== CONT TestSetClientTLSDoesNotMutateDefaultTransport256--- PASS: TestFileTokenReadsAndCaches (0.00s)257=== CONT TestStaticToken258--- PASS: TestStaticToken (0.00s)259=== CONT TestSetClientTLSErrors260=== RUN TestSetClientTLSErrors/missing_cert_file261=== PAUSE TestSetClientTLSErrors/missing_cert_file262=== RUN TestSetClientTLSErrors/missing_key_file263=== PAUSE TestSetClientTLSErrors/missing_key_file264=== RUN TestSetClientTLSErrors/missing_ca_file265=== PAUSE TestSetClientTLSErrors/missing_ca_file266=== RUN TestSetClientTLSErrors/invalid_ca_file267=== PAUSE TestSetClientTLSErrors/invalid_ca_file268=== CONT TestStreamPushGivesUpOnDeadServer2692026/10/06 10:46:21 ERROR Upload failed error="connection refused" count=202702026/10/06 10:46:21 ERROR Server seems unavailable, giving up on batch untried=17271--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)272=== CONT TestSetClientTLS273--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)274=== CONT TestClientSignaturesByStorePath275--- PASS: TestClientSignaturesByStorePath (0.00s)276=== CONT TestStreamPushReportsSignatures2772026/10/06 10:46:21 ERROR Upload failed error=boom count=1278--- PASS: TestStreamPushReportsSignatures (0.00s)279=== CONT TestStreamPushRequestLine2802026/10/06 10:46:21 ERROR Upload failed error=boom count=1281=== RUN TestSetClientTLS/rejects_connection_without_client_cert282=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert283=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA284=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA285=== RUN TestSetClientTLS/preserves_debug_logging_transport286=== PAUSE TestSetClientTLS/preserves_debug_logging_transport287=== CONT TestPartSizeForNAR/1_TiB288=== CONT TestPartSizeForNAR/capped_at_5_GiB289=== CONT TestPartSizeForNAR/5_TiB_S3_max_object290=== CONT TestStreamPushReportsEveryPath291--- PASS: TestStreamPushReportsEveryPath (0.00s)292=== CONT TestStreamPushIsolatesFailures2932026/10/06 10:46:21 ERROR Upload failed error="bad path" count=3294--- PASS: TestStreamPushIsolatesFailures (0.00s)295=== CONT TestStreamPushBatchesUnderLoad296--- PASS: TestStreamPushRequestLine (0.01s)297=== CONT TestShellSplitErrors298--- PASS: TestShellSplitErrors (0.00s)299=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts300=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum301=== CONT TestPartSizeForNAR/small_stays_at_minimum302--- PASS: TestPartSizeForNAR (0.00s)303 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)304 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)305 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)306 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)307 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)308 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)310=== CONT TestRegisterUploadedObjectReusesConnections311--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)312=== CONT TestShellSplit313--- PASS: TestShellSplit (0.00s)314=== CONT TestFilterOversizedClosures/no_limit_keeps_everything315=== CONT TestEncodeNixBase32/test_string_hash316=== CONT TestFilterOversizedClosures/all_closures_skipped3172026/10/06 10:46:21 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=50318=== CONT TestEncodeNixBase32/empty_input319--- PASS: TestEncodeNixBase32 (0.01s)320 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)321 --- PASS: TestEncodeNixBase32/empty_input (0.00s)322=== CONT TestRateLimiterFeedback/429_enables_limiter323--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)324=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter325--- PASS: TestDumpPathWriterError (0.04s)326=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3272026/10/06 10:46:21 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=2000328--- PASS: TestFilterOversizedClosures (0.00s)329 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)330 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)331 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)332=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3332026/10/06 10:46:21 WARN Rate limiter enabled after throttle name=server-test rate=53342026/10/06 10:46:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:53313335=== CONT TestRateLimiterFeedback/503_enables_limiter3362026/10/06 10:46:21 WARN Rate limiter backed off name=server-test rate=5337=== CONT TestPathInfoCACompatibility/null_ca_field338=== CONT TestPathInfoCACompatibility/new_structured_format_-_text339=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method340=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive341=== CONT TestPathInfoCACompatibility/old_string_format_-_text342--- PASS: TestPathInfoCACompatibility (0.00s)343 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)344 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)345 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)346 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)348=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)349=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI350=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512351=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon352--- PASS: TestPathInfoHashCompatibility (0.00s)353 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)354 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)355 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)356 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)357=== CONT TestGetStorePathHash/valid_store_path358=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error359=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error360=== CONT TestGetStorePathHash/basename_without_hyphen_should_error361--- PASS: TestGetStorePathHash (0.00s)362 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)363 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)364 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)365 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)366=== CONT TestConvertHashToNix32/invalid_format367=== CONT TestConvertHashToNix32/already_Nix32_format368=== CONT TestSetClientTLSErrors/missing_cert_file369=== CONT TestConvertHashToNix32/SRI_format_to_Nix32370--- PASS: TestConvertHashToNix32 (0.00s)371 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)372 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)373 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)374=== CONT TestSetClientTLSErrors/invalid_ca_file375=== CONT TestSetClientTLSErrors/missing_ca_file376=== CONT TestSetClientTLSErrors/missing_key_file377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA379--- PASS: TestSetClientTLSErrors (0.00s)380 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)381 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)382 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)3842026/10/06 10:46:21 WARN Rate limiter enabled after throttle name=server-test rate=53852026/10/06 10:46:21 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:533193862026/10/06 10:46:21 WARN Rate limiter backed off name=server-test rate=5387--- PASS: TestRateLimiterFeedback (0.00s)388 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)389 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)391 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)392=== CONT TestSetClientTLS/preserves_debug_logging_transport393--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3942026/10/06 10:46:21 http: TLS handshake error from 127.0.0.1:53321: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)397 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.06s)401--- PASS: TestDumpPathMatchesNix (0.07s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestUploadMultipart_PartsInParallel (0.61s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_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-24560-3109811407/postgres3165982526/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-24560-3109811407/postgres3165982526/data -l logfile start433434/nix/var/nix/builds/nix-24560-3109811407/postgres3165982526:5432 - no response4352026-10-06 10:46:22.649 UTC [24597] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-06 10:46:22.649 UTC [24597] LOG: listening on Unix socket "/nix/var/nix/builds/nix-24560-3109811407/postgres3165982526/.s.PGSQL.5432"4372026-10-06 10:46:22.651 UTC [24604] LOG: database system was shut down at 2026-10-06 10:46:22 UTC4382026-10-06 10:46:22.652 UTC [24597] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-24560-3109811407/postgres3165982526:5432 - accepting connections440{"timestamp":"2026-10-06T10:46:22.866879Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"271d6190-9d3f-488f-97fb-4afc5bc9a3c0","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)"}441{"timestamp":"2026-10-06T10:46:22.97028Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1bd86fc8-2b63-4b22-8ee7-5083d5f7e30d","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(2)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/06 10:46:23 INFO lead: acquired remote=192.0.2.1:12344882026/10/06 10:46:23 INFO lead: released remote=192.0.2.1:12344892026/10/06 10:46:23 INFO lead: acquired remote=192.0.2.1:12344902026/10/06 10:46:24 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/06 10:46:25 INFO lead: acquired remote=192.0.2.1:12344982026-10-06 10:46:26.334 UTC [24639] FATAL: terminating connection due to administrator command4992026/10/06 10:46:26 INFO lead: acquired remote=192.0.2.1:12345002026/10/06 10:46:27 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/06 10:46:27 INFO lead: released remote=192.0.2.1:12345022026/10/06 10:46:27 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyContentNegotiation605=== PAUSE TestReadProxyContentNegotiation606=== RUN TestReadProxyNarStreaming607=== PAUSE TestReadProxyNarStreaming608=== RUN TestReadProxy404609=== PAUSE TestReadProxy404610=== RUN TestReadProxyInvalidPath611=== PAUSE TestReadProxyInvalidPath612=== RUN TestReadProxyHead613=== PAUSE TestReadProxyHead614=== RUN TestReadProxyOutlastsServerWriteTimeout615=== PAUSE TestReadProxyOutlastsServerWriteTimeout616=== RUN TestReadProxyConditionalGet617=== PAUSE TestReadProxyConditionalGet618=== RUN TestReadProxyRootRedirectsToIndexHTML619=== PAUSE TestReadProxyRootRedirectsToIndexHTML620=== RUN TestReadProxyDisabled621=== PAUSE TestReadProxyDisabled622=== RUN TestReadRedirectNar623=== PAUSE TestReadRedirectNar624=== RUN TestReadRedirectKeepsNarinfoProxied625=== PAUSE TestReadRedirectKeepsNarinfoProxied626=== RUN TestReadProxyRangeRequest627=== PAUSE TestReadProxyRangeRequest628=== RUN TestReadRedirectUsesPublicS3URL629=== PAUSE TestReadRedirectUsesPublicS3URL630=== RUN TestPush_OverlappingRootsStoreOneRowPerKey631=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey632=== RUN TestPush_CompleteCommitsEveryRoot633=== PAUSE TestPush_CompleteCommitsEveryRoot634=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit635=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit636=== RUN TestPush_RejectsBadRequests637=== PAUSE TestPush_RejectsBadRequests638=== RUN TestPush_SignsNarinfosOfItsPendingObjects639=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects640=== RUN TestRedundantMultipartUpload641=== PAUSE TestRedundantMultipartUpload642=== RUN TestCompleteMultipartUpload_ErrorButObjectExists643=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists644=== RUN TestCompletedNarNotReofferedAcrossClosures645=== PAUSE TestCompletedNarNotReofferedAcrossClosures646=== RUN TestPresignedUploadRegisteredBeforeCommit647=== PAUSE TestPresignedUploadRegisteredBeforeCommit648=== RUN TestService_Rustfstest649=== PAUSE TestService_Rustfstest650=== RUN TestParseSize651=== PAUSE TestParseSize652=== RUN TestSkippedUploadsHandler653=== PAUSE TestSkippedUploadsHandler654=== RUN TestSystemdListenerNotActivated655--- PASS: TestSystemdListenerNotActivated (0.00s)656=== RUN TestWatchdogBeatsWhenHealthy657--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)658=== RUN TestWatchdogSkipsWhenUnhealthy6592026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6682026/10/06 10:46:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"669--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)670=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle672=== RUN TestProxyWriteTimeout673=== PAUSE TestProxyWriteTimeout674=== RUN TestPendingClosureWriteTimeout675=== PAUSE TestPendingClosureWriteTimeout676=== RUN TestIsValidUploadKey677=== PAUSE TestIsValidUploadKey678=== RUN TestUploadHandlersRejectInvalidKeys679=== PAUSE TestUploadHandlersRejectInvalidKeys680=== RUN TestUploadHandlersRejectOversizedBody681=== PAUSE TestUploadHandlersRejectOversizedBody682=== RUN TestService_cleanupPendingClosuresHandler683=== PAUSE TestService_cleanupPendingClosuresHandler684=== RUN TestService_createPendingClosureHandler685=== PAUSE TestService_createPendingClosureHandler686=== RUN TestService_verifyS3Integrity687=== PAUSE TestService_verifyS3Integrity688=== RUN TestCompleteMultipartUnregistered689=== PAUSE TestCompleteMultipartUnregistered690=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT691=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT692=== CONT TestCreatePin_ReservedPins693=== CONT TestPush_CompleteCommitsEveryRoot694=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded695=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle696=== CONT TestGCSweepDeliversEachKeyOnce697=== CONT TestService_AuthMiddleware698=== CONT TestOrphanedObjectsGCStressTest699=== CONT TestOrphanedObjectsGC700=== CONT TestObjectStatsTrigger701=== CONT TestPendingCleanupUsesOneCutoff7022026/10/06 10:46:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53347/oidc7032026/10/06 10:46:28 INFO Aborted multipart uploads count=0 kept=07042026/10/06 10:46:28 WARN Force mode enabled - objects will be deleted immediately without grace period7052026/10/06 10:46:28 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=07062026/10/06 10:46:28 INFO Vacuumed table table=pending_closures7072026/10/06 10:46:28 INFO Vacuumed table table=pending_objects7082026/10/06 10:46:28 INFO Vacuumed table table=multipart_uploads7092026/10/06 10:46:28 INFO Vacuumed table table=closures7102026/10/06 10:46:28 INFO Vacuumed table table=objects711--- PASS: TestGCSweepDeliversEachKeyOnce (0.54s)712=== CONT TestTombstonedObjectOfferedWithoutWaiting7132026/10/06 10:46:28 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"714--- PASS: TestService_AuthMiddleware (0.59s)715=== CONT TestGCSweepSkipsPendingObjects7162026/10/06 10:46:28 INFO Received uploads request method=POST path=/api/pending_closures7172026/10/06 10:46:28 INFO Received uploads request method=POST path=/api/pending_closures718--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.99s)719=== CONT TestDeduplicatedObjectsRecordedAsPending7202026/10/06 10:46:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7212026/10/06 10:46:29 INFO Received push request method=POST path=/api/pushes7222026/10/06 10:46:29 INFO Received complete push request method=POST path=/api/pushes/1/complete723--- PASS: TestPush_CompleteCommitsEveryRoot (1.19s)724=== CONT TestPushDedupSurvivesConcurrentGC725--- PASS: TestObjectStatsTrigger (1.73s)726=== CONT TestGCMetrics727=== NAME TestOrphanedObjectsGC728 orphaned_objects_gc_test.go:290: GC Test Summary:729 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A730 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B731 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)732 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)733 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects734--- PASS: TestOrphanedObjectsGC (1.81s)735=== CONT TestGCBugBareHashReferences7362026/10/06 10:46:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7372026/10/06 10:46:29 WARN Refused reserved pin name=worker-x86_64-linux7382026/10/06 10:46:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux7392026/10/06 10:46:29 INFO Received create pin request method=POST path=/api/pins/my-app7402026/10/06 10:46:29 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux741--- PASS: TestCreatePin_ReservedPins (1.91s)742=== CONT TestGCAdvisoryLockBlocksConcurrentRun7432026/10/06 10:46:30 INFO Received uploads request method=POST path=/api/pending_closures7442026/10/06 10:46:30 INFO Received uploads request method=POST path=/api/pending_closures7452026/10/06 10:46:30 INFO Received cleanup request method=DELETE path=/api/pending_closures7462026/10/06 10:46:30 INFO Received uploads request method=POST path=/api/pending_closures7472026/10/06 10:46:30 INFO Aborted multipart uploads count=0 kept=07482026/10/06 10:46:30 WARN Force mode enabled - objects will be deleted immediately without grace period7492026/10/06 10:46:30 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=07502026/10/06 10:46:30 INFO Vacuumed table table=pending_closures7512026/10/06 10:46:30 INFO Vacuumed table table=pending_objects7522026/10/06 10:46:30 INFO Vacuumed table table=multipart_uploads7532026/10/06 10:46:30 INFO Vacuumed table table=closures7542026/10/06 10:46:30 INFO Vacuumed table table=objects755--- PASS: TestGCSweepSkipsPendingObjects (1.86s)756=== CONT TestLeadEndsOnShutdown7572026/10/06 10:46:30 INFO Received uploads request method=POST path=/api/pending_closures758--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.05s)759=== CONT TestLeadIncumbentAnnouncesAtOnce7602026/10/06 10:46:30 INFO Received uploads request method=POST path=/api/pending_closures761--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.82s)762=== CONT TestLeadElectsOneAndHandsOver7632026/10/06 10:46:31 INFO Received uploads request method=POST path=/api/pending_closures7642026/10/06 10:46:31 INFO Aborted multipart uploads count=0 kept=07652026/10/06 10:46:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07662026/10/06 10:46:31 INFO Vacuumed table table=pending_closures7672026/10/06 10:46:31 INFO Vacuumed table table=pending_objects7682026/10/06 10:46:31 INFO Vacuumed table table=multipart_uploads7692026/10/06 10:46:31 INFO Vacuumed table table=closures7702026/10/06 10:46:31 INFO Vacuumed table table=objects7712026/10/06 10:46:31 INFO Aborted multipart uploads count=0 kept=07722026/10/06 10:46:31 WARN Force mode enabled - objects will be deleted immediately without grace period7732026/10/06 10:46:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07742026/10/06 10:46:31 INFO Vacuumed table table=pending_closures7752026/10/06 10:46:31 INFO Vacuumed table table=pending_objects7762026/10/06 10:46:31 INFO Vacuumed table table=multipart_uploads7772026/10/06 10:46:31 INFO Vacuumed table table=closures7782026/10/06 10:46:31 INFO Vacuumed table table=objects779--- PASS: TestPushDedupSurvivesConcurrentGC (2.15s)780=== CONT TestConnectWaitsForAPeerMigration7812026/10/06 10:46:31 INFO Aborted multipart uploads count=0 kept=07822026/10/06 10:46:31 WARN Force mode enabled - objects will be deleted immediately without grace period7832026/10/06 10:46:31 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=07842026/10/06 10:46:31 INFO Vacuumed table table=pending_closures7852026/10/06 10:46:31 INFO Vacuumed table table=pending_objects7862026/10/06 10:46:31 INFO Vacuumed table table=multipart_uploads7872026/10/06 10:46:31 INFO Vacuumed table table=closures7882026/10/06 10:46:31 INFO Vacuumed table table=objects789--- PASS: TestGCMetrics (1.91s)790=== CONT TestResolveDBConnectionString791=== RUN TestResolveDBConnectionString/flag_wins792=== PAUSE TestResolveDBConnectionString/flag_wins793=== RUN TestResolveDBConnectionString/file_when_flag_empty794=== PAUSE TestResolveDBConnectionString/file_when_flag_empty795=== RUN TestResolveDBConnectionString/missing_file_is_an_error796=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error797=== RUN TestResolveDBConnectionString/PGHOST_allows_empty798=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty799=== RUN TestResolveDBConnectionString/nothing_configured800=== PAUSE TestResolveDBConnectionString/nothing_configured801=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock802--- PASS: TestGCBugBareHashReferences (2.30s)803=== CONT TestUploadHandlersRejectOversizedBody804=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts805=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts806=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure807=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure808=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart809=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart810=== CONT TestUploadHandlersRejectInvalidKeys811=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info812=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info813=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal814=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal815=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key816=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key817=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key818=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key819=== CONT TestIsValidUploadKey820=== RUN TestIsValidUploadKey/narinfo821=== PAUSE TestIsValidUploadKey/narinfo822=== RUN TestIsValidUploadKey/nar_zst823=== PAUSE TestIsValidUploadKey/nar_zst824=== RUN TestIsValidUploadKey/nar_xz825=== PAUSE TestIsValidUploadKey/nar_xz826=== RUN TestIsValidUploadKey/nar_plain827=== PAUSE TestIsValidUploadKey/nar_plain828=== RUN TestIsValidUploadKey/listing829=== PAUSE TestIsValidUploadKey/listing830=== RUN TestIsValidUploadKey/build_log831=== PAUSE TestIsValidUploadKey/build_log832=== RUN TestIsValidUploadKey/build_log_home-manager_file833=== PAUSE TestIsValidUploadKey/build_log_home-manager_file834=== RUN TestIsValidUploadKey/build_log_plus_in_name835=== PAUSE TestIsValidUploadKey/build_log_plus_in_name836=== RUN TestIsValidUploadKey/build_log_question_mark837=== PAUSE TestIsValidUploadKey/build_log_question_mark838=== RUN TestIsValidUploadKey/build_log_equals839=== PAUSE TestIsValidUploadKey/build_log_equals840=== RUN TestIsValidUploadKey/realisation841=== PAUSE TestIsValidUploadKey/realisation842=== RUN TestIsValidUploadKey/realisation_plus_in_output843=== PAUSE TestIsValidUploadKey/realisation_plus_in_output844=== RUN TestIsValidUploadKey/nix-cache-info845=== PAUSE TestIsValidUploadKey/nix-cache-info846=== RUN TestIsValidUploadKey/index.html847=== PAUSE TestIsValidUploadKey/index.html848=== RUN TestIsValidUploadKey/narinfo_key,_nar_type849=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type850=== RUN TestIsValidUploadKey/nar_key,_narinfo_type851=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type852=== RUN TestIsValidUploadKey/listing_key,_narinfo_type853=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type854=== RUN TestIsValidUploadKey/traversal855=== PAUSE TestIsValidUploadKey/traversal856=== RUN TestIsValidUploadKey/traversal_nar857=== PAUSE TestIsValidUploadKey/traversal_nar858=== RUN TestIsValidUploadKey/absolute859=== PAUSE TestIsValidUploadKey/absolute860=== RUN TestIsValidUploadKey/empty_key861=== PAUSE TestIsValidUploadKey/empty_key862=== RUN TestIsValidUploadKey/unknown_type863=== PAUSE TestIsValidUploadKey/unknown_type864=== CONT TestPendingClosureWriteTimeout865=== RUN TestPendingClosureWriteTimeout/empty866=== PAUSE TestPendingClosureWriteTimeout/empty867=== RUN TestPendingClosureWriteTimeout/400_objects868=== PAUSE TestPendingClosureWriteTimeout/400_objects869=== RUN TestPendingClosureWriteTimeout/670k_objects870=== PAUSE TestPendingClosureWriteTimeout/670k_objects871=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline872=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline873=== CONT TestProxyWriteTimeout874=== RUN TestProxyWriteTimeout/narinfo875=== PAUSE TestProxyWriteTimeout/narinfo876=== RUN TestProxyWriteTimeout/1_GiB_nar877=== PAUSE TestProxyWriteTimeout/1_GiB_nar878=== RUN TestProxyWriteTimeout/10_GiB_nar879=== PAUSE TestProxyWriteTimeout/10_GiB_nar880=== RUN TestProxyWriteTimeout/unknown_size881=== PAUSE TestProxyWriteTimeout/unknown_size882=== CONT TestGCTaskStore_GetReturnsLatest883--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)884=== CONT TestMultipartCleanup8852026/10/06 10:46:32 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"886--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.27s)887=== CONT TestServerTLSConfig888=== RUN TestServerTLSConfig/no_client_CA889=== PAUSE TestServerTLSConfig/no_client_CA890=== RUN TestServerTLSConfig/missing_CA_file891=== PAUSE TestServerTLSConfig/missing_CA_file892=== RUN TestServerTLSConfig/not_a_PEM_file893=== PAUSE TestServerTLSConfig/not_a_PEM_file894=== CONT TestService_NativeMTLS8952026/10/06 10:46:32 INFO lead: acquired remote=192.0.2.1:12348962026/10/06 10:46:32 INFO lead: acquired remote=192.0.2.1:12348972026/10/06 10:46:32 INFO lead: released remote=192.0.2.1:1234898--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.16s)899=== CONT TestMetricsInventory9002026/10/06 10:46:32 INFO lead: acquired remote=192.0.2.1:12349012026/10/06 10:46:33 INFO lead: released remote=192.0.2.1:1234902--- PASS: TestLeadEndsOnShutdown (3.13s)903=== CONT TestNARDeduplicationMetadataUploadBug904=== NAME TestOrphanedObjectsGCStressTest905 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains906 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion9072026/10/06 10:46:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9082026/10/06 10:46:33 WARN mTLS auth: subject not in bound subjects subject="CN=reader"909--- PASS: TestService_NativeMTLS (1.85s)910=== CONT TestCreatePendingClosureRejectsOversizedNAR9112026/10/06 10:46:33 INFO Received uploads request method=POST path=/api/pending_closures912--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)913=== CONT TestCacheConfigHandlerMaxNarSize914--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)915=== CONT TestGenerateLandingPage916--- PASS: TestGenerateLandingPage (0.00s)917=== CONT TestService_readinessHandler9182026/10/06 10:46:34 WARN Rate limiter enabled after throttle name=s3-test rate=59192026/10/06 10:46:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."920=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle921 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=10922 throttle_test.go:215: Rate limiter: enabled=true, rate=5.00923--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.16s)924=== CONT TestService_healthCheckHandler9252026/10/06 10:46:34 INFO lead: released remote=192.0.2.1:12349262026/10/06 10:46:34 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/06 10:46:34 INFO lead: acquired remote=192.0.2.1:12349282026/10/06 10:46:34 INFO Received cleanup request method=DELETE path=/api/pending_closures9292026/10/06 10:46:34 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""9302026/10/06 10:46:34 INFO Aborted multipart uploads count=0 kept=19312026/10/06 10:46:34 INFO Received cleanup request method=DELETE path=/api/pending_closures9322026/10/06 10:46:34 INFO Aborted multipart uploads count=1 kept=0933--- PASS: TestMultipartCleanup (2.28s)934=== CONT TestGracefulShutdownDrainsInflight9352026/10/06 10:46:34 INFO Starting HTTP server address=127.0.0.1:534119362026/10/06 10:46:34 INFO Shutdown signal received, draining in-flight requests timeout=10s937--- PASS: TestMetricsInventory (1.72s)938=== CONT TestGCTaskStore_Fail939--- PASS: TestGCTaskStore_Fail (0.00s)940=== CONT TestGCTaskStore_PhaseUpdates941--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)942=== CONT TestGCTaskStore_CompletedAllowsNewTask943--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)944=== CONT TestPushWaitsForSweepHoldingRow945--- PASS: TestGracefulShutdownDrainsInflight (0.07s)946=== CONT TestGCTaskStore_GetEmpty947--- PASS: TestGCTaskStore_GetEmpty (0.00s)948=== CONT TestClientFallsBackToClosures949--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.88s)950=== CONT TestGCTaskStore_ConflictDifferentParams951--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)952=== CONT TestClientPushesUseOnePush953=== NAME TestNARDeduplicationMetadataUploadBug954 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-24560-3109811407/TestNARDeduplicationMetadataUploadBug98350115/001/store/mmzca3452jm1s6yg0p90k18y9gmjznqz-file1.txt955=== NAME TestOrphanedObjectsGCStressTest956 orphaned_objects_gc_test.go:509: Stress test completed successfully:957 orphaned_objects_gc_test.go:510: - Active objects preserved: 20958 orphaned_objects_gc_test.go:511: - Objects deleted: 210959 orphaned_objects_gc_test.go:512: - Total GC'd: 210960--- PASS: TestOrphanedObjectsGCStressTest (6.86s)961=== CONT TestGCTaskStore_DeduplicateSameParams962--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)963=== CONT TestGCTaskStore_StartNew964--- PASS: TestGCTaskStore_StartNew (0.00s)965=== CONT TestGCEndsOnShutdown966=== RUN TestGCEndsOnShutdown/before_the_run967=== PAUSE TestGCEndsOnShutdown/before_the_run968=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete969=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete970=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark971=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark972=== CONT TestCommitRacingPendingCleanupKeepsObjects9732026/10/06 10:46:34 INFO Received push request method=POST path=/api/pushes9742026/10/06 10:46:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9752026/10/06 10:46:34 INFO Uploading mmzca3452jm1s6yg0p90k18y9gmjznqz-file1.txt (160B)9762026/10/06 10:46:34 WARN Failed to register uploaded object key=mmzca3452jm1s6yg0p90k18y9gmjznqz.ls error="server returned 404: 404 page not found\n"9772026/10/06 10:46:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9782026/10/06 10:46:34 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9792026/10/06 10:46:34 INFO Signed narinfos id=1 count=19802026/10/06 10:46:34 INFO Uploading 1 narinfos9812026/10/06 10:46:34 INFO Received complete push request method=POST path=/api/pushes/1/complete9822026/10/06 10:46:34 WARN Failed to register uploaded object key=mmzca3452jm1s6yg0p90k18y9gmjznqz.narinfo error="server returned 404: 404 page not found\n"9832026/10/06 10:46:34 INFO Upload complete. (138ms)984=== NAME TestNARDeduplicationMetadataUploadBug985 metadata_upload_test.go:54: Retrieved narinfo from S3:986 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestNARDeduplicationMetadataUploadBug98350115/001/store/mmzca3452jm1s6yg0p90k18y9gmjznqz-file1.txt987 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst988 Compression: zstd989 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf990 NarSize: 160991 References: 992 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf993 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)994 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):995 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}996 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-24560-3109811407/TestNARDeduplicationMetadataUploadBug98350115/001/store/6ajmf5s4f5ygl3cyw4f8cg6ynkwychlp-file2.txt9972026/10/06 10:46:35 WARN readiness check failed error="closed pool"998--- PASS: TestService_readinessHandler (1.02s)999=== CONT TestReadProxyInvalidPath10002026/10/06 10:46:35 INFO Received push request method=POST path=/api/pushes10012026/10/06 10:46:35 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10022026/10/06 10:46:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10032026/10/06 10:46:35 INFO Signed narinfos id=2 count=110042026/10/06 10:46:35 INFO Uploading 1 narinfos10052026/10/06 10:46:35 WARN Failed to register uploaded object key=6ajmf5s4f5ygl3cyw4f8cg6ynkwychlp.ls error="server returned 404: 404 page not found\n"10062026/10/06 10:46:35 INFO Received complete push request method=POST path=/api/pushes/2/complete10072026/10/06 10:46:35 WARN Failed to register uploaded object key=6ajmf5s4f5ygl3cyw4f8cg6ynkwychlp.narinfo error="server returned 404: 404 page not found\n"10082026/10/06 10:46:35 INFO Upload complete. (81ms)1009=== NAME TestNARDeduplicationMetadataUploadBug1010 metadata_upload_test.go:76: Retrieved narinfo from S3:1011 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestNARDeduplicationMetadataUploadBug98350115/001/store/6ajmf5s4f5ygl3cyw4f8cg6ynkwychlp-file2.txt1012 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1013 Compression: zstd1014 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1015 NarSize: 1601016 References: 1017 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1018 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1019 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1020 {"version":1,"root":{"type":"regular","size":44}}1021--- PASS: TestNARDeduplicationMetadataUploadBug (1.62s)1022=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1023--- PASS: TestService_healthCheckHandler (1.06s)1024=== CONT TestReadRedirectUsesPublicS3URL10252026/10/06 10:46:35 INFO lead: released remote=192.0.2.1:12341026--- PASS: TestLeadElectsOneAndHandsOver (4.55s)1027=== CONT TestReadProxyRangeRequest10282026/10/06 10:46:35 INFO Received push request method=POST path=/api/pushes10292026/10/06 10:46:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10302026/10/06 10:46:35 INFO Uploading 3ja63cpxhiinxq32mbkfqjylban5bnjk-b (248B)10312026/10/06 10:46:35 INFO Uploading agk2xvi166qmgm27vkzl4vkgmrv59aqf-shared-dep (136B)10322026/10/06 10:46:35 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/06 10:46:35 WARN Failed to register uploaded object key=3ja63cpxhiinxq32mbkfqjylban5bnjk.ls error="server returned 404: 404 page not found\n"10342026/10/06 10:46:36 WARN Failed to register uploaded object key=ns90pigm4r7yihari9hq0n7hqbi75n1m.ls error="server returned 404: 404 page not found\n"10352026/10/06 10:46:36 WARN Failed to register uploaded object key=agk2xvi166qmgm27vkzl4vkgmrv59aqf.ls error="server returned 404: 404 page not found\n"10362026/10/06 10:46:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10372026/10/06 10:46:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10382026/10/06 10:46:36 WARN Failed to register uploaded object key=nar/05wyzdq7qyyc3z9hpp9nxmw4vsnsb6mfqyvl9nyvhqamk6arizr9.nar.zst error="server returned 404: 404 page not found\n"10392026/10/06 10:46:36 INFO Signed narinfos id=1 count=310402026/10/06 10:46:36 INFO Uploading 3 narinfos10412026/10/06 10:46:36 WARN Failed to register uploaded object key=ns90pigm4r7yihari9hq0n7hqbi75n1m.narinfo error="server returned 404: 404 page not found\n"10422026/10/06 10:46:36 WARN Failed to register uploaded object key=3ja63cpxhiinxq32mbkfqjylban5bnjk.narinfo error="server returned 404: 404 page not found\n"10432026/10/06 10:46:36 INFO Received complete push request method=POST path=/api/pushes/1/complete10442026/10/06 10:46:36 WARN Failed to register uploaded object key=agk2xvi166qmgm27vkzl4vkgmrv59aqf.narinfo error="server returned 404: 404 page not found\n"10452026/10/06 10:46:36 INFO Upload complete. (147ms)1046=== NAME TestClientPushesUseOnePush1047 client_pushes_test.go:97: Retrieved narinfo from S3:1048 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientPushesUseOnePush2595834061/001/store/agk2xvi166qmgm27vkzl4vkgmrv59aqf-shared-dep1049 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1050 Compression: zstd1051 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821052 NarSize: 1361053 References: 1054 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1055 client_pushes_test.go:97: Retrieved narinfo from S3:1056 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientPushesUseOnePush2595834061/001/store/ns90pigm4r7yihari9hq0n7hqbi75n1m-a1057 URL: nar/05wyzdq7qyyc3z9hpp9nxmw4vsnsb6mfqyvl9nyvhqamk6arizr9.nar.zst1058 Compression: zstd1059 NarHash: sha256:05wyzdq7qyyc3z9hpp9nxmw4vsnsb6mfqyvl9nyvhqamk6arizr91060 NarSize: 2481061 References: /nix/var/nix/builds/nix-24560-3109811407/TestClientPushesUseOnePush2595834061/001/store/agk2xvi166qmgm27vkzl4vkgmrv59aqf-shared-dep1062 CA: text:sha256:03pscljsvdwnr5i3yqshij0zpz9j0cdss619j4adfqr036yccfxk1063 client_pushes_test.go:97: Retrieved narinfo from S3:1064 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientPushesUseOnePush2595834061/001/store/3ja63cpxhiinxq32mbkfqjylban5bnjk-b1065 URL: nar/05wyzdq7qyyc3z9hpp9nxmw4vsnsb6mfqyvl9nyvhqamk6arizr9.nar.zst1066 Compression: zstd1067 NarHash: sha256:05wyzdq7qyyc3z9hpp9nxmw4vsnsb6mfqyvl9nyvhqamk6arizr91068 NarSize: 2481069 References: /nix/var/nix/builds/nix-24560-3109811407/TestClientPushesUseOnePush2595834061/001/store/agk2xvi166qmgm27vkzl4vkgmrv59aqf-shared-dep1070 CA: text:sha256:03pscljsvdwnr5i3yqshij0zpz9j0cdss619j4adfqr036yccfxk10712026/10/06 10:46:36 INFO Received uploads request method=POST path=/api/pending_closures1072--- PASS: TestClientPushesUseOnePush (1.61s)1073=== CONT TestReadRedirectKeepsNarinfoProxied10742026/10/06 10:46:36 INFO Received uploads request method=POST path=/api/pending_closures10752026/10/06 10:46:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10762026/10/06 10:46:36 INFO Uploading j5w98pfjflswlbsc96cnp1qhvh0jx9kg-a (248B)10772026/10/06 10:46:36 INFO Uploading knif547823lsmcs4nbvmxm05q4ci1zyh-shared-dep (136B)10782026/10/06 10:46:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10792026/10/06 10:46:36 WARN Failed to register uploaded object key=knif547823lsmcs4nbvmxm05q4ci1zyh.ls error="server returned 404: 404 page not found\n"10802026/10/06 10:46:36 WARN Failed to register uploaded object key=nar/0mii2rlxc6avsyf0d4rdxngsf3kghgws7qsq5klg36vd5cgljh3q.nar.zst error="server returned 404: 404 page not found\n"10812026/10/06 10:46:36 WARN Failed to register uploaded object key=3kpfw9awn53xnx21rwqlp6l19yv12sid.ls error="server returned 404: 404 page not found\n"10822026/10/06 10:46:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10832026/10/06 10:46:36 WARN Failed to register uploaded object key=j5w98pfjflswlbsc96cnp1qhvh0jx9kg.ls error="server returned 404: 404 page not found\n"10842026/10/06 10:46:36 INFO Signed narinfos id=1 count=210852026/10/06 10:46:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10862026/10/06 10:46:36 INFO Signed narinfos id=2 count=210872026/10/06 10:46:36 INFO Uploading 4 narinfos10882026/10/06 10:46:36 WARN Failed to register uploaded object key=knif547823lsmcs4nbvmxm05q4ci1zyh.narinfo error="server returned 404: 404 page not found\n"10892026/10/06 10:46:36 WARN Failed to register uploaded object key=3kpfw9awn53xnx21rwqlp6l19yv12sid.narinfo error="server returned 404: 404 page not found\n"10902026/10/06 10:46:36 WARN Failed to register uploaded object key=j5w98pfjflswlbsc96cnp1qhvh0jx9kg.narinfo error="server returned 404: 404 page not found\n"10912026/10/06 10:46:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10922026/10/06 10:46:36 WARN Failed to register uploaded object key=knif547823lsmcs4nbvmxm05q4ci1zyh.narinfo error="server returned 404: 404 page not found\n"10932026/10/06 10:46:36 INFO Aborted multipart uploads count=1 kept=010942026/10/06 10:46:36 INFO Completed upload id=110952026/10/06 10:46:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10962026/10/06 10:46:36 INFO Completed upload id=210972026/10/06 10:46:36 INFO Upload complete. (165ms)1098=== NAME TestClientFallsBackToClosures1099 client_pushes_test.go:112: Retrieved narinfo from S3:1100 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientFallsBackToClosures2699855031/001/store/knif547823lsmcs4nbvmxm05q4ci1zyh-shared-dep1101 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1102 Compression: zstd1103 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821104 NarSize: 1361105 References: 1106 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1107 client_pushes_test.go:112: Retrieved narinfo from S3:1108 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientFallsBackToClosures2699855031/001/store/j5w98pfjflswlbsc96cnp1qhvh0jx9kg-a1109 URL: nar/0mii2rlxc6avsyf0d4rdxngsf3kghgws7qsq5klg36vd5cgljh3q.nar.zst1110 Compression: zstd1111 NarHash: sha256:0mii2rlxc6avsyf0d4rdxngsf3kghgws7qsq5klg36vd5cgljh3q1112 NarSize: 2481113 References: /nix/var/nix/builds/nix-24560-3109811407/TestClientFallsBackToClosures2699855031/001/store/knif547823lsmcs4nbvmxm05q4ci1zyh-shared-dep1114 CA: text:sha256:1qzfxb8jqsj102fg14ph3qzz91hfwkp3glx3mgy49vkz6m50b1rj1115 client_pushes_test.go:112: Retrieved narinfo from S3:1116 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientFallsBackToClosures2699855031/001/store/3kpfw9awn53xnx21rwqlp6l19yv12sid-b1117 URL: nar/0mii2rlxc6avsyf0d4rdxngsf3kghgws7qsq5klg36vd5cgljh3q.nar.zst1118 Compression: zstd1119 NarHash: sha256:0mii2rlxc6avsyf0d4rdxngsf3kghgws7qsq5klg36vd5cgljh3q1120 NarSize: 2481121 References: /nix/var/nix/builds/nix-24560-3109811407/TestClientFallsBackToClosures2699855031/001/store/knif547823lsmcs4nbvmxm05q4ci1zyh-shared-dep1122 CA: text:sha256:1qzfxb8jqsj102fg14ph3qzz91hfwkp3glx3mgy49vkz6m50b1rj11232026/10/06 10:46:36 INFO Received cleanup request method=DELETE path=/api/pending_closures11242026/10/06 10:46:36 INFO Aborted multipart uploads count=1 kept=01125--- PASS: TestPendingCleanupUsesOneCutoff (8.25s)1126=== CONT TestReadRedirectNar1127--- PASS: TestClientFallsBackToClosures (1.79s)1128=== CONT TestReadProxyDisabled1129--- PASS: TestPushWaitsForSweepHoldingRow (2.05s)1130=== CONT TestPinProtectsFromGC11312026/10/06 10:46:36 INFO Aborted multipart uploads count=0 kept=011322026/10/06 10:46:36 WARN Force mode enabled - objects will be deleted immediately without grace period11332026/10/06 10:46: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=011342026/10/06 10:46:36 INFO Vacuumed table table=pending_closures11352026/10/06 10:46:36 INFO Vacuumed table table=pending_objects11362026/10/06 10:46:36 INFO Vacuumed table table=multipart_uploads11372026/10/06 10:46:36 INFO Vacuumed table table=closures11382026/10/06 10:46:36 INFO Vacuumed table table=objects1139--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.12s)1140=== CONT TestClientSharedPathCommittedMidPush1141--- PASS: TestReadProxyInvalidPath (2.00s)1142=== CONT TestReadProxyRootRedirectsToIndexHTML1143{"timestamp":"2026-10-06T10:46:37.202225Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}11442026/10/06 10:46:37 INFO Received push request method=POST path=/api/pushes1145--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.23s)1146=== CONT TestClientWithDependencies1147--- PASS: TestReadRedirectUsesPublicS3URL (2.47s)1148=== CONT TestReadProxyConditionalGet1149--- PASS: TestReadProxyRangeRequest (2.85s)1150=== CONT TestClientMultipleUploads1151--- PASS: TestConnectWaitsForAPeerMigration (7.03s)1152=== CONT TestClientIntegration1153--- PASS: TestReadRedirectKeepsNarinfoProxied (2.54s)1154=== CONT TestReadProxyOutlastsServerWriteTimeout1155--- PASS: TestReadRedirectNar (2.78s)1156=== CONT TestClientErrorHandling1157=== RUN TestClientErrorHandling/InvalidStorePath1158=== PAUSE TestClientErrorHandling/InvalidStorePath1159=== RUN TestClientErrorHandling/InvalidAuthToken1160=== PAUSE TestClientErrorHandling/InvalidAuthToken1161=== RUN TestClientErrorHandling/ServerNotAvailable1162=== PAUSE TestClientErrorHandling/ServerNotAvailable1163=== CONT TestReadProxyHead1164--- PASS: TestReadProxyDisabled (3.07s)1165=== CONT TestCompleteMultipartUnregistered1166=== NAME TestPinProtectsFromGC1167 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-24560-3109811407/TestPinProtectsFromGC1571362661/001/store/dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv-pinned-file.txt1168 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-24560-3109811407/TestPinProtectsFromGC1571362661/001/store/k7pajx1ca8cx6cmbpl76k4awmjhms6k4-unpinned-file.txt11692026/10/06 10:46:40 INFO Received push request method=POST path=/api/pushes11702026/10/06 10:46:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11712026/10/06 10:46:40 INFO Uploading dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv-pinned-file.txt (128B)11722026/10/06 10:46:40 WARN Failed to register uploaded object key=dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv.ls error="server returned 404: 404 page not found\n"11732026/10/06 10:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11742026/10/06 10:46:40 INFO Signed narinfos id=1 count=111752026/10/06 10:46:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11762026/10/06 10:46:40 INFO Uploading 1 narinfos11772026/10/06 10:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete11782026/10/06 10:46:40 WARN Failed to register uploaded object key=dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv.narinfo error="server returned 404: 404 page not found\n"11792026/10/06 10:46:40 INFO Upload complete. (163ms)11802026/10/06 10:46:40 INFO Received push request method=POST path=/api/pushes11812026/10/06 10:46:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11822026/10/06 10:46:40 INFO Uploading k7pajx1ca8cx6cmbpl76k4awmjhms6k4-unpinned-file.txt (128B)11832026/10/06 10:46:40 WARN Failed to register uploaded object key=k7pajx1ca8cx6cmbpl76k4awmjhms6k4.ls error="server returned 404: 404 page not found\n"11842026/10/06 10:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11852026/10/06 10:46:40 INFO Signed narinfos id=2 count=111862026/10/06 10:46:40 INFO Uploading 1 narinfos11872026/10/06 10:46:40 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11882026/10/06 10:46:40 INFO Received complete push request method=POST path=/api/pushes/2/complete11892026/10/06 10:46:40 WARN Failed to register uploaded object key=k7pajx1ca8cx6cmbpl76k4awmjhms6k4.narinfo error="server returned 404: 404 page not found\n"11902026/10/06 10:46:40 INFO Upload complete. (124ms)11912026/10/06 10:46:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures11922026/10/06 10:46:40 INFO Garbage collection started11932026/10/06 10:46:40 INFO Aborted multipart uploads count=0 kept=011942026/10/06 10:46:40 WARN Force mode enabled - objects will be deleted immediately without grace period11952026/10/06 10:46:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=01196--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.52s)1197=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11982026/10/06 10:46:40 INFO Vacuumed table table=pending_closures11992026/10/06 10:46:40 INFO Vacuumed table table=pending_objects12002026/10/06 10:46:40 INFO Vacuumed table table=multipart_uploads12012026/10/06 10:46:40 INFO Vacuumed table table=closures12022026/10/06 10:46:40 INFO Vacuumed table table=objects12032026/10/06 10:46:40 INFO Received push request method=POST path=/api/pushes12042026/10/06 10:46:40 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12052026/10/06 10:46:40 INFO Uploading mpwl24h8zvammqyhyil3r4gbkfn6l3m9-top (256B)12062026/10/06 10:46:40 INFO Uploading bsr97fb041rkhk7llaapswvybwca7z0i-shared-dep (136B)12072026/10/06 10:46:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12082026/10/06 10:46:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12092026/10/06 10:46:40 WARN Failed to register uploaded object key=mpwl24h8zvammqyhyil3r4gbkfn6l3m9.ls error="server returned 404: 404 page not found\n"12102026/10/06 10:46:40 WARN Failed to register uploaded object key=nar/1cpvspvghdwflzvz91gsyn4dz4sadblcqhhc9875xqz2hf2wvbpn.nar.zst error="server returned 404: 404 page not found\n"12112026/10/06 10:46:40 WARN Failed to register uploaded object key=bsr97fb041rkhk7llaapswvybwca7z0i.ls error="server returned 404: 404 page not found\n"12122026/10/06 10:46:40 INFO Signed narinfos id=1 count=212132026/10/06 10:46:40 INFO Uploading 2 narinfos12142026/10/06 10:46:40 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/10/06 10:46:40 WARN Failed to register uploaded object key=mpwl24h8zvammqyhyil3r4gbkfn6l3m9.narinfo error="server returned 404: 404 page not found\n"12162026/10/06 10:46:40 WARN Failed to register uploaded object key=bsr97fb041rkhk7llaapswvybwca7z0i.narinfo error="server returned 404: 404 page not found\n"12172026/10/06 10:46:40 INFO Upload complete. (167ms)1218=== NAME TestClientSharedPathCommittedMidPush1219 client_integration_test.go:680: Retrieved narinfo from S3:1220 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientSharedPathCommittedMidPush2957723812/001/store/bsr97fb041rkhk7llaapswvybwca7z0i-shared-dep1221 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1222 Compression: zstd1223 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821224 NarSize: 1361225 References: 1226 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1227 client_integration_test.go:680: Retrieved narinfo from S3:1228 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientSharedPathCommittedMidPush2957723812/001/store/mpwl24h8zvammqyhyil3r4gbkfn6l3m9-top1229 URL: nar/1cpvspvghdwflzvz91gsyn4dz4sadblcqhhc9875xqz2hf2wvbpn.nar.zst1230 Compression: zstd1231 NarHash: sha256:1cpvspvghdwflzvz91gsyn4dz4sadblcqhhc9875xqz2hf2wvbpn1232 NarSize: 2561233 References: /nix/var/nix/builds/nix-24560-3109811407/TestClientSharedPathCommittedMidPush2957723812/001/store/bsr97fb041rkhk7llaapswvybwca7z0i-shared-dep1234 CA: text:sha256:088z223bbs7vw40di8wpxm2rb3g3v5b5hbcjs39sdngq7pv906i71235--- PASS: TestClientSharedPathCommittedMidPush (3.96s)1236=== CONT TestCompletedNarNotReofferedAcrossClosures1237--- PASS: TestReadProxyConditionalGet (3.54s)1238=== CONT TestSkippedUploadsHandler12392026/10/06 10:46:41 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001240--- PASS: TestSkippedUploadsHandler (0.00s)1241=== CONT TestClientCADerivations1242=== NAME TestClientWithDependencies1243 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-24560-3109811407/TestClientWithDependencies2614183818/001/store/k8nw317plpwzfdnril8363a7l851kqsh-test-script1244 client_integration_test.go:615: Found 1 dependencies (including self)12452026/10/06 10:46:41 INFO Received push request method=POST path=/api/pushes12462026/10/06 10:46:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12472026/10/06 10:46:41 INFO Uploading k8nw317plpwzfdnril8363a7l851kqsh-test-script (136B)12482026/10/06 10:46:41 WARN Failed to register uploaded object key=k8nw317plpwzfdnril8363a7l851kqsh.ls error="server returned 404: 404 page not found\n"12492026/10/06 10:46:41 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12502026/10/06 10:46:41 WARN Failed to register uploaded object key=log/j7icx2x2is6xzgijn344bq9pbqqynaqq-test-script.drv error="server returned 404: 404 page not found\n"12512026/10/06 10:46:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12522026/10/06 10:46:41 INFO Signed narinfos id=1 count=112532026/10/06 10:46:41 INFO Uploading 1 narinfos12542026/10/06 10:46:41 INFO Received complete push request method=POST path=/api/pushes/1/complete12552026/10/06 10:46:41 WARN Failed to register uploaded object key=k8nw317plpwzfdnril8363a7l851kqsh.narinfo error="server returned 404: 404 page not found\n"12562026/10/06 10:46:41 INFO Upload complete. (153ms)1257 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-24560-3109811407/TestClientWithDependencies2614183818/001/store) requires matching store prefix1258--- PASS: TestClientWithDependencies (4.29s)1259=== CONT TestParseSize1260--- PASS: TestParseSize (0.00s)1261=== CONT TestService_Rustfstest1262=== NAME TestClientMultipleUploads1263 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-24560-3109811407/TestClientMultipleUploads143155952/001/store/8bgd2qappw91w6aiipi784nsw6pxq04f-test-file-0.txt1264 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-24560-3109811407/TestClientMultipleUploads143155952/001/store/gxlxm2syvcay40r7lllf3xiyfsaqfxy3-test-file-1.txt1265 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-24560-3109811407/TestClientMultipleUploads143155952/001/store/qv03b873431h96mb4msxf6vka2r85xy5-test-file-2.txt1266=== NAME TestClientIntegration1267 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-24560-3109811407/TestClientIntegration4167323405/002/store/9lz51l1d8qyk4l4aqr6dy2fr1rp0lbpj-test-file.txt12682026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes12692026/10/06 10:46:42 INFO Received push request method=POST path=/api/pushes12702026/10/06 10:46:42 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12712026/10/06 10:46:42 INFO Uploading gxlxm2syvcay40r7lllf3xiyfsaqfxy3-test-file-1.txt (160B)12722026/10/06 10:46:42 INFO Uploading qv03b873431h96mb4msxf6vka2r85xy5-test-file-2.txt (160B)12732026/10/06 10:46:42 INFO Uploading 8bgd2qappw91w6aiipi784nsw6pxq04f-test-file-0.txt (160B)12742026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12752026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12762026/10/06 10:46:42 WARN Failed to register uploaded object key=8bgd2qappw91w6aiipi784nsw6pxq04f.ls error="server returned 404: 404 page not found\n"12772026/10/06 10:46:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12782026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12792026/10/06 10:46:42 INFO Uploading 9lz51l1d8qyk4l4aqr6dy2fr1rp0lbpj-test-file.txt (152B)12802026/10/06 10:46:42 WARN Failed to register uploaded object key=qv03b873431h96mb4msxf6vka2r85xy5.ls error="server returned 404: 404 page not found\n"12812026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12822026/10/06 10:46:42 WARN Failed to register uploaded object key=gxlxm2syvcay40r7lllf3xiyfsaqfxy3.ls error="server returned 404: 404 page not found\n"12832026/10/06 10:46:42 INFO Signed narinfos id=1 count=312842026/10/06 10:46:42 INFO Uploading 3 narinfos12852026/10/06 10:46:42 WARN Failed to register uploaded object key=gxlxm2syvcay40r7lllf3xiyfsaqfxy3.narinfo error="server returned 404: 404 page not found\n"12862026/10/06 10:46:42 WARN Failed to register uploaded object key=8bgd2qappw91w6aiipi784nsw6pxq04f.narinfo error="server returned 404: 404 page not found\n"12872026/10/06 10:46:42 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12882026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete12892026/10/06 10:46:42 WARN Failed to register uploaded object key=qv03b873431h96mb4msxf6vka2r85xy5.narinfo error="server returned 404: 404 page not found\n"12902026/10/06 10:46:42 WARN Failed to register uploaded object key=9lz51l1d8qyk4l4aqr6dy2fr1rp0lbpj.ls error="server returned 404: 404 page not found\n"12912026/10/06 10:46:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12922026/10/06 10:46:42 INFO Signed narinfos id=1 count=112932026/10/06 10:46:42 INFO Uploading 1 narinfos12942026/10/06 10:46:42 INFO Upload complete. (122ms)1295=== NAME TestClientMultipleUploads1296 client_integration_test.go:369: Uploaded 3 paths in 153.076708ms12972026/10/06 10:46:42 INFO Received complete push request method=POST path=/api/pushes/1/complete12982026/10/06 10:46:42 WARN Failed to register uploaded object key=9lz51l1d8qyk4l4aqr6dy2fr1rp0lbpj.narinfo error="server returned 404: 404 page not found\n"12992026/10/06 10:46:42 INFO Upload complete. (136ms)13002026/10/06 10:46:42 INFO All 1 paths already cached1301=== NAME TestClientIntegration1302 client_integration_test.go:312: Retrieved narinfo from S3:1303 StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientIntegration4167323405/002/store/9lz51l1d8qyk4l4aqr6dy2fr1rp0lbpj-test-file.txt1304 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1305 Compression: zstd1306 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11307 NarSize: 1521308 References: 1309 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11310--- PASS: TestClientMultipleUploads (4.01s)1311=== CONT TestPresignedUploadRegisteredBeforeCommit1312{"timestamp":"2026-10-06T10:46:42.19704Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}1313=== NAME TestClientIntegration1314 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1315 client_integration_test.go:313: Decompressed .ls content (64 bytes):1316 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1317 client_integration_test.go:316: Testing garbage collection...13182026/10/06 10:46:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13192026/10/06 10:46:42 INFO Garbage collection started13202026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=013212026/10/06 10:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period13222026/10/06 10:46:42 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=013232026/10/06 10:46:42 INFO Vacuumed table table=pending_closures13242026/10/06 10:46:42 INFO Vacuumed table table=pending_objects13252026/10/06 10:46:42 INFO Vacuumed table table=multipart_uploads13262026/10/06 10:46:42 INFO Vacuumed table table=closures1327--- PASS: TestReadProxyHead (3.40s)1328=== CONT TestService_cleanupPendingClosuresHandler13292026/10/06 10:46:42 INFO Vacuumed table table=objects13302026/10/06 10:46:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013312026/10/06 10:46:42 INFO Received create pin request method=POST path=/api/pins/myapp13322026/10/06 10:46:42 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-24560-3109811407/TestPinProtectsFromGC1571362661/001/store/dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv-pinned-file.txt narinfo_key=dvnc2ssbx58wi1nf4cf0k2jdchlkdgmv.narinfo13332026/10/06 10:46:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13342026/10/06 10:46:42 INFO Garbage collection started13352026/10/06 10:46:42 INFO Aborted multipart uploads count=0 kept=013362026/10/06 10:46:42 WARN Force mode enabled - objects will be deleted immediately without grace period13372026/10/06 10:46:42 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013382026/10/06 10:46:42 INFO Vacuumed table table=pending_closures13392026/10/06 10:46:42 INFO Vacuumed table table=pending_objects13402026/10/06 10:46:42 INFO Vacuumed table table=multipart_uploads13412026/10/06 10:46:42 INFO Vacuumed table table=closures13422026/10/06 10:46:42 INFO Vacuumed table table=objects13432026/10/06 10:46:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13442026/10/06 10:46:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1345--- PASS: TestCompleteMultipartUnregistered (3.36s)1346=== CONT TestService_verifyS3Integrity13472026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures1348--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.68s)1349=== CONT TestService_createPendingClosureHandler13502026/10/06 10:46:43 INFO Received uploads request method=POST path=/api/pending_closures13512026/10/06 10:46:44 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01352=== NAME TestClientIntegration1353 client_integration_test.go:323: Objects in database after GC:1354 client_integration_test.go:323: Successfully deleted all objects with GC --force1355--- PASS: TestService_Rustfstest (2.60s)1356=== CONT TestReadProxyNarinfo1357--- PASS: TestClientIntegration (5.98s)1358=== CONT TestReadProxy4041359=== NAME TestClientCADerivations1360 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-24560-3109811407/TestClientCADerivations1603988077/001/store/lzs377f5jn3rh44qx4v3sbzz25l5ygca-ca-test1361=== NAME TestPinProtectsFromGC1362 client_integration_test.go:840: Pin successfully protected closure from garbage collection1363=== NAME TestClientCADerivations1364 client_ca_test.go:139: Found 1 dependencies (including self)1365--- PASS: TestPinProtectsFromGC (8.08s)1366=== CONT TestReadProxyNarStreaming13672026/10/06 10:46:44 INFO Received push request method=POST path=/api/pushes13682026/10/06 10:46:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13692026/10/06 10:46:44 INFO Uploading lzs377f5jn3rh44qx4v3sbzz25l5ygca-ca-test (144B)13702026/10/06 10:46:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13712026/10/06 10:46:44 WARN Failed to register uploaded object key=lzs377f5jn3rh44qx4v3sbzz25l5ygca.ls error="server returned 404: 404 page not found\n"13722026/10/06 10:46:44 WARN Failed to register uploaded object key=log/qnbmwxgnkasg3qdmp52jiivgbanlhv5f-ca-test.drv error="server returned 404: 404 page not found\n"13732026/10/06 10:46:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13742026/10/06 10:46:44 INFO Signed narinfos id=1 count=113752026/10/06 10:46:44 INFO Uploading 1 narinfos13762026/10/06 10:46:44 INFO Received complete push request method=POST path=/api/pushes/1/complete13772026/10/06 10:46:44 WARN Failed to register uploaded object key=lzs377f5jn3rh44qx4v3sbzz25l5ygca.narinfo error="server returned 404: 404 page not found\n"13782026/10/06 10:46:44 INFO Upload complete. (260ms)1379=== NAME TestClientCADerivations1380 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-24560-3109811407/TestClientCADerivations1603988077/001/store/lzs377f5jn3rh44qx4v3sbzz25l5ygca-ca-test1381 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1382 Compression: zstd1383 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1384 NarSize: 1441385 References: 1386 Deriver: /nix/var/nix/builds/nix-24560-3109811407/TestClientCADerivations1603988077/001/store/qnbmwxgnkasg3qdmp52jiivgbanlhv5f-ca-test.drv1387 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1388 client_ca_test.go:185: Checking for realisation files in S3...1389 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1390 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1391 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket53?endpoint=http://localhost:53326®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-24560-3109811407/TestClientCADerivations1603988077/001/store'1392 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 113932026/10/06 10:46:44 INFO Received uploads request method=POST path=/api/pending_closures1394--- PASS: TestClientCADerivations (3.82s)1395=== CONT TestReadProxyContentNegotiation13962026/10/06 10:46:45 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13972026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures1398--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.84s)1399=== CONT TestCacheStatsHandler14002026/10/06 10:46:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14012026/10/06 10:46:45 INFO Aborted multipart uploads count=0 kept=014022026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures14032026/10/06 10:46:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14042026/10/06 10:46:45 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLjA4NDNhNmFhLTI3YjYtNGE4Zi1hNDRmLWI3MGNlZDViN2JkMHgxNzkxMjgzNjAzNDczNDczMDAw parts=1214052026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures1406--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.53s)1407=== CONT TestReadProxyNarinfoAlreadyDecompressed14082026/10/06 10:46:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14092026/10/06 10:46:45 INFO Aborted multipart uploads count=1 kept=014102026/10/06 10:46:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14112026-10-06 10:46:45.487 UTC [24928] ERROR: Closure does not exist: id=114122026-10-06 10:46:45.487 UTC [24928] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE14132026-10-06 10:46:45.487 UTC [24928] STATEMENT: -- name: CommitPendingClosure :exec1414 SELECT commit_pending_closure($1::bigint)1415 1416--- PASS: TestService_cleanupPendingClosuresHandler (3.08s)1417=== CONT TestSweepSkipsRowsLockedByPush14182026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures14192026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures14202026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures14212026/10/06 10:46:45 INFO Received uploads request method=POST path=/api/pending_closures1422--- PASS: TestReadProxyOutlastsServerWriteTimeout (7.66s)1423=== CONT TestSweepRechecksPendingAfterLocking14242026/10/06 10:46:46 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1425--- PASS: TestReadProxyNarinfo (2.57s)1426=== CONT TestGetExistingObjectsLocksRows14272026/10/06 10:46:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14282026/10/06 10:46:47 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLjRhOTJhNmYwLTcxYjktNDVkNy1iNWFlLWYxZDJlNTc0MWVlYngxNzkxMjgzNjA1NjA4NDY1MDAw parts=1014292026/10/06 10:46:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14302026/10/06 10:46:47 INFO Completed upload id=114312026/10/06 10:46:47 INFO Received uploads request method=POST path=/api/pending_closures14322026/10/06 10:46:47 INFO Received uploads request method=POST path=/api/pending_closures14332026/10/06 10:46:47 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14342026/10/06 10:46:47 WARN Found objects in DB but missing from S3, will re-upload count=11435--- PASS: TestService_verifyS3Integrity (4.52s)1436=== CONT TestRegisterCompletedObjectNeedsPendingRow1437--- PASS: TestReadProxy404 (3.01s)1438=== CONT TestForceGCDuringPushOffersSweptObject1439=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1440=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1441=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1442=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1443=== CONT TestFailedS3DeleteKeepsTombstone1444--- PASS: TestReadProxyNarStreaming (3.03s)1445=== CONT TestService_ReadScope_PublicByDefault14462026/10/06 10:46:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14472026/10/06 10:46:47 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLmNlNDgwMWYxLWRiM2ItNDgxYy1iNjVhLTQ0YjgwMThkOGFkY3gxNzkxMjgzNjA2MDc5Nzg3MDAw parts=1014482026/10/06 10:46:47 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14492026/10/06 10:46:47 INFO Completed upload id=114502026/10/06 10:46:47 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014512026/10/06 10:46:47 INFO Received uploads request method=POST path=/api/pending_closures14522026/10/06 10:46:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures14532026/10/06 10:46:47 INFO Aborted multipart uploads count=0 kept=014542026/10/06 10:46:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014552026/10/06 10:46:47 INFO Vacuumed table table=pending_closures14562026/10/06 10:46:47 INFO Vacuumed table table=pending_objects14572026/10/06 10:46:47 INFO Vacuumed table table=multipart_uploads14582026/10/06 10:46:48 INFO Vacuumed table table=closures14592026/10/06 10:46:48 INFO Vacuumed table table=objects14602026/10/06 10:46:48 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001461--- PASS: TestService_createPendingClosureHandler (4.84s)1462=== CONT TestCacheConfigHandler1463=== RUN TestCacheConfigHandler/full_config,_no_issuer1464=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1465=== RUN TestCacheConfigHandler/no_cache_url_configured1466=== PAUSE TestCacheConfigHandler/no_cache_url_configured1467=== RUN TestCacheConfigHandler/no_signing_keys1468=== PAUSE TestCacheConfigHandler/no_signing_keys1469=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1470=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1471=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1472--- PASS: TestCacheStatsHandler (3.17s)1473=== CONT TestParseSingleRange1474=== RUN TestParseSingleRange/none1475=== PAUSE TestParseSingleRange/none1476=== RUN TestParseSingleRange/unknown_unit1477=== PAUSE TestParseSingleRange/unknown_unit1478=== RUN TestParseSingleRange/multi-range_ignored1479=== PAUSE TestParseSingleRange/multi-range_ignored1480=== RUN TestParseSingleRange/malformed_no_dash1481=== PAUSE TestParseSingleRange/malformed_no_dash1482=== RUN TestParseSingleRange/malformed_both_empty1483=== PAUSE TestParseSingleRange/malformed_both_empty1484=== RUN TestParseSingleRange/malformed_end_before_start1485=== PAUSE TestParseSingleRange/malformed_end_before_start1486=== RUN TestParseSingleRange/closed1487=== PAUSE TestParseSingleRange/closed1488=== RUN TestParseSingleRange/open-ended1489=== PAUSE TestParseSingleRange/open-ended1490=== RUN TestParseSingleRange/end_clamped_to_size1491=== PAUSE TestParseSingleRange/end_clamped_to_size1492=== RUN TestParseSingleRange/suffix1493=== PAUSE TestParseSingleRange/suffix1494=== RUN TestParseSingleRange/suffix_exceeds_size1495=== PAUSE TestParseSingleRange/suffix_exceeds_size1496=== RUN TestParseSingleRange/single_byte1497=== PAUSE TestParseSingleRange/single_byte1498=== RUN TestParseSingleRange/start_past_EOF1499=== PAUSE TestParseSingleRange/start_past_EOF1500=== RUN TestParseSingleRange/start_far_past_EOF1501=== PAUSE TestParseSingleRange/start_far_past_EOF1502=== CONT TestIsValidCachePath1503=== RUN TestIsValidCachePath/narinfo1504=== PAUSE TestIsValidCachePath/narinfo1505=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1506=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1507=== RUN TestIsValidCachePath/nar_zst1508=== PAUSE TestIsValidCachePath/nar_zst1509=== RUN TestIsValidCachePath/nar_xz1510=== PAUSE TestIsValidCachePath/nar_xz1511=== RUN TestIsValidCachePath/nar_bz21512=== PAUSE TestIsValidCachePath/nar_bz21513=== RUN TestIsValidCachePath/nar_uncompressed1514=== PAUSE TestIsValidCachePath/nar_uncompressed1515=== RUN TestIsValidCachePath/ls1516=== PAUSE TestIsValidCachePath/ls1517=== RUN TestIsValidCachePath/log1518=== PAUSE TestIsValidCachePath/log1519=== RUN TestIsValidCachePath/realisation1520=== PAUSE TestIsValidCachePath/realisation1521=== RUN TestIsValidCachePath/nix-cache-info1522=== PAUSE TestIsValidCachePath/nix-cache-info1523=== RUN TestIsValidCachePath/index.html1524=== PAUSE TestIsValidCachePath/index.html1525=== RUN TestIsValidCachePath/traversal_parent1526=== PAUSE TestIsValidCachePath/traversal_parent1527=== RUN TestIsValidCachePath/traversal_in_middle1528=== PAUSE TestIsValidCachePath/traversal_in_middle1529=== RUN TestIsValidCachePath/invalid_char_e1530=== PAUSE TestIsValidCachePath/invalid_char_e1531=== RUN TestIsValidCachePath/invalid_char_u1532=== PAUSE TestIsValidCachePath/invalid_char_u1533=== RUN TestIsValidCachePath/random_path1534=== PAUSE TestIsValidCachePath/random_path1535=== RUN TestIsValidCachePath/empty1536=== PAUSE TestIsValidCachePath/empty1537=== RUN TestIsValidCachePath/leading_slash1538=== PAUSE TestIsValidCachePath/leading_slash1539=== RUN TestIsValidCachePath/wrong_extension1540=== PAUSE TestIsValidCachePath/wrong_extension1541=== RUN TestIsValidCachePath/short_hash1542=== PAUSE TestIsValidCachePath/short_hash1543=== CONT TestProxyHeadersOnlyTrustedOnSocket1544--- PASS: TestReadProxyContentNegotiation (3.52s)1545=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1546--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.32s)1547=== CONT TestPush_SignsNarinfosOfItsPendingObjects15482026/10/06 10:46:49 INFO Aborted multipart uploads count=0 kept=015492026/10/06 10:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period15502026/10/06 10:46:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015512026/10/06 10:46:49 INFO Vacuumed table table=pending_closures15522026/10/06 10:46:49 INFO Vacuumed table table=pending_objects15532026/10/06 10:46:49 INFO Vacuumed table table=multipart_uploads15542026/10/06 10:46:49 INFO Vacuumed table table=closures15552026/10/06 10:46:49 INFO Vacuumed table table=objects15562026/10/06 10:46:49 INFO Aborted multipart uploads count=0 kept=015572026/10/06 10:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period15582026/10/06 10:46:49 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=015592026/10/06 10:46:49 INFO Vacuumed table table=pending_closures15602026/10/06 10:46:49 INFO Vacuumed table table=pending_objects15612026/10/06 10:46:49 INFO Vacuumed table table=multipart_uploads15622026/10/06 10:46:49 INFO Vacuumed table table=closures15632026/10/06 10:46:49 INFO Vacuumed table table=objects1564--- PASS: TestSweepSkipsRowsLockedByPush (3.80s)1565=== CONT TestPresentNotReportedWhileGCDeletesClosure15662026/10/06 10:46:49 INFO Aborted multipart uploads count=0 kept=015672026/10/06 10:46:49 WARN Force mode enabled - objects will be deleted immediately without grace period15682026/10/06 10:46:49 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015692026/10/06 10:46:49 INFO Vacuumed table table=pending_closures15702026/10/06 10:46:49 INFO Vacuumed table table=pending_objects15712026/10/06 10:46:49 INFO Vacuumed table table=multipart_uploads15722026/10/06 10:46:49 INFO Vacuumed table table=closures15732026/10/06 10:46:49 INFO Vacuumed table table=objects1574--- PASS: TestSweepRechecksPendingAfterLocking (3.42s)1575=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1576{"timestamp":"2026-10-06T10:46:49.925182Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}1577--- PASS: TestGetExistingObjectsLocksRows (3.18s)1578=== CONT TestRedundantMultipartUpload1579--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.15s)1580=== CONT TestPresentReportsOnlyClosureRoots15812026/10/06 10:46:50 INFO Received uploads request method=POST path=/api/pending_closures15822026/10/06 10:46:50 INFO Aborted multipart uploads count=0 kept=015832026/10/06 10:46:50 WARN Force mode enabled - objects will be deleted immediately without grace period15842026/10/06 10:46:50 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15852026/10/06 10:46:50 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1586--- PASS: TestFailedS3DeleteKeepsTombstone (3.64s)1587=== CONT TestService_AuthMiddleware_MTLSProxyHeader1588--- PASS: TestService_ReadScope_PublicByDefault (3.51s)1589=== CONT TestService_RequireScope_OIDC15902026/10/06 10:46:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53685/oidc15912026/10/06 10:46:51 INFO Received uploads request method=POST path=/api/pending_closures1592--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (3.60s)1593=== CONT TestPush_RejectsBadRequests15942026/10/06 10:46:51 INFO Starting HTTP server address=127.0.0.1:5369015952026/10/06 10:46:51 INFO Starting HTTP server address=/nix/var/nix/builds/nix-24560-3109811407/TestProxyHeadersOnlyTrustedOnSocket2451378833/001/proxy.sock15962026/10/06 10:46:51 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15972026/10/06 10:46:51 INFO Shutdown signal received, draining in-flight requests timeout=10s1598--- PASS: TestProxyHeadersOnlyTrustedOnSocket (3.54s)1599=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit16002026/10/06 10:46:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16012026/10/06 10:46:52 WARN mTLS auth: bound subjects configured but subject DN unavailable16022026/10/06 10:46:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1603--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (3.52s)1604=== CONT TestService_AuthMiddleware_OIDC16052026/10/06 10:46:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53696/oidc16062026/10/06 10:46:52 INFO Received push request method=POST path=/api/pushes16072026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16082026/10/06 10:46:52 INFO Signed narinfos id=1 count=116092026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16102026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16112026/10/06 10:46:52 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16122026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16132026/10/06 10:46:52 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16142026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16152026/10/06 10:46:52 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116162026/10/06 10:46:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16172026/10/06 10:46:52 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1618--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.80s)1619=== CONT TestService_ReadAuthMiddleware16202026/10/06 10:46:53 INFO Received uploads request method=POST path=/api/pending_closures1621--- PASS: TestPresentNotReportedWhileGCDeletesClosure (3.99s)1622=== CONT TestResolveDBConnectionString/flag_wins1623=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1624=== CONT TestResolveDBConnectionString/nothing_configured1625=== CONT TestResolveDBConnectionString/missing_file_is_an_error1626=== CONT TestResolveDBConnectionString/file_when_flag_empty1627=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16282026/10/06 10:46:53 INFO Received request for more parts method=POST path=/1629--- PASS: TestResolveDBConnectionString (0.03s)1630 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1631 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1632 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1633 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1634 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1635=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16362026/10/06 10:46:53 INFO Received uploads request method=POST path=/16372026/10/06 10:46:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16382026/10/06 10:46:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLmEyMzViZWNkLTBjNjktNDNlMy05MTAzLTgzMTMzZWQ0OGJkNngxNzkxMjgzNjEzMTQzOTAxMDAw16392026/10/06 10:46:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLmEyMzViZWNkLTBjNjktNDNlMy05MTAzLTgzMTMzZWQ0OGJkNngxNzkxMjgzNjEzMTQzOTAxMDAw parts=11640--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.68s)1641=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16422026/10/06 10:46:53 INFO Received complete multipart upload request method=POST path=/1643=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16442026/10/06 10:46:53 INFO Received uploads request method=POST path=/1645=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16462026/10/06 10:46:53 INFO Received complete multipart upload request method=POST path=/1647=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16482026/10/06 10:46:53 INFO Received request for more parts method=POST path=/1649=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16502026/10/06 10:46:53 INFO Received uploads request method=POST path=/1651--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1652 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1653 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1654 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1655 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1656=== CONT TestIsValidUploadKey/narinfo1657=== CONT TestIsValidUploadKey/realisation_plus_in_output1658=== CONT TestIsValidUploadKey/unknown_type1659=== CONT TestIsValidUploadKey/empty_key1660=== CONT TestIsValidUploadKey/absolute1661=== CONT TestIsValidUploadKey/traversal_nar1662=== CONT TestIsValidUploadKey/traversal1663=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1664=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1665=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1666=== CONT TestIsValidUploadKey/index.html1667=== CONT TestIsValidUploadKey/nix-cache-info1668=== CONT TestIsValidUploadKey/build_log_home-manager_file1669=== CONT TestIsValidUploadKey/realisation1670=== CONT TestIsValidUploadKey/build_log_equals1671=== CONT TestIsValidUploadKey/build_log_question_mark1672=== CONT TestIsValidUploadKey/build_log_plus_in_name1673=== CONT TestIsValidUploadKey/nar_plain1674=== CONT TestIsValidUploadKey/build_log1675=== CONT TestIsValidUploadKey/listing1676=== CONT TestIsValidUploadKey/nar_xz1677=== CONT TestIsValidUploadKey/nar_zst1678--- PASS: TestIsValidUploadKey (0.00s)1679 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1680 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1681 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1682 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1683 --- PASS: TestIsValidUploadKey/absolute (0.00s)1684 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1685 --- PASS: TestIsValidUploadKey/traversal (0.00s)1686 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1687 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1688 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1689 --- PASS: TestIsValidUploadKey/index.html (0.00s)1690 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1691 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1692 --- PASS: TestIsValidUploadKey/realisation (0.00s)1693 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1694 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1695 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1696 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1697 --- PASS: TestIsValidUploadKey/build_log (0.00s)1698 --- PASS: TestIsValidUploadKey/listing (0.00s)1699 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1700 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1701=== CONT TestPendingClosureWriteTimeout/empty1702=== CONT TestPendingClosureWriteTimeout/670k_objects1703=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17042026/10/06 10:46:53 INFO Received uploads request method=POST path=/api/pending_closures17052026/10/06 10:46:53 INFO Received uploads request method=POST path=/api/pending_closures1706--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1707 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1708 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1709 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1710=== CONT TestPendingClosureWriteTimeout/400_objects1711=== CONT TestProxyWriteTimeout/narinfo1712=== CONT TestProxyWriteTimeout/unknown_size1713=== CONT TestProxyWriteTimeout/10_GiB_nar1714=== CONT TestProxyWriteTimeout/1_GiB_nar1715--- PASS: TestProxyWriteTimeout (0.00s)1716 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1717 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1718 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1719 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1720=== CONT TestServerTLSConfig/no_client_CA1721=== CONT TestServerTLSConfig/not_a_PEM_file1722=== CONT TestServerTLSConfig/missing_CA_file1723--- PASS: TestServerTLSConfig (0.00s)1724 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1725 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1726 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1727=== CONT TestGCEndsOnShutdown/before_the_run1728--- PASS: TestPresentReportsOnlyClosureRoots (3.41s)1729=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1730--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (3.13s)1731=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1732=== RUN TestService_RequireScope_OIDC/builder_may_write1733=== PAUSE TestService_RequireScope_OIDC/builder_may_write1734=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1735=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1736=== RUN TestService_RequireScope_OIDC/ops_may_admin1737=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1738=== RUN TestService_RequireScope_OIDC/ops_may_not_write1739=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1740=== RUN TestService_RequireScope_OIDC/reader_may_not_write1741=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1742=== RUN TestService_RequireScope_OIDC/static_token_may_admin1743=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1744=== RUN TestService_RequireScope_OIDC/static_token_may_write1745=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1746=== RUN TestService_RequireScope_OIDC/reader_may_read1747=== PAUSE TestService_RequireScope_OIDC/reader_may_read1748=== RUN TestService_RequireScope_OIDC/writer_implies_read1749=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1750=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1751=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1752=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1753=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1754=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1755=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1756=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1757=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1758=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1759=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1760=== CONT TestClientErrorHandling/InvalidStorePath1761=== RUN TestPush_RejectsBadRequests/bad_root1762=== PAUSE TestPush_RejectsBadRequests/bad_root1763=== RUN TestPush_RejectsBadRequests/root_not_in_objects1764=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1765=== RUN TestPush_RejectsBadRequests/no_roots1766=== PAUSE TestPush_RejectsBadRequests/no_roots1767=== RUN TestPush_RejectsBadRequests/no_objects1768=== PAUSE TestPush_RejectsBadRequests/no_objects1769=== CONT TestClientErrorHandling/ServerNotAvailable17702026/10/06 10:46:55 INFO Received push request method=POST path=/api/pushes17712026/10/06 10:46:55 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17722026/10/06 10:46:55 INFO Received complete push request method=POST path=/api/pushes/1/complete17732026/10/06 10:46:55 INFO Received push request method=POST path=/api/pushes17742026/10/06 10:46:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.045359ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17752026/10/06 10:46:55 INFO Aborted multipart uploads count=0 kept=017762026/10/06 10:46:55 WARN Force mode enabled - objects will be deleted immediately without grace period17772026/10/06 10:46:55 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=017782026/10/06 10:46:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17792026/10/06 10:46:55 INFO Vacuumed table table=pending_closures17802026/10/06 10:46:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.837408ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17812026/10/06 10:46:55 INFO Vacuumed table table=pending_objects1782=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1783=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1784=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1785=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1786=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1787=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1788=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1789=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1790=== CONT TestClientErrorHandling/InvalidAuthToken17912026/10/06 10:46:55 INFO Vacuumed table table=multipart_uploads17922026/10/06 10:46:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLmM1ZmFjZTkwLWMzNmQtNDdjNC05Yzg4LTYxM2MxNThjMjMyNngxNzkxMjgzNjEzNDU4NzM3MDAw parts=1217932026/10/06 10:46:55 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/06 10:46:55 INFO Vacuumed table table=closures17952026/10/06 10:46:55 INFO Received uploads request method=POST path=/api/pending_closures17962026/10/06 10:46:55 INFO Vacuumed table table=objects17972026/10/06 10:46:55 INFO Received complete push request method=POST path=/api/pushes/2/complete1798--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.84s)1799=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18002026/10/06 10:46:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=814.133307ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1801--- PASS: TestService_ReadAuthMiddleware (3.39s)1802=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18032026/10/06 10:46:56 INFO Received uploads request method=POST path=/api/pending_closures18042026/10/06 10:46:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.465246271s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1805=== CONT TestCacheConfigHandler/full_config,_no_issuer1806=== CONT TestCacheConfigHandler/no_signing_keys1807=== CONT TestCacheConfigHandler/no_cache_url_configured1808=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1809--- PASS: TestCacheConfigHandler (0.00s)1810 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1811 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1812 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1813 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1814=== CONT TestParseSingleRange/none1815=== CONT TestParseSingleRange/open-ended1816=== CONT TestParseSingleRange/closed1817=== CONT TestParseSingleRange/malformed_end_before_start1818=== CONT TestParseSingleRange/malformed_both_empty1819=== CONT TestParseSingleRange/malformed_no_dash1820=== CONT TestParseSingleRange/multi-range_ignored1821=== CONT TestParseSingleRange/unknown_unit1822=== CONT TestParseSingleRange/start_past_EOF1823=== CONT TestParseSingleRange/end_clamped_to_size1824=== CONT TestParseSingleRange/suffix1825=== CONT TestParseSingleRange/single_byte1826=== CONT TestParseSingleRange/start_far_past_EOF1827=== CONT TestParseSingleRange/suffix_exceeds_size1828--- PASS: TestParseSingleRange (0.00s)1829 --- PASS: TestParseSingleRange/none (0.00s)1830 --- PASS: TestParseSingleRange/open-ended (0.00s)1831 --- PASS: TestParseSingleRange/closed (0.00s)1832 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1833 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1834 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1835 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1836 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1837 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1838 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1839 --- PASS: TestParseSingleRange/suffix (0.00s)1840 --- PASS: TestParseSingleRange/single_byte (0.00s)1841 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1842 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1843=== CONT TestIsValidCachePath/narinfo1844=== CONT TestIsValidCachePath/index.html1845=== CONT TestIsValidCachePath/short_hash1846=== CONT TestIsValidCachePath/wrong_extension1847=== CONT TestIsValidCachePath/leading_slash1848=== CONT TestIsValidCachePath/empty1849=== CONT TestIsValidCachePath/random_path1850=== CONT TestIsValidCachePath/invalid_char_u1851=== CONT TestIsValidCachePath/invalid_char_e1852=== CONT TestIsValidCachePath/traversal_in_middle1853=== CONT TestIsValidCachePath/traversal_parent1854=== CONT TestIsValidCachePath/nar_uncompressed1855=== CONT TestIsValidCachePath/nix-cache-info1856=== CONT TestIsValidCachePath/realisation1857=== CONT TestIsValidCachePath/log1858=== CONT TestIsValidCachePath/ls1859=== CONT TestIsValidCachePath/nar_xz1860=== CONT TestIsValidCachePath/nar_bz21861=== CONT TestIsValidCachePath/nar_zst1862=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1863--- PASS: TestIsValidCachePath (0.00s)1864 --- PASS: TestIsValidCachePath/narinfo (0.00s)1865 --- PASS: TestIsValidCachePath/index.html (0.00s)1866 --- PASS: TestIsValidCachePath/short_hash (0.00s)1867 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1868 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1869 --- PASS: TestIsValidCachePath/empty (0.00s)1870 --- PASS: TestIsValidCachePath/random_path (0.00s)1871 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1872 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1873 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1874 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1875 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1876 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1877 --- PASS: TestIsValidCachePath/realisation (0.00s)1878 --- PASS: TestIsValidCachePath/log (0.00s)1879 --- PASS: TestIsValidCachePath/ls (0.00s)1880 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1881 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1882 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1883 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1884=== CONT TestService_RequireScope_OIDC/builder_may_write1885=== CONT TestService_RequireScope_OIDC/reader_may_read1886=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1887=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18882026/10/06 10:46:56 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]1889=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1890=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1891=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1892=== CONT TestService_RequireScope_OIDC/writer_implies_read1893=== CONT TestService_RequireScope_OIDC/reader_may_not_write1894=== CONT TestService_RequireScope_OIDC/static_token_may_write1895=== CONT TestService_RequireScope_OIDC/static_token_may_admin1896=== CONT TestService_RequireScope_OIDC/ops_may_admin1897=== CONT TestService_RequireScope_OIDC/ops_may_not_write1898=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1899=== CONT TestPush_RejectsBadRequests/bad_root19002026/10/06 10:46:56 INFO Received push request method=POST path=/api/pushes1901=== CONT TestPush_RejectsBadRequests/no_roots19022026/10/06 10:46:56 INFO Received push request method=POST path=/api/pushes1903=== CONT TestPush_RejectsBadRequests/root_not_in_objects19042026/10/06 10:46:56 INFO Received push request method=POST path=/api/pushes1905=== CONT TestPush_RejectsBadRequests/no_objects19062026/10/06 10:46:56 INFO Received push request method=POST path=/api/pushes1907=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1908--- PASS: TestPush_RejectsBadRequests (3.14s)1909 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1910 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1911 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1912 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1913=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19142026/10/06 10:46:56 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1915=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1916=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19172026/10/06 10:46:56 WARN Authentication failed token_preview=eyJhbGciOi...gG1keB37jw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1918--- PASS: TestService_RequireScope_OIDC (3.41s)1919 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1926 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1933--- PASS: TestService_AuthMiddleware_OIDC (3.44s)1934 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1935 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1936 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1937 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19382026/10/06 10:46:57 INFO Aborted multipart uploads count=0 kept=019392026/10/06 10:46:57 WARN Force mode enabled - objects will be deleted immediately without grace period19402026/10/06 10:46:57 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53326/bucket87/?delete=\": context canceled"19412026/10/06 10:46:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1942--- PASS: TestPendingClosureWriteTimeout (0.00s)1943 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1944 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1945 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1946 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.93s)19472026/10/06 10:46:57 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLmViMDRkNjFmLWVlMTctNDNlMC04NmJmLTUxZjg4MWJlYWRiNHgxNzkxMjgzNjE1NTc3NTMxMDAw error="Get \"http://127.0.0.1:1/bucket77/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19482026/10/06 10:46:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTljZDdlN2EtNzA2OS00MWFhLTlkYTYtODI4MWIwZWQxMmEzLjRhZjhlOGNhLWU2Y2EtNDYxNi1iZThlLTNjY2IxMThlNGMwZHgxNzkxMjgzNjE1NTIyOTEzMDAw parts=1219492026/10/06 10:46:57 INFO Received cleanup request method=DELETE path=/api/pending_closures19502026/10/06 10:46:57 INFO Aborted multipart uploads count=1 kept=01951--- PASS: TestRedundantMultipartUpload (7.35s)19522026/10/06 10:46:57 INFO Aborted multipart uploads count=0 kept=019532026/10/06 10:46:57 WARN Force mode enabled - objects will be deleted immediately without grace period19542026-10-06 10:46:57.513 UTC [25060] ERROR: canceling statement due to user request19552026-10-06 10:46:57.513 UTC [25060] STATEMENT: -- name: MarkStaleObjects :execrows1956 WITH RECURSIVE ct AS (1957 SELECT timezone('UTC', now()) AS now1958 ),1959 closure_reach AS (1960 -- Start with all closure keys1961 SELECT o.key, o.refs1962 FROM objects o1963 INNER JOIN closures c ON o.key = c.key1964 UNION1965 -- Recursively add all referenced objects1966 SELECT o.key, o.refs1967 FROM objects o1968 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1969 ),1970 reachable_objects AS (1971 SELECT DISTINCT key FROM closure_reach1972 ),1973 stale_objects AS (1974 SELECT o.key1975 FROM objects AS o, ct1976 WHERE1977 NOT EXISTS (1978 SELECT 11979 FROM reachable_objects ro1980 WHERE ro.key = o.key1981 )1982 AND NOT EXISTS (1983 SELECT 11984 FROM pending_objects AS po1985 WHERE po.key = o.key1986 )1987 AND o.deleted_at IS NULL -- Only mark fresh objects1988 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1989 FOR UPDATE1990 )1991 UPDATE objects1992 SET1993 deleted_at = ct.now,1994 first_deleted_at = COALESCE(first_deleted_at, ct.now)1995 FROM stale_objects, ct1996 WHERE objects.key = stale_objects.key1997 1998--- PASS: TestGCEndsOnShutdown (0.00s)1999 --- PASS: TestGCEndsOnShutdown/before_the_run (3.22s)2000 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.40s)2001 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.42s)20022026/10/06 10:46:58 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20032026/10/06 10:46:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20042026/10/06 10:46:58 INFO Received uploads request method=POST path=/api/pending_closures20052026/10/06 10:46:58 INFO Aborted multipart uploads count=0 kept=020062026/10/06 10:46:58 WARN Force mode enabled - objects will be deleted immediately without grace period20072026/10/06 10:46:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=020082026/10/06 10:46:58 INFO Vacuumed table table=pending_closures20092026/10/06 10:46:58 INFO Vacuumed table table=pending_objects20102026/10/06 10:46:58 INFO Vacuumed table table=multipart_uploads20112026/10/06 10:46:58 INFO Vacuumed table table=closures20122026/10/06 10:46:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20132026/10/06 10:46:58 INFO Vacuumed table table=objects20142026/10/06 10:46:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.103787ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20152026/10/06 10:46:58 INFO Received uploads request method=POST path=/api/pending_closures20162026/10/06 10:46:58 INFO Aborted multipart uploads count=0 kept=020172026/10/06 10:46:58 WARN Force mode enabled - objects will be deleted immediately without grace period20182026/10/06 10:46:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020192026/10/06 10:46:58 INFO Vacuumed table table=pending_closures20202026/10/06 10:46:58 INFO Vacuumed table table=pending_objects20212026/10/06 10:46:58 INFO Vacuumed table table=multipart_uploads20222026/10/06 10:46:58 INFO Vacuumed table table=closures20232026/10/06 10:46:58 INFO Vacuumed table table=objects2024--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2025 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.73s)2026 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.53s)20272026/10/06 10:46:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.561307ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20282026/10/06 10:46:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.112059ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2029{"timestamp":"2026-10-06T10:46:59.376126Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}20302026/10/06 10:46:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.56556027s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/06 10:47:01 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"20322026/10/06 10:47:01 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20332026/10/06 10:47:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=186.962424ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20342026/10/06 10:47:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=368.783791ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/06 10:47:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=778.194392ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20362026/10/06 10:47:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.51888043s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20372026/10/06 10:47:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20382026/10/06 10:47:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.439232ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20392026/10/06 10:47:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.342401ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20402026/10/06 10:47:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.27566ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2041{"timestamp":"2026-10-06T10:47:05.049622Z","level":"ERROR","message":"Scanner cycle completed without a durable data usage snapshot","event":"scanner_persist_state","component":"scanner","subsystem":"runtime","cycle":4,"outcome":"NoUpdate","state":"usage_not_durable","target":"rustfs::scanner","filename":"crates/scanner/src/scanner.rs","line_number":2350,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}20422026/10/06 10:47:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.459892092s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2043--- PASS: TestClientErrorHandling (0.00s)2044 --- PASS: TestClientErrorHandling/InvalidStorePath (3.32s)2045 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.80s)2046 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.30s)2047PASS2048{"timestamp":"2026-10-06T10:47:07.103868Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53650","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(8)"}20492026-10-06 10:47:07.321 UTC [24597] LOG: received smart shutdown request20502026-10-06 10:47:07.322 UTC [24597] LOG: background worker "logical replication launcher" (PID 24607) exited with exit code 120512026-10-06 10:47:07.328 UTC [24602] LOG: shutting down20522026-10-06 10:47:07.328 UTC [24602] LOG: checkpoint starting: shutdown immediate20532026-10-06 10:47:08.660 UTC [24602] LOG: checkpoint complete: wrote 12786 buffers (78.0%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.745 s, sync=0.535 s, total=1.332 s; sync files=31335, longest=0.001 s, average=0.001 s; distance=440334 kB, estimate=440334 kB; lsn=0/1C5907D0, redo lsn=0/1C5907D020542026-10-06 10:47:08.666 UTC [24597] LOG: database system is shut down2055Running OIDC tests...2056=== RUN TestAudienceForIssuer2057=== PAUSE TestAudienceForIssuer2058=== RUN TestGlobMatch2059=== PAUSE TestGlobMatch2060=== RUN TestValidateToken_ValidToken2061=== PAUSE TestValidateToken_ValidToken2062=== RUN TestValidateToken_WrongAudience2063=== PAUSE TestValidateToken_WrongAudience2064=== RUN TestValidateToken_Expired2065=== PAUSE TestValidateToken_Expired2066=== RUN TestValidateToken_BoundClaimsMismatch2067=== PAUSE TestValidateToken_BoundClaimsMismatch2068=== RUN TestValidateToken_BoundSubjectMismatch2069=== PAUSE TestValidateToken_BoundSubjectMismatch2070=== RUN TestValidateToken_MultipleProviders2071=== PAUSE TestValidateToken_MultipleProviders2072=== RUN TestValidateToken_NoMatchingProvider2073=== PAUSE TestValidateToken_NoMatchingProvider2074=== RUN TestValidateToken_KubernetesServiceAccount2075=== PAUSE TestValidateToken_KubernetesServiceAccount2076=== RUN TestNewValidator_KubernetesRequiresCA2077=== PAUSE TestNewValidator_KubernetesRequiresCA2078=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2079=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2080=== RUN TestPins_ReservedForMatchingRule2081=== PAUSE TestPins_ReservedForMatchingRule2082=== RUN TestPins_TopLevelShorthand2083=== PAUSE TestPins_TopLevelShorthand2084=== RUN TestPins_ConfigValidation2085=== PAUSE TestPins_ConfigValidation2086=== RUN TestScopes_LegacyProviderDefaultsToWrite2087=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2088=== RUN TestScopes_Rules2089=== PAUSE TestScopes_Rules2090=== RUN TestScopes_ConfigValidation2091=== PAUSE TestScopes_ConfigValidation2092=== CONT TestAudienceForIssuer2093--- PASS: TestAudienceForIssuer (0.00s)2094=== CONT TestValidateToken_Expired2095=== CONT TestValidateToken_BoundClaimsMismatch2096=== CONT TestValidateToken_KubernetesServiceAccount2097=== CONT TestPins_ConfigValidation2098=== CONT TestValidateToken_ValidToken2099=== CONT TestGlobMatch2100=== RUN TestGlobMatch/foo_foo2101=== PAUSE TestGlobMatch/foo_foo2102=== RUN TestGlobMatch/foo_bar2103=== PAUSE TestGlobMatch/foo_bar2104=== RUN TestGlobMatch/*_2105=== PAUSE TestGlobMatch/*_2106=== RUN TestGlobMatch/*_anything2107=== PAUSE TestGlobMatch/*_anything2108=== RUN TestGlobMatch/foo*_foo2109=== PAUSE TestGlobMatch/foo*_foo2110=== RUN TestGlobMatch/foo*_foobar2111=== PAUSE TestGlobMatch/foo*_foobar2112=== RUN TestGlobMatch/foo*_bar2113=== PAUSE TestGlobMatch/foo*_bar2114=== RUN TestGlobMatch/*bar_bar2115=== PAUSE TestGlobMatch/*bar_bar2116=== RUN TestGlobMatch/*bar_foobar2117=== PAUSE TestGlobMatch/*bar_foobar2118=== RUN TestGlobMatch/*bar_foo2119=== PAUSE TestGlobMatch/*bar_foo2120=== RUN TestGlobMatch/foo*bar_foobar2121=== PAUSE TestGlobMatch/foo*bar_foobar2122=== RUN TestGlobMatch/foo*bar_foo123bar2123=== PAUSE TestGlobMatch/foo*bar_foo123bar2124=== RUN TestGlobMatch/foo*bar_foobarbaz2125=== PAUSE TestGlobMatch/foo*bar_foobarbaz2126=== RUN TestGlobMatch/*/*_foo/bar2127=== PAUSE TestGlobMatch/*/*_foo/bar2128=== RUN TestGlobMatch/*/*_foo2129=== PAUSE TestGlobMatch/*/*_foo2130=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2131=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2132=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02133=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02134=== RUN TestGlobMatch/refs/*/main_refs/heads/main2135=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2136=== RUN TestGlobMatch/fo?_foo2137=== PAUSE TestGlobMatch/fo?_foo2138=== RUN TestGlobMatch/fo?_fo2139=== PAUSE TestGlobMatch/fo?_fo2140=== RUN TestGlobMatch/fo?_fooo2141=== PAUSE TestGlobMatch/fo?_fooo2142=== RUN TestGlobMatch/?oo_foo2143=== PAUSE TestGlobMatch/?oo_foo2144=== RUN TestGlobMatch/?oo_boo2145=== PAUSE TestGlobMatch/?oo_boo2146=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2147=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2148=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2149=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2150=== CONT TestValidateToken_MultipleProviders2151=== CONT TestValidateToken_NoMatchingProvider2152=== CONT TestScopes_Rules2153--- PASS: TestPins_ConfigValidation (0.01s)2154=== CONT TestScopes_LegacyProviderDefaultsToWrite2155=== CONT TestScopes_ConfigValidation2156=== CONT TestValidateToken_BoundSubjectMismatch2157--- PASS: TestScopes_ConfigValidation (0.00s)2158=== CONT TestValidateToken_WrongAudience21592026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53795/oidc2160--- PASS: TestValidateToken_ValidToken (0.07s)2161=== CONT TestPins_ReservedForMatchingRule21622026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53798/oidc2163--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2164=== CONT TestPins_TopLevelShorthand21652026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53800/oidc21662026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53802/oidc2167--- PASS: TestValidateToken_WrongAudience (0.09s)2168=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2169--- PASS: TestPins_ReservedForMatchingRule (0.04s)2170=== CONT TestNewValidator_KubernetesRequiresCA21712026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53804/oidc21722026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53806/oidc2173--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)2174=== CONT TestGlobMatch/foo_foo2175=== CONT TestGlobMatch/*/*_foo/bar2176=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2177=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2178=== CONT TestGlobMatch/?oo_boo2179=== CONT TestGlobMatch/?oo_foo2180=== CONT TestGlobMatch/fo?_fooo2181=== CONT TestGlobMatch/fo?_fo2182=== CONT TestGlobMatch/fo?_foo2183=== CONT TestGlobMatch/refs/*/main_refs/heads/main2184=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02185=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2186=== CONT TestGlobMatch/*/*_foo2187=== CONT TestGlobMatch/*bar_bar2188=== CONT TestGlobMatch/foo*bar_foobarbaz2189=== CONT TestGlobMatch/foo*bar_foo123bar2190=== CONT TestGlobMatch/foo*bar_foobar2191=== CONT TestGlobMatch/*bar_foo2192=== CONT TestGlobMatch/*bar_foobar2193=== CONT TestGlobMatch/foo*_foo2194=== CONT TestGlobMatch/foo*_bar2195=== CONT TestGlobMatch/foo*_foobar2196=== CONT TestGlobMatch/*_2197=== CONT TestGlobMatch/*_anything2198=== CONT TestGlobMatch/foo_bar2199--- PASS: TestGlobMatch (0.00s)2200 --- PASS: TestGlobMatch/foo_foo (0.00s)2201 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2202 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2203 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2204 --- PASS: TestGlobMatch/?oo_boo (0.00s)2205 --- PASS: TestGlobMatch/?oo_foo (0.00s)2206 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2207 --- PASS: TestGlobMatch/fo?_fo (0.00s)2208 --- PASS: TestGlobMatch/fo?_foo (0.00s)2209 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2210 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2211 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2212 --- PASS: TestGlobMatch/*/*_foo (0.00s)2213 --- PASS: TestGlobMatch/*bar_bar (0.00s)2214 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2215 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2216 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2217 --- PASS: TestGlobMatch/*bar_foo (0.00s)2218 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2219 --- PASS: TestGlobMatch/foo*_foo (0.00s)2220 --- PASS: TestGlobMatch/foo*_bar (0.00s)2221 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2222 --- PASS: TestGlobMatch/*_ (0.00s)2223 --- PASS: TestGlobMatch/*_anything (0.00s)2224 --- PASS: TestGlobMatch/foo_bar (0.00s)2225--- PASS: TestScopes_Rules (0.11s)22262026/10/06 10:47:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53797/oidc2227--- PASS: TestValidateToken_NoMatchingProvider (0.13s)22282026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53810/oidc2229--- PASS: TestValidateToken_Expired (0.16s)22302026/10/06 10:47:10 http: TLS handshake error from 127.0.0.1:53813: remote error: tls: bad certificate2231--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)22322026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53814/oidc22332026/10/06 10:47:10 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:53794/oidc22342026/10/06 10:47:10 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:53816/oidc2235--- PASS: TestPins_TopLevelShorthand (0.10s)2236--- PASS: TestValidateToken_MultipleProviders (0.17s)22372026/10/06 10:47:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53819/oidc2238--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.20s)22392026/10/06 10:47:10 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:538212240--- PASS: TestValidateToken_KubernetesServiceAccount (0.24s)22412026/10/06 10:47:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232242--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)2243PASS2244Running hook tests...2245=== RUN TestSendPathsEmpty2246=== PAUSE TestSendPathsEmpty2247=== RUN TestQueueEnqueueAndFetch2248=== PAUSE TestQueueEnqueueAndFetch2249=== RUN TestQueueDeduplication2250=== PAUSE TestQueueDeduplication2251=== RUN TestQueueRemove2252=== PAUSE TestQueueRemove2253=== RUN TestQueueFetchBatchLimit2254=== PAUSE TestQueueFetchBatchLimit2255=== RUN TestQueueRetryMovesToBack2256=== PAUSE TestQueueRetryMovesToBack2257=== RUN TestQueueFetchRemoveLifecycle2258=== PAUSE TestQueueFetchRemoveLifecycle2259=== RUN TestQueueConcurrentWriters2260=== PAUSE TestQueueConcurrentWriters2261=== RUN TestQueueRemoveLargeClosure2262=== PAUSE TestQueueRemoveLargeClosure2263=== RUN TestServerClientIntegration2264=== PAUSE TestServerClientIntegration2265=== RUN TestServerQueueError2266=== PAUSE TestServerQueueError2267=== RUN TestGetListenerSocketActivation2268 server_test.go:210: === RUN TestGetListenerSocketActivation2269 --- PASS: TestGetListenerSocketActivation (0.00s)2270 PASS2271 2272--- PASS: TestGetListenerSocketActivation (0.01s)2273=== RUN TestDrainIsolatesPoisonPath2274=== PAUSE TestDrainIsolatesPoisonPath2275=== RUN TestRunNotBlockedByPoisonHead2276=== PAUSE TestRunNotBlockedByPoisonHead2277=== RUN TestDrainGivesUpWhenServerDown2278=== PAUSE TestDrainGivesUpWhenServerDown2279=== RUN TestFailedPathPrunedByLaterClosure2280=== PAUSE TestFailedPathPrunedByLaterClosure2281=== RUN TestWorkerUploadsAndRemoves2282=== PAUSE TestWorkerUploadsAndRemoves2283=== RUN TestWorkerSkipsGCdPaths2284=== PAUSE TestWorkerSkipsGCdPaths2285=== RUN TestWorkerPrunesClosureDeps2286=== PAUSE TestWorkerPrunesClosureDeps2287=== RUN TestDrainTimeout2288=== PAUSE TestDrainTimeout2289=== CONT TestSendPathsEmpty2290--- PASS: TestSendPathsEmpty (0.00s)2291=== CONT TestServerQueueError2292=== CONT TestQueueFetchBatchLimit2293=== CONT TestQueueRemove2294=== CONT TestQueueDeduplication2295=== CONT TestQueueEnqueueAndFetch2296=== CONT TestWorkerUploadsAndRemoves2297=== CONT TestDrainTimeout2298=== CONT TestWorkerPrunesClosureDeps2299=== CONT TestWorkerSkipsGCdPaths2300=== CONT TestQueueRemoveLargeClosure23012026/10/06 10:47:10 ERROR Failed to queue paths error="permission denied" count=12302--- PASS: TestServerQueueError (0.00s)2303=== CONT TestQueueRetryMovesToBack23042026/10/06 10:47:10 INFO Upload queue status pending=223052026/10/06 10:47:10 INFO Upload queue status pending=223062026/10/06 10:47:10 INFO Uploading batch count=123072026/10/06 10:47:10 INFO Uploading batch count=223082026/10/06 10:47:10 INFO Uploading batch count=22309--- PASS: TestQueueEnqueueAndFetch (0.01s)2310=== CONT TestServerClientIntegration23112026/10/06 10:47:10 INFO Upload queue status pending=223122026/10/06 10:47:10 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-24560-3109811407/TestWorkerSkipsGCdPaths849007506/002/nonexistent23132026/10/06 10:47:10 INFO Uploading batch count=12314--- PASS: TestQueueDeduplication (0.01s)2315=== CONT TestDrainGivesUpWhenServerDown2316--- PASS: TestServerClientIntegration (0.00s)2317=== CONT TestFailedPathPrunedByLaterClosure2318--- PASS: TestQueueRetryMovesToBack (0.01s)2319=== CONT TestQueueFetchRemoveLifecycle2320--- PASS: TestQueueFetchBatchLimit (0.01s)2321=== CONT TestRunNotBlockedByPoisonHead2322--- PASS: TestQueueRemove (0.01s)2323=== CONT TestDrainIsolatesPoisonPath23242026/10/06 10:47:10 INFO Uploading batch count=123252026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=123262026/10/06 10:47:10 INFO Uploading batch count=123272026/10/06 10:47:10 INFO Uploading batch count=123282026/10/06 10:47:10 INFO Uploading batch count=423292026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=423302026/10/06 10:47:10 INFO Upload queue status pending=323312026/10/06 10:47:10 INFO Uploading batch count=123322026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=123332026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainIsolatesPoisonPath2347263198/002/bbb2334--- PASS: TestQueueFetchRemoveLifecycle (0.00s)2335=== CONT TestQueueConcurrentWriters23362026/10/06 10:47:10 INFO Uploading batch count=223372026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=223382026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/a23392026/10/06 10:47:10 INFO Uploading batch count=123402026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=123412026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/b23422026/10/06 10:47:10 INFO Uploading batch count=223432026/10/06 10:47:10 INFO Uploading batch count=123442026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=223452026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=123462026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/c2347--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)23482026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/d23492026/10/06 10:47:10 INFO Uploading batch count=223502026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=223512026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/e23522026/10/06 10:47:10 INFO Uploading batch count=123532026/10/06 10:47:10 ERROR Upload failed error="upload failed" count=123542026/10/06 10:47:10 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-24560-3109811407/TestDrainGivesUpWhenServerDown1194377926/002/f23552026/10/06 10:47:10 ERROR Drain finished with paths left in queue remaining=123562026/10/06 10:47:10 ERROR Drain finished with paths left in queue remaining=102357--- PASS: TestDrainIsolatesPoisonPath (0.01s)2358--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2359--- PASS: TestWorkerPrunesClosureDeps (0.03s)2360--- PASS: TestWorkerUploadsAndRemoves (0.03s)2361--- PASS: TestWorkerSkipsGCdPaths (0.03s)2362--- PASS: TestQueueRemoveLargeClosure (0.04s)2363--- PASS: TestQueueConcurrentWriters (0.15s)23642026/10/06 10:47:10 ERROR Upload failed error="context deadline exceeded" count=223652026/10/06 10:47:10 ERROR Drain finished with paths left in queue remaining=42366--- PASS: TestDrainTimeout (0.21s)23672026/10/06 10:47:11 INFO Uploading batch count=123682026/10/06 10:47:11 INFO Uploading batch count=123692026/10/06 10:47:11 INFO Uploading batch count=123702026/10/06 10:47:11 ERROR Upload failed error="upload failed" count=123712026/10/06 10:47:11 INFO Uploading batch count=123722026/10/06 10:47:11 ERROR Upload failed error="upload failed" count=123732026/10/06 10:47:11 INFO Uploading batch count=123742026/10/06 10:47:11 ERROR Upload failed error="upload failed" count=123752026/10/06 10:47:11 INFO Uploading batch count=123762026/10/06 10:47:11 ERROR Upload failed error="upload failed" count=123772026/10/06 10:47:11 ERROR Drain finished with paths left in queue remaining=12378--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2379PASS2380Running signing tests...2381=== RUN TestExternalSigner2382=== PAUSE TestExternalSigner2383=== RUN TestExternalSignerWrongPublicKey2384=== PAUSE TestExternalSignerWrongPublicKey2385=== RUN TestExternalSignerErrors2386=== PAUSE TestExternalSignerErrors2387=== RUN TestExternalSignerRestartsAfterCrash2388=== PAUSE TestExternalSignerRestartsAfterCrash2389=== RUN TestExternalSignerProgramErrorKeepsProcess2390=== PAUSE TestExternalSignerProgramErrorKeepsProcess2391=== RUN TestExternalSignerClose2392=== PAUSE TestExternalSignerClose2393=== RUN TestExternalSignerRejectsInvalidPublicKey2394=== PAUSE TestExternalSignerRejectsInvalidPublicKey2395=== RUN TestExternalSignerCancellation2396=== PAUSE TestExternalSignerCancellation2397=== RUN TestGenerateFingerprint2398=== PAUSE TestGenerateFingerprint2399=== RUN TestParseSigningKey2400=== PAUSE TestParseSigningKey2401=== RUN TestSign2402=== PAUSE TestSign2403=== RUN TestSignBatch2404=== PAUSE TestSignBatch2405=== RUN TestNilKeyPublicKey2406=== PAUSE TestNilKeyPublicKey2407=== RUN TestSignErrors2408=== PAUSE TestSignErrors2409=== CONT TestExternalSigner2410=== CONT TestExternalSignerCancellation2411=== CONT TestSignBatch2412=== CONT TestExternalSignerProgramErrorKeepsProcess2413=== CONT TestParseSigningKey2414=== RUN TestParseSigningKey/valid_32-byte_key2415=== CONT TestExternalSignerErrors2416=== PAUSE TestParseSigningKey/valid_32-byte_key2417=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2418=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2419=== RUN TestParseSigningKey/no_colon2420=== RUN TestExternalSignerErrors/null2421=== PAUSE TestParseSigningKey/no_colon2422=== RUN TestParseSigningKey/empty_name2423=== PAUSE TestExternalSignerErrors/null2424=== PAUSE TestParseSigningKey/empty_name2425=== RUN TestExternalSignerErrors/wrong_signature_name2426=== CONT TestSignErrors2427=== PAUSE TestExternalSignerErrors/wrong_signature_name2428=== CONT TestGenerateFingerprint2429=== RUN TestExternalSignerErrors/invalid_signature_base642430=== RUN TestGenerateFingerprint/basic_with_references2431=== RUN TestParseSigningKey/invalid_base642432=== PAUSE TestParseSigningKey/invalid_base642433=== PAUSE TestGenerateFingerprint/basic_with_references2434=== PAUSE TestExternalSignerErrors/invalid_signature_base642435=== CONT TestExternalSignerRestartsAfterCrash2436=== RUN TestParseSigningKey/wrong_length2437=== PAUSE TestParseSigningKey/wrong_length2438=== CONT TestSign2439=== RUN TestGenerateFingerprint/no_references2440=== PAUSE TestGenerateFingerprint/no_references2441=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2442=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2443=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2444=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2445=== RUN TestGenerateFingerprint/invalid_nar_hash_length2446=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2447=== RUN TestGenerateFingerprint/invalid_store_path_prefix2448=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2449=== RUN TestGenerateFingerprint/invalid_reference_prefix2450=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2451=== CONT TestNilKeyPublicKey2452--- PASS: TestNilKeyPublicKey (0.00s)2453=== CONT TestExternalSignerRejectsInvalidPublicKey2454=== RUN TestExternalSignerRejectsInvalidPublicKey/#002455=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002456=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2457=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2458=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2459=== CONT TestExternalSignerWrongPublicKey2460=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2461=== RUN TestExternalSignerErrors/wrong_signature_length2462=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2463=== PAUSE TestExternalSignerErrors/wrong_signature_length2464=== RUN TestExternalSignerErrors/exit_at_startup2465=== PAUSE TestExternalSignerErrors/exit_at_startup2466=== RUN TestExternalSignerErrors/wrong_signatures_shape2467=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2468=== RUN TestExternalSignerErrors/program_error2469=== PAUSE TestExternalSignerErrors/program_error2470=== RUN TestExternalSignerErrors/wrong_id2471=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2472=== PAUSE TestExternalSignerErrors/wrong_id2473=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2474=== RUN TestExternalSignerErrors/missing_signatures2475=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2476=== PAUSE TestExternalSignerErrors/missing_signatures2477=== CONT TestExternalSignerClose2478=== RUN TestExternalSignerErrors/null_signatures2479=== PAUSE TestExternalSignerErrors/null_signatures2480=== RUN TestExternalSignerErrors/too_few_signatures2481=== PAUSE TestExternalSignerErrors/too_few_signatures2482=== RUN TestExternalSignerErrors/wrong_shape2483=== PAUSE TestExternalSignerErrors/wrong_shape2484=== RUN TestExternalSignerErrors/unrequested_key2485=== PAUSE TestExternalSignerErrors/unrequested_key2486=== RUN TestExternalSignerErrors/missing_signature_name2487=== PAUSE TestExternalSignerErrors/missing_signature_name2488=== RUN TestExternalSignerErrors/exit_on_request2489=== PAUSE TestExternalSignerErrors/exit_on_request2490=== RUN TestExternalSignerErrors/invalid_JSON2491=== PAUSE TestExternalSignerErrors/invalid_JSON2492=== CONT TestParseSigningKey/valid_32-byte_key2493=== RUN TestSignErrors/nil_key2494=== PAUSE TestSignErrors/nil_key2495=== RUN TestSignErrors/nil_narinfo2496=== CONT TestGenerateFingerprint/basic_with_references2497--- PASS: TestSign (0.00s)2498=== CONT TestGenerateFingerprint/invalid_reference_prefix2499=== PAUSE TestSignErrors/nil_narinfo2500=== RUN TestSignErrors/invalid_narinfo2501=== CONT TestGenerateFingerprint/invalid_store_path_prefix2502=== PAUSE TestSignErrors/invalid_narinfo2503=== CONT TestGenerateFingerprint/invalid_nar_hash_length2504=== RUN TestSignErrors/canceled2505=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2506=== PAUSE TestSignErrors/canceled2507=== CONT TestParseSigningKey/empty_name2508=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2509=== CONT TestGenerateFingerprint/no_references2510=== CONT TestParseSigningKey/wrong_length2511=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2512=== CONT TestParseSigningKey/no_colon2513=== CONT TestExternalSignerRejectsInvalidPublicKey/#002514=== CONT TestParseSigningKey/invalid_base642515=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2516--- PASS: TestGenerateFingerprint (0.00s)2517 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2518 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2519 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2520 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2521 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2522 --- PASS: TestGenerateFingerprint/no_references (0.00s)2523 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2524=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2525--- PASS: TestParseSigningKey (0.00s)2526 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2527 --- PASS: TestParseSigningKey/empty_name (0.00s)2528 --- PASS: TestParseSigningKey/wrong_length (0.00s)2529 --- PASS: TestParseSigningKey/no_colon (0.00s)2530 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2531 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2532=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2533=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2534=== CONT TestExternalSignerErrors/missing_signatures2535--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2536 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2537 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2538 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2539 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2540 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2541=== CONT TestExternalSignerErrors/null2542=== CONT TestExternalSignerErrors/null_signatures2543--- PASS: TestSignBatch (0.01s)2544=== CONT TestExternalSignerErrors/wrong_id2545--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.09s)2546=== CONT TestExternalSignerErrors/program_error2547--- PASS: TestExternalSignerCancellation (0.19s)2548=== CONT TestExternalSignerErrors/wrong_signatures_shape2549--- PASS: TestExternalSignerClose (0.23s)2550=== CONT TestExternalSignerErrors/exit_at_startup2551--- PASS: TestExternalSignerWrongPublicKey (0.30s)2552=== CONT TestExternalSignerErrors/wrong_signature_length2553--- PASS: TestExternalSignerRestartsAfterCrash (0.39s)2554=== CONT TestExternalSignerErrors/invalid_signature_base642555/nix/var/nix/builds/nix-24560-3109811407/TestExternalSignerRestartsAfterCrash3375700920/001/sign program: line 7: /nix/var/nix/builds/nix-24560-3109811407/TestExternalSignerRestartsAfterCrash3375700920/001/sign program.starts: No such file or directory2556--- PASS: TestExternalSigner (0.46s)2557=== CONT TestExternalSignerErrors/wrong_signature_name2558=== CONT TestExternalSignerErrors/missing_signature_name2559=== CONT TestExternalSignerErrors/invalid_JSON2560=== CONT TestExternalSignerErrors/exit_on_request2561=== CONT TestExternalSignerErrors/wrong_shape2562=== CONT TestExternalSignerErrors/unrequested_key2563=== CONT TestExternalSignerErrors/too_few_signatures2564=== CONT TestSignErrors/nil_key2565=== CONT TestSignErrors/nil_narinfo2566=== CONT TestSignErrors/canceled2567=== CONT TestSignErrors/invalid_narinfo2568--- PASS: TestSignErrors (0.00s)2569 --- PASS: TestSignErrors/nil_key (0.00s)2570 --- PASS: TestSignErrors/nil_narinfo (0.00s)2571 --- PASS: TestSignErrors/canceled (0.00s)2572 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2573--- PASS: TestExternalSignerErrors (0.00s)2574 --- PASS: TestExternalSignerErrors/null (0.51s)2575 --- PASS: TestExternalSignerErrors/missing_signatures (0.59s)2576 --- PASS: TestExternalSignerErrors/null_signatures (0.72s)2577 --- PASS: TestExternalSignerErrors/wrong_id (0.76s)2578 --- PASS: TestExternalSignerErrors/program_error (0.74s)2579 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.72s)2580 --- PASS: TestExternalSignerErrors/exit_at_startup (0.74s)2581 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.74s)2582 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.73s)2583 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.74s)2584 --- PASS: TestExternalSignerErrors/missing_signature_name (0.75s)2585 --- PASS: TestExternalSignerErrors/invalid_JSON (0.74s)2586 --- PASS: TestExternalSignerErrors/exit_on_request (0.68s)2587 --- PASS: TestExternalSignerErrors/wrong_shape (0.71s)2588 --- PASS: TestExternalSignerErrors/unrequested_key (0.71s)2589 --- PASS: TestExternalSignerErrors/too_few_signatures (0.71s)2590PASS2591Running OpenBao signer tests...2592=== RUN TestSign2593=== PAUSE TestSign2594=== RUN TestSignErrors2595=== PAUSE TestSignErrors2596=== RUN TestServe2597=== PAUSE TestServe2598=== RUN TestServeRejectsGarbage2599=== PAUSE TestServeRejectsGarbage2600=== CONT TestSign2601=== CONT TestServeRejectsGarbage2602=== CONT TestServe2603--- PASS: TestServeRejectsGarbage (0.00s)2604=== CONT TestSignErrors2605=== RUN TestSignErrors/invalid_base642606=== PAUSE TestSignErrors/invalid_base642607=== RUN TestSignErrors/http_error2608=== PAUSE TestSignErrors/http_error2609=== RUN TestSignErrors/invalid_json2610=== PAUSE TestSignErrors/invalid_json2611=== RUN TestSignErrors/no_prefix2612=== PAUSE TestSignErrors/no_prefix2613=== CONT TestSignErrors/invalid_base642614=== CONT TestSignErrors/invalid_json2615=== CONT TestSignErrors/http_error2616--- PASS: TestServe (0.00s)2617=== CONT TestSignErrors/no_prefix2618--- PASS: TestSign (0.00s)2619--- PASS: TestSignErrors (0.00s)2620 --- PASS: TestSignErrors/no_prefix (0.00s)2621 --- PASS: TestSignErrors/http_error (0.00s)2622 --- PASS: TestSignErrors/invalid_base64 (0.00s)2623 --- PASS: TestSignErrors/invalid_json (0.00s)2624PASS