niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #408
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestSupersededNARStillUploadsListing26=== PAUSE TestSupersededNARStillUploadsListing27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestResolveStorePath56=== PAUSE TestResolveStorePath57=== RUN TestDoWithRetry_BodyReplayedViaGetBody58=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody59=== RUN TestRetryTimeoutOutlastsMaxRetries60=== PAUSE TestRetryTimeoutOutlastsMaxRetries61=== RUN TestDoWithRetry_FinalResponseBodyReadable62=== PAUSE TestDoWithRetry_FinalResponseBodyReadable63=== RUN TestShellSplit64=== PAUSE TestShellSplit65=== RUN TestShellSplitErrors66=== PAUSE TestShellSplitErrors67=== RUN TestStreamPushReportsEveryPath68=== PAUSE TestStreamPushReportsEveryPath69=== RUN TestStreamPushBatchesUnderLoad70=== PAUSE TestStreamPushBatchesUnderLoad71=== RUN TestStreamPushIsolatesFailures72=== PAUSE TestStreamPushIsolatesFailures73=== RUN TestStreamPushGivesUpOnDeadServer74=== PAUSE TestStreamPushGivesUpOnDeadServer75=== RUN TestStreamPushRequestLine76=== PAUSE TestStreamPushRequestLine77=== RUN TestStreamPushReportsSignatures78=== PAUSE TestStreamPushReportsSignatures79=== RUN TestStreamPushReportsSkippedPaths80=== PAUSE TestStreamPushReportsSkippedPaths81=== RUN TestClientSignaturesByStorePath82=== PAUSE TestClientSignaturesByStorePath83=== RUN TestStreamPushStopsWhenCanceled84=== PAUSE TestStreamPushStopsWhenCanceled85=== RUN TestSetClientTLS86=== PAUSE TestSetClientTLS87=== RUN TestSetClientTLSDoesNotMutateDefaultTransport88=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport89=== RUN TestSetClientTLSErrors90=== PAUSE TestSetClientTLSErrors91=== RUN TestStaticToken92=== PAUSE TestStaticToken93=== RUN TestFileTokenReadsAndCaches94=== PAUSE TestFileTokenReadsAndCaches95=== RUN TestFileTokenMissing96=== PAUSE TestFileTokenMissing97=== RUN TestFileTokenEmpty98=== PAUSE TestFileTokenEmpty99=== RUN TestScriptTokenNoExpiryRerunsEveryCall100=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall101=== RUN TestScriptTokenCachesUntilRefresh102=== PAUSE TestScriptTokenCachesUntilRefresh103=== RUN TestScriptTokenEmptyToken104=== PAUSE TestScriptTokenEmptyToken105=== RUN TestScriptTokenBadJSON106=== PAUSE TestScriptTokenBadJSON107=== RUN TestScriptTokenScriptFails108=== PAUSE TestScriptTokenScriptFails109=== RUN TestScriptTokenEmptyCommand110=== PAUSE TestScriptTokenEmptyCommand111=== CONT TestDoServerRequestAttachesToken112=== CONT TestRetryTimeoutOutlastsMaxRetries113=== CONT TestEncodeNixBase32114=== RUN TestEncodeNixBase32/test_string_hash115=== CONT TestDoWithRetry_BodyReplayedViaGetBody116=== CONT TestResolveStorePath117=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer118=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1192026/10/10 19:42:18 WARN Rate limiter enabled after throttle name=server-test rate=5120=== CONT TestPathInfoHashCompatibility121=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)122=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)123=== CONT TestGetStorePathHash124=== CONT TestSetClientTLS125=== CONT TestConvertHashToNix32126=== CONT TestScriptTokenEmptyCommand127=== CONT TestScriptTokenScriptFails128=== CONT TestEncodeNixBase32WithRealHash129=== CONT TestScriptTokenBadJSON130--- PASS: TestResolveStorePath (0.00s)131=== CONT TestPathInfoCACompatibility132--- PASS: TestScriptTokenEmptyCommand (0.00s)133=== CONT TestCaseHackSuffix134=== CONT TestScriptTokenCachesUntilRefresh135=== CONT TestScriptTokenNoExpiryRerunsEveryCall136=== CONT TestFileTokenEmpty137=== CONT TestRateLimiterFeedback138=== CONT TestParsePathInfoJSON139=== CONT TestFileTokenMissing140=== CONT TestParsePathInfoJSONMultiplePaths141=== PAUSE TestEncodeNixBase32/test_string_hash142=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon143=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon144=== RUN TestGetStorePathHash/valid_store_path145=== CONT TestScriptTokenEmptyToken146=== RUN TestPathInfoCACompatibility/null_ca_field147=== CONT TestFileTokenReadsAndCaches148=== RUN TestEncodeNixBase32/empty_input149=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI150--- PASS: TestEncodeNixBase32WithRealHash (0.00s)151=== CONT TestStaticToken152=== RUN TestParsePathInfoJSON/Nix_format153=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154--- PASS: TestStaticToken (0.00s)155=== CONT TestUploadMultipart_PartsInParallel156--- PASS: TestFileTokenMissing (0.00s)157=== CONT TestSetClientTLSErrors1582026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39545159--- PASS: TestScriptTokenScriptFails (0.00s)160=== PAUSE TestGetStorePathHash/valid_store_path161=== PAUSE TestPathInfoCACompatibility/null_ca_field162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths164=== PAUSE TestEncodeNixBase32/empty_input1652026/10/10 19:42:18 WARN Rate limiter enabled after throttle name=server-test rate=51662026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39713167=== RUN TestPathInfoCACompatibility/old_string_format_-_text168=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text169=== RUN TestConvertHashToNix32/SRI_format_to_Nix32170=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32171=== RUN TestConvertHashToNix32/already_Nix32_format172=== PAUSE TestConvertHashToNix32/already_Nix32_format173=== RUN TestRateLimiterFeedback/429_enables_limiter174=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== CONT TestFilterOversizedClosures176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive177=== RUN TestPathInfoCACompatibility/new_structured_format_-_text178=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error179=== CONT TestSetClientTLSDoesNotMutateDefaultTransport180=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181--- PASS: TestFileTokenEmpty (0.00s)1822026/10/10 19:42:18 WARN Rate limiter backed off name=server-test rate=51832026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:39713184=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica185=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1862026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39545187=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512188=== PAUSE TestParsePathInfoJSON/Nix_format189=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun190=== RUN TestParsePathInfoJSON/Lix_format191=== PAUSE TestParsePathInfoJSON/Lix_format192=== RUN TestParsePathInfoJSON/empty_input193=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512194=== RUN TestConvertHashToNix32/invalid_format195=== CONT TestStreamPushStopsWhenCanceled196=== PAUSE TestConvertHashToNix32/invalid_format197=== PAUSE TestParsePathInfoJSON/empty_input198=== CONT TestClientSignaturesByStorePath199=== PAUSE TestRateLimiterFeedback/429_enables_limiter200--- PASS: TestScriptTokenBadJSON (0.01s)201=== RUN TestFilterOversizedClosures/no_limit_keeps_everything202=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text203=== CONT TestStreamPushReportsEveryPath204=== CONT TestStreamPushGivesUpOnDeadServer205=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error206=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths207=== CONT TestDumpPathMatchesNix208=== CONT TestStreamPushReportsSkippedPaths209--- PASS: TestFileTokenReadsAndCaches (0.00s)210=== RUN TestParsePathInfoJSON/whitespace_only211=== CONT TestDumpPathWriterError212=== CONT TestDumpPathSingleFile213=== CONT TestStreamPushReportsSignatures214--- PASS: TestDoServerRequestAttachesToken (0.01s)215--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)216--- PASS: TestClientSignaturesByStorePath (0.00s)217--- PASS: TestStreamPushStopsWhenCanceled (0.00s)218--- PASS: TestScriptTokenEmptyToken (0.00s)219--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)220=== CONT TestStreamPushRequestLine221=== RUN TestRateLimiterFeedback/503_enables_limiter222=== PAUSE TestRateLimiterFeedback/503_enables_limiter223=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter224=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter225=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter226=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter227=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method228=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method229=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything230=== CONT TestRegisterUploadedObjectReusesConnections231=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== CONT TestSupersededNARStillUploadsListing233=== RUN TestSupersededNARStillUploadsListing/small_NAR2342026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39545235=== PAUSE TestSupersededNARStillUploadsListing/small_NAR236=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped237=== RUN TestSupersededNARStillUploadsListing/dump_cut_short238=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short239=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails240=== RUN TestSetClientTLSErrors/missing_cert_file241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestSetClientTLSErrors/missing_key_file243--- PASS: TestStreamPushReportsEveryPath (0.00s)2442026/10/10 19:42:18 ERROR Upload failed error="connection refused" count=20245=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails2462026/10/10 19:42:18 ERROR Server seems unavailable, giving up on batch untried=17247=== CONT TestStreamPushBatchesUnderLoad248--- PASS: TestStreamPushReportsSkippedPaths (0.00s)2492026/10/10 19:42:18 INFO Garbage collection started250=== PAUSE TestSetClientTLSErrors/missing_key_file251=== RUN TestSetClientTLSErrors/missing_ca_file252=== PAUSE TestSetClientTLSErrors/missing_ca_file253=== RUN TestSetClientTLSErrors/invalid_ca_file254=== PAUSE TestSetClientTLSErrors/invalid_ca_file255=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error2562026/10/10 19:42:18 INFO Garbage collection started257=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error258=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error259=== RUN TestFilterOversizedClosures/all_closures_skipped260=== PAUSE TestFilterOversizedClosures/all_closures_skipped261=== CONT TestShellSplitErrors262=== CONT TestEncodeNixBase32/test_string_hash263=== CONT TestEncodeNixBase32/empty_input264=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)2652026/10/10 19:42:18 ERROR Upload failed error=boom count=1266=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512267=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2682026/10/10 19:42:18 ERROR Upload failed error=boom count=1269=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon270=== CONT TestConvertHashToNix32/SRI_format_to_Nix32271=== RUN TestSetClientTLS/rejects_connection_without_client_cert2722026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39545273=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert274=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA275=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA276=== RUN TestSetClientTLS/preserves_debug_logging_transport277=== PAUSE TestSetClientTLS/preserves_debug_logging_transport278=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths279=== CONT TestRateLimiterFeedback/429_enables_limiter280=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths281=== CONT TestConvertHashToNix32/invalid_format282=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter2842026/10/10 19:42:18 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=0285--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)286--- PASS: TestShellSplitErrors (0.00s)287=== CONT TestDoWithRetry_FinalResponseBodyReadable288--- PASS: TestEncodeNixBase32 (0.01s)289 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)291--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)292--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)293=== CONT TestPathInfoCACompatibility/null_ca_field294=== CONT TestShellSplit2952026/10/10 19:42:18 WARN Rate limiter enabled after throttle name=server-test rate=52962026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:46605297=== CONT TestPathInfoCACompatibility/new_structured_format_-_text298=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive299=== CONT TestPathInfoCACompatibility/old_string_format_-_text300=== CONT TestSupersededNARStillUploadsListing/small_NAR3012026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39545302=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3032026/10/10 19:42:18 WARN Rate limiter backed off name=server-test rate=5304=== PAUSE TestParsePathInfoJSON/whitespace_only305=== CONT TestPartSizeForNAR3062026/10/10 19:42:18 WARN Rate limiter enabled after throttle name=server-test rate=5307=== CONT TestConvertHashToNix32/already_Nix32_format308=== CONT TestUploadMultipart_SupersededByPeer309=== CONT TestRateLimiterFeedback/503_enables_limiter3102026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:368113112026/10/10 19:42:18 INFO Uploading abc-hello (1.0GB)312=== RUN TestUploadMultipart_SupersededByPeer/exists313=== PAUSE TestUploadMultipart_SupersededByPeer/exists314=== RUN TestUploadMultipart_SupersededByPeer/missing315=== PAUSE TestUploadMultipart_SupersededByPeer/missing316=== CONT TestSetClientTLSErrors/invalid_ca_file3172026/10/10 19:42:18 INFO Uploading abc-hello (1.0GB)3182026/10/10 19:42:18 WARN Rate limiter backed off name=server-test rate=53192026/10/10 19:42:18 WARN Garbage collection finished on another replica. Its statistics are not available here320=== CONT TestGetStorePathHash/valid_store_path3212026/10/10 19:42:18 WARN Rate limiter enabled after throttle name=server-test rate=5322=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error3232026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:34031324=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error325=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3262026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:39545327=== CONT TestFilterOversizedClosures/all_closures_skipped3282026/10/10 19:42:18 WARN Rate limiter backed off name=server-test rate=5329=== CONT TestSetClientTLSErrors/missing_ca_file3302026/10/10 19:42:18 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50331=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3322026/10/10 19:42:18 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=2000333=== CONT TestUploadMultipart_SupersededByPeer/exists334=== CONT TestSetClientTLS/rejects_connection_without_client_cert335=== RUN TestParsePathInfoJSON/invalid_JSON336=== CONT TestSupersededNARStillUploadsListing/dump_cut_short337=== CONT TestSetClientTLSErrors/missing_cert_file338=== CONT TestUploadMultipart_SupersededByPeer/missing339=== CONT TestStreamPushIsolatesFailures340=== RUN TestPartSizeForNAR/zero_stays_at_minimum341=== CONT TestSetClientTLSErrors/missing_key_file342=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method343=== CONT TestFilterOversizedClosures/no_limit_keeps_everything3442026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:39545345--- PASS: TestCaseHackSuffix (0.04s)3462026/10/10 19:42:18 ERROR Upload failed error="bad path" count=3347=== CONT TestSetClientTLS/preserves_debug_logging_transport348=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA349=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum350=== RUN TestPartSizeForNAR/small_stays_at_minimum351=== PAUSE TestPartSizeForNAR/small_stays_at_minimum352=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum353=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum354=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts355=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts356=== RUN TestPartSizeForNAR/1_TiB357=== PAUSE TestPartSizeForNAR/1_TiB358=== RUN TestPartSizeForNAR/5_TiB_S3_max_object359=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object360=== RUN TestPartSizeForNAR/capped_at_5_GiB361=== PAUSE TestPartSizeForNAR/capped_at_5_GiB362=== CONT TestPartSizeForNAR/zero_stays_at_minimum363--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)365 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)366=== CONT TestPartSizeForNAR/capped_at_5_GiB367=== CONT TestPartSizeForNAR/5_TiB_S3_max_object368=== CONT TestPartSizeForNAR/1_TiB3692026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:39545370=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts371=== CONT TestPartSizeForNAR/small_stays_at_minimum372=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum373--- PASS: TestStreamPushReportsSignatures (0.00s)374--- PASS: TestShellSplit (0.00s)375--- PASS: TestConvertHashToNix32 (0.00s)376 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)377 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)378 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)379--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)380--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)381--- PASS: TestGetStorePathHash (0.04s)382 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)383 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)384 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)385 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)386--- PASS: TestRateLimiterFeedback (0.03s)387 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)388 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)389 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)390 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)391--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)392--- PASS: TestStreamPushIsolatesFailures (0.00s)393--- PASS: TestPathInfoCACompatibility (0.04s)394 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)395 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)396 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)397 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)398 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)399--- PASS: TestFilterOversizedClosures (0.03s)400 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)401 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)402 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)403--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)404 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)405 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)406--- PASS: TestPathInfoHashCompatibility (0.01s)407 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)408 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)409 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)410 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)411--- PASS: TestPartSizeForNAR (0.01s)412 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)413 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)414 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)415 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)416 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)417 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)418 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)419--- PASS: TestSetClientTLSErrors (0.04s)420 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)421 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)422 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)423 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4242026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:39545425=== PAUSE TestParsePathInfoJSON/invalid_JSON426=== CONT TestParsePathInfoJSON/Nix_format427=== CONT TestParsePathInfoJSON/whitespace_only428=== CONT TestParsePathInfoJSON/invalid_JSON429=== CONT TestParsePathInfoJSON/empty_input430=== CONT TestParsePathInfoJSON/Lix_format4312026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:39545432--- PASS: TestParsePathInfoJSON (0.05s)433 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)434 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)435 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)436 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)437 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)4382026/10/10 19:42:18 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33309/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33309/api/uploads/complete439--- PASS: TestDumpPathSingleFile (0.38s)4402026/10/10 19:42:18 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4412026/10/10 19:42:18 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33309/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33309/api/uploads/complete4422026/10/10 19:42:18 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4432026/10/10 19:42:18 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33309/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:33309/api/uploads/complete4442026/10/10 19:42:18 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4452026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:39545446--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.39s)4472026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:395454482026/10/10 19:42:18 http: TLS handshake error from 127.0.0.1:49630: remote error: tls: bad certificate4492026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:39545450--- PASS: TestSetClientTLS (0.04s)451 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)452 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.34s)453 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.34s)4542026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:395454552026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:395454562026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:39545457--- PASS: TestStreamPushRequestLine (0.36s)4582026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:395454592026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:395454602026/10/10 19:42:18 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39545461--- PASS: TestRegisterUploadedObjectReusesConnections (0.36s)462--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.41s)4632026/10/10 19:42:18 INFO Uploading abc-hello (1.0GB)464--- PASS: TestDumpPathWriterError (0.42s)465--- PASS: TestStreamPushBatchesUnderLoad (0.40s)4662026/10/10 19:42:18 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:45059/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:45059/part/24672026/10/10 19:42:18 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"468--- PASS: TestDumpPathMatchesNix (0.46s)469--- PASS: TestSupersededNARStillUploadsListing (0.00s)470 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)471 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)472 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.88s)473--- PASS: TestUploadMultipart_PartsInParallel (0.95s)474--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)475PASS476Running server tests...477The files belonging to this database system will be owned by user "nixbld".478This user must also own the server process.479480The database cluster will be initialized with locale "C".481The default database encoding has accordingly been set to "SQL_ASCII".482The default text search configuration will be set to "english".483484Data page checksums are enabled.485486creating directory /build/postgres1340777106/data ... ok487creating subdirectories ... ok488selecting dynamic shared memory implementation ... posix489selecting default "max_connections" ... 100490selecting default "shared_buffers" ... 128MB491selecting default time zone ... UTC492creating configuration files ... ok493running bootstrap script ... ok494performing post-bootstrap initialization ... ok495syncing data to disk ... ok496497initdb: warning: enabling "trust" authentication for local connections498initdb: 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.499500Success. You can now start the database server using:501502 pg_ctl -D /build/postgres1340777106/data -l logfile start503504/build/postgres1340777106:5432 - no response5052026-10-10 19:42:20.288 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5062026-10-10 19:42:20.288 UTC [129] LOG: listening on Unix socket "/build/postgres1340777106/.s.PGSQL.5432"5072026-10-10 19:42:20.293 UTC [136] LOG: database system was shut down at 2026-10-10 19:42:19 UTC5082026-10-10 19:42:20.296 UTC [129] LOG: database system is ready to accept connections509/build/postgres1340777106:5432 - accepting connections510=== RUN TestService_AuthMiddleware511=== PAUSE TestService_AuthMiddleware512=== RUN TestService_AuthMiddleware_MTLSProxyHeader513=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader514=== RUN TestService_AuthMiddleware_MTLSBoundSubjects515=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects516=== RUN TestService_ReadAuthMiddleware517=== PAUSE TestService_ReadAuthMiddleware518=== RUN TestService_AuthMiddleware_OIDC519=== PAUSE TestService_AuthMiddleware_OIDC520=== RUN TestService_RequireScope_OIDC521=== PAUSE TestService_RequireScope_OIDC522=== RUN TestService_ReadScope_PublicByDefault523=== PAUSE TestService_ReadScope_PublicByDefault524=== RUN TestCacheConfigHandler525=== PAUSE TestCacheConfigHandler526=== RUN TestCacheStatsHandler527=== PAUSE TestCacheStatsHandler528=== RUN TestClientCADerivations529=== PAUSE TestClientCADerivations530=== RUN TestClientErrorHandling531=== PAUSE TestClientErrorHandling532=== RUN TestClientIntegration533=== PAUSE TestClientIntegration534=== RUN TestClientMultipleUploads535=== PAUSE TestClientMultipleUploads536=== RUN TestClientWithDependencies537=== PAUSE TestClientWithDependencies538=== RUN TestClientSharedPathCommittedMidPush539=== PAUSE TestClientSharedPathCommittedMidPush540=== RUN TestPinProtectsFromGC541=== PAUSE TestPinProtectsFromGC542=== RUN TestClientPushesUseOnePush543=== PAUSE TestClientPushesUseOnePush544=== RUN TestClientFallsBackToClosures545=== PAUSE TestClientFallsBackToClosures546=== RUN TestDeleteClosuresRacingPins547=== PAUSE TestDeleteClosuresRacingPins548=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock549=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock550=== RUN TestResolveDBConnectionString551=== PAUSE TestResolveDBConnectionString552=== RUN TestConnectWaitsForAPeerMigration553=== PAUSE TestConnectWaitsForAPeerMigration554=== RUN TestLeadElectsOneAndHandsOver555=== PAUSE TestLeadElectsOneAndHandsOver556=== RUN TestLeadIncumbentWinsAfterRestart5572026/10/10 19:42:20 INFO lead: acquired remote=192.0.2.1:12345582026/10/10 19:42:21 INFO lead: released remote=192.0.2.1:12345592026/10/10 19:42:21 INFO lead: acquired remote=192.0.2.1:12345602026/10/10 19:42:22 INFO lead: released remote=192.0.2.1:1234561--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)562=== RUN TestLeadIncumbentAnnouncesAtOnce563=== PAUSE TestLeadIncumbentAnnouncesAtOnce564=== RUN TestLeadEndsOnShutdown565=== PAUSE TestLeadEndsOnShutdown566=== RUN TestLeadEndsWhenItsConnectionHangs5672026/10/10 19:42:22 INFO lead: acquired remote=192.0.2.1:12345682026-10-10 19:42:24.098 UTC [576] FATAL: terminating connection due to administrator command5692026/10/10 19:42:24 INFO lead: acquired remote=192.0.2.1:12345702026/10/10 19:42:25 WARN lead: lock connection lost error="timeout: context deadline exceeded"5712026/10/10 19:42:25 INFO lead: released remote=192.0.2.1:12345722026/10/10 19:42:25 INFO lead: released remote=192.0.2.1:1234573--- PASS: TestLeadEndsWhenItsConnectionHangs (2.91s)574=== RUN TestGCAdvisoryLockBlocksConcurrentRun575=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun576=== RUN TestGCBugBareHashReferences577=== PAUSE TestGCBugBareHashReferences578=== RUN TestGCMetrics579=== PAUSE TestGCMetrics580=== RUN TestPushDedupSurvivesConcurrentGC581=== PAUSE TestPushDedupSurvivesConcurrentGC582=== RUN TestDeduplicatedObjectsRecordedAsPending583=== PAUSE TestDeduplicatedObjectsRecordedAsPending584=== RUN TestGCSweepSkipsPendingObjects585=== PAUSE TestGCSweepSkipsPendingObjects586=== RUN TestTombstonedObjectOfferedWithoutWaiting587=== PAUSE TestTombstonedObjectOfferedWithoutWaiting588=== RUN TestGCSweepDeliversEachKeyOnce589=== PAUSE TestGCSweepDeliversEachKeyOnce590=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection591=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection592=== RUN TestForceGCDuringPushOffersSweptObject593=== PAUSE TestForceGCDuringPushOffersSweptObject594=== RUN TestFailedS3DeleteKeepsTombstone595=== PAUSE TestFailedS3DeleteKeepsTombstone596=== RUN TestSweepSkipsRowsLockedByPush597=== PAUSE TestSweepSkipsRowsLockedByPush598=== RUN TestRegisterCompletedObjectNeedsPendingRow599=== PAUSE TestRegisterCompletedObjectNeedsPendingRow600=== RUN TestGetExistingObjectsLocksRows601=== PAUSE TestGetExistingObjectsLocksRows602=== RUN TestSweepRechecksPendingAfterLocking603=== PAUSE TestSweepRechecksPendingAfterLocking604=== RUN TestPushWaitsForSweepHoldingRow605=== PAUSE TestPushWaitsForSweepHoldingRow606=== RUN TestCommitRacingPendingCleanupKeepsObjects607=== PAUSE TestCommitRacingPendingCleanupKeepsObjects608=== RUN TestGCEndsOnShutdown609=== PAUSE TestGCEndsOnShutdown610=== RUN TestGCTaskStore_StartNew611=== PAUSE TestGCTaskStore_StartNew612=== RUN TestGCTaskStore_DeduplicateSameParams613=== PAUSE TestGCTaskStore_DeduplicateSameParams614=== RUN TestGCTaskStore_ConflictDifferentParams615=== PAUSE TestGCTaskStore_ConflictDifferentParams616=== RUN TestGCTaskStore_GetEmpty617=== PAUSE TestGCTaskStore_GetEmpty618=== RUN TestGCTaskStore_GetReturnsLatest619=== PAUSE TestGCTaskStore_GetReturnsLatest620=== RUN TestGCTaskStore_CompletedAllowsNewTask621=== PAUSE TestGCTaskStore_CompletedAllowsNewTask622=== RUN TestGCTaskStore_PhaseUpdates623=== PAUSE TestGCTaskStore_PhaseUpdates624=== RUN TestGCTaskStore_Fail625=== PAUSE TestGCTaskStore_Fail626=== RUN TestGracefulShutdownDrainsInflight627=== PAUSE TestGracefulShutdownDrainsInflight628=== RUN TestService_healthCheckHandler629=== PAUSE TestService_healthCheckHandler630=== RUN TestService_readinessHandler631=== PAUSE TestService_readinessHandler632=== RUN TestGenerateLandingPage633=== PAUSE TestGenerateLandingPage634=== RUN TestCacheConfigHandlerMaxNarSize635=== PAUSE TestCacheConfigHandlerMaxNarSize636=== RUN TestCreatePendingClosureRejectsOversizedNAR637=== PAUSE TestCreatePendingClosureRejectsOversizedNAR638=== RUN TestNARDeduplicationMetadataUploadBug639=== PAUSE TestNARDeduplicationMetadataUploadBug640=== RUN TestMetricsInventory641=== PAUSE TestMetricsInventory642=== RUN TestMetricsCommit643=== PAUSE TestMetricsCommit644=== RUN TestService_NativeMTLS645=== PAUSE TestService_NativeMTLS646=== RUN TestServerTLSConfig647=== PAUSE TestServerTLSConfig648=== RUN TestMultipartCleanup649=== PAUSE TestMultipartCleanup650=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded651=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded652=== RUN TestPendingCleanupUsesOneCutoff653=== PAUSE TestPendingCleanupUsesOneCutoff654=== RUN TestObjectStatsTrigger655=== PAUSE TestObjectStatsTrigger656=== RUN TestObjectStatsLargeCommit657=== PAUSE TestObjectStatsLargeCommit658=== RUN TestOrphanedObjectsGC659=== PAUSE TestOrphanedObjectsGC660=== RUN TestOrphanedObjectsGCStressTest661=== PAUSE TestOrphanedObjectsGCStressTest662=== RUN TestCreatePin_ReservedPins663=== PAUSE TestCreatePin_ReservedPins664=== RUN TestPresentReportsOnlyClosureRoots665=== PAUSE TestPresentReportsOnlyClosureRoots666=== RUN TestPresentRefreshesOnlyStaleClosures667=== PAUSE TestPresentRefreshesOnlyStaleClosures668=== RUN TestPresentNotReportedWhileGCDeletesClosure669=== PAUSE TestPresentNotReportedWhileGCDeletesClosure670=== RUN TestParseSingleRange671=== PAUSE TestParseSingleRange672=== RUN TestProxyHeadersOnlyTrustedOnSocket6732026/10/10 19:42:25 INFO Starting HTTP server address=127.0.0.1:404156742026/10/10 19:42:25 INFO Starting HTTP server address=proxy.sock6752026/10/10 19:42:25 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6762026/10/10 19:42:25 INFO Shutdown signal received, draining in-flight requests timeout=10s677--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)678=== RUN TestIsValidCachePath679=== PAUSE TestIsValidCachePath680=== RUN TestReadProxyNarinfo681=== PAUSE TestReadProxyNarinfo682=== RUN TestReadProxyNarinfoAlreadyDecompressed683=== PAUSE TestReadProxyNarinfoAlreadyDecompressed684=== RUN TestReadProxyContentNegotiation685=== PAUSE TestReadProxyContentNegotiation686=== RUN TestReadProxyNarStreaming687=== PAUSE TestReadProxyNarStreaming688=== RUN TestReadProxy404689=== PAUSE TestReadProxy404690=== RUN TestReadProxyInvalidPath691=== PAUSE TestReadProxyInvalidPath692=== RUN TestReadProxyHead693=== PAUSE TestReadProxyHead694=== RUN TestReadProxyOutlastsServerWriteTimeout695=== PAUSE TestReadProxyOutlastsServerWriteTimeout696=== RUN TestReadProxyConditionalGet697=== PAUSE TestReadProxyConditionalGet698=== RUN TestReadProxyRootRedirectsToIndexHTML699=== PAUSE TestReadProxyRootRedirectsToIndexHTML700=== RUN TestReadProxyDisabled701=== PAUSE TestReadProxyDisabled702=== RUN TestReadRedirectNar703=== PAUSE TestReadRedirectNar704=== RUN TestReadRedirectKeepsNarinfoProxied705=== PAUSE TestReadRedirectKeepsNarinfoProxied706=== RUN TestReadProxyRangeRequest707=== PAUSE TestReadProxyRangeRequest708=== RUN TestReadRedirectUsesPublicS3URL709=== PAUSE TestReadRedirectUsesPublicS3URL710=== RUN TestPush_OverlappingRootsStoreOneRowPerKey711=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey712=== RUN TestPush_CompleteCommitsEveryRoot713=== PAUSE TestPush_CompleteCommitsEveryRoot714=== RUN TestPush_RepeatedRootCommitsOnce715=== PAUSE TestPush_RepeatedRootCommitsOnce716=== RUN TestPush_CompleteWaitsForCleanupOfThePush717=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush718=== RUN TestPush_RootsAreLockedInByteOrder719=== PAUSE TestPush_RootsAreLockedInByteOrder720=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit721=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit722=== RUN TestPush_RejectsBadRequests723=== PAUSE TestPush_RejectsBadRequests724=== RUN TestPush_SignsNarinfosOfItsPendingObjects725=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects726=== RUN TestRedundantMultipartUpload727=== PAUSE TestRedundantMultipartUpload728=== RUN TestCompleteMultipartUpload_ErrorButObjectExists729=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists730=== RUN TestCompletedNarNotReofferedAcrossClosures731=== PAUSE TestCompletedNarNotReofferedAcrossClosures732=== RUN TestPresignedUploadRegisteredBeforeCommit733=== PAUSE TestPresignedUploadRegisteredBeforeCommit734=== RUN TestService_Rustfstest735=== PAUSE TestService_Rustfstest736=== RUN TestParseSize737=== PAUSE TestParseSize738=== RUN TestSkippedUploadsHandler739=== PAUSE TestSkippedUploadsHandler740=== RUN TestSystemdListenerNotActivated741--- PASS: TestSystemdListenerNotActivated (0.00s)742=== RUN TestWatchdogBeatsWhenHealthy743--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)744=== RUN TestWatchdogSkipsWhenUnhealthy7452026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7532026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7542026/10/10 19:42:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"755--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)756=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle757=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle758=== RUN TestProxyWriteTimeout759=== PAUSE TestProxyWriteTimeout760=== RUN TestPendingClosureWriteTimeout761=== PAUSE TestPendingClosureWriteTimeout762=== RUN TestIsValidUploadKey763=== PAUSE TestIsValidUploadKey764=== RUN TestUploadHandlersRejectInvalidKeys765=== PAUSE TestUploadHandlersRejectInvalidKeys766=== RUN TestUploadHandlersRejectOversizedBody767=== PAUSE TestUploadHandlersRejectOversizedBody768=== RUN TestService_cleanupPendingClosuresHandler769=== PAUSE TestService_cleanupPendingClosuresHandler770=== RUN TestService_createPendingClosureHandler771=== PAUSE TestService_createPendingClosureHandler772=== RUN TestService_verifyS3Integrity773=== PAUSE TestService_verifyS3Integrity774=== RUN TestCompleteMultipartUnregistered775=== PAUSE TestCompleteMultipartUnregistered776=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT777=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT778=== CONT TestService_AuthMiddleware779=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit780=== CONT TestPushWaitsForSweepHoldingRow781=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT782=== CONT TestCompleteMultipartUnregistered783=== CONT TestService_verifyS3Integrity784=== CONT TestService_createPendingClosureHandler785=== CONT TestService_cleanupPendingClosuresHandler786=== CONT TestUploadHandlersRejectOversizedBody787=== CONT TestUploadHandlersRejectInvalidKeys788=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info789=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info790=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal791=== CONT TestIsValidUploadKey792=== CONT TestPendingClosureWriteTimeout793=== CONT TestProxyWriteTimeout794=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle795=== CONT TestSkippedUploadsHandler796=== CONT TestParseSize797=== CONT TestService_Rustfstest798=== CONT TestPresignedUploadRegisteredBeforeCommit799=== CONT TestCompletedNarNotReofferedAcrossClosures800=== CONT TestCompleteMultipartUpload_ErrorButObjectExists801=== CONT TestRedundantMultipartUpload802=== CONT TestPush_SignsNarinfosOfItsPendingObjects803=== CONT TestPush_RejectsBadRequests804=== CONT TestReadProxyInvalidPath805=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal806=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key807=== RUN TestProxyWriteTimeout/narinfo808=== RUN TestIsValidUploadKey/narinfo809=== RUN TestPendingClosureWriteTimeout/empty810--- PASS: TestParseSize (0.00s)811=== CONT TestReadProxy4048122026/10/10 19:42:25 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000813=== PAUSE TestProxyWriteTimeout/narinfo814=== PAUSE TestIsValidUploadKey/narinfo815=== RUN TestIsValidUploadKey/nar_zst816=== PAUSE TestIsValidUploadKey/nar_zst817=== RUN TestIsValidUploadKey/nar_xz818=== PAUSE TestIsValidUploadKey/nar_xz819=== RUN TestIsValidUploadKey/nar_plain820=== PAUSE TestIsValidUploadKey/nar_plain821=== RUN TestIsValidUploadKey/listing822=== PAUSE TestIsValidUploadKey/listing823=== RUN TestIsValidUploadKey/build_log824=== PAUSE TestIsValidUploadKey/build_log825=== RUN TestIsValidUploadKey/build_log_home-manager_file826=== PAUSE TestIsValidUploadKey/build_log_home-manager_file827=== RUN TestIsValidUploadKey/build_log_plus_in_name828=== PAUSE TestIsValidUploadKey/build_log_plus_in_name829=== RUN TestIsValidUploadKey/build_log_question_mark830=== RUN TestProxyWriteTimeout/1_GiB_nar831=== PAUSE TestProxyWriteTimeout/1_GiB_nar832=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key833=== PAUSE TestPendingClosureWriteTimeout/empty834=== RUN TestPendingClosureWriteTimeout/400_objects835=== PAUSE TestPendingClosureWriteTimeout/400_objects836=== RUN TestPendingClosureWriteTimeout/670k_objects837=== PAUSE TestPendingClosureWriteTimeout/670k_objects838=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline839=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline840=== PAUSE TestIsValidUploadKey/build_log_question_mark841=== RUN TestProxyWriteTimeout/10_GiB_nar842=== PAUSE TestProxyWriteTimeout/10_GiB_nar843=== RUN TestProxyWriteTimeout/unknown_size844=== PAUSE TestProxyWriteTimeout/unknown_size845=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key846=== CONT TestReadProxyContentNegotiation847=== CONT TestReadProxyNarStreaming848=== RUN TestIsValidUploadKey/build_log_equals849=== PAUSE TestIsValidUploadKey/build_log_equals850=== RUN TestIsValidUploadKey/realisation851=== PAUSE TestIsValidUploadKey/realisation852=== RUN TestIsValidUploadKey/realisation_plus_in_output853=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key854=== PAUSE TestIsValidUploadKey/realisation_plus_in_output855=== CONT TestReadProxyNarinfoAlreadyDecompressed856=== RUN TestIsValidUploadKey/nix-cache-info857=== PAUSE TestIsValidUploadKey/nix-cache-info858=== RUN TestIsValidUploadKey/index.html859=== PAUSE TestIsValidUploadKey/index.html860=== RUN TestIsValidUploadKey/narinfo_key,_nar_type861=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type862=== RUN TestIsValidUploadKey/nar_key,_narinfo_type863=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type864=== RUN TestIsValidUploadKey/listing_key,_narinfo_type865=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type866=== RUN TestIsValidUploadKey/traversal867=== PAUSE TestIsValidUploadKey/traversal868=== RUN TestIsValidUploadKey/traversal_nar869=== PAUSE TestIsValidUploadKey/traversal_nar870=== RUN TestIsValidUploadKey/absolute871=== PAUSE TestIsValidUploadKey/absolute872=== RUN TestIsValidUploadKey/empty_key873=== PAUSE TestIsValidUploadKey/empty_key874=== RUN TestIsValidUploadKey/unknown_type875=== PAUSE TestIsValidUploadKey/unknown_type876=== CONT TestReadProxyNarinfo877--- PASS: TestSkippedUploadsHandler (0.08s)878=== CONT TestIsValidCachePath879=== RUN TestIsValidCachePath/narinfo880=== PAUSE TestIsValidCachePath/narinfo881=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars882=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars883=== RUN TestIsValidCachePath/nar_zst884=== PAUSE TestIsValidCachePath/nar_zst885=== RUN TestIsValidCachePath/nar_xz886=== PAUSE TestIsValidCachePath/nar_xz887=== RUN TestIsValidCachePath/nar_bz2888=== PAUSE TestIsValidCachePath/nar_bz2889=== RUN TestIsValidCachePath/nar_uncompressed890=== PAUSE TestIsValidCachePath/nar_uncompressed891=== RUN TestIsValidCachePath/ls892=== PAUSE TestIsValidCachePath/ls893=== RUN TestIsValidCachePath/log894=== PAUSE TestIsValidCachePath/log895=== RUN TestIsValidCachePath/realisation896=== PAUSE TestIsValidCachePath/realisation897=== RUN TestIsValidCachePath/nix-cache-info898=== PAUSE TestIsValidCachePath/nix-cache-info899=== RUN TestIsValidCachePath/index.html900=== PAUSE TestIsValidCachePath/index.html901=== RUN TestIsValidCachePath/traversal_parent902=== PAUSE TestIsValidCachePath/traversal_parent903=== RUN TestIsValidCachePath/traversal_in_middle904=== PAUSE TestIsValidCachePath/traversal_in_middle905=== RUN TestIsValidCachePath/invalid_char_e906=== PAUSE TestIsValidCachePath/invalid_char_e907=== RUN TestIsValidCachePath/invalid_char_u908=== PAUSE TestIsValidCachePath/invalid_char_u909=== RUN TestIsValidCachePath/random_path910=== PAUSE TestIsValidCachePath/random_path911=== RUN TestIsValidCachePath/empty912=== PAUSE TestIsValidCachePath/empty913=== RUN TestIsValidCachePath/leading_slash914=== PAUSE TestIsValidCachePath/leading_slash915=== RUN TestIsValidCachePath/wrong_extension916=== PAUSE TestIsValidCachePath/wrong_extension917=== RUN TestIsValidCachePath/short_hash918=== PAUSE TestIsValidCachePath/short_hash919=== CONT TestParseSingleRange920=== RUN TestParseSingleRange/none921=== PAUSE TestParseSingleRange/none922=== RUN TestParseSingleRange/unknown_unit923=== PAUSE TestParseSingleRange/unknown_unit924=== RUN TestParseSingleRange/multi-range_ignored925=== PAUSE TestParseSingleRange/multi-range_ignored926=== RUN TestParseSingleRange/malformed_no_dash927=== PAUSE TestParseSingleRange/malformed_no_dash928=== RUN TestParseSingleRange/malformed_both_empty929=== PAUSE TestParseSingleRange/malformed_both_empty930=== RUN TestParseSingleRange/malformed_end_before_start931=== PAUSE TestParseSingleRange/malformed_end_before_start932=== RUN TestParseSingleRange/closed933=== PAUSE TestParseSingleRange/closed934=== RUN TestParseSingleRange/open-ended935=== PAUSE TestParseSingleRange/open-ended936=== RUN TestParseSingleRange/end_clamped_to_size937=== PAUSE TestParseSingleRange/end_clamped_to_size938=== RUN TestParseSingleRange/suffix939=== PAUSE TestParseSingleRange/suffix940=== RUN TestParseSingleRange/suffix_exceeds_size941=== PAUSE TestParseSingleRange/suffix_exceeds_size942=== RUN TestParseSingleRange/single_byte943=== PAUSE TestParseSingleRange/single_byte944=== RUN TestParseSingleRange/start_past_EOF945=== PAUSE TestParseSingleRange/start_past_EOF946=== RUN TestParseSingleRange/start_far_past_EOF947=== PAUSE TestParseSingleRange/start_far_past_EOF948=== CONT TestPresentNotReportedWhileGCDeletesClosure949=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh950=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh951=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale952=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale953=== CONT TestPresentRefreshesOnlyStaleClosures954=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure955=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure956=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart957=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart958=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts959=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts960=== CONT TestPresentReportsOnlyClosureRoots9612026/10/10 19:42:26 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"962--- PASS: TestService_AuthMiddleware (0.34s)963=== CONT TestCreatePin_ReservedPins9642026/10/10 19:42:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9652026/10/10 19:42:26 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst966--- PASS: TestCompleteMultipartUnregistered (0.37s)967=== CONT TestOrphanedObjectsGCStressTest9682026/10/10 19:42:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37381/oidc9692026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures970--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)971=== CONT TestOrphanedObjectsGC9722026/10/10 19:42:26 INFO Received push request method=POST path=/api/pushes9732026/10/10 19:42:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9742026/10/10 19:42:26 INFO Received complete push request method=POST path=/api/pushes/1/complete9752026/10/10 19:42:26 INFO Aborted multipart uploads count=0 kept=09762026/10/10 19:42:26 INFO Completed push id=1 objects=4 duration=8.886084ms9772026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/10 19:42:26 INFO Received push request method=POST path=/api/pushes9792026/10/10 19:42:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9802026/10/10 19:42:26 INFO Aborted multipart uploads count=1 kept=0981=== RUN TestPush_RejectsBadRequests/no_objects982=== PAUSE TestPush_RejectsBadRequests/no_objects983=== RUN TestPush_RejectsBadRequests/bad_root984=== PAUSE TestPush_RejectsBadRequests/bad_root985=== RUN TestPush_RejectsBadRequests/root_not_in_objects986=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects987=== RUN TestPush_RejectsBadRequests/no_roots988=== PAUSE TestPush_RejectsBadRequests/no_roots989=== CONT TestObjectStatsLargeCommit9902026/10/10 19:42:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9912026-10-10 19:42:26.321 UTC [655] ERROR: Closure does not exist: id=19922026-10-10 19:42:26.321 UTC [655] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9932026-10-10 19:42:26.321 UTC [655] STATEMENT: -- name: CommitPendingClosure :one994 SELECT commit_pending_closure($1::bigint)::bigint995 996--- PASS: TestService_cleanupPendingClosuresHandler (0.47s)997=== CONT TestObjectStatsTrigger9982026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10002026/10/10 19:42:26 INFO Aborted multipart uploads count=0 kept=010012026/10/10 19:42:26 WARN Force mode enabled - objects will be deleted immediately without grace period10022026/10/10 19:42:26 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=010032026/10/10 19:42:26 INFO Vacuumed table table=pending_closures10042026/10/10 19:42:26 INFO Vacuumed table table=pending_objects10052026/10/10 19:42:26 INFO Vacuumed table table=multipart_uploads1006--- PASS: TestReadProxy404 (0.55s)1007=== CONT TestPendingCleanupUsesOneCutoff10082026/10/10 19:42:26 INFO Vacuumed table table=closures10092026/10/10 19:42:26 INFO Vacuumed table table=objects10102026/10/10 19:42:26 INFO Received push request method=POST path=/api/pushes10112026/10/10 19:42:26 INFO Received complete push request method=POST path=/api/pushes/2/complete10122026/10/10 19:42:26 INFO Completed push id=2 objects=4 duration=2.091986ms1013--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.57s)1014=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10152026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10162026/10/10 19:42:26 INFO Signed narinfos id=1 count=110172026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10182026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10192026/10/10 19:42:26 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10202026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10212026/10/10 19:42:26 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10222026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10232026/10/10 19:42:26 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110242026/10/10 19:42:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/10 19:42:26 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1026--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.58s)1027=== CONT TestMultipartCleanup10282026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/10 19:42:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10342026/10/10 19:42:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10352026/10/10 19:42:26 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLmU2YjRiZjllLTM5MmEtNGYxNC1iMWI1LTliZGE1NzJlYjhjYXgxNzkxNjYxMzQ2NDc0MTAzNjY410362026/10/10 19:42:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLmU2YjRiZjllLTM5MmEtNGYxNC1iMWI1LTliZGE1NzJlYjhjYXgxNzkxNjYxMzQ2NDc0MTAzNjY4 parts=11037--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.67s)1038=== CONT TestServerTLSConfig1039=== RUN TestServerTLSConfig/no_client_CA1040=== PAUSE TestServerTLSConfig/no_client_CA1041=== RUN TestServerTLSConfig/missing_CA_file1042=== PAUSE TestServerTLSConfig/missing_CA_file1043=== RUN TestServerTLSConfig/not_a_PEM_file1044=== PAUSE TestServerTLSConfig/not_a_PEM_file1045=== CONT TestService_NativeMTLS1046--- PASS: TestReadProxyInvalidPath (0.67s)1047=== CONT TestMetricsCommit1048--- PASS: TestService_Rustfstest (0.68s)1049=== CONT TestMetricsInventory10502026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures10512026/10/10 19:42:26 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10522026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures1053--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.68s)1054=== CONT TestNARDeduplicationMetadataUploadBug10552026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures1056--- PASS: TestPresentReportsOnlyClosureRoots (0.62s)1057=== CONT TestCreatePendingClosureRejectsOversizedNAR10582026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures1059--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1060=== CONT TestCacheConfigHandlerMaxNarSize1061--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1062=== CONT TestGenerateLandingPage1063--- PASS: TestGenerateLandingPage (0.00s)1064=== CONT TestService_readinessHandler1065--- PASS: TestPresentRefreshesOnlyStaleClosures (0.77s)1066=== CONT TestService_healthCheckHandler1067--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.80s)1068=== CONT TestGracefulShutdownDrainsInflight10692026/10/10 19:42:26 INFO Starting HTTP server address=127.0.0.1:3935710702026/10/10 19:42:26 INFO Shutdown signal received, draining in-flight requests timeout=10s1071--- PASS: TestReadProxyNarStreaming (0.83s)1072=== CONT TestGCTaskStore_Fail1073--- PASS: TestGCTaskStore_Fail (0.00s)1074=== CONT TestGCTaskStore_PhaseUpdates1075--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1076=== CONT TestGCTaskStore_CompletedAllowsNewTask1077--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1078=== CONT TestGCTaskStore_GetReturnsLatest1079--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1080=== CONT TestGCTaskStore_GetEmpty1081--- PASS: TestGCTaskStore_GetEmpty (0.00s)1082=== CONT TestGCTaskStore_ConflictDifferentParams1083--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1084=== CONT TestGCTaskStore_DeduplicateSameParams1085--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1086=== CONT TestGCTaskStore_StartNew1087--- PASS: TestGCTaskStore_StartNew (0.00s)1088=== CONT TestGCEndsOnShutdown1089=== RUN TestGCEndsOnShutdown/before_the_run1090=== PAUSE TestGCEndsOnShutdown/before_the_run1091=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1092=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1093=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1094=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1095=== CONT TestCommitRacingPendingCleanupKeepsObjects10962026/10/10 19:42:26 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1097--- PASS: TestReadProxyNarinfo (0.84s)1098=== CONT TestResolveDBConnectionString1099=== RUN TestResolveDBConnectionString/flag_wins1100=== PAUSE TestResolveDBConnectionString/flag_wins1101=== RUN TestResolveDBConnectionString/file_when_flag_empty1102=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1103=== RUN TestResolveDBConnectionString/missing_file_is_an_error1104=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1105=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1106=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1107=== RUN TestResolveDBConnectionString/nothing_configured1108=== PAUSE TestResolveDBConnectionString/nothing_configured1109=== CONT TestSweepRechecksPendingAfterLocking11102026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1112=== CONT TestGetExistingObjectsLocksRows11132026/10/10 19:42:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11142026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures11152026/10/10 19:42:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLmI2MmE0MWQ2LTFjZGMtNDQ1Ni1iOWMwLTdmYjg1Y2IwMmM0YXgxNzkxNjYxMzQ2MzQ3NjM3NjQ4 parts=1011162026/10/10 19:42:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11172026/10/10 19:42:26 INFO Completed upload id=1 objects=2 duration=6.086059ms11182026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/10 19:42:26 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/10 19:42:26 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11212026/10/10 19:42:26 WARN Found objects in DB but missing from S3, will re-upload count=11122--- PASS: TestService_verifyS3Integrity (1.01s)1123=== CONT TestRegisterCompletedObjectNeedsPendingRow1124--- PASS: TestReadProxyContentNegotiation (0.94s)1125=== CONT TestSweepSkipsRowsLockedByPush11262026/10/10 19:42:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11272026/10/10 19:42:26 WARN Refused reserved pin name=worker-x86_64-linux11282026/10/10 19:42:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11292026/10/10 19:42:26 INFO Received create pin request method=POST path=/api/pins/my-app11302026/10/10 19:42:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1131--- PASS: TestCreatePin_ReservedPins (0.69s)1132=== CONT TestFailedS3DeleteKeepsTombstone1133--- PASS: TestPushWaitsForSweepHoldingRow (1.10s)1134=== CONT TestForceGCDuringPushOffersSweptObject1135=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1136=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1137=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1138=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1139=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11402026/10/10 19:42:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1141--- PASS: TestObjectStatsTrigger (0.68s)1142=== CONT TestGCSweepDeliversEachKeyOnce11432026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/10 19:42:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLjU0ZDZhYmEwLThjM2EtNGYxNi1iY2ZlLWQzNWNkYzRhY2M5ZngxNzkxNjYxMzQ2NTE0ODcwMDA0 parts=1011452026/10/10 19:42:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1146--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.60s)1147=== CONT TestTombstonedObjectOfferedWithoutWaiting11482026/10/10 19:42:27 INFO Completed upload id=1 objects=2 duration=5.873479ms11492026/10/10 19:42:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011502026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures11512026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/10 19:42:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures11532026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures11542026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=011552026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/10 19:42:27 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=011572026/10/10 19:42:27 INFO Received cleanup request method=DELETE path=/api/pending_closures11582026/10/10 19:42:27 INFO Vacuumed table table=pending_closures11592026/10/10 19:42:27 INFO Vacuumed table table=pending_objects11602026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads11612026/10/10 19:42:27 INFO Vacuumed table table=closures11622026/10/10 19:42:27 INFO Vacuumed table table=objects11632026/10/10 19:42:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011642026/10/10 19:42:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11652026/10/10 19:42:27 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1166--- PASS: TestService_NativeMTLS (0.57s)1167=== CONT TestGCSweepSkipsPendingObjects1168--- PASS: TestService_createPendingClosureHandler (1.24s)1169=== CONT TestDeduplicatedObjectsRecordedAsPending11702026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes11712026/10/10 19:42:27 INFO Received complete push request method=POST path=/api/pushes/1/complete11722026/10/10 19:42:27 INFO Completed push id=1 objects=4 duration=8.924824ms11732026/10/10 19:42:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11742026/10/10 19:42:27 INFO Completed upload id=2 objects=2 duration=3.122234ms1175--- PASS: TestMetricsCommit (0.65s)1176=== CONT TestPushDedupSurvivesConcurrentGC11772026/10/10 19:42:27 INFO Received cleanup request method=DELETE path=/api/pending_closures1178--- PASS: TestMetricsInventory (0.63s)1179=== CONT TestGCMetrics11802026/10/10 19:42:27 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket35/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11812026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=111822026/10/10 19:42:27 INFO Received cleanup request method=DELETE path=/api/pending_closures11832026/10/10 19:42:27 INFO Aborted multipart uploads count=1 kept=011842026/10/10 19:42:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1185--- PASS: TestMultipartCleanup (0.77s)1186=== CONT TestGCBugBareHashReferences11872026/10/10 19:42:27 WARN readiness check failed error="closed pool"1188--- PASS: TestService_readinessHandler (0.56s)1189=== CONT TestGCAdvisoryLockBlocksConcurrentRun11902026/10/10 19:42:27 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLjJjZDEzMGEyLWU0ZTQtNGNiZC05MmJmLTI4NjVlZWRhYTEwNngxNzkxNjYxMzQ2NjE4NDE0NjM2 parts=1211912026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures1192=== NAME TestNARDeduplicationMetadataUploadBug1193 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2896960619/001/store/4n07gq5dz5ryblshqc876f589xf8hv7w-file1.txt1194--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.32s)1195=== CONT TestLeadEndsOnShutdown1196--- PASS: TestService_healthCheckHandler (0.54s)1197=== CONT TestLeadIncumbentAnnouncesAtOnce1198=== NAME TestOrphanedObjectsGC1199 orphaned_objects_gc_test.go:287: GC Test Summary:1200 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1201 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1202 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1203 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1204 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1205--- PASS: TestOrphanedObjectsGC (1.02s)1206=== CONT TestLeadElectsOneAndHandsOver12072026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes12082026/10/10 19:42:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12092026/10/10 19:42:27 INFO Uploading 4n07gq5dz5ryblshqc876f589xf8hv7w-file1.txt (160B)12102026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=012112026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=012122026/10/10 19:42:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12132026/10/10 19:42:27 WARN Failed to register uploaded object key=4n07gq5dz5ryblshqc876f589xf8hv7w.ls error="server returned 404: 404 page not found\n"12142026/10/10 19:42:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12152026/10/10 19:42:27 INFO Signed narinfos id=1 count=112162026/10/10 19:42:27 INFO Uploading 1 narinfos12172026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period12182026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period12192026/10/10 19:42:27 INFO Received complete push request method=POST path=/api/pushes/1/complete12202026/10/10 19:42:27 WARN Failed to register uploaded object key=4n07gq5dz5ryblshqc876f589xf8hv7w.narinfo error="server returned 404: 404 page not found\n"12212026/10/10 19:42:27 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=012222026/10/10 19:42:27 INFO Vacuumed table table=pending_closures12232026/10/10 19:42:27 INFO Vacuumed table table=pending_objects12242026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads12252026/10/10 19:42:27 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=012262026/10/10 19:42:27 INFO Completed push id=1 objects=3 duration=10.854031ms12272026/10/10 19:42:27 INFO Upload complete. (81ms)12282026/10/10 19:42:27 INFO Vacuumed table table=closures12292026/10/10 19:42:27 INFO Vacuumed table table=objects1230=== NAME TestNARDeduplicationMetadataUploadBug1231 metadata_upload_test.go:54: Retrieved narinfo from S3:1232 StorePath: /build/TestNARDeduplicationMetadataUploadBug2896960619/001/store/4n07gq5dz5ryblshqc876f589xf8hv7w-file1.txt1233 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1234 Compression: zstd1235 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1236 NarSize: 1601237 References: 1238 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12392026/10/10 19:42:27 INFO Vacuumed table table=pending_closures1240 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1241 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):12422026/10/10 19:42:27 INFO Vacuumed table table=pending_objects1243 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12442026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads12452026/10/10 19:42:27 INFO Vacuumed table table=closures12462026/10/10 19:42:27 INFO Vacuumed table table=objects1247--- PASS: TestSweepRechecksPendingAfterLocking (0.60s)1248=== CONT TestConnectWaitsForAPeerMigration1249--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.61s)1250=== CONT TestReadProxyRangeRequest12512026/10/10 19:42:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1252--- PASS: TestGetExistingObjectsLocksRows (0.61s)1253=== CONT TestPush_RootsAreLockedInByteOrder1254=== NAME TestNARDeduplicationMetadataUploadBug1255 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2896960619/001/store/m9wchvf45m7zjcp6sdncwyfz5jjckzw6-file2.txt1256--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.56s)1257=== CONT TestPush_CompleteWaitsForCleanupOfThePush12582026/10/10 19:42:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLjBhOTNhZDk5LTAzZDktNGViNy04YzEwLTk3ZWJhMjkyOTVjNXgxNzkxNjYxMzQ2Nzk1Nzc5NTQz parts=1212592026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures12602026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures12612026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures12622026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=012632026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period12642026/10/10 19:42:27 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=012652026/10/10 19:42:27 INFO Vacuumed table table=pending_closures12662026/10/10 19:42:27 INFO Vacuumed table table=pending_objects12672026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads12682026/10/10 19:42:27 INFO Vacuumed table table=closures12692026/10/10 19:42:27 INFO Vacuumed table table=objects12702026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures12712026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=012722026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period12732026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes12742026/10/10 19:42:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12752026/10/10 19:42:27 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12762026/10/10 19:42:27 INFO Signed narinfos id=2 count=112772026/10/10 19:42:27 WARN Failed to register uploaded object key=m9wchvf45m7zjcp6sdncwyfz5jjckzw6.ls error="server returned 404: 404 page not found\n"12782026/10/10 19:42:27 INFO Uploading 1 narinfos12792026/10/10 19:42:27 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=012802026/10/10 19:42:27 INFO Vacuumed table table=pending_closures12812026/10/10 19:42:27 INFO Vacuumed table table=pending_objects12822026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads12832026/10/10 19:42:27 INFO Vacuumed table table=closures12842026/10/10 19:42:27 INFO Vacuumed table table=objects12852026/10/10 19:42:27 INFO Received complete push request method=POST path=/api/pushes/2/complete12862026/10/10 19:42:27 WARN Failed to register uploaded object key=m9wchvf45m7zjcp6sdncwyfz5jjckzw6.narinfo error="server returned 404: 404 page not found\n"1287--- PASS: TestSweepSkipsRowsLockedByPush (0.65s)1288=== CONT TestPush_RepeatedRootCommitsOnce12892026/10/10 19:42:27 INFO Completed push id=2 objects=3 duration=6.125039ms12902026/10/10 19:42:27 INFO Upload complete. (64ms)1291=== NAME TestNARDeduplicationMetadataUploadBug1292 metadata_upload_test.go:76: Retrieved narinfo from S3:1293 StorePath: /build/TestNARDeduplicationMetadataUploadBug2896960619/001/store/m9wchvf45m7zjcp6sdncwyfz5jjckzw6-file2.txt1294 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1295 Compression: zstd1296 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1297 NarSize: 1601298 References: 1299 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1300 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1301 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1302 {"version":1,"root":{"type":"regular","size":44}}1303--- PASS: TestNARDeduplicationMetadataUploadBug (0.93s)1304=== CONT TestPush_CompleteCommitsEveryRoot13052026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=01307--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.53s)1308=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13092026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=013102026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period13112026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period13122026/10/10 19:42:27 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13132026/10/10 19:42:27 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13142026/10/10 19:42:27 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=01315--- PASS: TestFailedS3DeleteKeepsTombstone (0.69s)1316=== CONT TestReadRedirectUsesPublicS3URL13172026/10/10 19:42:27 INFO Vacuumed table table=pending_closures13182026/10/10 19:42:27 INFO Vacuumed table table=pending_objects13192026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads13202026/10/10 19:42:27 INFO Vacuumed table table=closures13212026/10/10 19:42:27 INFO Vacuumed table table=objects1322--- PASS: TestGCSweepDeliversEachKeyOnce (0.58s)1323=== CONT TestClientErrorHandling1324=== RUN TestClientErrorHandling/InvalidStorePath1325=== PAUSE TestClientErrorHandling/InvalidStorePath1326=== RUN TestClientErrorHandling/InvalidAuthToken1327=== PAUSE TestClientErrorHandling/InvalidAuthToken1328=== RUN TestClientErrorHandling/ServerNotAvailable1329=== PAUSE TestClientErrorHandling/ServerNotAvailable1330=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13312026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures1332--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.49s)1333=== CONT TestDeleteClosuresRacingPins13342026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures13352026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=013362026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period13372026/10/10 19:42:27 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013382026/10/10 19:42:27 INFO Vacuumed table table=pending_closures13392026/10/10 19:42:27 INFO Vacuumed table table=pending_objects13402026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads13412026/10/10 19:42:27 INFO Vacuumed table table=closures13422026/10/10 19:42:27 INFO Received uploads request method=POST path=/api/pending_closures13432026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=013442026/10/10 19:42:27 INFO Vacuumed table table=objects13452026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period1346--- PASS: TestGCSweepSkipsPendingObjects (0.58s)1347=== CONT TestClientFallsBackToClosures13482026/10/10 19:42:27 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=013492026/10/10 19:42:27 INFO Vacuumed table table=pending_closures13502026/10/10 19:42:27 INFO Vacuumed table table=pending_objects13512026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads13522026/10/10 19:42:27 INFO Vacuumed table table=closures13532026/10/10 19:42:27 INFO Vacuumed table table=objects1354--- PASS: TestGCMetrics (0.51s)1355=== CONT TestClientWithDependencies13562026/10/10 19:42:27 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1357--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.48s)1358=== CONT TestClientMultipleUploads1359--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.75s)1360=== CONT TestClientIntegration13612026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=013622026/10/10 19:42:27 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=013632026/10/10 19:42:27 INFO lead: acquired remote=192.0.2.1:123413642026/10/10 19:42:27 INFO lead: released remote=192.0.2.1:12341365--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.55s)1366=== CONT TestClientPushesUseOnePush13672026/10/10 19:42:27 INFO Vacuumed table table=pending_closures13682026/10/10 19:42:27 INFO Vacuumed table table=pending_objects13692026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads13702026/10/10 19:42:27 INFO Vacuumed table table=closures13712026/10/10 19:42:27 INFO Vacuumed table table=objects13722026/10/10 19:42:27 INFO Aborted multipart uploads count=0 kept=013732026/10/10 19:42:27 WARN Force mode enabled - objects will be deleted immediately without grace period13742026/10/10 19:42:27 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=013752026/10/10 19:42:27 INFO Vacuumed table table=pending_closures13762026/10/10 19:42:27 INFO Vacuumed table table=pending_objects13772026/10/10 19:42:27 INFO Vacuumed table table=multipart_uploads13782026/10/10 19:42:27 INFO lead: acquired remote=192.0.2.1:123413792026/10/10 19:42:27 INFO Vacuumed table table=closures13802026/10/10 19:42:27 INFO Vacuumed table table=objects1381--- PASS: TestPushDedupSurvivesConcurrentGC (0.65s)1382=== CONT TestService_RequireScope_OIDC13832026/10/10 19:42:27 INFO lead: acquired remote=192.0.2.1:123413842026/10/10 19:42:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39487/oidc1385--- PASS: TestReadProxyRangeRequest (0.51s)1386=== CONT TestClientCADerivations1387--- PASS: TestObjectStatsLargeCommit (1.58s)1388=== CONT TestCacheStatsHandler13892026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes13902026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes13912026-10-10 19:42:27.955 UTC [975] ERROR: could not obtain lock on row in relation "closures"13922026-10-10 19:42:27.955 UTC [975] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13932026-10-10 19:42:27.956 UTC [975] ERROR: could not obtain lock on row in relation "closures"13942026-10-10 19:42:27.956 UTC [975] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13952026-10-10 19:42:27.956 UTC [975] ERROR: could not obtain lock on row in relation "closures"13962026-10-10 19:42:27.956 UTC [975] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13972026-10-10 19:42:27.957 UTC [975] ERROR: could not obtain lock on row in relation "closures"13982026-10-10 19:42:27.957 UTC [975] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT13992026-10-10 19:42:27.957 UTC [975] ERROR: could not obtain lock on row in relation "closures"14002026-10-10 19:42:27.957 UTC [975] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14012026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes1402--- PASS: TestPush_RootsAreLockedInByteOrder (0.56s)1403=== CONT TestCacheConfigHandler1404=== RUN TestCacheConfigHandler/full_config,_no_issuer1405=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1406=== RUN TestCacheConfigHandler/no_cache_url_configured1407=== PAUSE TestCacheConfigHandler/no_cache_url_configured1408=== RUN TestCacheConfigHandler/no_signing_keys1409=== PAUSE TestCacheConfigHandler/no_signing_keys1410=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1411=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1412=== CONT TestService_ReadScope_PublicByDefault14132026/10/10 19:42:27 INFO Received push request method=POST path=/api/pushes14142026/10/10 19:42:27 INFO Received complete push request method=POST path=/api/pushes/1/complete14152026/10/10 19:42:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14162026/10/10 19:42:27 INFO Completed push id=1 objects=4 duration=8.936374ms1417--- PASS: TestPush_RepeatedRootCommitsOnce (0.47s)1418=== CONT TestService_ReadAuthMiddleware14192026/10/10 19:42:28 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLjM1YTRhOGU5LTBlOGUtNGM0Mi1iNTY1LTU4YzdiYjg1NjQzZXgxNzkxNjYxMzQ3NDM0MTAzNDAz error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14202026/10/10 19:42:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODM5MmIwNWYtZmRmYy00ODZmLThlMTMtZmUxMzExYTQwODFkLmIzNmMyOWYzLTM5N2EtNGY3YS04YjViLTRhMDVjMjkzOGU0ZngxNzkxNjYxMzQ3NDI2NTc1MjM2 parts=1214212026/10/10 19:42:28 INFO Received cleanup request method=DELETE path=/api/pending_closures14222026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes14232026/10/10 19:42:28 INFO Aborted multipart uploads count=1 kept=014242026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete1425--- PASS: TestRedundantMultipartUpload (2.15s)1426=== CONT TestService_AuthMiddleware_OIDC1427--- PASS: TestGCBugBareHashReferences (0.81s)1428=== CONT TestPinProtectsFromGC14292026/10/10 19:42:28 INFO Completed push id=1 objects=6 duration=9.476332ms1430--- PASS: TestPush_CompleteCommitsEveryRoot (0.48s)1431=== CONT TestReadProxyRootRedirectsToIndexHTML1432--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.49s)1433=== CONT TestReadRedirectKeepsNarinfoProxied1434--- PASS: TestReadRedirectUsesPublicS3URL (0.47s)1435=== CONT TestReadRedirectNar14362026/10/10 19:42:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45979/oidc1437=== NAME TestClientMultipleUploads1438 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2077289907/001/store/38vm6dipsj2qn6cnzc5qlih78qik2xww-test-file-0.txt1439=== NAME TestClientWithDependencies1440 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3982060075/001/store/r7h4vrnmdi5i3n7hq6hc4q6jaiws575i-test-script1441=== NAME TestClientIntegration1442 client_integration_test.go:286: Created store path: /build/TestClientIntegration1051763967/002/store/ka3p7vysk1fknvvhr9p01a74yxv8lxq6-test-file.txt1443=== NAME TestClientMultipleUploads1444 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2077289907/001/store/ljy7p22w5j614hd6fzdy9sjmfvs3f3xk-test-file-1.txt14452026-10-10 19:42:28.254 UTC [976] ERROR: Push does not exist: id=114462026-10-10 19:42:28.254 UTC [976] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14472026-10-10 19:42:28.254 UTC [976] STATEMENT: SELECT commit_push($1)1448--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.84s)1449=== CONT TestReadProxyDisabled1450=== NAME TestClientWithDependencies1451 client_integration_test.go:615: Found 1 dependencies (including self)1452=== RUN TestService_RequireScope_OIDC/builder_may_write1453=== PAUSE TestService_RequireScope_OIDC/builder_may_write1454=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1455=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1456=== RUN TestService_RequireScope_OIDC/ops_may_admin1457=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1458=== RUN TestService_RequireScope_OIDC/ops_may_not_write1459=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1460=== RUN TestService_RequireScope_OIDC/reader_may_not_write1461=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1462=== RUN TestService_RequireScope_OIDC/static_token_may_admin1463=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1464=== RUN TestService_RequireScope_OIDC/static_token_may_write1465=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1466=== RUN TestService_RequireScope_OIDC/reader_may_read1467=== PAUSE TestService_RequireScope_OIDC/reader_may_read1468=== RUN TestService_RequireScope_OIDC/writer_implies_read1469=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1470=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1471=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1472=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1473=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1474=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1475=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1476=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1477=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1478=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1479=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1480=== CONT TestReadProxyOutlastsServerWriteTimeout1481--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.69s)1482=== CONT TestReadProxyConditionalGet1483=== NAME TestClientMultipleUploads1484 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2077289907/001/store/589d886a2723hslv45a6w034ajzhmk73-test-file-2.txt14852026/10/10 19:42:28 INFO Received uploads request method=POST path=/api/pending_closures1486--- PASS: TestCacheStatsHandler (0.41s)1487=== CONT TestReadProxyHead1488--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1489=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14902026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes14912026/10/10 19:42:28 INFO Received uploads request method=POST path=/api/pending_closures14922026/10/10 19:42:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14932026/10/10 19:42:28 INFO Uploading kla0y364plwaw3pd37pf2gh5qs3b89ik-b (216B)14942026/10/10 19:42:28 INFO Uploading cngby1gfaivfymkq47vgfjhbk3kvyqcz-shared-dep (136B)14952026/10/10 19:42:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14962026/10/10 19:42:28 INFO Uploading ka3p7vysk1fknvvhr9p01a74yxv8lxq6-test-file.txt (152B)14972026/10/10 19:42:28 WARN Failed to register uploaded object key=aib24hqakjs3aq6akjj1h3x9a4jmdw4q.ls error="server returned 404: 404 page not found\n"14982026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/0lr9j6jsx7r89zm19x6mi7b3l4776zy1a0zi0lsp2lr95w9wgirz.nar.zst error="server returned 404: 404 page not found\n"14992026/10/10 19:42:28 WARN Failed to register uploaded object key=kla0y364plwaw3pd37pf2gh5qs3b89ik.ls error="server returned 404: 404 page not found\n"15002026/10/10 19:42:28 WARN Failed to register uploaded object key=cngby1gfaivfymkq47vgfjhbk3kvyqcz.ls error="server returned 404: 404 page not found\n"15012026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15022026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15032026/10/10 19:42:28 INFO Signed narinfos id=1 count=215042026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15052026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15062026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15072026/10/10 19:42:28 INFO Signed narinfos id=2 count=215082026/10/10 19:42:28 WARN Failed to register uploaded object key=ka3p7vysk1fknvvhr9p01a74yxv8lxq6.ls error="server returned 404: 404 page not found\n"15092026/10/10 19:42:28 INFO Uploading 4 narinfos15102026/10/10 19:42:28 INFO Signed narinfos id=1 count=115112026/10/10 19:42:28 INFO Uploading 1 narinfos1512--- PASS: TestService_ReadAuthMiddleware (0.34s)1513=== CONT TestService_AuthMiddleware_MTLSProxyHeader15142026/10/10 19:42:28 WARN Failed to register uploaded object key=cngby1gfaivfymkq47vgfjhbk3kvyqcz.narinfo error="server returned 404: 404 page not found\n"15152026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15162026/10/10 19:42:28 WARN Failed to register uploaded object key=ka3p7vysk1fknvvhr9p01a74yxv8lxq6.narinfo error="server returned 404: 404 page not found\n"15172026/10/10 19:42:28 WARN Failed to register uploaded object key=aib24hqakjs3aq6akjj1h3x9a4jmdw4q.narinfo error="server returned 404: 404 page not found\n"15182026/10/10 19:42:28 WARN Failed to register uploaded object key=kla0y364plwaw3pd37pf2gh5qs3b89ik.narinfo error="server returned 404: 404 page not found\n"15192026/10/10 19:42:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15202026/10/10 19:42:28 WARN Failed to register uploaded object key=cngby1gfaivfymkq47vgfjhbk3kvyqcz.narinfo error="server returned 404: 404 page not found\n"15212026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes15222026/10/10 19:42:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15232026/10/10 19:42:28 INFO Uploading r7h4vrnmdi5i3n7hq6hc4q6jaiws575i-test-script (136B)15242026/10/10 19:42:28 INFO Completed upload id=1 objects=6 duration=8.831024ms15252026/10/10 19:42:28 INFO Completed push id=1 objects=3 duration=10.233871ms15262026/10/10 19:42:28 INFO Upload complete. (71ms)15272026/10/10 19:42:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15282026/10/10 19:42:28 INFO Completed upload id=2 objects=6 duration=2.733445ms15292026/10/10 19:42:28 INFO Upload complete. (81ms)15302026/10/10 19:42:28 WARN Failed to register uploaded object key=log/jkpsbn97x38q4lvcynmdxmg0ldk7if0c-test-script.drv error="server returned 404: 404 page not found\n"15312026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15322026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15332026/10/10 19:42:28 WARN Failed to register uploaded object key=r7h4vrnmdi5i3n7hq6hc4q6jaiws575i.ls error="server returned 404: 404 page not found\n"1534=== NAME TestClientFallsBackToClosures1535 client_pushes_test.go:112: Retrieved narinfo from S3:1536 StorePath: /build/TestClientFallsBackToClosures2669849524/001/store/cngby1gfaivfymkq47vgfjhbk3kvyqcz-shared-dep1537 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1538 Compression: zstd1539 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821540 NarSize: 1361541 References: 15422026/10/10 19:42:28 INFO Signed narinfos id=1 count=11543 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15442026/10/10 19:42:28 INFO Uploading 1 narinfos1545 client_pushes_test.go:112: Retrieved narinfo from S3:1546 StorePath: /build/TestClientFallsBackToClosures2669849524/001/store/aib24hqakjs3aq6akjj1h3x9a4jmdw4q-a1547 URL: nar/0lr9j6jsx7r89zm19x6mi7b3l4776zy1a0zi0lsp2lr95w9wgirz.nar.zst1548 Compression: zstd1549 NarHash: sha256:0lr9j6jsx7r89zm19x6mi7b3l4776zy1a0zi0lsp2lr95w9wgirz1550 NarSize: 2161551 References: /build/TestClientFallsBackToClosures2669849524/001/store/cngby1gfaivfymkq47vgfjhbk3kvyqcz-shared-dep1552 CA: text:sha256:0f5ick5kvcs92fyh72vb7n44ayi247706d37hn15kg8wa7s8vrsk15532026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete15542026/10/10 19:42:28 WARN Failed to register uploaded object key=r7h4vrnmdi5i3n7hq6hc4q6jaiws575i.narinfo error="server returned 404: 404 page not found\n"1555 client_pushes_test.go:112: Retrieved narinfo from S3:1556 StorePath: /build/TestClientFallsBackToClosures2669849524/001/store/kla0y364plwaw3pd37pf2gh5qs3b89ik-b1557 URL: nar/0lr9j6jsx7r89zm19x6mi7b3l4776zy1a0zi0lsp2lr95w9wgirz.nar.zst1558 Compression: zstd1559 NarHash: sha256:0lr9j6jsx7r89zm19x6mi7b3l4776zy1a0zi0lsp2lr95w9wgirz1560 NarSize: 2161561 References: /build/TestClientFallsBackToClosures2669849524/001/store/cngby1gfaivfymkq47vgfjhbk3kvyqcz-shared-dep1562 CA: text:sha256:0f5ick5kvcs92fyh72vb7n44ayi247706d37hn15kg8wa7s8vrsk1563--- PASS: TestReadRedirectKeepsNarinfoProxied (0.32s)1564=== CONT TestClientSharedPathCommittedMidPush15652026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes1566--- PASS: TestClientFallsBackToClosures (0.68s)1567=== CONT TestPendingClosureWriteTimeout/empty1568=== CONT TestPendingClosureWriteTimeout/400_objects1569=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1570=== NAME TestClientCADerivations1571 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations579056019/001/store/rlwkjbki5zb7kcqk0q57kavz5gahwydf-ca-test15722026/10/10 19:42:28 INFO Completed push id=1 objects=4 duration=16.905909ms15732026/10/10 19:42:28 INFO Upload complete. (75ms)15742026/10/10 19:42:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15752026/10/10 19:42:28 INFO Uploading 38vm6dipsj2qn6cnzc5qlih78qik2xww-test-file-0.txt (160B)15762026/10/10 19:42:28 INFO Uploading ljy7p22w5j614hd6fzdy9sjmfvs3f3xk-test-file-1.txt (160B)15772026/10/10 19:42:28 INFO Uploading 589d886a2723hslv45a6w034ajzhmk73-test-file-2.txt (160B)1578=== NAME TestClientWithDependencies1579 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3982060075/001/store) requires matching store prefix15802026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15812026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15822026/10/10 19:42:28 WARN Failed to register uploaded object key=38vm6dipsj2qn6cnzc5qlih78qik2xww.ls error="server returned 404: 404 page not found\n"15832026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15842026/10/10 19:42:28 WARN Failed to register uploaded object key=589d886a2723hslv45a6w034ajzhmk73.ls error="server returned 404: 404 page not found\n"15852026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15862026/10/10 19:42:28 WARN Failed to register uploaded object key=ljy7p22w5j614hd6fzdy9sjmfvs3f3xk.ls error="server returned 404: 404 page not found\n"15872026/10/10 19:42:28 INFO Signed narinfos id=1 count=315882026/10/10 19:42:28 INFO Uploading 3 narinfos15892026/10/10 19:42:28 INFO All 1 paths already cached1590--- PASS: TestClientWithDependencies (0.69s)1591=== CONT TestPendingClosureWriteTimeout/670k_objects1592=== CONT TestProxyWriteTimeout/narinfo1593=== CONT TestProxyWriteTimeout/unknown_size1594=== CONT TestProxyWriteTimeout/10_GiB_nar1595=== CONT TestProxyWriteTimeout/1_GiB_nar1596--- PASS: TestReadRedirectNar (0.34s)1597=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1598=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15992026/10/10 19:42:28 INFO Received uploads request method=POST path=/16002026/10/10 19:42:28 INFO Received request for more parts method=POST path=/1601=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16022026/10/10 19:42:28 INFO Received complete multipart upload request method=POST path=/1603--- PASS: TestProxyWriteTimeout (0.08s)1604 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1605 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1606 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1607 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1608=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16092026/10/10 19:42:28 INFO Received uploads request method=POST path=/1610=== NAME TestClientIntegration1611 client_integration_test.go:312: Retrieved narinfo from S3:1612 StorePath: /build/TestClientIntegration1051763967/002/store/ka3p7vysk1fknvvhr9p01a74yxv8lxq6-test-file.txt16132026/10/10 19:42:28 WARN Failed to register uploaded object key=589d886a2723hslv45a6w034ajzhmk73.narinfo error="server returned 404: 404 page not found\n"1614 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1615 Compression: zstd1616 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116172026/10/10 19:42:28 WARN Failed to register uploaded object key=ljy7p22w5j614hd6fzdy9sjmfvs3f3xk.narinfo error="server returned 404: 404 page not found\n"1618 NarSize: 1521619 References: 1620=== CONT TestIsValidUploadKey/narinfo1621--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1622 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1623 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1624 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1625 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)16262026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete1627=== CONT TestIsValidUploadKey/realisation_plus_in_output16282026/10/10 19:42:28 WARN Failed to register uploaded object key=38vm6dipsj2qn6cnzc5qlih78qik2xww.narinfo error="server returned 404: 404 page not found\n"1629=== NAME TestClientIntegration1630 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11631=== CONT TestIsValidUploadKey/realisation1632=== CONT TestIsValidUploadKey/build_log_equals1633=== CONT TestIsValidUploadKey/build_log_plus_in_name1634=== CONT TestIsValidUploadKey/build_log_home-manager_file1635=== CONT TestIsValidUploadKey/build_log1636=== CONT TestIsValidUploadKey/listing1637=== CONT TestIsValidUploadKey/nar_plain1638=== CONT TestIsValidUploadKey/nix-cache-info1639=== CONT TestIsValidUploadKey/nar_xz1640=== CONT TestIsValidUploadKey/nar_zst1641=== CONT TestIsValidUploadKey/traversal1642=== CONT TestIsValidUploadKey/absolute1643=== CONT TestIsValidUploadKey/build_log_question_mark1644=== CONT TestIsValidUploadKey/traversal_nar1645=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1646=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1647=== CONT TestIsValidUploadKey/unknown_type1648=== CONT TestIsValidUploadKey/index.html1649=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1650=== CONT TestIsValidUploadKey/empty_key1651--- PASS: TestIsValidUploadKey (0.08s)1652 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1653 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1654 --- PASS: TestIsValidUploadKey/realisation (0.00s)1655 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1656 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1657 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1658 --- PASS: TestIsValidUploadKey/build_log (0.00s)1659 --- PASS: TestIsValidUploadKey/listing (0.00s)1660 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1661 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1662 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1663 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1664 --- PASS: TestIsValidUploadKey/traversal (0.00s)1665 --- PASS: TestIsValidUploadKey/absolute (0.00s)1666 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1667 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1668 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1669 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1670 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1671 --- PASS: TestIsValidUploadKey/index.html (0.00s)1672 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1673 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1674=== CONT TestIsValidCachePath/narinfo1675=== CONT TestIsValidCachePath/random_path1676=== CONT TestIsValidCachePath/invalid_char_e1677=== CONT TestIsValidCachePath/traversal_in_middle1678=== CONT TestIsValidCachePath/traversal_parent1679=== CONT TestIsValidCachePath/index.html1680=== CONT TestIsValidCachePath/nix-cache-info1681=== CONT TestIsValidCachePath/realisation1682=== CONT TestIsValidCachePath/log1683=== CONT TestIsValidCachePath/ls1684=== CONT TestIsValidCachePath/nar_uncompressed1685=== CONT TestIsValidCachePath/nar_bz21686=== CONT TestIsValidCachePath/nar_xz1687=== CONT TestIsValidCachePath/nar_zst1688=== CONT TestIsValidCachePath/invalid_char_u1689=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1690=== NAME TestClientIntegration1691 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1692=== CONT TestIsValidCachePath/short_hash1693=== CONT TestIsValidCachePath/empty1694=== CONT TestIsValidCachePath/leading_slash1695=== CONT TestIsValidCachePath/wrong_extension1696=== NAME TestClientIntegration1697 client_integration_test.go:313: Decompressed .ls content (64 bytes):1698 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1699 client_integration_test.go:316: Testing garbage collection...1700=== CONT TestParseSingleRange/none1701=== CONT TestParseSingleRange/start_far_past_EOF1702=== CONT TestParseSingleRange/start_past_EOF1703=== CONT TestParseSingleRange/suffix1704=== CONT TestParseSingleRange/end_clamped_to_size1705=== CONT TestParseSingleRange/single_byte1706=== CONT TestParseSingleRange/malformed_both_empty1707=== CONT TestParseSingleRange/suffix_exceeds_size1708=== CONT TestParseSingleRange/closed1709=== CONT TestParseSingleRange/multi-range_ignored1710=== CONT TestParseSingleRange/malformed_end_before_start1711=== CONT TestParseSingleRange/malformed_no_dash1712=== CONT TestParseSingleRange/unknown_unit1713=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1714--- PASS: TestIsValidCachePath (0.00s)1715 --- PASS: TestIsValidCachePath/narinfo (0.00s)1716 --- PASS: TestIsValidCachePath/random_path (0.00s)1717 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1718 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1719 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1720 --- PASS: TestIsValidCachePath/index.html (0.00s)1721 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1722 --- PASS: TestIsValidCachePath/realisation (0.00s)1723 --- PASS: TestIsValidCachePath/log (0.00s)1724 --- PASS: TestIsValidCachePath/ls (0.00s)1725 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1726 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1727 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1728 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1729 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1730 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1731 --- PASS: TestIsValidCachePath/short_hash (0.00s)1732 --- PASS: TestIsValidCachePath/empty (0.00s)1733 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1734 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1735=== CONT TestParseSingleRange/open-ended1736--- PASS: TestParseSingleRange (0.00s)1737 --- PASS: TestParseSingleRange/none (0.00s)1738 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1739 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1740 --- PASS: TestParseSingleRange/suffix (0.00s)1741 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1742 --- PASS: TestParseSingleRange/single_byte (0.00s)1743 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1744 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1745 --- PASS: TestParseSingleRange/closed (0.00s)1746 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1747 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1748 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1749 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1750 --- PASS: TestParseSingleRange/open-ended (0.00s)1751=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale17522026/10/10 19:42:28 INFO Completed push id=1 objects=9 duration=6.214919ms17532026/10/10 19:42:28 INFO Upload complete. (81ms)1754=== NAME TestClientMultipleUploads1755 client_integration_test.go:369: Uploaded 3 paths in 111.200077ms1756=== NAME TestClientCADerivations1757 client_ca_test.go:139: Found 1 dependencies (including self)1758--- PASS: TestClientMultipleUploads (0.71s)1759=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17602026/10/10 19:42:28 INFO Received uploads request method=POST path=/17612026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes17622026/10/10 19:42:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures17632026/10/10 19:42:28 INFO Garbage collection started1764--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.41s)1765=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17662026/10/10 19:42:28 INFO Received request for more parts method=POST path=/17672026/10/10 19:42:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17682026/10/10 19:42:28 INFO Uploading gafl4yz5a8lw72356g33x2xnpsx5vi41-shared-dep (136B)17692026/10/10 19:42:28 INFO Uploading i6vw98fk3nqjr4gh31sgv8j12wndx6hc-b (208B)17702026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=017712026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1cp5h5rmrg4hvmqr61vfcwhxag1ysqr77j9wa2z7hlc5xpz13886.nar.zst error="server returned 404: 404 page not found\n"17722026/10/10 19:42:28 WARN Failed to register uploaded object key=51min4iy2swvfvc84k7bdzlfhf79kxc8.ls error="server returned 404: 404 page not found\n"17732026/10/10 19:42:28 WARN Failed to register uploaded object key=i6vw98fk3nqjr4gh31sgv8j12wndx6hc.ls error="server returned 404: 404 page not found\n"17742026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17752026/10/10 19:42:28 WARN Failed to register uploaded object key=gafl4yz5a8lw72356g33x2xnpsx5vi41.ls error="server returned 404: 404 page not found\n"17762026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17772026/10/10 19:42:28 INFO Signed narinfos id=1 count=317782026/10/10 19:42:28 INFO Uploading 3 narinfos17792026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period17802026/10/10 19:42:28 WARN Failed to register uploaded object key=gafl4yz5a8lw72356g33x2xnpsx5vi41.narinfo error="server returned 404: 404 page not found\n"1781=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1782=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1783=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1784=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1785=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1786=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1787=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1788=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1789=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17902026/10/10 19:42:28 INFO Received complete multipart upload request method=POST path=/17912026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete17922026/10/10 19:42:28 WARN Failed to register uploaded object key=51min4iy2swvfvc84k7bdzlfhf79kxc8.narinfo error="server returned 404: 404 page not found\n"17932026/10/10 19:42:28 WARN Failed to register uploaded object key=i6vw98fk3nqjr4gh31sgv8j12wndx6hc.narinfo error="server returned 404: 404 page not found\n"17942026/10/10 19:42:28 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=017952026/10/10 19:42:28 INFO Completed push id=1 objects=8 duration=10.419341ms17962026/10/10 19:42:28 INFO Upload complete. (81ms)1797=== NAME TestClientPushesUseOnePush1798 client_pushes_test.go:97: Retrieved narinfo from S3:1799 StorePath: /build/TestClientPushesUseOnePush392700270/001/store/gafl4yz5a8lw72356g33x2xnpsx5vi41-shared-dep1800 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1801 Compression: zstd1802 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821803 NarSize: 1361804 References: 1805 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1806 client_pushes_test.go:97: Retrieved narinfo from S3:1807 StorePath: /build/TestClientPushesUseOnePush392700270/001/store/51min4iy2swvfvc84k7bdzlfhf79kxc8-a1808 URL: nar/1cp5h5rmrg4hvmqr61vfcwhxag1ysqr77j9wa2z7hlc5xpz13886.nar.zst1809 Compression: zstd18102026/10/10 19:42:28 INFO Vacuumed table table=pending_closures1811 NarHash: sha256:1cp5h5rmrg4hvmqr61vfcwhxag1ysqr77j9wa2z7hlc5xpz138861812 NarSize: 2081813 References: /build/TestClientPushesUseOnePush392700270/001/store/gafl4yz5a8lw72356g33x2xnpsx5vi41-shared-dep1814 CA: text:sha256:1aibjfcs7nsgcmadlsiz8nzkkafrj80nprs46alyb26zv3x57mgp1815 client_pushes_test.go:97: Retrieved narinfo from S3:1816 StorePath: /build/TestClientPushesUseOnePush392700270/001/store/i6vw98fk3nqjr4gh31sgv8j12wndx6hc-b1817 URL: nar/1cp5h5rmrg4hvmqr61vfcwhxag1ysqr77j9wa2z7hlc5xpz13886.nar.zst1818 Compression: zstd1819 NarHash: sha256:1cp5h5rmrg4hvmqr61vfcwhxag1ysqr77j9wa2z7hlc5xpz138861820 NarSize: 2081821 References: /build/TestClientPushesUseOnePush392700270/001/store/gafl4yz5a8lw72356g33x2xnpsx5vi41-shared-dep1822 CA: text:sha256:1aibjfcs7nsgcmadlsiz8nzkkafrj80nprs46alyb26zv3x57mgp18232026/10/10 19:42:28 INFO Vacuumed table table=pending_objects18242026/10/10 19:42:28 INFO Vacuumed table table=multipart_uploads1825--- PASS: TestClientPushesUseOnePush (0.66s)1826=== CONT TestPush_RejectsBadRequests/no_objects18272026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes1828=== CONT TestPush_RejectsBadRequests/no_roots1829=== CONT TestPush_RejectsBadRequests/root_not_in_objects18302026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes18312026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes1832=== CONT TestPush_RejectsBadRequests/bad_root18332026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes1834=== CONT TestServerTLSConfig/no_client_CA1835=== CONT TestServerTLSConfig/missing_CA_file1836--- PASS: TestPush_RejectsBadRequests (0.45s)1837 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1838 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1839 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1840 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1841=== CONT TestServerTLSConfig/not_a_PEM_file1842=== CONT TestGCEndsOnShutdown/before_the_run1843--- PASS: TestServerTLSConfig (0.00s)1844 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1845 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1846 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1847--- PASS: TestReadProxyDisabled (0.21s)1848=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1849=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18502026/10/10 19:42:28 INFO Vacuumed table table=closures18512026/10/10 19:42:28 INFO Vacuumed table table=objects1852=== NAME TestPinProtectsFromGC1853 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC2901328758/001/store/2k7w7qssbqvl8yzl6acvy1dyba8bnh28-pinned-file.txt1854 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC2901328758/001/store/m0zald6y3pynyi2cpcd3slzb7z0gl9i4-unpinned-file.txt1855--- PASS: TestReadProxyConditionalGet (0.23s)1856=== CONT TestResolveDBConnectionString/flag_wins1857=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1858=== CONT TestResolveDBConnectionString/nothing_configured1859=== CONT TestResolveDBConnectionString/missing_file_is_an_error1860=== CONT TestResolveDBConnectionString/file_when_flag_empty1861=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1862--- PASS: TestResolveDBConnectionString (0.00s)1863 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1864 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1865 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1866 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1867 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1868=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18692026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes18702026/10/10 19:42:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18712026/10/10 19:42:28 INFO Uploading rlwkjbki5zb7kcqk0q57kavz5gahwydf-ca-test (144B)18722026/10/10 19:42:28 WARN Failed to register uploaded object key=log/m14y5gmm7x102cggp06wmjrbh8fd7ndh-ca-test.drv error="server returned 404: 404 page not found\n"18732026/10/10 19:42:28 WARN Failed to register uploaded object key=rlwkjbki5zb7kcqk0q57kavz5gahwydf.ls error="server returned 404: 404 page not found\n"18742026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18752026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18762026/10/10 19:42:28 INFO Signed narinfos id=1 count=118772026/10/10 19:42:28 INFO Uploading 1 narinfos18782026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete18792026/10/10 19:42:28 WARN Failed to register uploaded object key=rlwkjbki5zb7kcqk0q57kavz5gahwydf.narinfo error="server returned 404: 404 page not found\n"18802026/10/10 19:42:28 INFO Completed push id=1 objects=4 duration=9.567893ms18812026/10/10 19:42:28 INFO Upload complete. (105ms)1882=== NAME TestClientCADerivations1883 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations579056019/001/store/rlwkjbki5zb7kcqk0q57kavz5gahwydf-ca-test1884 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1885 Compression: zstd1886 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1887 NarSize: 1441888 References: 1889 Deriver: /build/TestClientCADerivations579056019/001/store/m14y5gmm7x102cggp06wmjrbh8fd7ndh-ca-test.drv1890 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1891 client_ca_test.go:185: Checking for realisation files in S3...1892 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1893 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1894--- PASS: TestReadProxyHead (0.23s)1895=== CONT TestClientErrorHandling/InvalidStorePath18962026/10/10 19:42:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18972026/10/10 19:42:28 WARN mTLS auth: bound subjects configured but subject DN unavailable18982026/10/10 19:42:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1899--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)1900=== CONT TestClientErrorHandling/ServerNotAvailable19012026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes19022026/10/10 19:42:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19032026/10/10 19:42:28 INFO Uploading 2k7w7qssbqvl8yzl6acvy1dyba8bnh28-pinned-file.txt (128B)1904--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.26s)1905=== CONT TestClientErrorHandling/InvalidAuthToken19062026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19072026/10/10 19:42:28 WARN Failed to register uploaded object key=2k7w7qssbqvl8yzl6acvy1dyba8bnh28.ls error="server returned 404: 404 page not found\n"19082026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19092026/10/10 19:42:28 INFO Signed narinfos id=1 count=119102026/10/10 19:42:28 INFO Uploading 1 narinfos19112026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete19122026/10/10 19:42:28 INFO Completed push id=1 objects=3 duration=10.295391ms19132026/10/10 19:42:28 INFO Upload complete. (80ms)19142026/10/10 19:42:28 WARN Failed to register uploaded object key=2k7w7qssbqvl8yzl6acvy1dyba8bnh28.narinfo error="server returned 404: 404 page not found\n"19152026/10/10 19:42:28 INFO Received uploads request method=POST path=/api/pending_closures19162026/10/10 19:42:28 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1917=== NAME TestOrphanedObjectsGCStressTest1918 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains19192026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes19202026/10/10 19:42:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19212026/10/10 19:42:28 INFO Uploading m0zald6y3pynyi2cpcd3slzb7z0gl9i4-unpinned-file.txt (128B)1922=== NAME TestClientCADerivations1923 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1924 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1925 error: binary cache 's3://bucket75?endpoint=http://localhost:43107®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations579056019/001/store'1926 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119272026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19282026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19292026/10/10 19:42:28 INFO Signed narinfos id=2 count=119302026/10/10 19:42:28 WARN Failed to register uploaded object key=m0zald6y3pynyi2cpcd3slzb7z0gl9i4.ls error="server returned 404: 404 page not found\n"19312026/10/10 19:42:28 INFO Uploading 1 narinfos1932--- PASS: TestClientCADerivations (0.80s)1933=== CONT TestCacheConfigHandler/full_config,_no_issuer19342026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/2/complete1935=== CONT TestCacheConfigHandler/no_signing_keys19362026/10/10 19:42:28 WARN Failed to register uploaded object key=m0zald6y3pynyi2cpcd3slzb7z0gl9i4.narinfo error="server returned 404: 404 page not found\n"1937=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1938=== CONT TestCacheConfigHandler/no_cache_url_configured1939--- PASS: TestCacheConfigHandler (0.00s)1940 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1941 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1942 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1943 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1944=== CONT TestService_RequireScope_OIDC/builder_may_write19452026/10/10 19:42:28 INFO Completed push id=2 objects=3 duration=1.197068ms19462026/10/10 19:42:28 INFO Upload complete. (49ms)1947=== CONT TestService_RequireScope_OIDC/writer_implies_read1948=== CONT TestService_RequireScope_OIDC/reader_may_read1949=== CONT TestService_RequireScope_OIDC/static_token_may_write1950=== CONT TestService_RequireScope_OIDC/static_token_may_admin1951=== CONT TestService_RequireScope_OIDC/reader_may_not_write1952=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1953=== CONT TestService_RequireScope_OIDC/ops_may_not_write1954=== CONT TestService_RequireScope_OIDC/ops_may_admin1955=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1956=== NAME TestOrphanedObjectsGCStressTest1957 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1958=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19592026/10/10 19:42:28 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]1960=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1961=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1962=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1963=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1964--- PASS: TestService_RequireScope_OIDC (0.44s)1965 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1969 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1971 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1972 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1973 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1974 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1975 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1976 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1977 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1978 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1979=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19802026/10/10 19:42:28 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]1981=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1982=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19832026/10/10 19:42:28 WARN Authentication failed token_preview=eyJhbGciOi...fHLyc-qdnw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1984--- PASS: TestService_AuthMiddleware_OIDC (0.43s)1985 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1986 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1987 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1988 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)19892026/10/10 19:42:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures19902026/10/10 19:42:28 INFO Garbage collection started19912026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=019922026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period19932026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=019942026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=019952026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/10 19:42:28 WARN Request failed, retrying attempt=2 backoff=196.771026ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19972026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period19982026/10/10 19:42:28 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43107/bucket95/?delete=\": context canceled"19992026/10/10 19:42:28 INFO Received uploads request method=POST path=/api/pending_closures20002026/10/10 19:42:28 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=020012026/10/10 19:42:28 INFO Vacuumed table table=pending_closures20022026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=020032026/10/10 19:42:28 INFO Vacuumed table table=pending_objects20042026/10/10 19:42:28 INFO Vacuumed table table=multipart_uploads20052026/10/10 19:42:28 INFO Vacuumed table table=closures20062026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period20072026/10/10 19:42:28 INFO Vacuumed table table=objects2008--- PASS: TestGCEndsOnShutdown (0.00s)2009 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.29s)2010 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.30s)2011 --- PASS: TestGCEndsOnShutdown/before_the_run (0.32s)20122026/10/10 19:42:28 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=020132026/10/10 19:42:28 INFO Vacuumed table table=pending_closures20142026/10/10 19:42:28 INFO Vacuumed table table=pending_objects20152026/10/10 19:42:28 INFO Vacuumed table table=multipart_uploads20162026/10/10 19:42:28 INFO Vacuumed table table=closures20172026/10/10 19:42:28 INFO Vacuumed table table=objects20182026/10/10 19:42:28 INFO Received uploads request method=POST path=/api/pending_closures20192026/10/10 19:42:28 INFO Aborted multipart uploads count=0 kept=020202026/10/10 19:42:28 WARN Force mode enabled - objects will be deleted immediately without grace period20212026/10/10 19:42:28 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=020222026/10/10 19:42:28 INFO Vacuumed table table=pending_closures20232026/10/10 19:42:28 INFO Vacuumed table table=pending_objects20242026/10/10 19:42:28 INFO Vacuumed table table=multipart_uploads20252026/10/10 19:42:28 INFO Vacuumed table table=closures20262026/10/10 19:42:28 INFO Vacuumed table table=objects20272026/10/10 19:42:28 INFO Received push request method=POST path=/api/pushes20282026/10/10 19:42:28 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)20292026/10/10 19:42:28 INFO Uploading 5nq8v4rzlnxfb8pvdbwsgip6d8afc96k-shared-dep (136B)20302026/10/10 19:42:28 INFO Uploading ayv74fd3586568f1n99pwm12l4vii4wr-top (224B)20312026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20322026/10/10 19:42:28 WARN Failed to register uploaded object key=5nq8v4rzlnxfb8pvdbwsgip6d8afc96k.ls error="server returned 404: 404 page not found\n"20332026/10/10 19:42:28 WARN Failed to register uploaded object key=nar/0p21bm305blf2dr55y3g4j08l5ni4z1vz1zc313cr80n4nax3qyq.nar.zst error="server returned 404: 404 page not found\n"20342026/10/10 19:42:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2035--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2036 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.31s)2037 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)20382026/10/10 19:42:28 WARN Failed to register uploaded object key=ayv74fd3586568f1n99pwm12l4vii4wr.ls error="server returned 404: 404 page not found\n"20392026/10/10 19:42:28 INFO Signed narinfos id=1 count=220402026/10/10 19:42:28 INFO Uploading 2 narinfos20412026/10/10 19:42:28 INFO Received complete push request method=POST path=/api/pushes/1/complete20422026/10/10 19:42:28 WARN Failed to register uploaded object key=5nq8v4rzlnxfb8pvdbwsgip6d8afc96k.narinfo error="server returned 404: 404 page not found\n"20432026/10/10 19:42:28 WARN Failed to register uploaded object key=ayv74fd3586568f1n99pwm12l4vii4wr.narinfo error="server returned 404: 404 page not found\n"20442026/10/10 19:42:28 INFO Completed push id=1 objects=6 duration=7.839066ms20452026/10/10 19:42:28 INFO Upload complete. (65ms)2046=== NAME TestClientSharedPathCommittedMidPush2047 client_integration_test.go:680: Retrieved narinfo from S3:2048 StorePath: /build/TestClientSharedPathCommittedMidPush4089389456/001/store/5nq8v4rzlnxfb8pvdbwsgip6d8afc96k-shared-dep2049 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2050 Compression: zstd2051 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822052 NarSize: 1362053 References: 2054 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2055 client_integration_test.go:680: Retrieved narinfo from S3:2056 StorePath: /build/TestClientSharedPathCommittedMidPush4089389456/001/store/ayv74fd3586568f1n99pwm12l4vii4wr-top2057 URL: nar/0p21bm305blf2dr55y3g4j08l5ni4z1vz1zc313cr80n4nax3qyq.nar.zst2058 Compression: zstd2059 NarHash: sha256:0p21bm305blf2dr55y3g4j08l5ni4z1vz1zc313cr80n4nax3qyq2060 NarSize: 2242061 References: /build/TestClientSharedPathCommittedMidPush4089389456/001/store/5nq8v4rzlnxfb8pvdbwsgip6d8afc96k-shared-dep2062 CA: text:sha256:0fcp98p04ghyfk3wzcjhlg4vqyf22w23pj712r2b79hh1v81x2gs2063--- PASS: TestClientSharedPathCommittedMidPush (0.50s)20642026/10/10 19:42:28 INFO lead: released remote=192.0.2.1:12342065--- PASS: TestLeadEndsOnShutdown (1.63s)20662026/10/10 19:42:28 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20672026/10/10 19:42:28 WARN Request failed, retrying attempt=3 backoff=376.093254ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20682026/10/10 19:42:28 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2069=== NAME TestOrphanedObjectsGCStressTest2070 orphaned_objects_gc_test.go:503: Stress test completed successfully:2071 orphaned_objects_gc_test.go:504: - Active objects preserved: 202072 orphaned_objects_gc_test.go:505: - Objects deleted: 2102073 orphaned_objects_gc_test.go:506: - Total GC'd: 2102074--- PASS: TestOrphanedObjectsGCStressTest (2.79s)2075--- PASS: TestDeleteClosuresRacingPins (1.49s)20762026/10/10 19:42:29 INFO lead: released remote=192.0.2.1:123420772026/10/10 19:42:29 INFO lead: acquired remote=192.0.2.1:12342078--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2079 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2080 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)2081 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.78s)2082--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2083 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.79s)2084 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.81s)20852026/10/10 19:42:29 WARN Request failed, retrying attempt=4 backoff=874.161803ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2086--- PASS: TestPendingClosureWriteTimeout (0.08s)2087 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2088 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2089 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2090 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)20912026/10/10 19:42:30 WARN Request failed, retrying attempt=5 backoff=1.608441019s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20922026/10/10 19:42:30 INFO lead: released remote=192.0.2.1:12342093--- PASS: TestLeadElectsOneAndHandsOver (2.93s)20942026/10/10 19:42:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02095=== NAME TestClientIntegration2096 client_integration_test.go:323: Objects in database after GC:2097 client_integration_test.go:323: Successfully deleted all objects with GC --force2098--- PASS: TestClientIntegration (2.73s)20992026/10/10 19:42:30 WARN Rate limiter enabled after throttle name=s3-test rate=521002026/10/10 19:42:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2101=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2102 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102103 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002104--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.59s)21052026/10/10 19:42:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021062026/10/10 19:42:30 INFO Received create pin request method=POST path=/api/pins/myapp21072026/10/10 19:42:30 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2901328758/001/store/2k7w7qssbqvl8yzl6acvy1dyba8bnh28-pinned-file.txt narinfo_key=2k7w7qssbqvl8yzl6acvy1dyba8bnh28.narinfo21082026/10/10 19:42:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures21092026/10/10 19:42:30 INFO Garbage collection started21102026/10/10 19:42:30 INFO Aborted multipart uploads count=0 kept=021112026/10/10 19:42:30 WARN Force mode enabled - objects will be deleted immediately without grace period21122026/10/10 19:42:30 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021132026/10/10 19:42:30 INFO Vacuumed table table=pending_closures21142026/10/10 19:42:30 INFO Vacuumed table table=pending_objects21152026/10/10 19:42:30 INFO Vacuumed table table=multipart_uploads21162026/10/10 19:42:30 INFO Vacuumed table table=closures21172026/10/10 19:42:30 INFO Vacuumed table table=objects21182026/10/10 19:42:31 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21192026/10/10 19:42:31 WARN Request failed, retrying attempt=2 backoff=182.257889ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21202026/10/10 19:42:32 WARN Request failed, retrying attempt=3 backoff=417.437063ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2121--- PASS: TestConnectWaitsForAPeerMigration (5.18s)21222026/10/10 19:42:32 WARN Request failed, retrying attempt=4 backoff=799.999654ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2123--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.45s)2124=== NAME TestPinProtectsFromGC2125 client_integration_test.go:840: Pin successfully protected closure from garbage collection2126--- PASS: TestPinProtectsFromGC (4.75s)21272026/10/10 19:42:33 INFO Aborted multipart uploads count=1 kept=021282026/10/10 19:42:33 INFO Received cleanup request method=DELETE path=/api/pending_closures21292026/10/10 19:42:33 INFO Aborted multipart uploads count=1 kept=02130--- PASS: TestPendingCleanupUsesOneCutoff (6.68s)21312026/10/10 19:42:33 WARN Request failed, retrying attempt=5 backoff=1.568741657s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21322026/10/10 19:42:34 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"21332026/10/10 19:42:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21342026/10/10 19:42:35 WARN Request failed, retrying attempt=2 backoff=211.682261ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21352026/10/10 19:42:35 WARN Request failed, retrying attempt=3 backoff=370.721495ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21362026/10/10 19:42:35 WARN Request failed, retrying attempt=4 backoff=739.019468ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21372026/10/10 19:42:36 WARN Request failed, retrying attempt=5 backoff=1.643859583s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21382026/10/10 19:42:38 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21392026/10/10 19:42:38 WARN Request failed, retrying attempt=2 backoff=181.610405ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21402026/10/10 19:42:38 WARN Request failed, retrying attempt=3 backoff=404.933302ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21412026/10/10 19:42:38 WARN Request failed, retrying attempt=4 backoff=872.736227ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21422026/10/10 19:42:39 WARN Request failed, retrying attempt=5 backoff=1.471782367s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2143--- PASS: TestClientErrorHandling (0.00s)2144 --- PASS: TestClientErrorHandling/InvalidStorePath (0.32s)2145 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2146 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.49s)2147PASS2148{"timestamp":"2026-10-10T19:42:41.058176191Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43394","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(397)"}21492026-10-10 19:42:41.463 UTC [129] LOG: received smart shutdown request21502026-10-10 19:42:41.469 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 121512026-10-10 19:42:41.481 UTC [134] LOG: shutting down21522026-10-10 19:42:41.482 UTC [134] LOG: checkpoint starting: shutdown immediate21532026-10-10 19:42:42.408 UTC [134] LOG: checkpoint complete: wrote 10738 buffers (65.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.265 s, sync=0.606 s, total=0.928 s; sync files=34045, longest=0.077 s, average=0.001 s; distance=531521 kB, estimate=531521 kB; lsn=0/21E761E0, redo lsn=0/21E761E021542026-10-10 19:42:42.492 UTC [129] LOG: database system is shut down2155Running OIDC tests...2156=== RUN TestAudienceForIssuer2157=== PAUSE TestAudienceForIssuer2158=== RUN TestGlobMatch2159=== PAUSE TestGlobMatch2160=== RUN TestValidateToken_ValidToken2161=== PAUSE TestValidateToken_ValidToken2162=== RUN TestValidateToken_WrongAudience2163=== PAUSE TestValidateToken_WrongAudience2164=== RUN TestValidateToken_Expired2165=== PAUSE TestValidateToken_Expired2166=== RUN TestValidateToken_BoundClaimsMismatch2167=== PAUSE TestValidateToken_BoundClaimsMismatch2168=== RUN TestValidateToken_BoundSubjectMismatch2169=== PAUSE TestValidateToken_BoundSubjectMismatch2170=== RUN TestValidateToken_MultipleProviders2171=== PAUSE TestValidateToken_MultipleProviders2172=== RUN TestValidateToken_NoMatchingProvider2173=== PAUSE TestValidateToken_NoMatchingProvider2174=== RUN TestValidateToken_KubernetesServiceAccount2175=== PAUSE TestValidateToken_KubernetesServiceAccount2176=== RUN TestNewValidator_KubernetesRequiresCA2177=== PAUSE TestNewValidator_KubernetesRequiresCA2178=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2179=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2180=== RUN TestPins_ReservedForMatchingRule2181=== PAUSE TestPins_ReservedForMatchingRule2182=== RUN TestPins_TopLevelShorthand2183=== PAUSE TestPins_TopLevelShorthand2184=== RUN TestPins_ConfigValidation2185=== PAUSE TestPins_ConfigValidation2186=== RUN TestScopes_LegacyProviderDefaultsToWrite2187=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2188=== RUN TestScopes_Rules2189=== PAUSE TestScopes_Rules2190=== RUN TestScopes_ConfigValidation2191=== PAUSE TestScopes_ConfigValidation2192=== CONT TestAudienceForIssuer2193=== CONT TestValidateToken_KubernetesServiceAccount2194--- PASS: TestAudienceForIssuer (0.00s)2195=== CONT TestValidateToken_NoMatchingProvider2196=== CONT TestValidateToken_MultipleProviders2197=== CONT TestValidateToken_BoundSubjectMismatch2198=== CONT TestValidateToken_BoundClaimsMismatch2199=== CONT TestValidateToken_Expired2200=== CONT TestValidateToken_WrongAudience2201=== CONT TestValidateToken_ValidToken2202=== CONT TestGlobMatch2203=== RUN TestGlobMatch/foo_foo2204=== PAUSE TestGlobMatch/foo_foo2205=== CONT TestPins_ConfigValidation2206=== CONT TestPins_TopLevelShorthand2207=== CONT TestScopes_ConfigValidation2208=== CONT TestScopes_Rules2209=== CONT TestScopes_LegacyProviderDefaultsToWrite2210=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2211--- PASS: TestPins_ConfigValidation (0.00s)2212=== CONT TestNewValidator_KubernetesRequiresCA2213=== CONT TestPins_ReservedForMatchingRule2214=== RUN TestGlobMatch/foo_bar2215--- PASS: TestScopes_ConfigValidation (0.00s)2216=== PAUSE TestGlobMatch/foo_bar2217=== RUN TestGlobMatch/*_2218=== PAUSE TestGlobMatch/*_2219=== RUN TestGlobMatch/*_anything2220=== PAUSE TestGlobMatch/*_anything2221=== RUN TestGlobMatch/foo*_foo2222=== PAUSE TestGlobMatch/foo*_foo2223=== RUN TestGlobMatch/foo*_foobar2224=== PAUSE TestGlobMatch/foo*_foobar2225=== RUN TestGlobMatch/foo*_bar2226=== PAUSE TestGlobMatch/foo*_bar2227=== RUN TestGlobMatch/*bar_bar2228=== PAUSE TestGlobMatch/*bar_bar2229=== RUN TestGlobMatch/*bar_foobar2230=== PAUSE TestGlobMatch/*bar_foobar2231=== RUN TestGlobMatch/*bar_foo2232=== PAUSE TestGlobMatch/*bar_foo2233=== RUN TestGlobMatch/foo*bar_foobar2234=== PAUSE TestGlobMatch/foo*bar_foobar2235=== RUN TestGlobMatch/foo*bar_foo123bar2236=== PAUSE TestGlobMatch/foo*bar_foo123bar2237=== RUN TestGlobMatch/foo*bar_foobarbaz2238=== PAUSE TestGlobMatch/foo*bar_foobarbaz2239=== RUN TestGlobMatch/*/*_foo/bar2240=== PAUSE TestGlobMatch/*/*_foo/bar2241=== RUN TestGlobMatch/*/*_foo2242=== PAUSE TestGlobMatch/*/*_foo2243=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2244=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2245=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02246=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02247=== RUN TestGlobMatch/refs/*/main_refs/heads/main2248=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2249=== RUN TestGlobMatch/fo?_foo2250=== PAUSE TestGlobMatch/fo?_foo2251=== RUN TestGlobMatch/fo?_fo2252=== PAUSE TestGlobMatch/fo?_fo2253=== RUN TestGlobMatch/fo?_fooo2254=== PAUSE TestGlobMatch/fo?_fooo2255=== RUN TestGlobMatch/?oo_foo2256=== PAUSE TestGlobMatch/?oo_foo2257=== RUN TestGlobMatch/?oo_boo2258=== PAUSE TestGlobMatch/?oo_boo2259=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2260=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2261=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2262=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2263=== CONT TestGlobMatch/foo_foo2264=== CONT TestGlobMatch/*/*_foo/bar2265=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2266=== CONT TestGlobMatch/*/*_foo2267=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2268=== CONT TestGlobMatch/foo*bar_foobarbaz2269=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2270=== CONT TestGlobMatch/?oo_boo2271=== CONT TestGlobMatch/?oo_foo2272=== CONT TestGlobMatch/fo?_fooo2273=== CONT TestGlobMatch/fo?_fo2274=== CONT TestGlobMatch/fo?_foo2275=== CONT TestGlobMatch/refs/*/main_refs/heads/main2276=== CONT TestGlobMatch/*bar_bar2277=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02278=== CONT TestGlobMatch/foo*bar_foobar2279=== CONT TestGlobMatch/*bar_foobar2280=== CONT TestGlobMatch/foo*bar_foo123bar2281=== CONT TestGlobMatch/*bar_foo2282=== CONT TestGlobMatch/foo*_foo2283=== CONT TestGlobMatch/foo*_foobar2284=== CONT TestGlobMatch/*_anything2285=== CONT TestGlobMatch/*_2286=== CONT TestGlobMatch/foo*_bar2287=== CONT TestGlobMatch/foo_bar2288--- PASS: TestGlobMatch (0.01s)2289 --- PASS: TestGlobMatch/foo_foo (0.00s)2290 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2291 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2292 --- PASS: TestGlobMatch/*/*_foo (0.00s)2293 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2294 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2295 --- PASS: TestGlobMatch/?oo_boo (0.00s)2296 --- PASS: TestGlobMatch/?oo_foo (0.00s)2297 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2298 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2299 --- PASS: TestGlobMatch/fo?_fo (0.00s)2300 --- PASS: TestGlobMatch/fo?_foo (0.00s)2301 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2302 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2303 --- PASS: TestGlobMatch/*bar_bar (0.00s)2304 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2305 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2306 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2307 --- PASS: TestGlobMatch/*bar_foo (0.00s)2308 --- PASS: TestGlobMatch/foo*_foo (0.00s)2309 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2310 --- PASS: TestGlobMatch/*_anything (0.00s)2311 --- PASS: TestGlobMatch/*_ (0.00s)2312 --- PASS: TestGlobMatch/foo*_bar (0.00s)2313 --- PASS: TestGlobMatch/foo_bar (0.00s)23142026/10/10 19:42:45 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323152026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35935/oidc2316--- PASS: TestPins_ReservedForMatchingRule (0.03s)2317--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)23182026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35557/oidc23192026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34471/oidc2320--- PASS: TestScopes_Rules (0.05s)2321--- PASS: TestValidateToken_ValidToken (0.05s)23222026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44623/oidc23232026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37703/oidc2324--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2325--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23262026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39193/oidc2327--- PASS: TestPins_TopLevelShorthand (0.06s)23282026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36159/oidc23292026/10/10 19:42:45 http: TLS handshake error from 127.0.0.1:44772: remote error: tls: bad certificate2330--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)2331--- PASS: TestValidateToken_WrongAudience (0.07s)23322026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35637/oidc2333--- PASS: TestValidateToken_Expired (0.12s)23342026/10/10 19:42:45 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:344092335--- PASS: TestValidateToken_KubernetesServiceAccount (0.14s)23362026/10/10 19:42:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40647/oidc2337--- PASS: TestValidateToken_NoMatchingProvider (0.16s)23382026/10/10 19:42:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45499/oidc2339--- PASS: TestValidateToken_BoundSubjectMismatch (0.17s)23402026/10/10 19:42:45 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42027/oidc23412026/10/10 19:42:45 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:36897/oidc2342--- PASS: TestValidateToken_MultipleProviders (0.21s)2343PASS2344Running hook tests...2345=== RUN TestSendPathsEmpty2346=== PAUSE TestSendPathsEmpty2347=== RUN TestQueueEnqueueAndFetch2348=== PAUSE TestQueueEnqueueAndFetch2349=== RUN TestQueueDeduplication2350=== PAUSE TestQueueDeduplication2351=== RUN TestQueueRemove2352=== PAUSE TestQueueRemove2353=== RUN TestQueueFetchBatchLimit2354=== PAUSE TestQueueFetchBatchLimit2355=== RUN TestQueueRetryMovesToBack2356=== PAUSE TestQueueRetryMovesToBack2357=== RUN TestQueueFetchRemoveLifecycle2358=== PAUSE TestQueueFetchRemoveLifecycle2359=== RUN TestQueueConcurrentWriters2360=== PAUSE TestQueueConcurrentWriters2361=== RUN TestQueueRemoveLargeClosure2362=== PAUSE TestQueueRemoveLargeClosure2363=== RUN TestServerClientIntegration2364--- PASS: TestServerClientIntegration (0.00s)2365=== RUN TestServerQueueError23662026/10/10 19:42:45 ERROR Failed to queue paths error="permission denied" count=12367--- PASS: TestServerQueueError (0.00s)2368=== RUN TestGetListenerSocketActivation2369 server_test.go:219: === RUN TestGetListenerSocketActivation2370 --- PASS: TestGetListenerSocketActivation (0.00s)2371 PASS2372 2373--- PASS: TestGetListenerSocketActivation (0.01s)2374=== RUN TestDrainIsolatesPoisonPath2375=== PAUSE TestDrainIsolatesPoisonPath2376=== RUN TestRunNotBlockedByPoisonHead2377=== PAUSE TestRunNotBlockedByPoisonHead2378=== RUN TestDrainGivesUpWhenServerDown2379=== PAUSE TestDrainGivesUpWhenServerDown2380=== RUN TestFailedPathPrunedByLaterClosure2381=== PAUSE TestFailedPathPrunedByLaterClosure2382=== RUN TestWorkerUploadsAndRemoves2383=== PAUSE TestWorkerUploadsAndRemoves2384=== RUN TestWorkerSkipsGCdPaths2385=== PAUSE TestWorkerSkipsGCdPaths2386=== RUN TestWorkerPrunesClosureDeps2387=== PAUSE TestWorkerPrunesClosureDeps2388=== RUN TestDrainTimeout2389=== PAUSE TestDrainTimeout2390=== CONT TestSendPathsEmpty2391=== CONT TestDrainTimeout2392--- PASS: TestSendPathsEmpty (0.00s)2393=== CONT TestDrainIsolatesPoisonPath2394=== CONT TestWorkerUploadsAndRemoves2395=== CONT TestQueueRemoveLargeClosure2396=== CONT TestWorkerPrunesClosureDeps2397=== CONT TestQueueConcurrentWriters2398=== CONT TestQueueFetchRemoveLifecycle2399=== CONT TestWorkerSkipsGCdPaths2400=== CONT TestQueueDeduplication2401=== CONT TestDrainGivesUpWhenServerDown2402=== CONT TestQueueEnqueueAndFetch2403=== CONT TestFailedPathPrunedByLaterClosure2404=== CONT TestQueueRemove2405=== CONT TestQueueRetryMovesToBack2406=== CONT TestQueueFetchBatchLimit2407=== CONT TestRunNotBlockedByPoisonHead24082026/10/10 19:42:45 INFO Upload queue status pending=224092026/10/10 19:42:45 INFO Upload queue status pending=224102026/10/10 19:42:45 INFO Uploading batch count=124112026/10/10 19:42:45 INFO Uploading batch count=224122026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=224132026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/a24142026/10/10 19:42:45 INFO Uploading batch count=224152026/10/10 19:42:45 INFO Uploading batch count=424162026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=424172026/10/10 19:42:45 INFO Uploading batch count=124182026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=124192026/10/10 19:42:45 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2459010822/002/nonexistent24202026/10/10 19:42:45 INFO Upload queue status pending=224212026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1133783051/002/bbb24222026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/b24232026/10/10 19:42:45 INFO Uploading batch count=22424--- PASS: TestQueueRemove (0.02s)2425--- PASS: TestQueueEnqueueAndFetch (0.02s)24262026/10/10 19:42:45 INFO Uploading batch count=124272026/10/10 19:42:45 INFO Uploading batch count=224282026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=224292026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/c24302026/10/10 19:42:45 INFO Uploading batch count=124312026/10/10 19:42:45 INFO Upload queue status pending=324322026/10/10 19:42:45 INFO Uploading batch count=124332026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/d24342026/10/10 19:42:45 INFO Uploading batch count=124352026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=12436--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2437--- PASS: TestQueueDeduplication (0.02s)2438--- PASS: TestQueueRetryMovesToBack (0.02s)24392026/10/10 19:42:45 INFO Uploading batch count=224402026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=224412026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/e2442--- PASS: TestQueueFetchBatchLimit (0.02s)24432026/10/10 19:42:45 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3138359566/002/f24442026/10/10 19:42:45 INFO Uploading batch count=124452026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=124462026/10/10 19:42:45 INFO Uploading batch count=124472026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=124482026/10/10 19:42:45 ERROR Drain finished with paths left in queue remaining=1024492026/10/10 19:42:45 INFO Uploading batch count=124502026/10/10 19:42:45 ERROR Upload failed error="upload failed" count=12451--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24522026/10/10 19:42:45 ERROR Drain finished with paths left in queue remaining=12453--- PASS: TestDrainIsolatesPoisonPath (0.03s)2454--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2455--- PASS: TestWorkerSkipsGCdPaths (0.04s)2456--- PASS: TestWorkerPrunesClosureDeps (0.04s)2457--- PASS: TestWorkerUploadsAndRemoves (0.04s)2458--- PASS: TestQueueRemoveLargeClosure (0.07s)24592026/10/10 19:42:45 ERROR Upload failed error="context deadline exceeded" count=224602026/10/10 19:42:45 ERROR Drain finished with paths left in queue remaining=42461--- PASS: TestDrainTimeout (0.22s)2462--- PASS: TestQueueConcurrentWriters (0.39s)24632026/10/10 19:42:46 INFO Uploading batch count=124642026/10/10 19:42:46 INFO Uploading batch count=124652026/10/10 19:42:46 INFO Uploading batch count=124662026/10/10 19:42:46 ERROR Upload failed error="upload failed" count=124672026/10/10 19:42:46 INFO Uploading batch count=124682026/10/10 19:42:46 ERROR Upload failed error="upload failed" count=124692026/10/10 19:42:46 INFO Uploading batch count=124702026/10/10 19:42:46 ERROR Upload failed error="upload failed" count=124712026/10/10 19:42:46 INFO Uploading batch count=124722026/10/10 19:42:46 ERROR Upload failed error="upload failed" count=124732026/10/10 19:42:46 ERROR Drain finished with paths left in queue remaining=12474--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2475PASS2476Running signing tests...2477=== RUN TestExternalSigner2478=== PAUSE TestExternalSigner2479=== RUN TestExternalSignerWrongPublicKey2480=== PAUSE TestExternalSignerWrongPublicKey2481=== RUN TestExternalSignerErrors2482=== PAUSE TestExternalSignerErrors2483=== RUN TestExternalSignerRestartsAfterCrash2484=== PAUSE TestExternalSignerRestartsAfterCrash2485=== RUN TestExternalSignerProgramErrorKeepsProcess2486=== PAUSE TestExternalSignerProgramErrorKeepsProcess2487=== RUN TestExternalSignerClose2488=== PAUSE TestExternalSignerClose2489=== RUN TestExternalSignerRejectsInvalidPublicKey2490=== PAUSE TestExternalSignerRejectsInvalidPublicKey2491=== RUN TestExternalSignerCancellation2492=== PAUSE TestExternalSignerCancellation2493=== RUN TestGenerateFingerprint2494=== PAUSE TestGenerateFingerprint2495=== RUN TestParseSigningKey2496=== PAUSE TestParseSigningKey2497=== RUN TestSign2498=== PAUSE TestSign2499=== RUN TestSignBatch2500=== PAUSE TestSignBatch2501=== RUN TestNilKeyPublicKey2502=== PAUSE TestNilKeyPublicKey2503=== RUN TestSignErrors2504=== PAUSE TestSignErrors2505=== CONT TestExternalSigner2506=== CONT TestExternalSignerCancellation2507=== CONT TestSignBatch2508=== CONT TestExternalSignerProgramErrorKeepsProcess2509=== CONT TestExternalSignerRejectsInvalidPublicKey2510=== RUN TestExternalSignerRejectsInvalidPublicKey/#002511=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002512=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2513=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2514=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2515=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2516=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2517=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2518=== CONT TestExternalSignerClose2519=== CONT TestExternalSignerErrors2520=== CONT TestExternalSignerRestartsAfterCrash2521=== CONT TestParseSigningKey2522=== CONT TestSign2523=== CONT TestSignErrors2524=== CONT TestGenerateFingerprint2525=== CONT TestExternalSignerWrongPublicKey2526=== CONT TestNilKeyPublicKey2527=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2528=== RUN TestExternalSignerErrors/exit_on_request2529--- PASS: TestNilKeyPublicKey (0.00s)2530--- PASS: TestSignBatch (0.00s)2531=== RUN TestGenerateFingerprint/basic_with_references2532=== RUN TestParseSigningKey/valid_32-byte_key2533--- PASS: TestSign (0.00s)2534=== RUN TestSignErrors/nil_key2535=== PAUSE TestSignErrors/nil_key2536=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2537=== RUN TestSignErrors/nil_narinfo2538=== PAUSE TestSignErrors/nil_narinfo2539=== CONT TestExternalSignerRejectsInvalidPublicKey/#002540=== PAUSE TestGenerateFingerprint/basic_with_references2541=== RUN TestGenerateFingerprint/no_references2542=== PAUSE TestGenerateFingerprint/no_references2543=== PAUSE TestParseSigningKey/valid_32-byte_key2544=== PAUSE TestExternalSignerErrors/exit_on_request2545=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2546=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2547=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2548=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2549--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2550 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2551 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2552 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2553 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2554 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2555=== RUN TestSignErrors/invalid_narinfo2556=== PAUSE TestSignErrors/invalid_narinfo2557=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2558=== RUN TestExternalSignerErrors/missing_signature_name2559=== PAUSE TestExternalSignerErrors/missing_signature_name2560=== RUN TestExternalSignerErrors/invalid_JSON2561=== PAUSE TestExternalSignerErrors/invalid_JSON2562=== RUN TestExternalSignerErrors/missing_signatures2563=== PAUSE TestExternalSignerErrors/missing_signatures2564=== RUN TestExternalSignerErrors/too_few_signatures2565=== PAUSE TestExternalSignerErrors/too_few_signatures2566=== RUN TestExternalSignerErrors/unrequested_key2567=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2568=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2569=== RUN TestSignErrors/canceled2570=== PAUSE TestSignErrors/canceled2571=== CONT TestSignErrors/nil_key2572=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2573=== PAUSE TestExternalSignerErrors/unrequested_key2574=== RUN TestExternalSignerErrors/wrong_signature_name2575=== PAUSE TestExternalSignerErrors/wrong_signature_name2576=== RUN TestExternalSignerErrors/wrong_signature_length2577=== PAUSE TestExternalSignerErrors/wrong_signature_length2578=== RUN TestExternalSignerErrors/exit_at_startup2579=== RUN TestParseSigningKey/no_colon2580=== PAUSE TestParseSigningKey/no_colon2581=== RUN TestParseSigningKey/empty_name2582=== PAUSE TestParseSigningKey/empty_name2583=== CONT TestSignErrors/invalid_narinfo2584=== CONT TestSignErrors/canceled2585=== CONT TestSignErrors/nil_narinfo2586--- PASS: TestSignErrors (0.00s)2587 --- PASS: TestSignErrors/nil_key (0.00s)2588 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2589 --- PASS: TestSignErrors/canceled (0.00s)2590 --- PASS: TestSignErrors/nil_narinfo (0.00s)2591=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2592=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2593=== RUN TestGenerateFingerprint/invalid_nar_hash_length2594=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2595=== PAUSE TestExternalSignerErrors/exit_at_startup2596=== RUN TestParseSigningKey/invalid_base642597=== PAUSE TestParseSigningKey/invalid_base642598=== RUN TestGenerateFingerprint/invalid_store_path_prefix2599=== RUN TestExternalSignerErrors/wrong_id2600=== PAUSE TestExternalSignerErrors/wrong_id2601=== RUN TestExternalSignerErrors/wrong_signatures_shape2602=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2603=== RUN TestExternalSignerErrors/program_error2604=== PAUSE TestExternalSignerErrors/program_error2605=== RUN TestExternalSignerErrors/wrong_shape2606=== PAUSE TestExternalSignerErrors/wrong_shape2607=== RUN TestParseSigningKey/wrong_length2608=== PAUSE TestParseSigningKey/wrong_length2609=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2610=== RUN TestExternalSignerErrors/null2611=== CONT TestParseSigningKey/wrong_length2612=== CONT TestParseSigningKey/valid_32-byte_key2613=== CONT TestParseSigningKey/empty_name2614=== CONT TestParseSigningKey/invalid_base642615=== CONT TestParseSigningKey/no_colon2616=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2617--- PASS: TestParseSigningKey (0.00s)2618 --- PASS: TestParseSigningKey/wrong_length (0.00s)2619 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2620 --- PASS: TestParseSigningKey/empty_name (0.00s)2621 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2622 --- PASS: TestParseSigningKey/no_colon (0.00s)2623 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2624=== RUN TestGenerateFingerprint/invalid_reference_prefix2625=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2626=== PAUSE TestExternalSignerErrors/null2627--- PASS: TestExternalSignerWrongPublicKey (0.00s)2628=== CONT TestGenerateFingerprint/basic_with_references2629=== CONT TestGenerateFingerprint/invalid_reference_prefix2630=== CONT TestGenerateFingerprint/invalid_store_path_prefix2631=== CONT TestGenerateFingerprint/invalid_nar_hash_length2632=== CONT TestGenerateFingerprint/no_references2633=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2634=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2635--- PASS: TestGenerateFingerprint (0.00s)2636 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2637 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2638 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2639 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2640 --- PASS: TestGenerateFingerprint/no_references (0.00s)2641 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2642 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2643=== RUN TestExternalSignerErrors/null_signatures2644=== PAUSE TestExternalSignerErrors/null_signatures2645=== RUN TestExternalSignerErrors/invalid_signature_base642646=== PAUSE TestExternalSignerErrors/invalid_signature_base642647=== CONT TestExternalSignerErrors/exit_on_request2648=== CONT TestExternalSignerErrors/invalid_signature_base642649--- PASS: TestExternalSignerClose (0.00s)2650=== CONT TestExternalSignerErrors/exit_at_startup2651=== CONT TestExternalSignerErrors/null_signatures2652=== CONT TestExternalSignerErrors/null2653=== CONT TestExternalSignerErrors/wrong_shape2654=== CONT TestExternalSignerErrors/program_error2655=== CONT TestExternalSignerErrors/too_few_signatures2656=== CONT TestExternalSignerErrors/wrong_signatures_shape2657=== CONT TestExternalSignerErrors/wrong_signature_length2658=== CONT TestExternalSignerErrors/wrong_signature_name2659=== CONT TestExternalSignerErrors/wrong_id2660=== CONT TestExternalSignerErrors/unrequested_key2661=== CONT TestExternalSignerErrors/missing_signatures2662=== CONT TestExternalSignerErrors/invalid_JSON2663=== CONT TestExternalSignerErrors/missing_signature_name2664--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2665--- PASS: TestExternalSigner (0.01s)2666--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2667--- PASS: TestExternalSignerErrors (0.00s)2668 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2669 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2670 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2671 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2672 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2673 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2674 --- PASS: TestExternalSignerErrors/program_error (0.01s)2675 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2676 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2677 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2678 --- PASS: TestExternalSignerErrors/null (0.01s)2679 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2680 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2681 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2682 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2683 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2684--- PASS: TestExternalSignerCancellation (0.02s)2685PASS2686Running OpenBao signer tests...2687=== RUN TestSign2688=== PAUSE TestSign2689=== RUN TestSignErrors2690=== PAUSE TestSignErrors2691=== RUN TestServe2692=== PAUSE TestServe2693=== RUN TestServeRejectsGarbage2694=== PAUSE TestServeRejectsGarbage2695=== CONT TestSign2696=== CONT TestServe2697=== CONT TestServeRejectsGarbage2698=== CONT TestSignErrors2699=== RUN TestSignErrors/http_error2700--- PASS: TestServeRejectsGarbage (0.00s)2701=== PAUSE TestSignErrors/http_error2702=== RUN TestSignErrors/invalid_json2703=== PAUSE TestSignErrors/invalid_json2704=== RUN TestSignErrors/no_prefix2705--- PASS: TestServe (0.00s)2706=== PAUSE TestSignErrors/no_prefix2707=== RUN TestSignErrors/invalid_base642708=== PAUSE TestSignErrors/invalid_base642709=== CONT TestSignErrors/http_error2710=== CONT TestSignErrors/no_prefix2711=== CONT TestSignErrors/invalid_base642712=== CONT TestSignErrors/invalid_json2713--- PASS: TestSign (0.00s)2714--- PASS: TestSignErrors (0.00s)2715 --- PASS: TestSignErrors/http_error (0.00s)2716 --- PASS: TestSignErrors/invalid_json (0.00s)2717 --- PASS: TestSignErrors/invalid_base64 (0.00s)2718 --- PASS: TestSignErrors/no_prefix (0.00s)2719PASS