niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #354
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestDoWithRetry_BodyReplayedViaGetBody100=== CONT TestSetClientTLSErrors101=== CONT TestScriptTokenEmptyCommand102--- PASS: TestScriptTokenEmptyCommand (0.00s)103=== CONT TestFileTokenMissing104=== CONT TestScriptTokenScriptFails105=== CONT TestScriptTokenBadJSON106=== CONT TestScriptTokenEmptyToken107=== CONT TestScriptTokenCachesUntilRefresh108=== CONT TestScriptTokenNoExpiryRerunsEveryCall109=== CONT TestFileTokenEmpty110--- PASS: TestFileTokenMissing (0.00s)111=== CONT TestFileTokenReadsAndCaches1122026/10/04 20:03:49 WARN Rate limiter enabled after throttle name=server-test rate=51132026/10/04 20:03:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49515114--- PASS: TestFileTokenReadsAndCaches (0.00s)115=== RUN TestSetClientTLSErrors/missing_cert_file116=== CONT TestStaticToken1172026/10/04 20:03:49 WARN Rate limiter backed off name=server-test rate=5118--- PASS: TestStaticToken (0.00s)119=== CONT TestEncodeNixBase321202026/10/04 20:03:49 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:49515121=== PAUSE TestSetClientTLSErrors/missing_cert_file122=== RUN TestEncodeNixBase32/test_string_hash123=== PAUSE TestEncodeNixBase32/test_string_hash124=== RUN TestEncodeNixBase32/empty_input125=== PAUSE TestEncodeNixBase32/empty_input126=== CONT TestResolveStorePath127=== RUN TestSetClientTLSErrors/missing_key_file128=== PAUSE TestSetClientTLSErrors/missing_key_file129=== RUN TestSetClientTLSErrors/missing_ca_file130--- PASS: TestDoServerRequestAttachesToken (0.00s)131=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess132=== PAUSE TestSetClientTLSErrors/missing_ca_file133=== RUN TestSetClientTLSErrors/invalid_ca_file134=== PAUSE TestSetClientTLSErrors/invalid_ca_file135=== CONT TestRateLimiterFeedback136=== RUN TestRateLimiterFeedback/429_enables_limiter137=== PAUSE TestRateLimiterFeedback/429_enables_limiter138=== RUN TestRateLimiterFeedback/503_enables_limiter139=== PAUSE TestRateLimiterFeedback/503_enables_limiter140=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter141=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter142=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter143=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter144=== CONT TestPathInfoCACompatibility145=== RUN TestPathInfoCACompatibility/null_ca_field146=== PAUSE TestPathInfoCACompatibility/null_ca_field147=== RUN TestPathInfoCACompatibility/old_string_format_-_text148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text149--- PASS: TestScriptTokenScriptFails (0.00s)150=== CONT TestParsePathInfoJSONMultiplePaths151=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths153=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1552026/10/04 20:03:49 WARN Rate limiter enabled after throttle name=server-test rate=5156--- PASS: TestFileTokenEmpty (0.00s)157=== CONT TestParsePathInfoJSON158=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive159=== RUN TestParsePathInfoJSON/Nix_format160=== PAUSE TestParsePathInfoJSON/Nix_format161=== RUN TestParsePathInfoJSON/Lix_format162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive163=== PAUSE TestParsePathInfoJSON/Lix_format164=== CONT TestPathInfoHashCompatibility165=== RUN TestParsePathInfoJSON/empty_input166=== RUN TestPathInfoCACompatibility/new_structured_format_-_text167=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text169=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method171=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon172=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method173=== PAUSE TestParsePathInfoJSON/empty_input174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon175=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI177=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512179=== RUN TestParsePathInfoJSON/whitespace_only180=== CONT TestEncodeNixBase32WithRealHash181=== CONT TestConvertHashToNix32182=== RUN TestConvertHashToNix32/SRI_format_to_Nix32183=== CONT TestUploadMultipart_PartsInParallel184=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32185=== RUN TestConvertHashToNix32/already_Nix32_format186=== PAUSE TestConvertHashToNix32/already_Nix32_format187=== RUN TestConvertHashToNix32/invalid_format188=== PAUSE TestConvertHashToNix32/invalid_format189=== CONT TestGetStorePathHash190=== RUN TestGetStorePathHash/valid_store_path191=== PAUSE TestGetStorePathHash/valid_store_path192=== RUN TestGetStorePathHash/basename_without_hyphen_should_error193=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error194=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error195=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error196=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error197=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error198=== CONT TestDumpPathWriterError199=== CONT TestDumpPathSingleFile200=== PAUSE TestParsePathInfoJSON/whitespace_only201=== RUN TestParsePathInfoJSON/invalid_JSON202=== PAUSE TestParsePathInfoJSON/invalid_JSON203=== CONT TestDumpPathMatchesNix204--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)205--- PASS: TestEncodeNixBase32WithRealHash (0.00s)206--- PASS: TestResolveStorePath (0.00s)207=== CONT TestUploadMultipart_SupersededByPeer208=== RUN TestUploadMultipart_SupersededByPeer/exists209=== PAUSE TestUploadMultipart_SupersededByPeer/exists210=== RUN TestUploadMultipart_SupersededByPeer/missing211=== PAUSE TestUploadMultipart_SupersededByPeer/missing212=== CONT TestPartSizeForNAR213=== RUN TestPartSizeForNAR/zero_stays_at_minimum214=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum215=== RUN TestPartSizeForNAR/small_stays_at_minimum216=== PAUSE TestPartSizeForNAR/small_stays_at_minimum217=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum218=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum219=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts220=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts221=== RUN TestPartSizeForNAR/1_TiB222=== PAUSE TestPartSizeForNAR/1_TiB223=== RUN TestPartSizeForNAR/5_TiB_S3_max_object224=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object225=== RUN TestPartSizeForNAR/capped_at_5_GiB226=== PAUSE TestPartSizeForNAR/capped_at_5_GiB227=== CONT TestStreamPushGivesUpOnDeadServer2282026/10/04 20:03:49 ERROR Upload failed error="connection refused" count=202292026/10/04 20:03:49 ERROR Server seems unavailable, giving up on batch untried=17230--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)231--- PASS: TestScriptTokenEmptyToken (0.01s)232=== CONT TestSetClientTLSDoesNotMutateDefaultTransport233=== CONT TestSetClientTLS234--- PASS: TestScriptTokenBadJSON (0.01s)235=== CONT TestClientSignaturesByStorePath236--- PASS: TestClientSignaturesByStorePath (0.00s)237=== CONT TestStreamPushReportsSignatures2382026/10/04 20:03:49 ERROR Upload failed error=boom count=1239--- PASS: TestStreamPushReportsSignatures (0.00s)240=== CONT TestStreamPushRequestLine2412026/10/04 20:03:49 ERROR Upload failed error=boom count=1242--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)243=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun244=== RUN TestSetClientTLS/rejects_connection_without_client_cert245=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert246=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA247=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA248=== RUN TestSetClientTLS/preserves_debug_logging_transport249=== PAUSE TestSetClientTLS/preserves_debug_logging_transport250=== CONT TestFilterOversizedClosures251=== RUN TestFilterOversizedClosures/no_limit_keeps_everything252=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything253=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped254=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped255=== RUN TestFilterOversizedClosures/all_closures_skipped256=== PAUSE TestFilterOversizedClosures/all_closures_skipped257=== CONT TestCaseHackSuffix2582026/10/04 20:03:49 INFO Garbage collection started259--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)260=== CONT TestStreamPushReportsEveryPath261--- PASS: TestStreamPushReportsEveryPath (0.00s)262=== CONT TestStreamPushIsolatesFailures2632026/10/04 20:03:49 ERROR Upload failed error="bad path" count=3264--- PASS: TestStreamPushIsolatesFailures (0.00s)265=== CONT TestStreamPushBatchesUnderLoad266--- PASS: TestStreamPushRequestLine (0.01s)267=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2682026/10/04 20:03:49 INFO Garbage collection started2692026/10/04 20:03:49 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=02702026/10/04 20:03:49 WARN Garbage collection finished on another replica; its statistics are not available here271--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)272=== CONT TestRegisterUploadedObjectReusesConnections273--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)274=== CONT TestShellSplitErrors275--- PASS: TestShellSplitErrors (0.00s)276=== CONT TestShellSplit277--- PASS: TestShellSplit (0.00s)278=== CONT TestEncodeNixBase32/test_string_hash279=== CONT TestEncodeNixBase32/empty_input280--- PASS: TestEncodeNixBase32 (0.00s)281 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)282 --- PASS: TestEncodeNixBase32/empty_input (0.00s)283=== CONT TestSetClientTLSErrors/missing_cert_file284=== CONT TestSetClientTLSErrors/missing_ca_file285--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)286=== CONT TestSetClientTLSErrors/invalid_ca_file287=== CONT TestSetClientTLSErrors/missing_key_file288=== CONT TestRateLimiterFeedback/429_enables_limiter289=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter290--- PASS: TestSetClientTLSErrors (0.01s)291 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)292 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)293 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)294 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)2952026/10/04 20:03:49 WARN Rate limiter enabled after throttle name=server-test rate=52962026/10/04 20:03:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:49583297=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2982026/10/04 20:03:49 WARN Rate limiter backed off name=server-test rate=5299=== CONT TestRateLimiterFeedback/503_enables_limiter300=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths301=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths302--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)303 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)304 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)305=== CONT TestPathInfoCACompatibility/null_ca_field306=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method307=== CONT TestPathInfoCACompatibility/new_structured_format_-_text308=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive309=== CONT TestPathInfoCACompatibility/old_string_format_-_text310--- PASS: TestPathInfoCACompatibility (0.00s)311 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)312 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)313 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)314 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)315 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== CONT TestConvertHashToNix32/SRI_format_to_Nix32318=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512319=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI320=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon321--- PASS: TestPathInfoHashCompatibility (0.00s)322 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)323 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)324 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)325 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)326=== CONT TestGetStorePathHash/valid_store_path327=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error328=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error329=== CONT TestGetStorePathHash/basename_without_hyphen_should_error330--- PASS: TestGetStorePathHash (0.00s)331 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)332 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)333 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)334 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)335=== CONT TestConvertHashToNix32/invalid_format336=== CONT TestConvertHashToNix32/already_Nix32_format337--- PASS: TestConvertHashToNix32 (0.00s)338 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)339 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)340 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)341=== CONT TestParsePathInfoJSON/Nix_format3422026/10/04 20:03:49 WARN Rate limiter enabled after throttle name=server-test rate=5343=== CONT TestParsePathInfoJSON/whitespace_only3442026/10/04 20:03:49 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:49601345=== CONT TestParsePathInfoJSON/invalid_JSON346=== CONT TestParsePathInfoJSON/empty_input347=== CONT TestParsePathInfoJSON/Lix_format348--- PASS: TestParsePathInfoJSON (0.00s)349 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)350 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)351 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)352 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)353 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)354=== CONT TestUploadMultipart_SupersededByPeer/exists3552026/10/04 20:03:49 WARN Rate limiter backed off name=server-test rate=5356--- PASS: TestRateLimiterFeedback (0.00s)357 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)359 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)360 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)361=== CONT TestUploadMultipart_SupersededByPeer/missing362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts364=== CONT TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestPartSizeForNAR/5_TiB_S3_max_object366=== CONT TestPartSizeForNAR/1_TiB367=== CONT TestPartSizeForNAR/small_stays_at_minimum368=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum369--- PASS: TestPartSizeForNAR (0.00s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)374 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)375 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)380 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)381=== CONT TestSetClientTLS/preserves_debug_logging_transport382=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA383=== CONT TestFilterOversizedClosures/no_limit_keeps_everything384=== CONT TestFilterOversizedClosures/all_closures_skipped3852026/10/04 20:03:49 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=50386=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3872026/10/04 20:03:49 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=2000388--- PASS: TestFilterOversizedClosures (0.00s)389 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)390 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)391 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)392--- PASS: TestDumpPathWriterError (0.04s)393--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3942026/10/04 20:03:49 http: TLS handshake error from 127.0.0.1:49607: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)399--- PASS: TestDumpPathSingleFile (0.05s)400--- PASS: TestCaseHackSuffix (0.04s)401--- PASS: TestDumpPathMatchesNix (0.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 "_nixbld10".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-5948-865822547/postgres3785813306/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-5948-865822547/postgres3785813306/data -l logfile start433434/nix/var/nix/builds/nix-5948-865822547/postgres3785813306:5432 - no response4352026-10-04 20:03:51.612 UTC [6005] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-04 20:03:51.612 UTC [6005] LOG: listening on Unix socket "/nix/var/nix/builds/nix-5948-865822547/postgres3785813306/.s.PGSQL.5432"4372026-10-04 20:03:51.614 UTC [6012] LOG: database system was shut down at 2026-10-04 20:03:51 UTC4382026-10-04 20:03:51.615 UTC [6005] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-5948-865822547/postgres3785813306:5432 - accepting connections440{"timestamp":"2026-10-04T20:03:51.829458Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"712de8ba-61cf-4093-b838-276644a7a360","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}441=== RUN TestService_AuthMiddleware442=== PAUSE TestService_AuthMiddleware443=== RUN TestService_AuthMiddleware_MTLSProxyHeader444=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader445=== RUN TestService_AuthMiddleware_MTLSBoundSubjects446=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects447=== RUN TestService_ReadAuthMiddleware448=== PAUSE TestService_ReadAuthMiddleware449=== RUN TestService_AuthMiddleware_OIDC450=== PAUSE TestService_AuthMiddleware_OIDC451=== RUN TestService_RequireScope_OIDC452=== PAUSE TestService_RequireScope_OIDC453=== RUN TestService_ReadScope_PublicByDefault454=== PAUSE TestService_ReadScope_PublicByDefault455=== RUN TestCacheConfigHandler456=== PAUSE TestCacheConfigHandler457=== RUN TestCacheStatsHandler458=== PAUSE TestCacheStatsHandler459=== RUN TestClientCADerivations460=== PAUSE TestClientCADerivations461=== RUN TestClientErrorHandling462=== PAUSE TestClientErrorHandling463=== RUN TestClientIntegration464=== PAUSE TestClientIntegration465=== RUN TestClientMultipleUploads466=== PAUSE TestClientMultipleUploads467=== RUN TestClientWithDependencies468=== PAUSE TestClientWithDependencies469=== RUN TestClientSharedPathCommittedMidPush470=== PAUSE TestClientSharedPathCommittedMidPush471=== RUN TestPinProtectsFromGC472=== PAUSE TestPinProtectsFromGC473=== RUN TestClientPushesUseOnePush474=== PAUSE TestClientPushesUseOnePush475=== RUN TestClientFallsBackToClosures476=== PAUSE TestClientFallsBackToClosures477=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock478=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== RUN TestResolveDBConnectionString480=== PAUSE TestResolveDBConnectionString481=== RUN TestConnectWaitsForAPeerMigration482=== PAUSE TestConnectWaitsForAPeerMigration483=== RUN TestLeadElectsOneAndHandsOver484=== PAUSE TestLeadElectsOneAndHandsOver485=== RUN TestLeadIncumbentWinsAfterRestart4862026/10/04 20:03:52 INFO lead: acquired remote=192.0.2.1:12344872026/10/04 20:03:53 INFO lead: released remote=192.0.2.1:12344882026/10/04 20:03:53 INFO lead: acquired remote=192.0.2.1:12344892026/10/04 20:03:54 INFO lead: released remote=192.0.2.1:1234490--- PASS: TestLeadIncumbentWinsAfterRestart (2.33s)491=== RUN TestLeadEndsOnShutdown492=== PAUSE TestLeadEndsOnShutdown493=== RUN TestLeadEndsWhenItsConnectionHangs4942026/10/04 20:03:55 INFO lead: acquired remote=192.0.2.1:12344952026-10-04 20:03:56.803 UTC [6105] FATAL: terminating connection due to administrator command4962026/10/04 20:03:57 INFO lead: acquired remote=192.0.2.1:12344972026/10/04 20:03:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"4982026/10/04 20:03:58 INFO lead: released remote=192.0.2.1:12344992026/10/04 20:03:58 INFO lead: released remote=192.0.2.1:1234500--- PASS: TestLeadEndsWhenItsConnectionHangs (3.94s)501=== RUN TestGCAdvisoryLockBlocksConcurrentRun502=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun503=== RUN TestGCBugBareHashReferences504=== PAUSE TestGCBugBareHashReferences505=== RUN TestGCMetrics506=== PAUSE TestGCMetrics507=== RUN TestPushDedupSurvivesConcurrentGC508=== PAUSE TestPushDedupSurvivesConcurrentGC509=== RUN TestDeduplicatedObjectsRecordedAsPending510=== PAUSE TestDeduplicatedObjectsRecordedAsPending511=== RUN TestGCSweepSkipsPendingObjects512=== PAUSE TestGCSweepSkipsPendingObjects513=== RUN TestTombstonedObjectOfferedWithoutWaiting514=== PAUSE TestTombstonedObjectOfferedWithoutWaiting515=== RUN TestGCSweepDeliversEachKeyOnce516=== PAUSE TestGCSweepDeliversEachKeyOnce517=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection518=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection519=== RUN TestForceGCDuringPushOffersSweptObject520=== PAUSE TestForceGCDuringPushOffersSweptObject521=== RUN TestFailedS3DeleteKeepsTombstone522=== PAUSE TestFailedS3DeleteKeepsTombstone523=== RUN TestSweepSkipsRowsLockedByPush524=== PAUSE TestSweepSkipsRowsLockedByPush525=== RUN TestRegisterCompletedObjectNeedsPendingRow526=== PAUSE TestRegisterCompletedObjectNeedsPendingRow527=== RUN TestGetExistingObjectsLocksRows528=== PAUSE TestGetExistingObjectsLocksRows529=== RUN TestSweepRechecksPendingAfterLocking530=== PAUSE TestSweepRechecksPendingAfterLocking531=== RUN TestPushWaitsForSweepHoldingRow532=== PAUSE TestPushWaitsForSweepHoldingRow533=== RUN TestCommitRacingPendingCleanupKeepsObjects534=== PAUSE TestCommitRacingPendingCleanupKeepsObjects535=== RUN TestGCEndsOnShutdown536=== PAUSE TestGCEndsOnShutdown537=== RUN TestGCTaskStore_StartNew538=== PAUSE TestGCTaskStore_StartNew539=== RUN TestGCTaskStore_DeduplicateSameParams540=== PAUSE TestGCTaskStore_DeduplicateSameParams541=== RUN TestGCTaskStore_ConflictDifferentParams542=== PAUSE TestGCTaskStore_ConflictDifferentParams543=== RUN TestGCTaskStore_GetEmpty544=== PAUSE TestGCTaskStore_GetEmpty545=== RUN TestGCTaskStore_GetReturnsLatest546=== PAUSE TestGCTaskStore_GetReturnsLatest547=== RUN TestGCTaskStore_CompletedAllowsNewTask548=== PAUSE TestGCTaskStore_CompletedAllowsNewTask549=== RUN TestGCTaskStore_PhaseUpdates550=== PAUSE TestGCTaskStore_PhaseUpdates551=== RUN TestGCTaskStore_Fail552=== PAUSE TestGCTaskStore_Fail553=== RUN TestGracefulShutdownDrainsInflight554=== PAUSE TestGracefulShutdownDrainsInflight555=== RUN TestService_healthCheckHandler556=== PAUSE TestService_healthCheckHandler557=== RUN TestService_readinessHandler558=== PAUSE TestService_readinessHandler559=== RUN TestGenerateLandingPage560=== PAUSE TestGenerateLandingPage561=== RUN TestCacheConfigHandlerMaxNarSize562=== PAUSE TestCacheConfigHandlerMaxNarSize563=== RUN TestCreatePendingClosureRejectsOversizedNAR564=== PAUSE TestCreatePendingClosureRejectsOversizedNAR565=== RUN TestNARDeduplicationMetadataUploadBug566=== PAUSE TestNARDeduplicationMetadataUploadBug567=== RUN TestMetricsInventory568=== PAUSE TestMetricsInventory569=== RUN TestService_NativeMTLS570=== PAUSE TestService_NativeMTLS571=== RUN TestServerTLSConfig572=== PAUSE TestServerTLSConfig573=== RUN TestMultipartCleanup574=== PAUSE TestMultipartCleanup575=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded576=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded577=== RUN TestPendingCleanupUsesOneCutoff578=== PAUSE TestPendingCleanupUsesOneCutoff579=== RUN TestObjectStatsTrigger580=== PAUSE TestObjectStatsTrigger581=== RUN TestOrphanedObjectsGC582=== PAUSE TestOrphanedObjectsGC583=== RUN TestOrphanedObjectsGCStressTest584=== PAUSE TestOrphanedObjectsGCStressTest585=== RUN TestCreatePin_ReservedPins586=== PAUSE TestCreatePin_ReservedPins587=== RUN TestPresentReportsOnlyClosureRoots588=== PAUSE TestPresentReportsOnlyClosureRoots589=== RUN TestPresentNotReportedWhileGCDeletesClosure590=== PAUSE TestPresentNotReportedWhileGCDeletesClosure591=== RUN TestParseSingleRange592=== PAUSE TestParseSingleRange593=== RUN TestProxyHeadersOnlyTrustedOnSocket594=== PAUSE TestProxyHeadersOnlyTrustedOnSocket595=== RUN TestIsValidCachePath596=== PAUSE TestIsValidCachePath597=== RUN TestReadProxyNarinfo598=== PAUSE TestReadProxyNarinfo599=== RUN TestReadProxyNarinfoAlreadyDecompressed600=== PAUSE TestReadProxyNarinfoAlreadyDecompressed601=== RUN TestReadProxyNarStreaming602=== PAUSE TestReadProxyNarStreaming603=== RUN TestReadProxy404604=== PAUSE TestReadProxy404605=== RUN TestReadProxyInvalidPath606=== PAUSE TestReadProxyInvalidPath607=== RUN TestReadProxyHead608=== PAUSE TestReadProxyHead609=== RUN TestReadProxyOutlastsServerWriteTimeout610=== PAUSE TestReadProxyOutlastsServerWriteTimeout611=== RUN TestReadProxyConditionalGet612=== PAUSE TestReadProxyConditionalGet613=== RUN TestReadProxyRootRedirectsToIndexHTML614=== PAUSE TestReadProxyRootRedirectsToIndexHTML615=== RUN TestReadProxyDisabled616=== PAUSE TestReadProxyDisabled617=== RUN TestReadRedirectNar618=== PAUSE TestReadRedirectNar619=== RUN TestReadRedirectKeepsNarinfoProxied620=== PAUSE TestReadRedirectKeepsNarinfoProxied621=== RUN TestReadProxyRangeRequest622=== PAUSE TestReadProxyRangeRequest623=== RUN TestReadRedirectUsesPublicS3URL624=== PAUSE TestReadRedirectUsesPublicS3URL625=== RUN TestPush_OverlappingRootsStoreOneRowPerKey626=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey627=== RUN TestPush_CompleteCommitsEveryRoot628=== PAUSE TestPush_CompleteCommitsEveryRoot629=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit630=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit631=== RUN TestPush_RejectsBadRequests632=== PAUSE TestPush_RejectsBadRequests633=== RUN TestPush_SignsNarinfosOfItsPendingObjects634=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects635=== RUN TestRedundantMultipartUpload636=== PAUSE TestRedundantMultipartUpload637=== RUN TestCompleteMultipartUpload_ErrorButObjectExists638=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists639=== RUN TestCompletedNarNotReofferedAcrossClosures640=== PAUSE TestCompletedNarNotReofferedAcrossClosures641=== RUN TestPresignedUploadRegisteredBeforeCommit642=== PAUSE TestPresignedUploadRegisteredBeforeCommit643=== RUN TestService_Rustfstest644=== PAUSE TestService_Rustfstest645=== RUN TestParseSize646=== PAUSE TestParseSize647=== RUN TestSkippedUploadsHandler648=== PAUSE TestSkippedUploadsHandler649=== RUN TestSystemdListenerNotActivated650--- PASS: TestSystemdListenerNotActivated (0.00s)651=== RUN TestWatchdogBeatsWhenHealthy652--- PASS: TestWatchdogBeatsWhenHealthy (0.05s)653=== RUN TestWatchdogSkipsWhenUnhealthy6542026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6552026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6562026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6572026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/04 20:03:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"663--- PASS: TestWatchdogSkipsWhenUnhealthy (0.22s)664=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle665=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle666=== RUN TestProxyWriteTimeout667=== PAUSE TestProxyWriteTimeout668=== RUN TestPendingClosureWriteTimeout669=== PAUSE TestPendingClosureWriteTimeout670=== RUN TestIsValidUploadKey671=== PAUSE TestIsValidUploadKey672=== RUN TestUploadHandlersRejectInvalidKeys673=== PAUSE TestUploadHandlersRejectInvalidKeys674=== RUN TestUploadHandlersRejectOversizedBody675=== PAUSE TestUploadHandlersRejectOversizedBody676=== RUN TestService_cleanupPendingClosuresHandler677=== PAUSE TestService_cleanupPendingClosuresHandler678=== RUN TestService_createPendingClosureHandler679=== PAUSE TestService_createPendingClosureHandler680=== RUN TestService_verifyS3Integrity681=== PAUSE TestService_verifyS3Integrity682=== RUN TestCompleteMultipartUnregistered683=== PAUSE TestCompleteMultipartUnregistered684=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT685=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT686=== CONT TestService_AuthMiddleware687=== CONT TestCreatePendingClosureRejectsOversizedNAR688=== CONT TestDeduplicatedObjectsRecordedAsPending6892026/10/04 20:03:58 INFO Received uploads request method=POST path=/api/pending_closures690=== CONT TestGCTaskStore_StartNew691--- PASS: TestGCTaskStore_StartNew (0.00s)692=== CONT TestCacheConfigHandlerMaxNarSize693=== CONT TestReadRedirectNar694=== CONT TestGCEndsOnShutdown695=== CONT TestCommitRacingPendingCleanupKeepsObjects696=== CONT TestPushWaitsForSweepHoldingRow697=== CONT TestParseSingleRange698=== RUN TestParseSingleRange/none699=== PAUSE TestParseSingleRange/none700=== CONT TestGCTaskStore_PhaseUpdates701=== RUN TestParseSingleRange/unknown_unit702=== PAUSE TestParseSingleRange/unknown_unit703=== RUN TestParseSingleRange/multi-range_ignored704=== PAUSE TestParseSingleRange/multi-range_ignored705=== RUN TestParseSingleRange/malformed_no_dash706=== PAUSE TestParseSingleRange/malformed_no_dash707=== RUN TestParseSingleRange/malformed_both_empty708=== CONT TestGracefulShutdownDrainsInflight709=== PAUSE TestParseSingleRange/malformed_both_empty710=== RUN TestParseSingleRange/malformed_end_before_start711=== PAUSE TestParseSingleRange/malformed_end_before_start712=== RUN TestGCEndsOnShutdown/before_the_run713=== PAUSE TestGCEndsOnShutdown/before_the_run714=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete715=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete716=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark717=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark718--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)719--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)720--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)721=== CONT TestGCTaskStore_GetEmpty722--- PASS: TestGCTaskStore_GetEmpty (0.00s)723=== CONT TestGCTaskStore_GetReturnsLatest724--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)725=== CONT TestGCTaskStore_CompletedAllowsNewTask726--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)727=== CONT TestPushDedupSurvivesConcurrentGC728=== CONT TestGCTaskStore_Fail729--- PASS: TestGCTaskStore_Fail (0.00s)730=== RUN TestParseSingleRange/closed731=== CONT TestGCMetrics732=== PAUSE TestParseSingleRange/closed733=== RUN TestParseSingleRange/open-ended734=== PAUSE TestParseSingleRange/open-ended735=== RUN TestParseSingleRange/end_clamped_to_size736=== CONT TestClientSharedPathCommittedMidPush737=== PAUSE TestParseSingleRange/end_clamped_to_size738=== RUN TestParseSingleRange/suffix739=== PAUSE TestParseSingleRange/suffix7402026/10/04 20:03:58 INFO Starting HTTP server address=127.0.0.1:49683741=== RUN TestParseSingleRange/suffix_exceeds_size742=== PAUSE TestParseSingleRange/suffix_exceeds_size743=== RUN TestParseSingleRange/single_byte744=== PAUSE TestParseSingleRange/single_byte745=== RUN TestParseSingleRange/start_past_EOF746=== PAUSE TestParseSingleRange/start_past_EOF747=== RUN TestParseSingleRange/start_far_past_EOF748=== PAUSE TestParseSingleRange/start_far_past_EOF749=== CONT TestGCBugBareHashReferences7502026/10/04 20:03:58 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestGracefulShutdownDrainsInflight (0.08s)752=== CONT TestGCAdvisoryLockBlocksConcurrentRun753--- PASS: TestReadRedirectNar (3.26s)754=== CONT TestLeadEndsOnShutdown7552026/10/04 20:04:02 INFO Received uploads request method=POST path=/api/pending_closures7562026/10/04 20:04:02 INFO Received uploads request method=POST path=/api/pending_closures757--- PASS: TestDeduplicatedObjectsRecordedAsPending (4.09s)758=== CONT TestLeadElectsOneAndHandsOver759--- PASS: TestPushWaitsForSweepHoldingRow (4.12s)760=== CONT TestConnectWaitsForAPeerMigration7612026/10/04 20:04:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"762--- PASS: TestService_AuthMiddleware (4.97s)763=== CONT TestResolveDBConnectionString764=== RUN TestResolveDBConnectionString/flag_wins765=== PAUSE TestResolveDBConnectionString/flag_wins766=== RUN TestResolveDBConnectionString/file_when_flag_empty767=== PAUSE TestResolveDBConnectionString/file_when_flag_empty768=== RUN TestResolveDBConnectionString/missing_file_is_an_error769=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error770=== RUN TestResolveDBConnectionString/PGHOST_allows_empty771=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty772=== RUN TestResolveDBConnectionString/nothing_configured773=== PAUSE TestResolveDBConnectionString/nothing_configured774=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock7752026/10/04 20:04:03 INFO Received push request method=POST path=/api/pushes7762026/10/04 20:04:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)7772026/10/04 20:04:03 INFO Uploading z6zv6lvhi992hjpp4j1gqra2iz3d27ir-top (256B)7782026/10/04 20:04:03 INFO Uploading yhfmy10fqddcl6lmvw7s7banwd397xq3-shared-dep (136B)7792026/10/04 20:04:03 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld10 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"780--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.30s)781=== CONT TestClientFallsBackToClosures7822026/10/04 20:04:03 WARN Failed to register uploaded object key=nar/0ghk2y6d7jarfdvzah26asby86sma6fhy0p2zxcc9pmvx65ch3ya.nar.zst error="server returned 404: 404 page not found\n"7832026/10/04 20:04:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"7842026/10/04 20:04:03 WARN Failed to register uploaded object key=z6zv6lvhi992hjpp4j1gqra2iz3d27ir.ls error="server returned 404: 404 page not found\n"7852026/10/04 20:04:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign7862026/10/04 20:04:03 INFO Signed narinfos id=1 count=27872026/10/04 20:04:03 WARN Failed to register uploaded object key=yhfmy10fqddcl6lmvw7s7banwd397xq3.ls error="server returned 404: 404 page not found\n"7882026/10/04 20:04:03 INFO Uploading 2 narinfos7892026/10/04 20:04:03 WARN Failed to register uploaded object key=yhfmy10fqddcl6lmvw7s7banwd397xq3.narinfo error="server returned 404: 404 page not found\n"7902026/10/04 20:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete7912026/10/04 20:04:03 WARN Failed to register uploaded object key=z6zv6lvhi992hjpp4j1gqra2iz3d27ir.narinfo error="server returned 404: 404 page not found\n"7922026/10/04 20:04:03 INFO Upload complete. (222ms)793=== NAME TestClientSharedPathCommittedMidPush794 client_integration_test.go:680: Retrieved narinfo from S3:795 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientSharedPathCommittedMidPush851916393/001/store/yhfmy10fqddcl6lmvw7s7banwd397xq3-shared-dep796 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst797 Compression: zstd798 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82799 NarSize: 136800 References: 801 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n802 client_integration_test.go:680: Retrieved narinfo from S3:803 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientSharedPathCommittedMidPush851916393/001/store/z6zv6lvhi992hjpp4j1gqra2iz3d27ir-top804 URL: nar/0ghk2y6d7jarfdvzah26asby86sma6fhy0p2zxcc9pmvx65ch3ya.nar.zst805 Compression: zstd806 NarHash: sha256:0ghk2y6d7jarfdvzah26asby86sma6fhy0p2zxcc9pmvx65ch3ya807 NarSize: 256808 References: /nix/var/nix/builds/nix-5948-865822547/TestClientSharedPathCommittedMidPush851916393/001/store/yhfmy10fqddcl6lmvw7s7banwd397xq3-shared-dep809 CA: text:sha256:0ns68kwhygblcdyirw5jigsb5xkbr8r14dwcn1wnw64q1275mqr6810--- PASS: TestClientSharedPathCommittedMidPush (5.61s)811=== CONT TestClientPushesUseOnePush8122026/10/04 20:04:04 INFO Received uploads request method=POST path=/api/pending_closures8132026/10/04 20:04:04 INFO Aborted multipart uploads count=0 kept=08142026/10/04 20:04:04 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=08152026/10/04 20:04:04 INFO Vacuumed table table=pending_closures8162026/10/04 20:04:04 INFO Vacuumed table table=pending_objects8172026/10/04 20:04:04 INFO Vacuumed table table=multipart_uploads8182026/10/04 20:04:04 INFO Vacuumed table table=closures8192026/10/04 20:04:04 INFO Vacuumed table table=objects8202026/10/04 20:04:04 INFO Aborted multipart uploads count=0 kept=08212026/10/04 20:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period8222026/10/04 20:04:04 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=08232026/10/04 20:04:04 INFO Vacuumed table table=pending_closures8242026/10/04 20:04:04 INFO Vacuumed table table=pending_objects8252026/10/04 20:04:04 INFO Vacuumed table table=multipart_uploads8262026/10/04 20:04:04 INFO Vacuumed table table=closures8272026/10/04 20:04:04 INFO Vacuumed table table=objects828--- PASS: TestPushDedupSurvivesConcurrentGC (6.35s)829=== CONT TestPinProtectsFromGC830--- PASS: TestGCBugBareHashReferences (6.58s)831=== CONT TestReadProxy4048322026/10/04 20:04:05 INFO Aborted multipart uploads count=0 kept=08332026/10/04 20:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period8342026/10/04 20:04:05 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=08352026/10/04 20:04:05 INFO Vacuumed table table=pending_closures8362026/10/04 20:04:05 INFO Vacuumed table table=pending_objects8372026/10/04 20:04:05 INFO Vacuumed table table=multipart_uploads8382026/10/04 20:04:05 INFO Vacuumed table table=closures8392026/10/04 20:04:05 INFO Vacuumed table table=objects840--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.89s)841=== CONT TestReadProxyDisabled8422026/10/04 20:04:05 INFO Aborted multipart uploads count=0 kept=08432026/10/04 20:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period8442026/10/04 20:04:05 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=08452026/10/04 20:04:05 INFO Vacuumed table table=pending_closures8462026/10/04 20:04:05 INFO Vacuumed table table=pending_objects8472026/10/04 20:04:05 INFO Vacuumed table table=multipart_uploads8482026/10/04 20:04:05 INFO Vacuumed table table=closures8492026/10/04 20:04:05 INFO Vacuumed table table=objects850--- PASS: TestGCMetrics (7.01s)851=== CONT TestReadProxyRootRedirectsToIndexHTML8522026/10/04 20:04:06 INFO lead: acquired remote=192.0.2.1:12348532026/10/04 20:04:06 INFO lead: acquired remote=192.0.2.1:12348542026/10/04 20:04:07 INFO lead: released remote=192.0.2.1:1234855--- PASS: TestLeadEndsOnShutdown (5.66s)856=== CONT TestReadProxyConditionalGet8572026/10/04 20:04:08 INFO lead: released remote=192.0.2.1:12348582026/10/04 20:04:08 INFO lead: acquired remote=192.0.2.1:12348592026/10/04 20:04:08 INFO Received uploads request method=POST path=/api/pending_closures8602026/10/04 20:04:08 INFO Received uploads request method=POST path=/api/pending_closures8612026/10/04 20:04:08 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8622026/10/04 20:04:08 INFO Uploading q73yihakzrw745pizqfclcbrnhg2v1fk-shared-dep (136B)8632026/10/04 20:04:08 INFO Uploading 8acllfn04jkxlq1zpv7sx6pb88g9cw29-a (248B)8642026/10/04 20:04:08 WARN Failed to register uploaded object key=wr7vvvjmlaardcpa8vykf3bck1b3hj25.ls error="server returned 404: 404 page not found\n"8652026/10/04 20:04:08 WARN Failed to register uploaded object key=q73yihakzrw745pizqfclcbrnhg2v1fk.ls error="server returned 404: 404 page not found\n"8662026/10/04 20:04:08 WARN Failed to register uploaded object key=8acllfn04jkxlq1zpv7sx6pb88g9cw29.ls error="server returned 404: 404 page not found\n"8672026/10/04 20:04:08 WARN Failed to register uploaded object key=nar/131nf9mlgrz88hycm7g7bi4c1rc6r24m4z62njw57gap8sgy6xkj.nar.zst error="server returned 404: 404 page not found\n"8682026/10/04 20:04:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign8692026/10/04 20:04:08 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8702026/10/04 20:04:08 INFO Signed narinfos id=2 count=28712026/10/04 20:04:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign8722026/10/04 20:04:08 INFO Signed narinfos id=1 count=28732026/10/04 20:04:08 INFO Uploading 4 narinfos8742026/10/04 20:04:08 WARN Failed to register uploaded object key=q73yihakzrw745pizqfclcbrnhg2v1fk.narinfo error="server returned 404: 404 page not found\n"8752026/10/04 20:04:08 WARN Failed to register uploaded object key=wr7vvvjmlaardcpa8vykf3bck1b3hj25.narinfo error="server returned 404: 404 page not found\n"8762026/10/04 20:04:08 WARN Failed to register uploaded object key=8acllfn04jkxlq1zpv7sx6pb88g9cw29.narinfo error="server returned 404: 404 page not found\n"8772026/10/04 20:04:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8782026/10/04 20:04:08 WARN Failed to register uploaded object key=q73yihakzrw745pizqfclcbrnhg2v1fk.narinfo error="server returned 404: 404 page not found\n"8792026/10/04 20:04:08 INFO Completed upload id=18802026/10/04 20:04:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete8812026/10/04 20:04:08 INFO Completed upload id=28822026/10/04 20:04:08 INFO Upload complete. (278ms)883=== NAME TestClientFallsBackToClosures884 client_pushes_test.go:112: Retrieved narinfo from S3:885 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientFallsBackToClosures75832986/001/store/q73yihakzrw745pizqfclcbrnhg2v1fk-shared-dep886 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst887 Compression: zstd888 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82889 NarSize: 136890 References: 891 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n892 client_pushes_test.go:112: Retrieved narinfo from S3:893 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientFallsBackToClosures75832986/001/store/8acllfn04jkxlq1zpv7sx6pb88g9cw29-a894 URL: nar/131nf9mlgrz88hycm7g7bi4c1rc6r24m4z62njw57gap8sgy6xkj.nar.zst895 Compression: zstd896 NarHash: sha256:131nf9mlgrz88hycm7g7bi4c1rc6r24m4z62njw57gap8sgy6xkj897 NarSize: 248898 References: /nix/var/nix/builds/nix-5948-865822547/TestClientFallsBackToClosures75832986/001/store/q73yihakzrw745pizqfclcbrnhg2v1fk-shared-dep899 CA: text:sha256:0q0qgd7ah8rwwnp73gvg11a5hpzagfc6z1zidwpgj5pffc93add1900 client_pushes_test.go:112: Retrieved narinfo from S3:901 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientFallsBackToClosures75832986/001/store/wr7vvvjmlaardcpa8vykf3bck1b3hj25-b902 URL: nar/131nf9mlgrz88hycm7g7bi4c1rc6r24m4z62njw57gap8sgy6xkj.nar.zst903 Compression: zstd904 NarHash: sha256:131nf9mlgrz88hycm7g7bi4c1rc6r24m4z62njw57gap8sgy6xkj905 NarSize: 248906 References: /nix/var/nix/builds/nix-5948-865822547/TestClientFallsBackToClosures75832986/001/store/q73yihakzrw745pizqfclcbrnhg2v1fk-shared-dep907 CA: text:sha256:0q0qgd7ah8rwwnp73gvg11a5hpzagfc6z1zidwpgj5pffc93add1908--- PASS: TestClientFallsBackToClosures (5.06s)909=== CONT TestReadProxyOutlastsServerWriteTimeout910--- PASS: TestReadProxy404 (3.89s)911=== CONT TestReadProxyHead9122026/10/04 20:04:08 INFO Received push request method=POST path=/api/pushes913--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (5.55s)914=== CONT TestReadProxyInvalidPath9152026/10/04 20:04:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9162026/10/04 20:04:09 INFO Uploading q7gbncvmpkvaailzxllx942qmb16xfq9-shared-dep (136B)9172026/10/04 20:04:09 INFO Uploading in7386ixw6gxb2kfb95n9zlymjqlkqvz-b (248B)9182026/10/04 20:04:09 WARN Failed to register uploaded object key=1sbjr0dazy68w6l8jkcjxp5pix2wycgf.ls error="server returned 404: 404 page not found\n"9192026/10/04 20:04:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9202026/10/04 20:04:09 WARN Failed to register uploaded object key=nar/09pcqw0x0sp79iqbp6zdi2izh7amdzgpdh8alf9hq2yby997a14q.nar.zst error="server returned 404: 404 page not found\n"9212026/10/04 20:04:09 WARN Failed to register uploaded object key=in7386ixw6gxb2kfb95n9zlymjqlkqvz.ls error="server returned 404: 404 page not found\n"9222026/10/04 20:04:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9232026/10/04 20:04:09 WARN Failed to register uploaded object key=q7gbncvmpkvaailzxllx942qmb16xfq9.ls error="server returned 404: 404 page not found\n"9242026/10/04 20:04:09 INFO Signed narinfos id=1 count=39252026/10/04 20:04:09 INFO Uploading 3 narinfos9262026/10/04 20:04:09 WARN Failed to register uploaded object key=1sbjr0dazy68w6l8jkcjxp5pix2wycgf.narinfo error="server returned 404: 404 page not found\n"9272026/10/04 20:04:09 WARN Failed to register uploaded object key=q7gbncvmpkvaailzxllx942qmb16xfq9.narinfo error="server returned 404: 404 page not found\n"9282026/10/04 20:04:09 INFO lead: released remote=192.0.2.1:1234929--- PASS: TestLeadElectsOneAndHandsOver (6.60s)930=== CONT TestFailedS3DeleteKeepsTombstone9312026/10/04 20:04:09 INFO Received complete push request method=POST path=/api/pushes/1/complete9322026/10/04 20:04:09 WARN Failed to register uploaded object key=in7386ixw6gxb2kfb95n9zlymjqlkqvz.narinfo error="server returned 404: 404 page not found\n"9332026/10/04 20:04:09 INFO Upload complete. (316ms)934=== NAME TestClientPushesUseOnePush935 client_pushes_test.go:97: Retrieved narinfo from S3:936 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientPushesUseOnePush1324129679/001/store/q7gbncvmpkvaailzxllx942qmb16xfq9-shared-dep937 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst938 Compression: zstd939 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82940 NarSize: 136941 References: 942 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n943 client_pushes_test.go:97: Retrieved narinfo from S3:944 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientPushesUseOnePush1324129679/001/store/1sbjr0dazy68w6l8jkcjxp5pix2wycgf-a945 URL: nar/09pcqw0x0sp79iqbp6zdi2izh7amdzgpdh8alf9hq2yby997a14q.nar.zst946 Compression: zstd947 NarHash: sha256:09pcqw0x0sp79iqbp6zdi2izh7amdzgpdh8alf9hq2yby997a14q948 NarSize: 248949 References: /nix/var/nix/builds/nix-5948-865822547/TestClientPushesUseOnePush1324129679/001/store/q7gbncvmpkvaailzxllx942qmb16xfq9-shared-dep950 CA: text:sha256:0sgsyckwy448kf9256dzk10wvkhqnfr82czzhqmqgginnrkpsz54951 client_pushes_test.go:97: Retrieved narinfo from S3:952 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientPushesUseOnePush1324129679/001/store/in7386ixw6gxb2kfb95n9zlymjqlkqvz-b953 URL: nar/09pcqw0x0sp79iqbp6zdi2izh7amdzgpdh8alf9hq2yby997a14q.nar.zst954 Compression: zstd955 NarHash: sha256:09pcqw0x0sp79iqbp6zdi2izh7amdzgpdh8alf9hq2yby997a14q956 NarSize: 248957 References: /nix/var/nix/builds/nix-5948-865822547/TestClientPushesUseOnePush1324129679/001/store/q7gbncvmpkvaailzxllx942qmb16xfq9-shared-dep958 CA: text:sha256:0sgsyckwy448kf9256dzk10wvkhqnfr82czzhqmqgginnrkpsz54959--- PASS: TestClientPushesUseOnePush (5.30s)960=== CONT TestSweepRechecksPendingAfterLocking961--- PASS: TestReadProxyDisabled (4.26s)962=== CONT TestGetExistingObjectsLocksRows963=== NAME TestPinProtectsFromGC964 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-5948-865822547/TestPinProtectsFromGC939487428/001/store/gy4qdzr6wylqnm54pl698cnpq1k7dvqr-pinned-file.txt965 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-5948-865822547/TestPinProtectsFromGC939487428/001/store/9b82yyn4hid8a4abm7pcy5yqjk7yvrp2-unpinned-file.txt9662026/10/04 20:04:10 INFO Received push request method=POST path=/api/pushes967--- PASS: TestReadProxyRootRedirectsToIndexHTML (4.59s)968=== CONT TestRegisterCompletedObjectNeedsPendingRow9692026/10/04 20:04:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9702026/10/04 20:04:10 INFO Uploading gy4qdzr6wylqnm54pl698cnpq1k7dvqr-pinned-file.txt (128B)9712026/10/04 20:04:10 WARN Failed to register uploaded object key=gy4qdzr6wylqnm54pl698cnpq1k7dvqr.ls error="server returned 404: 404 page not found\n"9722026/10/04 20:04:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9732026/10/04 20:04:10 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9742026/10/04 20:04:10 INFO Signed narinfos id=1 count=19752026/10/04 20:04:10 INFO Uploading 1 narinfos9762026/10/04 20:04:10 INFO Received complete push request method=POST path=/api/pushes/1/complete9772026/10/04 20:04:10 WARN Failed to register uploaded object key=gy4qdzr6wylqnm54pl698cnpq1k7dvqr.narinfo error="server returned 404: 404 page not found\n"9782026/10/04 20:04:10 INFO Upload complete. (326ms)9792026/10/04 20:04:10 INFO Received push request method=POST path=/api/pushes9802026/10/04 20:04:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9812026/10/04 20:04:10 INFO Uploading 9b82yyn4hid8a4abm7pcy5yqjk7yvrp2-unpinned-file.txt (128B)9822026/10/04 20:04:10 WARN Failed to register uploaded object key=9b82yyn4hid8a4abm7pcy5yqjk7yvrp2.ls error="server returned 404: 404 page not found\n"9832026/10/04 20:04:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9842026/10/04 20:04:10 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9852026/10/04 20:04:10 INFO Signed narinfos id=2 count=19862026/10/04 20:04:10 INFO Uploading 1 narinfos9872026/10/04 20:04:10 INFO Received complete push request method=POST path=/api/pushes/2/complete9882026/10/04 20:04:10 WARN Failed to register uploaded object key=9b82yyn4hid8a4abm7pcy5yqjk7yvrp2.narinfo error="server returned 404: 404 page not found\n"9892026/10/04 20:04:10 INFO Upload complete. (277ms)9902026/10/04 20:04:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures9912026/10/04 20:04:10 INFO Garbage collection started9922026/10/04 20:04:10 INFO Aborted multipart uploads count=0 kept=09932026/10/04 20:04:10 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/10/04 20:04:10 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=09952026/10/04 20:04:10 INFO Vacuumed table table=pending_closures9962026/10/04 20:04:10 INFO Vacuumed table table=pending_objects9972026/10/04 20:04:10 INFO Vacuumed table table=multipart_uploads9982026/10/04 20:04:10 INFO Vacuumed table table=closures9992026/10/04 20:04:10 INFO Vacuumed table table=objects1000--- PASS: TestConnectWaitsForAPeerMigration (9.06s)1001=== CONT TestSweepSkipsRowsLockedByPush1002--- PASS: TestReadProxyConditionalGet (4.40s)1003=== CONT TestGenerateLandingPage1004--- PASS: TestGenerateLandingPage (0.00s)1005=== CONT TestGCEndsOnShutdown/before_the_run10062026/10/04 20:04:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=010072026/10/04 20:04:12 INFO Received create pin request method=POST path=/api/pins/myapp10082026/10/04 20:04:12 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-5948-865822547/TestPinProtectsFromGC939487428/001/store/gy4qdzr6wylqnm54pl698cnpq1k7dvqr-pinned-file.txt narinfo_key=gy4qdzr6wylqnm54pl698cnpq1k7dvqr.narinfo10092026/10/04 20:04:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures10102026/10/04 20:04:12 INFO Garbage collection started10112026/10/04 20:04:12 INFO Aborted multipart uploads count=0 kept=010122026/10/04 20:04:12 WARN Force mode enabled - objects will be deleted immediately without grace period10132026/10/04 20:04:12 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=010142026/10/04 20:04:12 INFO Vacuumed table table=pending_closures10152026/10/04 20:04:12 INFO Vacuumed table table=pending_objects10162026/10/04 20:04:12 INFO Vacuumed table table=multipart_uploads10172026/10/04 20:04:12 INFO Vacuumed table table=closures10182026/10/04 20:04:12 INFO Vacuumed table table=objects1019--- PASS: TestReadProxyHead (4.31s)1020=== CONT TestCacheConfigHandler1021=== RUN TestCacheConfigHandler/full_config,_no_issuer1022=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1023=== RUN TestCacheConfigHandler/no_cache_url_configured1024=== PAUSE TestCacheConfigHandler/no_cache_url_configured1025=== RUN TestCacheConfigHandler/no_signing_keys1026=== PAUSE TestCacheConfigHandler/no_signing_keys1027=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1028=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1029=== CONT TestClientWithDependencies10302026/10/04 20:04:13 INFO Received uploads request method=POST path=/api/pending_closures10312026/10/04 20:04:14 INFO Aborted multipart uploads count=0 kept=010322026/10/04 20:04:14 WARN Force mode enabled - objects will be deleted immediately without grace period10332026/10/04 20:04:14 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10342026/10/04 20:04:14 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1035--- PASS: TestFailedS3DeleteKeepsTombstone (5.15s)1036=== CONT TestClientMultipleUploads1037--- PASS: TestReadProxyInvalidPath (5.42s)1038=== CONT TestClientIntegration1039=== NAME TestPinProtectsFromGC1040 client_integration_test.go:840: Pin successfully protected closure from garbage collection1041--- PASS: TestPinProtectsFromGC (10.10s)1042=== CONT TestClientErrorHandling1043=== RUN TestClientErrorHandling/InvalidStorePath1044=== PAUSE TestClientErrorHandling/InvalidStorePath1045=== RUN TestClientErrorHandling/InvalidAuthToken1046=== PAUSE TestClientErrorHandling/InvalidAuthToken1047=== RUN TestClientErrorHandling/ServerNotAvailable1048=== PAUSE TestClientErrorHandling/ServerNotAvailable1049=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT10502026/10/04 20:04:15 INFO Aborted multipart uploads count=0 kept=010512026/10/04 20:04:15 WARN Force mode enabled - objects will be deleted immediately without grace period10522026/10/04 20:04:15 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=010532026/10/04 20:04:15 INFO Vacuumed table table=pending_closures10542026/10/04 20:04:15 INFO Vacuumed table table=pending_objects10552026/10/04 20:04:15 INFO Vacuumed table table=multipart_uploads10562026/10/04 20:04:15 INFO Vacuumed table table=closures10572026/10/04 20:04:15 INFO Vacuumed table table=objects1058--- PASS: TestSweepRechecksPendingAfterLocking (5.82s)1059=== CONT TestClientCADerivations1060--- PASS: TestGetExistingObjectsLocksRows (5.74s)1061=== CONT TestCacheStatsHandler1062--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.57s)1063=== CONT TestService_readinessHandler1064=== CONT TestCompleteMultipartUnregistered10652026/10/04 20:04:16 INFO Aborted multipart uploads count=0 kept=010662026/10/04 20:04:16 WARN Force mode enabled - objects will be deleted immediately without grace period10672026/10/04 20:04:16 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=010682026/10/04 20:04:16 INFO Vacuumed table table=pending_closures10692026/10/04 20:04:16 INFO Vacuumed table table=pending_objects10702026/10/04 20:04:16 INFO Vacuumed table table=multipart_uploads10712026/10/04 20:04:16 INFO Vacuumed table table=closures10722026/10/04 20:04:16 INFO Vacuumed table table=objects10732026/10/04 20:04:16 INFO Aborted multipart uploads count=0 kept=010742026/10/04 20:04:16 WARN Force mode enabled - objects will be deleted immediately without grace period10752026/10/04 20:04:16 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=010762026/10/04 20:04:16 INFO Vacuumed table table=pending_closures10772026/10/04 20:04:16 INFO Vacuumed table table=pending_objects10782026/10/04 20:04:16 INFO Vacuumed table table=multipart_uploads10792026/10/04 20:04:16 INFO Vacuumed table table=closures10802026/10/04 20:04:16 INFO Vacuumed table table=objects1081--- PASS: TestSweepSkipsRowsLockedByPush (4.82s)1082=== CONT TestPendingCleanupUsesOneCutoff1083=== NAME TestClientWithDependencies1084 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-5948-865822547/TestClientWithDependencies4081770288/001/store/mq8b0dnjhrapj565kh1gs8gmpmyc1jhh-test-script1085 client_integration_test.go:615: Found 1 dependencies (including self)10862026/10/04 20:04:17 INFO Received push request method=POST path=/api/pushes10872026/10/04 20:04:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10882026/10/04 20:04:17 INFO Uploading mq8b0dnjhrapj565kh1gs8gmpmyc1jhh-test-script (136B)1089--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.92s)1090=== CONT TestPresentNotReportedWhileGCDeletesClosure10912026/10/04 20:04:17 WARN Failed to register uploaded object key=mq8b0dnjhrapj565kh1gs8gmpmyc1jhh.ls error="server returned 404: 404 page not found\n"10922026/10/04 20:04:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10932026/10/04 20:04:17 WARN Failed to register uploaded object key=log/5vx76jp8chc2afij32ivx09a3dkqgawq-test-script.drv error="server returned 404: 404 page not found\n"10942026/10/04 20:04:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10952026/10/04 20:04:17 INFO Signed narinfos id=1 count=110962026/10/04 20:04:17 INFO Uploading 1 narinfos10972026/10/04 20:04:17 INFO Received complete push request method=POST path=/api/pushes/1/complete10982026/10/04 20:04:17 WARN Failed to register uploaded object key=mq8b0dnjhrapj565kh1gs8gmpmyc1jhh.narinfo error="server returned 404: 404 page not found\n"1099=== NAME TestClientMultipleUploads1100 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-5948-865822547/TestClientMultipleUploads3899681840/001/store/pkddrdawh9y51wpn5cfya5mqh518g8b1-test-file-0.txt11012026/10/04 20:04:17 INFO Upload complete. (195ms)1102=== NAME TestClientWithDependencies1103 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-5948-865822547/TestClientWithDependencies4081770288/001/store) requires matching store prefix1104--- PASS: TestClientWithDependencies (4.74s)1105=== CONT TestPresentReportsOnlyClosureRoots1106=== NAME TestClientMultipleUploads1107 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-5948-865822547/TestClientMultipleUploads3899681840/001/store/xij7a2pdvjhml6lq5vvdrjh5i4sj2kmj-test-file-1.txt1108 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-5948-865822547/TestClientMultipleUploads3899681840/001/store/yyqs4flvzra9j091vlc9k4flpbakgpqb-test-file-2.txt1109=== NAME TestClientIntegration1110 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-5948-865822547/TestClientIntegration3894660998/002/store/0lxa13cmqbw0nlv5pnnywq6lxws21h7s-test-file.txt11112026/10/04 20:04:18 INFO Received push request method=POST path=/api/pushes11122026/10/04 20:04:18 INFO Received push request method=POST path=/api/pushes11132026/10/04 20:04:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11142026/10/04 20:04:18 INFO Uploading 0lxa13cmqbw0nlv5pnnywq6lxws21h7s-test-file.txt (152B)11152026/10/04 20:04:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11162026/10/04 20:04:18 INFO Uploading yyqs4flvzra9j091vlc9k4flpbakgpqb-test-file-2.txt (160B)11172026/10/04 20:04:18 INFO Uploading xij7a2pdvjhml6lq5vvdrjh5i4sj2kmj-test-file-1.txt (160B)11182026/10/04 20:04:18 INFO Uploading pkddrdawh9y51wpn5cfya5mqh518g8b1-test-file-0.txt (160B)11192026/10/04 20:04:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11202026/10/04 20:04:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11212026/10/04 20:04:18 WARN Failed to register uploaded object key=pkddrdawh9y51wpn5cfya5mqh518g8b1.ls error="server returned 404: 404 page not found\n"11222026/10/04 20:04:18 WARN Failed to register uploaded object key=yyqs4flvzra9j091vlc9k4flpbakgpqb.ls error="server returned 404: 404 page not found\n"11232026/10/04 20:04:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11242026/10/04 20:04:18 WARN Failed to register uploaded object key=0lxa13cmqbw0nlv5pnnywq6lxws21h7s.ls error="server returned 404: 404 page not found\n"11252026/10/04 20:04:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11262026/10/04 20:04:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11272026/10/04 20:04:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11282026/10/04 20:04:18 WARN Failed to register uploaded object key=xij7a2pdvjhml6lq5vvdrjh5i4sj2kmj.ls error="server returned 404: 404 page not found\n"11292026/10/04 20:04:18 INFO Signed narinfos id=1 count=111302026/10/04 20:04:18 INFO Signed narinfos id=1 count=311312026/10/04 20:04:18 INFO Uploading 1 narinfos11322026/10/04 20:04:18 INFO Uploading 3 narinfos11332026/10/04 20:04:18 WARN Failed to register uploaded object key=xij7a2pdvjhml6lq5vvdrjh5i4sj2kmj.narinfo error="server returned 404: 404 page not found\n"11342026/10/04 20:04:18 INFO Received complete push request method=POST path=/api/pushes/1/complete11352026/10/04 20:04:18 WARN Failed to register uploaded object key=pkddrdawh9y51wpn5cfya5mqh518g8b1.narinfo error="server returned 404: 404 page not found\n"11362026/10/04 20:04:18 INFO Received complete push request method=POST path=/api/pushes/1/complete11372026/10/04 20:04:18 WARN Failed to register uploaded object key=yyqs4flvzra9j091vlc9k4flpbakgpqb.narinfo error="server returned 404: 404 page not found\n"11382026/10/04 20:04:18 WARN Failed to register uploaded object key=0lxa13cmqbw0nlv5pnnywq6lxws21h7s.narinfo error="server returned 404: 404 page not found\n"11392026/10/04 20:04:18 INFO Upload complete. (206ms)11402026/10/04 20:04:18 INFO Upload complete. (207ms)1141=== NAME TestClientMultipleUploads1142 client_integration_test.go:369: Uploaded 3 paths in 248.866ms11432026/10/04 20:04:18 INFO All 1 paths already cached1144=== NAME TestClientIntegration1145 client_integration_test.go:312: Retrieved narinfo from S3:1146 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientIntegration3894660998/002/store/0lxa13cmqbw0nlv5pnnywq6lxws21h7s-test-file.txt1147 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1148 Compression: zstd1149 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11150 NarSize: 1521151 References: 1152 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11153 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1154 client_integration_test.go:313: Decompressed .ls content (64 bytes):1155 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1156 client_integration_test.go:316: Testing garbage collection...11572026/10/04 20:04:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures11582026/10/04 20:04:18 INFO Garbage collection started11592026/10/04 20:04:18 INFO Aborted multipart uploads count=0 kept=011602026/10/04 20:04:18 WARN Force mode enabled - objects will be deleted immediately without grace period11612026/10/04 20:04:18 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=01162--- PASS: TestClientMultipleUploads (4.24s)1163=== CONT TestCreatePin_ReservedPins11642026/10/04 20:04:18 INFO Vacuumed table table=pending_closures11652026/10/04 20:04:18 INFO Vacuumed table table=pending_objects11662026/10/04 20:04:18 INFO Vacuumed table table=multipart_uploads11672026/10/04 20:04:18 INFO Vacuumed table table=closures11682026/10/04 20:04:18 INFO Received uploads request method=POST path=/api/pending_closures11692026/10/04 20:04:18 INFO Vacuumed table table=objects11702026/10/04 20:04:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50039/oidc1171--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.88s)1172=== CONT TestOrphanedObjectsGCStressTest1173--- PASS: TestCacheStatsHandler (4.28s)1174=== CONT TestOrphanedObjectsGC11752026/10/04 20:04:19 WARN readiness check failed error="closed pool"1176--- PASS: TestService_readinessHandler (4.17s)1177=== CONT TestObjectStatsTrigger1178=== NAME TestClientCADerivations1179 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-5948-865822547/TestClientCADerivations2161445489/001/store/63bcp1ln5g6m57l3mc1syznw1hgi7wxn-ca-test1180 client_ca_test.go:139: Found 1 dependencies (including self)11812026/10/04 20:04:20 INFO Received push request method=POST path=/api/pushes11822026/10/04 20:04:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11832026/10/04 20:04:20 INFO Uploading 63bcp1ln5g6m57l3mc1syznw1hgi7wxn-ca-test (144B)11842026/10/04 20:04:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11852026/10/04 20:04:20 WARN Failed to register uploaded object key=63bcp1ln5g6m57l3mc1syznw1hgi7wxn.ls error="server returned 404: 404 page not found\n"11862026/10/04 20:04:20 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11872026/10/04 20:04:20 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1188--- PASS: TestCompleteMultipartUnregistered (3.99s)1189=== CONT TestService_verifyS3Integrity11902026/10/04 20:04:20 WARN Failed to register uploaded object key=log/b7qz3w7zd927nijbcpvd5ciycrnyk20k-ca-test.drv error="server returned 404: 404 page not found\n"11912026/10/04 20:04:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11922026/10/04 20:04:20 INFO Signed narinfos id=1 count=111932026/10/04 20:04:20 INFO Uploading 1 narinfos11942026/10/04 20:04:20 INFO Received complete push request method=POST path=/api/pushes/1/complete11952026/10/04 20:04:20 WARN Failed to register uploaded object key=63bcp1ln5g6m57l3mc1syznw1hgi7wxn.narinfo error="server returned 404: 404 page not found\n"11962026/10/04 20:04:20 INFO Upload complete. (277ms)1197=== NAME TestClientCADerivations1198 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-5948-865822547/TestClientCADerivations2161445489/001/store/63bcp1ln5g6m57l3mc1syznw1hgi7wxn-ca-test1199 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1200 Compression: zstd1201 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1202 NarSize: 1441203 References: 1204 Deriver: /nix/var/nix/builds/nix-5948-865822547/TestClientCADerivations2161445489/001/store/b7qz3w7zd927nijbcpvd5ciycrnyk20k-ca-test.drv1205 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1206 client_ca_test.go:185: Checking for realisation files in S3...1207 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1208 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache12092026/10/04 20:04:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01210=== NAME TestClientIntegration1211 client_integration_test.go:323: Objects in database after GC:1212 client_integration_test.go:323: Successfully deleted all objects with GC --force1213=== NAME TestClientCADerivations1214 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket36?endpoint=http://localhost:49616®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-5948-865822547/TestClientCADerivations2161445489/001/store'1215 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 112162026/10/04 20:04:20 INFO Received uploads request method=POST path=/api/pending_closures1217--- PASS: TestClientIntegration (6.01s)1218=== CONT TestService_createPendingClosureHandler1219--- PASS: TestClientCADerivations (5.35s)1220=== CONT TestService_cleanupPendingClosuresHandler12212026/10/04 20:04:20 INFO Received uploads request method=POST path=/api/pending_closures12222026/10/04 20:04:20 INFO Received cleanup request method=DELETE path=/api/pending_closures1223--- PASS: TestPresentNotReportedWhileGCDeletesClosure (4.09s)1224=== CONT TestGCSweepDeliversEachKeyOnce1225--- PASS: TestPresentReportsOnlyClosureRoots (3.96s)1226=== CONT TestForceGCDuringPushOffersSweptObject1227=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1228=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1229=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1230=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1231=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12322026/10/04 20:04:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12332026/10/04 20:04:23 WARN Refused reserved pin name=worker-x86_64-linux12342026/10/04 20:04:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12352026/10/04 20:04:23 INFO Received create pin request method=POST path=/api/pins/my-app12362026/10/04 20:04:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1237--- PASS: TestCreatePin_ReservedPins (5.39s)1238=== CONT TestUploadHandlersRejectOversizedBody1239=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1240=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1241=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1242=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1243=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1244=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1245=== CONT TestUploadHandlersRejectInvalidKeys1246=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1247=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1248=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1249=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1250=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1251=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1252=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1253=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1254=== CONT TestIsValidUploadKey1255=== RUN TestIsValidUploadKey/narinfo1256=== PAUSE TestIsValidUploadKey/narinfo1257=== RUN TestIsValidUploadKey/nar_zst1258=== PAUSE TestIsValidUploadKey/nar_zst1259=== RUN TestIsValidUploadKey/nar_xz1260=== PAUSE TestIsValidUploadKey/nar_xz1261=== RUN TestIsValidUploadKey/nar_plain1262=== PAUSE TestIsValidUploadKey/nar_plain1263=== RUN TestIsValidUploadKey/listing1264=== PAUSE TestIsValidUploadKey/listing1265=== RUN TestIsValidUploadKey/build_log1266=== PAUSE TestIsValidUploadKey/build_log1267=== RUN TestIsValidUploadKey/build_log_home-manager_file1268=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1269=== RUN TestIsValidUploadKey/build_log_plus_in_name1270=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1271=== RUN TestIsValidUploadKey/build_log_question_mark1272=== PAUSE TestIsValidUploadKey/build_log_question_mark1273=== RUN TestIsValidUploadKey/build_log_equals1274=== PAUSE TestIsValidUploadKey/build_log_equals1275=== RUN TestIsValidUploadKey/realisation1276=== PAUSE TestIsValidUploadKey/realisation1277=== RUN TestIsValidUploadKey/realisation_plus_in_output1278=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1279=== RUN TestIsValidUploadKey/nix-cache-info1280=== PAUSE TestIsValidUploadKey/nix-cache-info1281=== RUN TestIsValidUploadKey/index.html1282=== PAUSE TestIsValidUploadKey/index.html1283=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1284=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1285=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1286=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1287=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1288=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1289=== RUN TestIsValidUploadKey/traversal1290=== PAUSE TestIsValidUploadKey/traversal1291=== RUN TestIsValidUploadKey/traversal_nar1292=== PAUSE TestIsValidUploadKey/traversal_nar1293=== RUN TestIsValidUploadKey/absolute1294=== PAUSE TestIsValidUploadKey/absolute1295=== RUN TestIsValidUploadKey/empty_key1296=== PAUSE TestIsValidUploadKey/empty_key1297=== RUN TestIsValidUploadKey/unknown_type1298=== PAUSE TestIsValidUploadKey/unknown_type1299=== CONT TestPendingClosureWriteTimeout1300=== RUN TestPendingClosureWriteTimeout/empty1301=== PAUSE TestPendingClosureWriteTimeout/empty1302=== RUN TestPendingClosureWriteTimeout/400_objects1303=== PAUSE TestPendingClosureWriteTimeout/400_objects1304=== RUN TestPendingClosureWriteTimeout/670k_objects1305=== PAUSE TestPendingClosureWriteTimeout/670k_objects1306=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1307=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1308=== CONT TestService_AuthMiddleware_OIDC13092026/10/04 20:04:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50108/oidc1310--- PASS: TestObjectStatsTrigger (5.25s)1311=== CONT TestService_ReadScope_PublicByDefault13122026/10/04 20:04:25 INFO Received uploads request method=POST path=/api/pending_closures1313=== NAME TestOrphanedObjectsGC1314 orphaned_objects_gc_test.go:290: GC Test Summary:1315 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1316 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1317 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1318 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1319 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1320--- PASS: TestOrphanedObjectsGC (6.28s)1321=== CONT TestService_RequireScope_OIDC13222026/10/04 20:04:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50130/oidc13232026/10/04 20:04:26 INFO Aborted multipart uploads count=1 kept=013242026/10/04 20:04:26 INFO Received uploads request method=POST path=/api/pending_closures13252026/10/04 20:04:26 INFO Received uploads request method=POST path=/api/pending_closures13262026/10/04 20:04:26 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/04 20:04:26 INFO Received cleanup request method=DELETE path=/api/pending_closures13282026/10/04 20:04:26 INFO Aborted multipart uploads count=1 kept=01329--- PASS: TestPendingCleanupUsesOneCutoff (10.19s)1330=== CONT TestServerTLSConfig1331=== RUN TestServerTLSConfig/no_client_CA1332=== PAUSE TestServerTLSConfig/no_client_CA1333=== RUN TestServerTLSConfig/missing_CA_file1334=== PAUSE TestServerTLSConfig/missing_CA_file1335=== RUN TestServerTLSConfig/not_a_PEM_file1336=== PAUSE TestServerTLSConfig/not_a_PEM_file1337=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded13382026/10/04 20:04:27 INFO Received cleanup request method=DELETE path=/api/pending_closures13392026/10/04 20:04:27 INFO Aborted multipart uploads count=0 kept=013402026/10/04 20:04:27 INFO Received uploads request method=POST path=/api/pending_closures13412026/10/04 20:04:27 INFO Received cleanup request method=DELETE path=/api/pending_closures13422026/10/04 20:04:27 INFO Aborted multipart uploads count=1 kept=013432026/10/04 20:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13442026-10-04 20:04:27.385 UTC [6646] ERROR: Closure does not exist: id=113452026-10-04 20:04:27.385 UTC [6646] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13462026-10-04 20:04:27.385 UTC [6646] STATEMENT: -- name: CommitPendingClosure :exec1347 SELECT commit_pending_closure($1::bigint)1348 1349--- PASS: TestService_cleanupPendingClosuresHandler (6.83s)1350=== CONT TestMultipartCleanup13512026/10/04 20:04:28 INFO Received uploads request method=POST path=/api/pending_closures13522026/10/04 20:04:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1353--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.40s)1354=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13552026/10/04 20:04:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LmFjM2M2ZDc2LWEyYzMtNGMxNS1hNzdiLTk1MTUyODI4NWU0MHgxNzkxMTQ0MjY1NjQwNjk4MDAw parts=1013562026/10/04 20:04:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13572026/10/04 20:04:28 INFO Completed upload id=113582026/10/04 20:04:28 INFO Received uploads request method=POST path=/api/pending_closures13592026/10/04 20:04:28 INFO Received uploads request method=POST path=/api/pending_closures13602026/10/04 20:04:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13612026/10/04 20:04:28 WARN Found objects in DB but missing from S3, will re-upload count=11362--- PASS: TestService_verifyS3Integrity (8.37s)1363=== CONT TestService_ReadAuthMiddleware13642026/10/04 20:04:28 INFO Aborted multipart uploads count=0 kept=013652026/10/04 20:04:28 WARN Force mode enabled - objects will be deleted immediately without grace period13662026/10/04 20:04: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=013672026/10/04 20:04:28 INFO Vacuumed table table=pending_closures13682026/10/04 20:04:28 INFO Vacuumed table table=pending_objects13692026/10/04 20:04:28 INFO Vacuumed table table=multipart_uploads13702026/10/04 20:04:28 INFO Vacuumed table table=closures13712026/10/04 20:04:28 INFO Vacuumed table table=objects1372--- PASS: TestGCSweepDeliversEachKeyOnce (7.04s)1373=== CONT TestGCTaskStore_ConflictDifferentParams1374--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1375=== CONT TestTombstonedObjectOfferedWithoutWaiting13762026/10/04 20:04:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13772026/10/04 20:04:29 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LjM4M2E2NTEwLWQ2OWEtNDI0MC1iODA4LWFmNzc5MjllNDczZngxNzkxMTQ0MjY2Njg3ODMyMDAw parts=1013782026/10/04 20:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13792026/10/04 20:04:29 INFO Completed upload id=113802026/10/04 20:04:29 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013812026/10/04 20:04:29 INFO Received uploads request method=POST path=/api/pending_closures13822026/10/04 20:04:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures13832026/10/04 20:04:29 INFO Aborted multipart uploads count=0 kept=013842026/10/04 20:04:29 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=013852026/10/04 20:04:29 INFO Vacuumed table table=pending_closures13862026/10/04 20:04:29 INFO Vacuumed table table=pending_objects13872026/10/04 20:04:29 INFO Vacuumed table table=multipart_uploads13882026/10/04 20:04:29 INFO Vacuumed table table=closures13892026/10/04 20:04:29 INFO Vacuumed table table=objects13902026/10/04 20:04:29 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001391--- PASS: TestService_createPendingClosureHandler (9.11s)1392=== CONT TestService_AuthMiddleware_MTLSProxyHeader1393=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1394=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1395=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1396=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1397=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1398=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1399=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1400=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1401=== CONT TestGCTaskStore_DeduplicateSameParams1402--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1403=== CONT TestReadProxyNarinfo1404--- PASS: TestService_ReadScope_PublicByDefault (5.48s)1405=== CONT TestReadProxyNarStreaming1406=== RUN TestService_RequireScope_OIDC/builder_may_write1407=== PAUSE TestService_RequireScope_OIDC/builder_may_write1408=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1409=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1410=== RUN TestService_RequireScope_OIDC/ops_may_admin1411=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1412=== RUN TestService_RequireScope_OIDC/ops_may_not_write1413=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1414=== RUN TestService_RequireScope_OIDC/reader_may_not_write1415=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1416=== RUN TestService_RequireScope_OIDC/static_token_may_admin1417=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1418=== RUN TestService_RequireScope_OIDC/static_token_may_write1419=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1420=== RUN TestService_RequireScope_OIDC/reader_may_read1421=== PAUSE TestService_RequireScope_OIDC/reader_may_read1422=== RUN TestService_RequireScope_OIDC/writer_implies_read1423=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1424=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1425=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1426=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1427=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1428=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1429=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1430=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1431=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1432=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1433=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1434=== CONT TestReadProxyNarinfoAlreadyDecompressed14352026/10/04 20:04:32 INFO Received uploads request method=POST path=/api/pending_closures1436--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.50s)1437=== CONT TestGCSweepSkipsPendingObjects14382026/10/04 20:04:32 INFO Received uploads request method=POST path=/api/pending_closures14392026/10/04 20:04:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14402026/10/04 20:04:32 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket56/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14412026/10/04 20:04:32 INFO Aborted multipart uploads count=0 kept=114422026/10/04 20:04:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14432026/10/04 20:04:32 INFO Aborted multipart uploads count=1 kept=01444--- PASS: TestMultipartCleanup (5.54s)1445=== CONT TestMetricsInventory1446--- PASS: TestService_ReadAuthMiddleware (4.66s)1447=== CONT TestService_NativeMTLS14482026/10/04 20:04:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14492026/10/04 20:04:33 WARN mTLS auth: bound subjects configured but subject DN unavailable14502026/10/04 20:04:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1451--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.16s)1452=== CONT TestProxyHeadersOnlyTrustedOnSocket1453=== NAME TestOrphanedObjectsGCStressTest1454 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1455 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion14562026/10/04 20:04:33 INFO Received uploads request method=POST path=/api/pending_closures1457--- PASS: TestTombstonedObjectOfferedWithoutWaiting (4.99s)1458=== CONT TestIsValidCachePath1459=== RUN TestIsValidCachePath/narinfo1460=== PAUSE TestIsValidCachePath/narinfo1461=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1462=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1463=== RUN TestIsValidCachePath/nar_zst1464=== PAUSE TestIsValidCachePath/nar_zst1465=== RUN TestIsValidCachePath/nar_xz1466=== PAUSE TestIsValidCachePath/nar_xz1467=== RUN TestIsValidCachePath/nar_bz21468=== PAUSE TestIsValidCachePath/nar_bz21469=== RUN TestIsValidCachePath/nar_uncompressed1470=== PAUSE TestIsValidCachePath/nar_uncompressed1471=== RUN TestIsValidCachePath/ls1472=== PAUSE TestIsValidCachePath/ls1473=== RUN TestIsValidCachePath/log1474=== PAUSE TestIsValidCachePath/log1475=== RUN TestIsValidCachePath/realisation1476=== PAUSE TestIsValidCachePath/realisation1477=== RUN TestIsValidCachePath/nix-cache-info1478=== PAUSE TestIsValidCachePath/nix-cache-info1479=== RUN TestIsValidCachePath/index.html1480=== PAUSE TestIsValidCachePath/index.html1481=== RUN TestIsValidCachePath/traversal_parent1482=== PAUSE TestIsValidCachePath/traversal_parent1483=== RUN TestIsValidCachePath/traversal_in_middle1484=== PAUSE TestIsValidCachePath/traversal_in_middle1485=== RUN TestIsValidCachePath/invalid_char_e1486=== PAUSE TestIsValidCachePath/invalid_char_e1487=== RUN TestIsValidCachePath/invalid_char_u1488=== PAUSE TestIsValidCachePath/invalid_char_u1489=== RUN TestIsValidCachePath/random_path1490=== PAUSE TestIsValidCachePath/random_path1491=== RUN TestIsValidCachePath/empty1492=== PAUSE TestIsValidCachePath/empty1493=== RUN TestIsValidCachePath/leading_slash1494=== PAUSE TestIsValidCachePath/leading_slash1495=== RUN TestIsValidCachePath/wrong_extension1496=== PAUSE TestIsValidCachePath/wrong_extension1497=== RUN TestIsValidCachePath/short_hash1498=== PAUSE TestIsValidCachePath/short_hash1499=== CONT TestNARDeduplicationMetadataUploadBug1500--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.70s)1501=== CONT TestPush_RejectsBadRequests15022026/10/04 20:04:34 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1503--- PASS: TestReadProxyNarStreaming (4.65s)1504=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15052026/10/04 20:04:35 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161506--- PASS: TestReadProxyNarinfo (5.23s)1507=== CONT TestParseSize1508--- PASS: TestParseSize (0.00s)1509=== CONT TestPresignedUploadRegisteredBeforeCommit1510--- PASS: TestReadProxyNarinfoAlreadyDecompressed (4.27s)1511=== CONT TestSkippedUploadsHandler15122026/10/04 20:04:35 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001513--- PASS: TestSkippedUploadsHandler (0.00s)1514=== CONT TestService_Rustfstest15152026/10/04 20:04:36 INFO Received uploads request method=POST path=/api/pending_closures15162026/10/04 20:04:36 INFO Aborted multipart uploads count=0 kept=015172026/10/04 20:04:36 WARN Force mode enabled - objects will be deleted immediately without grace period15182026/10/04 20:04: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=015192026/10/04 20:04:36 INFO Vacuumed table table=pending_closures15202026/10/04 20:04:36 INFO Vacuumed table table=pending_objects15212026/10/04 20:04:36 INFO Vacuumed table table=multipart_uploads15222026/10/04 20:04:36 INFO Vacuumed table table=closures15232026/10/04 20:04:36 INFO Vacuumed table table=objects1524--- PASS: TestGCSweepSkipsPendingObjects (4.74s)1525=== CONT TestCompletedNarNotReofferedAcrossClosures1526--- PASS: TestMetricsInventory (4.36s)1527=== CONT TestReadProxyRangeRequest15282026/10/04 20:04:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15292026/10/04 20:04:37 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1530--- PASS: TestService_NativeMTLS (4.53s)1531=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15322026/10/04 20:04:38 INFO Starting HTTP server address=/nix/var/nix/builds/nix-5948-865822547/TestProxyHeadersOnlyTrustedOnSocket1561755536/001/proxy.sock15332026/10/04 20:04:38 INFO Starting HTTP server address=127.0.0.1:5031515342026/10/04 20:04:38 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15352026/10/04 20:04:38 INFO Shutdown signal received, draining in-flight requests timeout=10s1536--- PASS: TestProxyHeadersOnlyTrustedOnSocket (4.96s)1537=== CONT TestReadRedirectKeepsNarinfoProxied1538=== NAME TestOrphanedObjectsGCStressTest1539 orphaned_objects_gc_test.go:509: Stress test completed successfully:1540 orphaned_objects_gc_test.go:510: - Active objects preserved: 201541 orphaned_objects_gc_test.go:511: - Objects deleted: 2101542 orphaned_objects_gc_test.go:512: - Total GC'd: 2101543--- PASS: TestOrphanedObjectsGCStressTest (20.28s)1544=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1545=== NAME TestNARDeduplicationMetadataUploadBug1546 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-5948-865822547/TestNARDeduplicationMetadataUploadBug1883064210/001/store/4ixqsc8ykfnaymjfmf228didvp9vw75q-file1.txt15472026/10/04 20:04:39 INFO Received push request method=POST path=/api/pushes15482026/10/04 20:04:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15492026/10/04 20:04:39 INFO Uploading 4ixqsc8ykfnaymjfmf228didvp9vw75q-file1.txt (160B)15502026/10/04 20:04:39 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15512026/10/04 20:04:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15522026/10/04 20:04:39 WARN Failed to register uploaded object key=4ixqsc8ykfnaymjfmf228didvp9vw75q.ls error="server returned 404: 404 page not found\n"15532026/10/04 20:04:39 INFO Signed narinfos id=1 count=115542026/10/04 20:04:39 INFO Uploading 1 narinfos1555=== RUN TestPush_RejectsBadRequests/no_objects1556=== PAUSE TestPush_RejectsBadRequests/no_objects1557=== RUN TestPush_RejectsBadRequests/bad_root1558=== PAUSE TestPush_RejectsBadRequests/bad_root1559=== RUN TestPush_RejectsBadRequests/root_not_in_objects1560=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1561=== RUN TestPush_RejectsBadRequests/no_roots1562=== PAUSE TestPush_RejectsBadRequests/no_roots1563=== CONT TestRedundantMultipartUpload15642026/10/04 20:04:39 INFO Received complete push request method=POST path=/api/pushes/1/complete15652026/10/04 20:04:39 WARN Failed to register uploaded object key=4ixqsc8ykfnaymjfmf228didvp9vw75q.narinfo error="server returned 404: 404 page not found\n"15662026/10/04 20:04:39 INFO Upload complete. (161ms)1567=== NAME TestNARDeduplicationMetadataUploadBug1568 metadata_upload_test.go:54: Retrieved narinfo from S3:1569 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestNARDeduplicationMetadataUploadBug1883064210/001/store/4ixqsc8ykfnaymjfmf228didvp9vw75q-file1.txt1570 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1571 Compression: zstd1572 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1573 NarSize: 1601574 References: 1575 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1576 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1577 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1578 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1579 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-5948-865822547/TestNARDeduplicationMetadataUploadBug1883064210/001/store/g9b5v0wrpbphly9vi1dl5s8a9sw9pcgp-file2.txt15802026/10/04 20:04:39 INFO Received push request method=POST path=/api/pushes15812026/10/04 20:04:39 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15822026/10/04 20:04:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15832026/10/04 20:04:39 WARN Failed to register uploaded object key=g9b5v0wrpbphly9vi1dl5s8a9sw9pcgp.ls error="server returned 404: 404 page not found\n"15842026/10/04 20:04:39 INFO Signed narinfos id=2 count=115852026/10/04 20:04:39 INFO Uploading 1 narinfos15862026/10/04 20:04:39 INFO Received complete push request method=POST path=/api/pushes/2/complete15872026/10/04 20:04:39 WARN Failed to register uploaded object key=g9b5v0wrpbphly9vi1dl5s8a9sw9pcgp.narinfo error="server returned 404: 404 page not found\n"15882026/10/04 20:04:39 INFO Upload complete. (77ms)1589 metadata_upload_test.go:76: Retrieved narinfo from S3:1590 StorePath: /nix/var/nix/builds/nix-5948-865822547/TestNARDeduplicationMetadataUploadBug1883064210/001/store/g9b5v0wrpbphly9vi1dl5s8a9sw9pcgp-file2.txt1591 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1592 Compression: zstd1593 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1594 NarSize: 1601595 References: 1596 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1597 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1598 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1599 {"version":1,"root":{"type":"regular","size":44}}16002026/10/04 20:04:39 INFO Received uploads request method=POST path=/api/pending_closures1601--- PASS: TestNARDeduplicationMetadataUploadBug (5.69s)1602=== CONT TestPush_SignsNarinfosOfItsPendingObjects16032026/10/04 20:04:39 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst16042026/10/04 20:04:39 INFO Received uploads request method=POST path=/api/pending_closures1605--- PASS: TestPresignedUploadRegisteredBeforeCommit (4.45s)1606=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16072026/10/04 20:04:39 INFO Received uploads request method=POST path=/api/pending_closures1608--- PASS: TestService_Rustfstest (4.63s)1609=== CONT TestPush_CompleteCommitsEveryRoot16102026/10/04 20:04:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16112026/10/04 20:04:40 INFO Received uploads request method=POST path=/api/pending_closures1612--- PASS: TestReadProxyRangeRequest (3.75s)1613=== CONT TestReadRedirectUsesPublicS3URL16142026/10/04 20:04:41 INFO Received push request method=POST path=/api/pushes16152026/10/04 20:04:41 INFO Received complete push request method=POST path=/api/pushes/1/complete16162026/10/04 20:04:41 INFO Received push request method=POST path=/api/pushes16172026/10/04 20:04:41 INFO Aborted multipart uploads count=0 kept=016182026/10/04 20:04:41 WARN Force mode enabled - objects will be deleted immediately without grace period16192026/10/04 20:04:41 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=016202026/10/04 20:04:41 INFO Vacuumed table table=pending_closures16212026/10/04 20:04:41 INFO Vacuumed table table=pending_objects16222026/10/04 20:04:41 INFO Vacuumed table table=multipart_uploads16232026/10/04 20:04:41 INFO Vacuumed table table=closures16242026/10/04 20:04:41 INFO Vacuumed table table=objects16252026/10/04 20:04:41 INFO Received complete push request method=POST path=/api/pushes/2/complete1626--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (4.02s)1627=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1628--- PASS: TestReadRedirectKeepsNarinfoProxied (3.39s)1629=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16302026/10/04 20:04:42 INFO Received uploads request method=POST path=/api/pending_closures16312026/10/04 20:04:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16322026/10/04 20:04:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16332026/10/04 20:04:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LjI0NWM0Y2EzLTdlNGUtNGNjMi1iYmVmLTEwNTBlYWZmODI0MngxNzkxMTQ0MjgyMTg1MTU2MDAw16342026/10/04 20:04:42 INFO Received uploads request method=POST path=/api/pending_closures16352026/10/04 20:04:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LjI0NWM0Y2EzLTdlNGUtNGNjMi1iYmVmLTEwNTBlYWZmODI0MngxNzkxMTQ0MjgyMTg1MTU2MDAw parts=11636--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.42s)1637=== CONT TestProxyWriteTimeout1638=== RUN TestProxyWriteTimeout/narinfo1639=== PAUSE TestProxyWriteTimeout/narinfo1640=== RUN TestProxyWriteTimeout/1_GiB_nar1641=== PAUSE TestProxyWriteTimeout/1_GiB_nar1642=== RUN TestProxyWriteTimeout/10_GiB_nar1643=== PAUSE TestProxyWriteTimeout/10_GiB_nar1644=== RUN TestProxyWriteTimeout/unknown_size1645=== PAUSE TestProxyWriteTimeout/unknown_size1646=== CONT TestService_healthCheckHandler16472026/10/04 20:04:42 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LmJjNmFjNWU4LWIyNTYtNGEyOS05ZmI3LTI0ODEyNTRjNTQyNXgxNzkxMTQ0MjgwNzA1MjY3MDAw parts=1216482026/10/04 20:04:42 INFO Received uploads request method=POST path=/api/pending_closures1649--- PASS: TestCompletedNarNotReofferedAcrossClosures (5.63s)1650=== CONT TestParseSingleRange/none1651=== CONT TestParseSingleRange/open-ended1652=== CONT TestParseSingleRange/start_far_past_EOF1653=== CONT TestParseSingleRange/start_past_EOF1654=== CONT TestParseSingleRange/single_byte1655=== CONT TestParseSingleRange/suffix_exceeds_size1656=== CONT TestParseSingleRange/suffix1657=== CONT TestParseSingleRange/end_clamped_to_size1658=== CONT TestParseSingleRange/malformed_both_empty1659=== CONT TestParseSingleRange/closed1660=== CONT TestParseSingleRange/malformed_end_before_start1661=== CONT TestParseSingleRange/multi-range_ignored1662=== CONT TestParseSingleRange/malformed_no_dash1663=== CONT TestParseSingleRange/unknown_unit1664--- PASS: TestParseSingleRange (0.00s)1665 --- PASS: TestParseSingleRange/none (0.00s)1666 --- PASS: TestParseSingleRange/open-ended (0.00s)1667 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1668 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1669 --- PASS: TestParseSingleRange/single_byte (0.00s)1670 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1671 --- PASS: TestParseSingleRange/suffix (0.00s)1672 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1673 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1674 --- PASS: TestParseSingleRange/closed (0.00s)1675 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1676 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1677 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1678 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1679=== CONT TestResolveDBConnectionString/flag_wins1680=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1681=== CONT TestResolveDBConnectionString/nothing_configured1682=== CONT TestResolveDBConnectionString/missing_file_is_an_error1683=== CONT TestResolveDBConnectionString/file_when_flag_empty1684=== CONT TestCacheConfigHandler/full_config,_no_issuer1685=== CONT TestCacheConfigHandler/no_signing_keys1686=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1687=== CONT TestCacheConfigHandler/no_cache_url_configured1688--- PASS: TestCacheConfigHandler (0.00s)1689 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1690 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1691 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1692 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1693=== CONT TestClientErrorHandling/InvalidStorePath1694--- PASS: TestResolveDBConnectionString (0.05s)1695 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1696 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1697 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1698 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1699 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)17002026/10/04 20:04:42 INFO Received uploads request method=POST path=/api/pending_closures17012026/10/04 20:04:42 INFO Received push request method=POST path=/api/pushes17022026/10/04 20:04:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17032026/10/04 20:04:42 INFO Signed narinfos id=1 count=11704--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.20s)1705=== CONT TestClientErrorHandling/ServerNotAvailable17062026/10/04 20:04:43 INFO Aborted multipart uploads count=0 kept=017072026/10/04 20:04:43 WARN Force mode enabled - objects will be deleted immediately without grace period17082026-10-04 20:04:43.139 UTC [6853] ERROR: canceling statement due to user request17092026-10-04 20:04:43.139 UTC [6853] STATEMENT: -- name: MarkStaleObjects :execrows1710 WITH RECURSIVE ct AS (1711 SELECT timezone('UTC', now()) AS now1712 ),1713 closure_reach AS (1714 -- Start with all closure keys1715 SELECT o.key, o.refs1716 FROM objects o1717 INNER JOIN closures c ON o.key = c.key1718 UNION1719 -- Recursively add all referenced objects1720 SELECT o.key, o.refs1721 FROM objects o1722 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1723 ),1724 reachable_objects AS (1725 SELECT DISTINCT key FROM closure_reach1726 ),1727 stale_objects AS (1728 SELECT o.key1729 FROM objects AS o, ct1730 WHERE1731 NOT EXISTS (1732 SELECT 11733 FROM reachable_objects ro1734 WHERE ro.key = o.key1735 )1736 AND NOT EXISTS (1737 SELECT 11738 FROM pending_objects AS po1739 WHERE po.key = o.key1740 )1741 AND o.deleted_at IS NULL -- Only mark fresh objects1742 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1743 FOR UPDATE1744 )1745 UPDATE objects1746 SET1747 deleted_at = ct.now,1748 first_deleted_at = COALESCE(first_deleted_at, ct.now)1749 FROM stale_objects, ct1750 WHERE objects.key = stale_objects.key1751 1752=== CONT TestClientErrorHandling/InvalidAuthToken17532026/10/04 20:04:43 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/present17542026/10/04 20:04:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=191.387365ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17552026/10/04 20:04:43 INFO Received push request method=POST path=/api/pushes17562026/10/04 20:04:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.961817ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17572026/10/04 20:04:43 INFO Received complete push request method=POST path=/api/pushes/1/complete1758--- PASS: TestPush_CompleteCommitsEveryRoot (3.26s)1759=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17602026/10/04 20:04:43 WARN Rate limiter enabled after throttle name=s3-test rate=517612026/10/04 20:04:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1762=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1763 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101764 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001765--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.50s)1766=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17672026/10/04 20:04:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=795.748249ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1768--- PASS: TestReadRedirectUsesPublicS3URL (2.90s)1769=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17702026/10/04 20:04:43 INFO Received uploads request method=POST path=/1771=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17722026/10/04 20:04:44 INFO Received request for more parts method=POST path=/1773=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17742026/10/04 20:04:44 INFO Received complete multipart upload request method=POST path=/1775--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1776 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1777 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1778 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1779=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17802026/10/04 20:04:44 INFO Received uploads request method=POST path=/1781=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17822026/10/04 20:04:44 INFO Received complete multipart upload request method=POST path=/1783=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17842026/10/04 20:04:44 INFO Received request for more parts method=POST path=/1785=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17862026/10/04 20:04:44 INFO Received uploads request method=POST path=/1787--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1788 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1789 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1790 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1791 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1792=== CONT TestIsValidUploadKey/narinfo1793=== CONT TestIsValidUploadKey/realisation_plus_in_output1794=== CONT TestIsValidUploadKey/unknown_type1795=== CONT TestIsValidUploadKey/empty_key1796=== CONT TestIsValidUploadKey/absolute1797=== CONT TestIsValidUploadKey/traversal_nar1798=== CONT TestIsValidUploadKey/traversal1799=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1800=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1801=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1802=== CONT TestIsValidUploadKey/index.html1803=== CONT TestIsValidUploadKey/nix-cache-info1804=== CONT TestIsValidUploadKey/build_log_home-manager_file1805=== CONT TestIsValidUploadKey/realisation1806=== CONT TestIsValidUploadKey/build_log_equals1807=== CONT TestIsValidUploadKey/build_log_question_mark1808=== CONT TestIsValidUploadKey/build_log_plus_in_name1809=== CONT TestIsValidUploadKey/build_log1810=== CONT TestIsValidUploadKey/nar_xz1811=== CONT TestIsValidUploadKey/listing1812=== CONT TestIsValidUploadKey/nar_zst1813=== CONT TestIsValidUploadKey/nar_plain1814--- PASS: TestIsValidUploadKey (0.00s)1815 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1816 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1817 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1818 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1819 --- PASS: TestIsValidUploadKey/absolute (0.00s)1820 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1821 --- PASS: TestIsValidUploadKey/traversal (0.00s)1822 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1823 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1824 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1825 --- PASS: TestIsValidUploadKey/index.html (0.00s)1826 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1827 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1828 --- PASS: TestIsValidUploadKey/realisation (0.00s)1829 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1830 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1831 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1832 --- PASS: TestIsValidUploadKey/build_log (0.00s)1833 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1834 --- PASS: TestIsValidUploadKey/listing (0.00s)1835 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1836 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1837=== CONT TestPendingClosureWriteTimeout/empty1838=== CONT TestPendingClosureWriteTimeout/670k_objects1839=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18402026/10/04 20:04:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18412026/10/04 20:04:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LmI5OTgyODg4LWMzMDMtNGMxOS1hNGE4LWQ0ZDg1MmE3MTI1ZXgxNzkxMTQ0MjgyNTIxNDk2MDAw parts=1218422026/10/04 20:04:44 INFO Received uploads request method=POST path=/api/pending_closures18432026/10/04 20:04:44 INFO Received uploads request method=POST path=/api/pending_closures18442026/10/04 20:04:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.720539766s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18452026/10/04 20:04:44 INFO Received push request method=POST path=/api/pushes1846--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.23s)1847=== CONT TestPendingClosureWriteTimeout/400_objects1848=== CONT TestServerTLSConfig/no_client_CA1849=== CONT TestServerTLSConfig/not_a_PEM_file1850=== CONT TestServerTLSConfig/missing_CA_file1851--- PASS: TestServerTLSConfig (0.00s)1852 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1853 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1854 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1855=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1856=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18572026/10/04 20:04:44 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]1858=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18592026/10/04 20:04:44 WARN Authentication failed token_preview=eyJhbGciOi...m5FNVHgMrQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1860=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1861=== CONT TestService_RequireScope_OIDC/builder_may_write1862=== CONT TestService_RequireScope_OIDC/reader_may_read1863=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1864=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18652026/10/04 20:04:44 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]1866=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1867=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1868=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1869=== CONT TestService_RequireScope_OIDC/writer_implies_read1870=== CONT TestService_RequireScope_OIDC/reader_may_not_write1871=== CONT TestService_RequireScope_OIDC/static_token_may_write1872=== CONT TestService_RequireScope_OIDC/static_token_may_admin1873=== CONT TestService_RequireScope_OIDC/ops_may_admin1874=== CONT TestService_RequireScope_OIDC/ops_may_not_write1875=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1876=== CONT TestIsValidCachePath/narinfo1877=== CONT TestIsValidCachePath/index.html1878=== CONT TestIsValidCachePath/nix-cache-info1879=== CONT TestIsValidCachePath/realisation1880=== CONT TestIsValidCachePath/log1881=== CONT TestIsValidCachePath/ls1882=== CONT TestIsValidCachePath/traversal_parent1883=== CONT TestIsValidCachePath/nar_uncompressed1884=== CONT TestIsValidCachePath/nar_bz21885=== CONT TestIsValidCachePath/nar_xz1886=== CONT TestIsValidCachePath/nar_zst1887=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1888=== CONT TestIsValidCachePath/empty1889=== CONT TestIsValidCachePath/short_hash1890=== CONT TestIsValidCachePath/wrong_extension1891=== CONT TestIsValidCachePath/leading_slash1892=== CONT TestIsValidCachePath/invalid_char_u1893=== CONT TestIsValidCachePath/random_path1894=== CONT TestIsValidCachePath/invalid_char_e1895=== CONT TestIsValidCachePath/traversal_in_middle1896--- PASS: TestIsValidCachePath (0.00s)1897 --- PASS: TestIsValidCachePath/narinfo (0.00s)1898 --- PASS: TestIsValidCachePath/index.html (0.00s)1899 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1900 --- PASS: TestIsValidCachePath/realisation (0.00s)1901 --- PASS: TestIsValidCachePath/log (0.00s)1902 --- PASS: TestIsValidCachePath/ls (0.00s)1903 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1904 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1905 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1906 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1907 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1908 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1909 --- PASS: TestIsValidCachePath/empty (0.00s)1910 --- PASS: TestIsValidCachePath/short_hash (0.00s)1911 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1912 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1913 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1914 --- PASS: TestIsValidCachePath/random_path (0.00s)1915 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1916 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1917=== CONT TestPush_RejectsBadRequests/no_objects19182026/10/04 20:04:44 INFO Received push request method=POST path=/api/pushes1919=== CONT TestPush_RejectsBadRequests/root_not_in_objects19202026/10/04 20:04:44 INFO Received push request method=POST path=/api/pushes1921=== CONT TestPush_RejectsBadRequests/no_roots19222026/10/04 20:04:44 INFO Received push request method=POST path=/api/pushes1923=== CONT TestPush_RejectsBadRequests/bad_root19242026/10/04 20:04:44 INFO Received push request method=POST path=/api/pushes1925=== CONT TestProxyWriteTimeout/narinfo1926=== CONT TestProxyWriteTimeout/10_GiB_nar1927=== CONT TestProxyWriteTimeout/unknown_size1928=== CONT TestProxyWriteTimeout/1_GiB_nar1929--- PASS: TestProxyWriteTimeout (0.00s)1930 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1931 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1932 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1933 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1934--- PASS: TestPush_RejectsBadRequests (5.05s)1935 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1936 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1937 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1938 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1939--- PASS: TestService_AuthMiddleware_OIDC (6.06s)1940 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1941 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1942 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1943 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1944--- PASS: TestService_RequireScope_OIDC (5.47s)1945 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19592026/10/04 20:04:45 INFO Aborted multipart uploads count=0 kept=019602026/10/04 20:04:45 WARN Force mode enabled - objects will be deleted immediately without grace period19612026/10/04 20:04:45 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:49616/bucket84/?delete=\": context canceled"1962--- PASS: TestGCEndsOnShutdown (0.00s)1963 --- PASS: TestGCEndsOnShutdown/before_the_run (4.33s)1964 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.42s)1965 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.35s)1966--- PASS: TestService_healthCheckHandler (3.22s)19672026/10/04 20:04:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19682026/10/04 20:04:46 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LjJlMjVmMzFmLTVhMjUtNDdhMy05MDgwLTNhNGQ4MmFhNGFkMngxNzkxMTQ0Mjg0NTMxMTU2MDAw error="Get \"http://127.0.0.1:1/bucket78/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19692026/10/04 20:04:46 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGJkYjllMGYtZGEyMC00NWY0LWJkYTEtNmY2Mzg5YjU5M2Y3LjIzZjNiOWU0LWExMTctNDc1Ny1iMGIwLTAzNjdkZWJjOTg3ZXgxNzkxMTQ0Mjg0NDgzNjc2MDAw parts=1219702026/10/04 20:04:46 INFO Received cleanup request method=DELETE path=/api/pending_closures19712026/10/04 20:04:46 INFO Aborted multipart uploads count=1 kept=01972--- PASS: TestRedundantMultipartUpload (6.86s)19732026/10/04 20:04:46 INFO Received uploads request method=POST path=/api/pending_closures19742026/10/04 20:04:46 INFO Aborted multipart uploads count=0 kept=019752026/10/04 20:04:46 WARN Force mode enabled - objects will be deleted immediately without grace period19762026/10/04 20:04:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19772026/10/04 20:04:46 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=019782026/10/04 20:04:46 INFO Vacuumed table table=pending_closures19792026/10/04 20:04:46 INFO Vacuumed table table=pending_objects19802026/10/04 20:04:46 INFO Vacuumed table table=multipart_uploads19812026/10/04 20:04:46 INFO Vacuumed table table=closures19822026/10/04 20:04:46 INFO Vacuumed table table=objects19832026/10/04 20:04:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19842026/10/04 20:04:46 INFO Received uploads request method=POST path=/api/pending_closures19852026/10/04 20:04:46 INFO Aborted multipart uploads count=0 kept=019862026/10/04 20:04:46 WARN Force mode enabled - objects will be deleted immediately without grace period19872026/10/04 20:04:46 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=019882026/10/04 20:04:46 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-config19892026/10/04 20:04:46 INFO Vacuumed table table=pending_closures19902026/10/04 20:04:46 INFO Vacuumed table table=pending_objects19912026/10/04 20:04:46 INFO Vacuumed table table=multipart_uploads19922026/10/04 20:04:46 INFO Vacuumed table table=closures19932026/10/04 20:04:46 INFO Vacuumed table table=objects1994--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1995 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (2.78s)1996 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.77s)19972026/10/04 20:04:46 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.411154ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19982026/10/04 20:04:46 INFO Received uploads request method=POST path=/api/pending_closures19992026/10/04 20:04:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=375.596454ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20002026/10/04 20:04:47 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=846.263615ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2001--- PASS: TestPendingClosureWriteTimeout (0.00s)2002 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2003 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2004 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2005 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.06s)20062026/10/04 20:04:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.685211893s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20072026/10/04 20:04:49 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"20082026/10/04 20:04:49 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-config20092026/10/04 20:04:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.687986ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20102026/10/04 20:04:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.914305ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20112026/10/04 20:04:50 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=745.882591ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20122026/10/04 20:04:51 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.508998247s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20132026/10/04 20:04:52 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_closures20142026/10/04 20:04:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.850546ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20152026/10/04 20:04:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.769592ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20162026/10/04 20:04:53 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=872.260979ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20172026/10/04 20:04:54 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.62944261s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2018--- PASS: TestClientErrorHandling (0.00s)2019 --- PASS: TestClientErrorHandling/InvalidStorePath (2.94s)2020 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.20s)2021 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.02s)2022PASS2023{"timestamp":"2026-10-04T20:04:55.871939Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50159","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(9)"}20242026-10-04 20:04:56.017 UTC [6005] LOG: received smart shutdown request20252026-10-04 20:04:56.018 UTC [6005] LOG: background worker "logical replication launcher" (PID 6015) exited with exit code 120262026-10-04 20:04:56.024 UTC [6010] LOG: shutting down20272026-10-04 20:04:56.024 UTC [6010] LOG: checkpoint starting: shutdown immediate20282026-10-04 20:04:57.329 UTC [6010] LOG: checkpoint complete: wrote 12977 buffers (79.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.732 s, sync=0.524 s, total=1.305 s; sync files=30669, longest=0.001 s, average=0.001 s; distance=431154 kB, estimate=431154 kB; lsn=0/1BC999A8, redo lsn=0/1BC999A820292026-10-04 20:04:57.335 UTC [6005] LOG: database system is shut down2030Running OIDC tests...2031=== RUN TestAudienceForIssuer2032=== PAUSE TestAudienceForIssuer2033=== RUN TestGlobMatch2034=== PAUSE TestGlobMatch2035=== RUN TestValidateToken_ValidToken2036=== PAUSE TestValidateToken_ValidToken2037=== RUN TestValidateToken_WrongAudience2038=== PAUSE TestValidateToken_WrongAudience2039=== RUN TestValidateToken_Expired2040=== PAUSE TestValidateToken_Expired2041=== RUN TestValidateToken_BoundClaimsMismatch2042=== PAUSE TestValidateToken_BoundClaimsMismatch2043=== RUN TestValidateToken_BoundSubjectMismatch2044=== PAUSE TestValidateToken_BoundSubjectMismatch2045=== RUN TestValidateToken_MultipleProviders2046=== PAUSE TestValidateToken_MultipleProviders2047=== RUN TestValidateToken_NoMatchingProvider2048=== PAUSE TestValidateToken_NoMatchingProvider2049=== RUN TestValidateToken_KubernetesServiceAccount2050=== PAUSE TestValidateToken_KubernetesServiceAccount2051=== RUN TestNewValidator_KubernetesRequiresCA2052=== PAUSE TestNewValidator_KubernetesRequiresCA2053=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2054=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2055=== RUN TestPins_ReservedForMatchingRule2056=== PAUSE TestPins_ReservedForMatchingRule2057=== RUN TestPins_TopLevelShorthand2058=== PAUSE TestPins_TopLevelShorthand2059=== RUN TestPins_ConfigValidation2060=== PAUSE TestPins_ConfigValidation2061=== RUN TestScopes_LegacyProviderDefaultsToWrite2062=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2063=== RUN TestScopes_Rules2064=== PAUSE TestScopes_Rules2065=== RUN TestScopes_ConfigValidation2066=== PAUSE TestScopes_ConfigValidation2067=== CONT TestAudienceForIssuer2068--- PASS: TestAudienceForIssuer (0.00s)2069=== CONT TestValidateToken_NoMatchingProvider2070=== CONT TestValidateToken_Expired2071=== CONT TestValidateToken_KubernetesServiceAccount2072=== CONT TestValidateToken_ValidToken2073=== CONT TestGlobMatch2074=== RUN TestGlobMatch/foo_foo2075=== CONT TestValidateToken_WrongAudience2076=== PAUSE TestGlobMatch/foo_foo2077=== RUN TestGlobMatch/foo_bar2078=== PAUSE TestGlobMatch/foo_bar2079=== RUN TestGlobMatch/*_2080=== PAUSE TestGlobMatch/*_2081=== RUN TestGlobMatch/*_anything2082=== PAUSE TestGlobMatch/*_anything2083=== RUN TestGlobMatch/foo*_foo2084=== PAUSE TestGlobMatch/foo*_foo2085=== RUN TestGlobMatch/foo*_foobar2086=== PAUSE TestGlobMatch/foo*_foobar2087=== RUN TestGlobMatch/foo*_bar2088=== PAUSE TestGlobMatch/foo*_bar2089=== CONT TestValidateToken_BoundSubjectMismatch2090=== RUN TestGlobMatch/*bar_bar2091=== PAUSE TestGlobMatch/*bar_bar2092=== RUN TestGlobMatch/*bar_foobar2093=== PAUSE TestGlobMatch/*bar_foobar2094=== RUN TestGlobMatch/*bar_foo2095=== CONT TestScopes_Rules2096=== CONT TestScopes_ConfigValidation2097=== CONT TestScopes_LegacyProviderDefaultsToWrite2098=== PAUSE TestGlobMatch/*bar_foo2099=== RUN TestGlobMatch/foo*bar_foobar2100=== PAUSE TestGlobMatch/foo*bar_foobar2101=== RUN TestGlobMatch/foo*bar_foo123bar2102=== PAUSE TestGlobMatch/foo*bar_foo123bar2103=== RUN TestGlobMatch/foo*bar_foobarbaz2104=== PAUSE TestGlobMatch/foo*bar_foobarbaz2105=== RUN TestGlobMatch/*/*_foo/bar2106=== PAUSE TestGlobMatch/*/*_foo/bar2107=== RUN TestGlobMatch/*/*_foo2108=== PAUSE TestGlobMatch/*/*_foo2109=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2110=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2111=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02112=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02113=== RUN TestGlobMatch/refs/*/main_refs/heads/main2114=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2115=== RUN TestGlobMatch/fo?_foo2116=== PAUSE TestGlobMatch/fo?_foo2117=== RUN TestGlobMatch/fo?_fo2118=== PAUSE TestGlobMatch/fo?_fo2119=== RUN TestGlobMatch/fo?_fooo2120=== PAUSE TestGlobMatch/fo?_fooo2121=== RUN TestGlobMatch/?oo_foo2122=== PAUSE TestGlobMatch/?oo_foo2123=== RUN TestGlobMatch/?oo_boo2124=== PAUSE TestGlobMatch/?oo_boo2125=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2126=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2127=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2128=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2129=== CONT TestValidateToken_BoundClaimsMismatch2130--- PASS: TestScopes_ConfigValidation (0.00s)2131=== CONT TestValidateToken_MultipleProviders21322026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50531/oidc21332026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50533/oidc2134--- PASS: TestValidateToken_Expired (0.03s)2135=== CONT TestPins_ReservedForMatchingRule2136--- PASS: TestScopes_Rules (0.03s)2137=== CONT TestPins_TopLevelShorthand21382026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50536/oidc2139--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)2140=== CONT TestValidateToken_KubernetesIssuerFromOwnToken21412026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50538/oidc2142--- PASS: TestValidateToken_BoundSubjectMismatch (0.05s)2143=== CONT TestNewValidator_KubernetesRequiresCA21442026/10/04 20:04:58 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5054021452026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50542/oidc2146--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)2147=== CONT TestPins_ConfigValidation2148--- PASS: TestValidateToken_ValidToken (0.08s)2149=== CONT TestGlobMatch/foo_foo2150=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2151=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2152=== CONT TestGlobMatch/?oo_boo2153=== CONT TestGlobMatch/?oo_foo2154=== CONT TestGlobMatch/fo?_fooo2155=== CONT TestGlobMatch/fo?_fo2156=== CONT TestGlobMatch/fo?_foo2157=== CONT TestGlobMatch/refs/*/main_refs/heads/main2158=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02159=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2160=== CONT TestGlobMatch/*/*_foo2161=== CONT TestGlobMatch/*/*_foo/bar2162=== CONT TestGlobMatch/foo*bar_foobarbaz2163=== CONT TestGlobMatch/foo*bar_foo123bar2164=== CONT TestGlobMatch/foo*bar_foobar2165=== CONT TestGlobMatch/*bar_foo2166=== CONT TestGlobMatch/*bar_foobar2167=== CONT TestGlobMatch/*bar_bar2168=== CONT TestGlobMatch/foo*_bar2169=== CONT TestGlobMatch/foo*_foobar2170=== CONT TestGlobMatch/foo*_foo2171=== CONT TestGlobMatch/*_anything2172=== CONT TestGlobMatch/*_2173=== CONT TestGlobMatch/foo_bar2174--- PASS: TestGlobMatch (0.00s)2175 --- PASS: TestGlobMatch/foo_foo (0.00s)2176 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2177 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2178 --- PASS: TestGlobMatch/?oo_boo (0.00s)2179 --- PASS: TestGlobMatch/?oo_foo (0.00s)2180 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2181 --- PASS: TestGlobMatch/fo?_fo (0.00s)2182 --- PASS: TestGlobMatch/fo?_foo (0.00s)2183 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2184 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2185 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2186 --- PASS: TestGlobMatch/*/*_foo (0.00s)2187 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2188 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2189 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2190 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2191 --- PASS: TestGlobMatch/*bar_foo (0.00s)2192 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2193 --- PASS: TestGlobMatch/*bar_bar (0.00s)2194 --- PASS: TestGlobMatch/foo*_bar (0.00s)2195 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2196 --- PASS: TestGlobMatch/foo*_foo (0.00s)2197 --- PASS: TestGlobMatch/*_anything (0.00s)2198 --- PASS: TestGlobMatch/*_ (0.00s)2199 --- PASS: TestGlobMatch/foo_bar (0.00s)2200--- PASS: TestPins_ConfigValidation (0.00s)22012026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50545/oidc2202--- PASS: TestPins_ReservedForMatchingRule (0.06s)22032026/10/04 20:04:58 http: TLS handshake error from 127.0.0.1:50549: remote error: tls: bad certificate2204--- PASS: TestNewValidator_KubernetesRequiresCA (0.05s)22052026/10/04 20:04:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50535/oidc2206--- PASS: TestValidateToken_NoMatchingProvider (0.11s)22072026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50552/oidc2208--- PASS: TestValidateToken_WrongAudience (0.11s)22092026/10/04 20:04:58 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232210--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)22112026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50556/oidc2212--- PASS: TestPins_TopLevelShorthand (0.09s)22132026/10/04 20:04:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50558/oidc2214--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)22152026/10/04 20:04:58 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50560/oidc22162026/10/04 20:04:58 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50547/oidc2217--- PASS: TestValidateToken_MultipleProviders (0.17s)2218PASS2219Running hook tests...2220=== RUN TestSendPathsEmpty2221=== PAUSE TestSendPathsEmpty2222=== RUN TestQueueEnqueueAndFetch2223=== PAUSE TestQueueEnqueueAndFetch2224=== RUN TestQueueDeduplication2225=== PAUSE TestQueueDeduplication2226=== RUN TestQueueRemove2227=== PAUSE TestQueueRemove2228=== RUN TestQueueFetchBatchLimit2229=== PAUSE TestQueueFetchBatchLimit2230=== RUN TestQueueRetryMovesToBack2231=== PAUSE TestQueueRetryMovesToBack2232=== RUN TestQueueFetchRemoveLifecycle2233=== PAUSE TestQueueFetchRemoveLifecycle2234=== RUN TestQueueConcurrentWriters2235=== PAUSE TestQueueConcurrentWriters2236=== RUN TestQueueRemoveLargeClosure2237=== PAUSE TestQueueRemoveLargeClosure2238=== RUN TestServerClientIntegration2239=== PAUSE TestServerClientIntegration2240=== RUN TestServerQueueError2241=== PAUSE TestServerQueueError2242=== RUN TestGetListenerSocketActivation2243 server_test.go:210: === RUN TestGetListenerSocketActivation2244 --- PASS: TestGetListenerSocketActivation (0.00s)2245 PASS2246 2247--- PASS: TestGetListenerSocketActivation (0.01s)2248=== RUN TestDrainIsolatesPoisonPath2249=== PAUSE TestDrainIsolatesPoisonPath2250=== RUN TestRunNotBlockedByPoisonHead2251=== PAUSE TestRunNotBlockedByPoisonHead2252=== RUN TestDrainGivesUpWhenServerDown2253=== PAUSE TestDrainGivesUpWhenServerDown2254=== RUN TestFailedPathPrunedByLaterClosure2255=== PAUSE TestFailedPathPrunedByLaterClosure2256=== RUN TestWorkerUploadsAndRemoves2257=== PAUSE TestWorkerUploadsAndRemoves2258=== RUN TestWorkerSkipsGCdPaths2259=== PAUSE TestWorkerSkipsGCdPaths2260=== RUN TestWorkerPrunesClosureDeps2261=== PAUSE TestWorkerPrunesClosureDeps2262=== RUN TestDrainTimeout2263=== PAUSE TestDrainTimeout2264=== CONT TestSendPathsEmpty2265=== CONT TestServerQueueError2266--- PASS: TestSendPathsEmpty (0.00s)2267=== CONT TestServerClientIntegration2268=== CONT TestWorkerUploadsAndRemoves2269=== CONT TestWorkerPrunesClosureDeps2270=== CONT TestQueueRetryMovesToBack2271=== CONT TestWorkerSkipsGCdPaths2272=== CONT TestQueueFetchBatchLimit2273=== CONT TestQueueConcurrentWriters2274=== CONT TestQueueRemoveLargeClosure2275=== CONT TestQueueDeduplication22762026/10/04 20:04:58 ERROR Failed to queue paths error="permission denied" count=12277--- PASS: TestServerQueueError (0.00s)2278=== CONT TestQueueFetchRemoveLifecycle2279--- PASS: TestServerClientIntegration (0.00s)2280=== CONT TestQueueEnqueueAndFetch22812026/10/04 20:04:59 INFO Upload queue status pending=222822026/10/04 20:04:59 INFO Uploading batch count=12283--- PASS: TestQueueEnqueueAndFetch (0.01s)2284=== CONT TestDrainGivesUpWhenServerDown22852026/10/04 20:04:59 INFO Upload queue status pending=222862026/10/04 20:04:59 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-5948-865822547/TestWorkerSkipsGCdPaths961122965/002/nonexistent22872026/10/04 20:04:59 INFO Uploading batch count=12288--- PASS: TestQueueDeduplication (0.01s)2289=== CONT TestFailedPathPrunedByLaterClosure22902026/10/04 20:04:59 INFO Upload queue status pending=222912026/10/04 20:04:59 INFO Uploading batch count=22292--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2293=== CONT TestDrainTimeout2294--- PASS: TestQueueFetchBatchLimit (0.01s)2295=== CONT TestRunNotBlockedByPoisonHead2296--- PASS: TestQueueRetryMovesToBack (0.01s)2297=== CONT TestDrainIsolatesPoisonPath22982026/10/04 20:04:59 INFO Uploading batch count=222992026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=223002026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/a23012026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/b23022026/10/04 20:04:59 INFO Uploading batch count=223032026/10/04 20:04:59 INFO Uploading batch count=223042026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=223052026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/c23062026/10/04 20:04:59 INFO Uploading batch count=123072026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=123082026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/d23092026/10/04 20:04:59 INFO Upload queue status pending=323102026/10/04 20:04:59 INFO Uploading batch count=123112026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=123122026/10/04 20:04:59 INFO Uploading batch count=123132026/10/04 20:04:59 INFO Uploading batch count=223142026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=223152026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/e23162026/10/04 20:04:59 INFO Uploading batch count=123172026/10/04 20:04:59 INFO Uploading batch count=423182026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=423192026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainGivesUpWhenServerDown2396242367/002/f23202026/10/04 20:04:59 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-5948-865822547/TestDrainIsolatesPoisonPath3144029323/002/bbb23212026/10/04 20:04:59 ERROR Drain finished with paths left in queue remaining=1023222026/10/04 20:04:59 INFO Uploading batch count=123232026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=123242026/10/04 20:04:59 INFO Uploading batch count=123252026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=123262026/10/04 20:04:59 INFO Uploading batch count=123272026/10/04 20:04:59 ERROR Upload failed error="upload failed" count=12328--- PASS: TestFailedPathPrunedByLaterClosure (0.00s)2329=== CONT TestQueueRemove23302026/10/04 20:04:59 ERROR Drain finished with paths left in queue remaining=12331--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2332--- PASS: TestDrainIsolatesPoisonPath (0.00s)2333--- PASS: TestQueueRemove (0.00s)2334--- PASS: TestWorkerPrunesClosureDeps (0.03s)2335--- PASS: TestWorkerUploadsAndRemoves (0.03s)2336--- PASS: TestWorkerSkipsGCdPaths (0.03s)2337--- PASS: TestQueueRemoveLargeClosure (0.05s)2338--- PASS: TestQueueConcurrentWriters (0.13s)23392026/10/04 20:04:59 ERROR Upload failed error="context deadline exceeded" count=223402026/10/04 20:04:59 ERROR Drain finished with paths left in queue remaining=42341--- PASS: TestDrainTimeout (0.21s)23422026/10/04 20:05:00 INFO Uploading batch count=123432026/10/04 20:05:00 INFO Uploading batch count=123442026/10/04 20:05:00 INFO Uploading batch count=123452026/10/04 20:05:00 ERROR Upload failed error="upload failed" count=123462026/10/04 20:05:00 INFO Uploading batch count=123472026/10/04 20:05:00 ERROR Upload failed error="upload failed" count=123482026/10/04 20:05:00 INFO Uploading batch count=123492026/10/04 20:05:00 ERROR Upload failed error="upload failed" count=123502026/10/04 20:05:00 INFO Uploading batch count=123512026/10/04 20:05:00 ERROR Upload failed error="upload failed" count=123522026/10/04 20:05:00 ERROR Drain finished with paths left in queue remaining=12353--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2354PASS