niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #418
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (4.35s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestClientSignaturesByStorePath115=== CONT TestStreamPushRequestLine116=== CONT TestStreamPushReportsEveryPath117=== CONT TestStreamPushStopsWhenCanceled118=== CONT TestScriptTokenEmptyCommand119=== CONT TestDoWithRetry_BodyReplayedViaGetBody120=== CONT TestResolveStorePath121=== CONT TestScriptTokenScriptFails122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess131=== CONT TestSetClientTLSErrors132=== CONT TestSetClientTLSDoesNotMutateDefaultTransport133=== CONT TestSetClientTLS134=== CONT TestStreamPushIsolatesFailures135=== CONT TestStreamPushGivesUpOnDeadServer136=== CONT TestConvertHashToNix32137=== RUN TestConvertHashToNix32/SRI_format_to_Nix321382026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=server-test rate=5139=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32140=== RUN TestConvertHashToNix32/already_Nix32_format141=== PAUSE TestConvertHashToNix32/already_Nix32_format142=== CONT TestShellSplitErrors143=== CONT TestShellSplit144=== CONT TestDoWithRetry_FinalResponseBodyReadable145=== RUN TestConvertHashToNix32/invalid_format146=== PAUSE TestConvertHashToNix32/invalid_format147=== CONT TestRetryTimeoutOutlastsMaxRetries148=== CONT TestPathInfoCACompatibility149=== RUN TestPathInfoCACompatibility/null_ca_field150--- PASS: TestClientSignaturesByStorePath (0.00s)151=== CONT TestRateLimiterFeedback152=== CONT TestParsePathInfoJSONMultiplePaths1532026/10/20 08:16:56 ERROR Upload failed error="connection refused" count=20154=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer155=== RUN TestRateLimiterFeedback/429_enables_limiter156=== PAUSE TestRateLimiterFeedback/429_enables_limiter157=== RUN TestRateLimiterFeedback/503_enables_limiter158=== PAUSE TestRateLimiterFeedback/503_enables_limiter159=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter1602026/10/20 08:16:56 ERROR Upload failed error="bad path" count=31612026/10/20 08:16:56 ERROR Upload failed error=boom count=11622026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=server-test rate=5163--- PASS: TestScriptTokenEmptyCommand (0.00s)164--- PASS: TestStreamPushStopsWhenCanceled (0.00s)1652026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:520021662026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=server-test rate=51672026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:520071682026/10/20 08:16:56 WARN Rate limiter backed off name=server-test rate=51692026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:520021702026/10/20 08:16:56 ERROR Server seems unavailable, giving up on batch untried=171712026/10/20 08:16:56 WARN Rate limiter backed off name=server-test rate=5172=== PAUSE TestPathInfoCACompatibility/null_ca_field173=== RUN TestPathInfoCACompatibility/old_string_format_-_text174=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths175=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176--- PASS: TestStreamPushReportsEveryPath (0.00s)177--- PASS: TestStaticToken (0.00s)178--- PASS: TestShellSplit (0.00s)179--- PASS: TestShellSplitErrors (0.00s)180--- PASS: TestDoServerRequestAttachesToken (0.00s)181=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter182=== CONT TestParsePathInfoJSON183=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter1842026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:52009185=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter186=== RUN TestParsePathInfoJSON/Nix_format187=== CONT TestEncodeNixBase32188=== RUN TestEncodeNixBase32/test_string_hash189=== PAUSE TestParsePathInfoJSON/Nix_format190=== RUN TestParsePathInfoJSON/Lix_format191=== PAUSE TestParsePathInfoJSON/Lix_format192=== CONT TestPartSizeForNAR193=== RUN TestPartSizeForNAR/zero_stays_at_minimum194=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text195=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive197=== RUN TestPathInfoCACompatibility/new_structured_format_-_text198=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text199=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method200=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method201=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== CONT TestDumpPathWriterError204=== CONT TestDumpPathSingleFile205--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)206=== CONT TestEncodeNixBase32WithRealHash207=== CONT TestPathInfoHashCompatibility208=== CONT TestGetStorePathHash209=== PAUSE TestEncodeNixBase32/test_string_hash210=== RUN TestEncodeNixBase32/empty_input211=== PAUSE TestEncodeNixBase32/empty_input212--- PASS: TestStreamPushIsolatesFailures (0.00s)213--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)214--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)215=== RUN TestGetStorePathHash/valid_store_path216=== PAUSE TestGetStorePathHash/valid_store_path217=== RUN TestGetStorePathHash/basename_without_hyphen_should_error218=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)219=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)220=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon221=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon222--- PASS: TestEncodeNixBase32WithRealHash (0.00s)223=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error224=== CONT TestSupersededNARStillUploadsListing225=== RUN TestSupersededNARStillUploadsListing/small_NAR226=== PAUSE TestSupersededNARStillUploadsListing/small_NAR227=== RUN TestSupersededNARStillUploadsListing/dump_cut_short228=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short229=== RUN TestParsePathInfoJSON/empty_input230=== CONT TestDumpPathMatchesNix231=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum232=== RUN TestPartSizeForNAR/small_stays_at_minimum233=== PAUSE TestPartSizeForNAR/small_stays_at_minimum234=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum235=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI236=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error237=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails238=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails239=== PAUSE TestParsePathInfoJSON/empty_input240=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum241=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI242=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error243=== CONT TestUploadMultipart_SupersededByPeer244=== RUN TestUploadMultipart_SupersededByPeer/exists245=== PAUSE TestUploadMultipart_SupersededByPeer/exists246=== RUN TestUploadMultipart_SupersededByPeer/missing247=== PAUSE TestUploadMultipart_SupersededByPeer/missing248=== RUN TestParsePathInfoJSON/whitespace_only249=== PAUSE TestParsePathInfoJSON/whitespace_only250=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts251=== RUN TestParsePathInfoJSON/invalid_JSON252=== PAUSE TestParsePathInfoJSON/invalid_JSON253=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts254=== RUN TestPartSizeForNAR/1_TiB255=== CONT TestStreamPushReportsSkippedPaths256=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512257=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512258--- PASS: TestStreamPushReportsSkippedPaths (0.00s)259=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun262=== PAUSE TestPartSizeForNAR/1_TiB263=== RUN TestPartSizeForNAR/5_TiB_S3_max_object264=== CONT TestStreamPushBatchesUnderLoad265=== CONT TestStreamPushReportsSignatures266=== CONT TestCaseHackSuffix2672026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:520092682026/10/20 08:16:56 ERROR Upload failed error=boom count=1269=== CONT TestConvertHashToNix32/invalid_format270=== CONT TestConvertHashToNix32/already_Nix32_format271=== CONT TestRateLimiterFeedback/429_enables_limiter272--- PASS: TestFileTokenMissing (0.01s)273--- PASS: TestFileTokenEmpty (0.01s)274--- PASS: TestFileTokenReadsAndCaches (0.01s)275--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)276--- PASS: TestResolveStorePath (0.01s)277--- PASS: TestScriptTokenScriptFails (0.01s)278--- PASS: TestStreamPushReportsSignatures (0.00s)279=== CONT TestFilterOversizedClosures280=== RUN TestSetClientTLSErrors/missing_cert_file281=== RUN TestFilterOversizedClosures/no_limit_keeps_everything282=== PAUSE TestSetClientTLSErrors/missing_cert_file283=== RUN TestSetClientTLSErrors/missing_key_file284=== PAUSE TestSetClientTLSErrors/missing_key_file285=== RUN TestSetClientTLSErrors/missing_ca_file286=== PAUSE TestSetClientTLSErrors/missing_ca_file287=== RUN TestSetClientTLSErrors/invalid_ca_file288=== PAUSE TestSetClientTLSErrors/invalid_ca_file289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== RUN TestPartSizeForNAR/capped_at_5_GiB291=== PAUSE TestPartSizeForNAR/capped_at_5_GiB292=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica293=== CONT TestConvertHashToNix32/SRI_format_to_Nix32294--- PASS: TestConvertHashToNix32 (0.00s)295 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)298=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything299=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped300=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped301=== RUN TestFilterOversizedClosures/all_closures_skipped302=== PAUSE TestFilterOversizedClosures/all_closures_skipped303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry305=== RUN TestSetClientTLS/rejects_connection_without_client_cert306=== CONT TestRegisterUploadedObjectReusesConnections307=== CONT TestUploadMultipart_PartsInParallel308=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert309=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA310=== CONT TestRateLimiterFeedback/503_enables_limiter311=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter312=== CONT TestPathInfoCACompatibility/null_ca_field313--- PASS: TestScriptTokenEmptyToken (0.03s)314=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths315=== CONT TestPathInfoCACompatibility/old_string_format_-_text316=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method317=== CONT TestPathInfoCACompatibility/new_structured_format_-_text318=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive319=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths320--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)321 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)322 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)323=== CONT TestEncodeNixBase32/test_string_hash324=== CONT TestEncodeNixBase32/empty_input325--- PASS: TestEncodeNixBase32 (0.00s)326 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)327 --- PASS: TestEncodeNixBase32/empty_input (0.00s)328=== CONT TestSupersededNARStillUploadsListing/small_NAR3292026/10/20 08:16:56 INFO Uploading abc-hello (1.0GB)3302026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=s3-test rate=53312026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:520323322026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:52009333--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)334=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails335--- PASS: TestPathInfoCACompatibility (0.00s)336 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)337 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)338 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)339 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)340 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)3412026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:52009342=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA343=== RUN TestSetClientTLS/preserves_debug_logging_transport344=== PAUSE TestSetClientTLS/preserves_debug_logging_transport345=== CONT TestUploadMultipart_SupersededByPeer/exists3462026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=server-test rate=53472026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:520173482026/10/20 08:16:56 WARN Rate limiter backed off name=server-test rate=53492026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:52009350=== CONT TestUploadMultipart_SupersededByPeer/missing3512026/10/20 08:16:56 INFO Garbage collection started352=== CONT TestParsePathInfoJSON/Nix_format353=== CONT TestParsePathInfoJSON/invalid_JSON354=== CONT TestParsePathInfoJSON/whitespace_only355=== CONT TestParsePathInfoJSON/empty_input356=== CONT TestParsePathInfoJSON/Lix_format357--- PASS: TestParsePathInfoJSON (0.00s)358 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)359 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)360 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)361 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)362 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)363=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)364=== CONT TestGetStorePathHash/valid_store_path365=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512366--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)367 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)368 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)369=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI370=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon371=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error372=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error373=== CONT TestGetStorePathHash/basename_without_hyphen_should_error374--- PASS: TestGetStorePathHash (0.00s)375 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)376 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)377 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)378 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)379=== CONT TestSetClientTLSErrors/missing_cert_file3802026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:52009381=== CONT TestPartSizeForNAR/zero_stays_at_minimum382=== CONT TestFilterOversizedClosures/no_limit_keeps_everything383=== CONT TestSetClientTLSErrors/invalid_ca_file384--- PASS: TestPathInfoHashCompatibility (0.00s)385 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)386 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)387 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)388 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)389=== CONT TestSetClientTLSErrors/missing_ca_file390=== CONT TestSetClientTLSErrors/missing_key_file3912026/10/20 08:16:56 INFO Garbage collection started392=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum393=== CONT TestFilterOversizedClosures/all_closures_skipped3942026/10/20 08:16:56 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50395=== CONT TestPartSizeForNAR/small_stays_at_minimum396=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3972026/10/20 08:16:56 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=2000398--- PASS: TestFilterOversizedClosures (0.00s)399 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)400 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)401 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)402=== CONT TestPartSizeForNAR/5_TiB_S3_max_object403=== CONT TestSupersededNARStillUploadsListing/dump_cut_short404=== CONT TestPartSizeForNAR/capped_at_5_GiB405=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts406=== CONT TestPartSizeForNAR/1_TiB407--- PASS: TestPartSizeForNAR (0.01s)408 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)409 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)410 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)411 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)412 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)413 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)414 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)415=== CONT TestSetClientTLS/rejects_connection_without_client_cert416=== CONT TestSetClientTLS/preserves_debug_logging_transport4172026/10/20 08:16:56 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=0418--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.05s)419=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA4202026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:520094212026/10/20 08:16:56 WARN Garbage collection finished on another replica. Its statistics are not available here422--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)4232026/10/20 08:16:56 WARN Rate limiter enabled after throttle name=server-test rate=54242026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:520224252026/10/20 08:16:56 WARN Rate limiter backed off name=server-test rate=5426--- PASS: TestRateLimiterFeedback (0.00s)427 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)428 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.04s)429 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.03s)430 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.03s)4312026/10/20 08:16:56 INFO Uploading abc-hello (1.0GB)432--- PASS: TestSetClientTLSErrors (0.02s)433 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)434 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)435 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)436 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4372026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:52009438--- PASS: TestStreamPushRequestLine (0.07s)4392026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:52009440--- PASS: TestScriptTokenBadJSON (0.07s)4412026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:520094422026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:520094432026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:520094442026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:520094452026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:520094462026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:520094472026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:520094482026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:520094492026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:520094502026/10/20 08:16:56 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:52009451--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.09s)452--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)453--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)4542026/10/20 08:16:56 http: TLS handshake error from 127.0.0.1:52108: remote error: tls: bad certificate455--- PASS: TestSetClientTLS (0.05s)456 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)457 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)458 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.04s)459--- PASS: TestScriptTokenCachesUntilRefresh (0.11s)460--- PASS: TestStreamPushBatchesUnderLoad (0.11s)461--- PASS: TestDumpPathSingleFile (0.12s)4622026/10/20 08:16:56 INFO Uploading abc-hello (1.0GB)463--- PASS: TestDumpPathWriterError (0.16s)4642026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/24652026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/34662026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/44672026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/54682026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/6\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/64692026/10/20 08:16:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:52106/part/7\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:52106/part/7470--- PASS: TestCaseHackSuffix (0.21s)471--- PASS: TestDumpPathMatchesNix (0.26s)472--- PASS: TestUploadMultipart_PartsInParallel (0.63s)473--- PASS: TestSupersededNARStillUploadsListing (0.00s)474 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.03s)475 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)476 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.61s)4772026/10/20 08:16:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:52010/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:52010/api/uploads/complete4782026/10/20 08:16:57 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/20 08:16:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:52010/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:52010/api/uploads/complete4802026/10/20 08:16:57 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4812026/10/20 08:16:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:52010/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:52010/api/uploads/complete4822026/10/20 08:16:57 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"483--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)484--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)485PASS486Running server tests...487The files belonging to this database system will be owned by user "_tribuchetbld4".488This user must also own the server process.489490The database cluster will be initialized with locale "C".491The default database encoding has accordingly been set to "SQL_ASCII".492The default text search configuration will be set to "english".493494Data page checksums are enabled.495496creating directory /private/var/tb/4/scratch/961630a4308c198f/build/postgres1228355558/data ... ok497creating subdirectories ... ok498selecting dynamic shared memory implementation ... posix499selecting default "max_connections" ... 100500selecting default "shared_buffers" ... 128MB501selecting default time zone ... UTC502creating configuration files ... ok503running bootstrap script ... ok504performing post-bootstrap initialization ... ok505syncing data to disk ... ok506507initdb: warning: enabling "trust" authentication for local connections508initdb: 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.509510Success. You can now start the database server using:511512 pg_ctl -D /private/var/tb/4/scratch/961630a4308c198f/build/postgres1228355558/data -l logfile start5135142026-10-20 08:16:59.823 UTC [48425] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5152026-10-20 08:16:59.824 UTC [48425] LOG: listening on Unix socket "/private/var/tb/4/scratch/961630a4308c198f/build/postgres1228355558/.s.PGSQL.5432"5162026-10-20 08:16:59.834 UTC [48443] LOG: database system was shut down at 2026-10-20 08:16:59 UTC5172026-10-20 08:16:59.836 UTC [48425] LOG: database system is ready to accept connections518/private/var/tb/4/scratch/961630a4308c198f/build/postgres1228355558:5432 - accepting connections519{"timestamp":"2026-10-20T08:17:02.280971Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"107fd9a2-ad56-4374-92e5-5479228f5694","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}520{"timestamp":"2026-10-20T08:17:02.384876Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3465c901-ac9a-4c55-885c-0e3fd7ca7bc6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}521=== RUN TestService_AuthMiddleware522=== PAUSE TestService_AuthMiddleware523=== RUN TestService_AuthMiddleware_MTLSProxyHeader524=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader525=== RUN TestService_AuthMiddleware_MTLSBoundSubjects526=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects527=== RUN TestService_ReadAuthMiddleware528=== PAUSE TestService_ReadAuthMiddleware529=== RUN TestService_AuthMiddleware_OIDC530=== PAUSE TestService_AuthMiddleware_OIDC531=== RUN TestService_RequireScope_OIDC532=== PAUSE TestService_RequireScope_OIDC533=== RUN TestService_ReadScope_PublicByDefault534=== PAUSE TestService_ReadScope_PublicByDefault535=== RUN TestCacheConfigHandler536=== PAUSE TestCacheConfigHandler537=== RUN TestCacheStatsHandler538=== PAUSE TestCacheStatsHandler539=== RUN TestClientCADerivations540=== PAUSE TestClientCADerivations541=== RUN TestClientErrorHandling542=== PAUSE TestClientErrorHandling543=== RUN TestClientIntegration544=== PAUSE TestClientIntegration545=== RUN TestClientMultipleUploads546=== PAUSE TestClientMultipleUploads547=== RUN TestClientWithDependencies548=== PAUSE TestClientWithDependencies549=== RUN TestClientSharedPathCommittedMidPush550=== PAUSE TestClientSharedPathCommittedMidPush551=== RUN TestPinProtectsFromGC552=== PAUSE TestPinProtectsFromGC553=== RUN TestClientPushesUseOnePush554=== PAUSE TestClientPushesUseOnePush555=== RUN TestClientFallsBackToClosures556=== PAUSE TestClientFallsBackToClosures557=== RUN TestDeleteClosuresRacingPins558=== PAUSE TestDeleteClosuresRacingPins559=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock560=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== RUN TestResolveDBConnectionString562=== PAUSE TestResolveDBConnectionString563=== RUN TestConnectWaitsForAPeerMigration564=== PAUSE TestConnectWaitsForAPeerMigration565=== RUN TestLeadElectsOneAndHandsOver566=== PAUSE TestLeadElectsOneAndHandsOver567=== RUN TestLeadIncumbentWinsAfterRestart5682026/10/20 08:17:02 INFO lead: acquired remote=192.0.2.1:12345692026/10/20 08:17:03 INFO lead: released remote=192.0.2.1:12345702026/10/20 08:17:03 INFO lead: acquired remote=192.0.2.1:12345712026/10/20 08:17:04 INFO lead: released remote=192.0.2.1:1234572--- PASS: TestLeadIncumbentWinsAfterRestart (2.15s)573=== RUN TestLeadIncumbentAnnouncesAtOnce574=== PAUSE TestLeadIncumbentAnnouncesAtOnce575=== RUN TestLeadEndsOnShutdown576=== PAUSE TestLeadEndsOnShutdown577=== RUN TestLeadEndsWhenItsConnectionHangs5782026/10/20 08:17:04 INFO lead: acquired remote=192.0.2.1:12345792026-10-20 08:17:06.273 UTC [50938] FATAL: terminating connection due to administrator command5802026/10/20 08:17:06 INFO lead: acquired remote=192.0.2.1:12345812026/10/20 08:17:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5822026/10/20 08:17:07 INFO lead: released remote=192.0.2.1:12345832026/10/20 08:17:07 INFO lead: released remote=192.0.2.1:1234584--- PASS: TestLeadEndsWhenItsConnectionHangs (3.04s)585=== RUN TestGCAdvisoryLockBlocksConcurrentRun586=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun587=== RUN TestGCBugBareHashReferences588=== PAUSE TestGCBugBareHashReferences589=== RUN TestGCMetrics590=== PAUSE TestGCMetrics591=== RUN TestPushDedupSurvivesConcurrentGC592=== PAUSE TestPushDedupSurvivesConcurrentGC593=== RUN TestDeduplicatedObjectsRecordedAsPending594=== PAUSE TestDeduplicatedObjectsRecordedAsPending595=== RUN TestGCSweepSkipsPendingObjects596=== PAUSE TestGCSweepSkipsPendingObjects597=== RUN TestTombstonedObjectOfferedWithoutWaiting598=== PAUSE TestTombstonedObjectOfferedWithoutWaiting599=== RUN TestGCSweepDeliversEachKeyOnce600=== PAUSE TestGCSweepDeliversEachKeyOnce601=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection602=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== RUN TestForceGCDuringPushOffersSweptObject604=== PAUSE TestForceGCDuringPushOffersSweptObject605=== RUN TestFailedS3DeleteKeepsTombstone606=== PAUSE TestFailedS3DeleteKeepsTombstone607=== RUN TestSweepSkipsRowsLockedByPush608=== PAUSE TestSweepSkipsRowsLockedByPush609=== RUN TestRegisterCompletedObjectNeedsPendingRow610=== PAUSE TestRegisterCompletedObjectNeedsPendingRow611=== RUN TestGetExistingObjectsLocksRows612=== PAUSE TestGetExistingObjectsLocksRows613=== RUN TestSweepRechecksPendingAfterLocking614=== PAUSE TestSweepRechecksPendingAfterLocking615=== RUN TestPushWaitsForSweepHoldingRow616=== PAUSE TestPushWaitsForSweepHoldingRow617=== RUN TestCommitRacingPendingCleanupKeepsObjects618=== PAUSE TestCommitRacingPendingCleanupKeepsObjects619=== RUN TestGCEndsOnShutdown620=== PAUSE TestGCEndsOnShutdown621=== RUN TestGCTaskStore_StartNew622=== PAUSE TestGCTaskStore_StartNew623=== RUN TestGCTaskStore_DeduplicateSameParams624=== PAUSE TestGCTaskStore_DeduplicateSameParams625=== RUN TestGCTaskStore_ConflictDifferentParams626=== PAUSE TestGCTaskStore_ConflictDifferentParams627=== RUN TestGCTaskStore_GetEmpty628=== PAUSE TestGCTaskStore_GetEmpty629=== RUN TestGCTaskStore_GetReturnsLatest630=== PAUSE TestGCTaskStore_GetReturnsLatest631=== RUN TestGCTaskStore_CompletedAllowsNewTask632=== PAUSE TestGCTaskStore_CompletedAllowsNewTask633=== RUN TestGCTaskStore_PhaseUpdates634=== PAUSE TestGCTaskStore_PhaseUpdates635=== RUN TestGCTaskStore_Fail636=== PAUSE TestGCTaskStore_Fail637=== RUN TestGracefulShutdownDrainsInflight638=== PAUSE TestGracefulShutdownDrainsInflight639=== RUN TestService_healthCheckHandler640=== PAUSE TestService_healthCheckHandler641=== RUN TestService_readinessHandler642=== PAUSE TestService_readinessHandler643=== RUN TestGenerateLandingPage644=== PAUSE TestGenerateLandingPage645=== RUN TestCacheConfigHandlerMaxNarSize646=== PAUSE TestCacheConfigHandlerMaxNarSize647=== RUN TestCreatePendingClosureRejectsOversizedNAR648=== PAUSE TestCreatePendingClosureRejectsOversizedNAR649=== RUN TestNARDeduplicationMetadataUploadBug650=== PAUSE TestNARDeduplicationMetadataUploadBug651=== RUN TestMetricsInventory652=== PAUSE TestMetricsInventory653=== RUN TestMetricsCommit654=== PAUSE TestMetricsCommit655=== RUN TestService_NativeMTLS656=== PAUSE TestService_NativeMTLS657=== RUN TestServerTLSConfig658=== PAUSE TestServerTLSConfig659=== RUN TestMultipartCleanup660=== PAUSE TestMultipartCleanup661=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded662=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== RUN TestPendingCleanupUsesOneCutoff664=== PAUSE TestPendingCleanupUsesOneCutoff665=== RUN TestObjectStatsTrigger666=== PAUSE TestObjectStatsTrigger667=== RUN TestObjectStatsLargeCommit668=== PAUSE TestObjectStatsLargeCommit669=== RUN TestOrphanedObjectsGC670=== PAUSE TestOrphanedObjectsGC671=== RUN TestOrphanedObjectsGCStressTest672=== PAUSE TestOrphanedObjectsGCStressTest673=== RUN TestCreatePin_ReservedPins674=== PAUSE TestCreatePin_ReservedPins675=== RUN TestPresentReportsOnlyClosureRoots676=== PAUSE TestPresentReportsOnlyClosureRoots677=== RUN TestPresentRefreshesOnlyStaleClosures678=== PAUSE TestPresentRefreshesOnlyStaleClosures679=== RUN TestPresentNotReportedWhileGCDeletesClosure680=== PAUSE TestPresentNotReportedWhileGCDeletesClosure681=== RUN TestParseSingleRange682=== PAUSE TestParseSingleRange683=== RUN TestProxyHeadersOnlyTrustedOnSocket6842026/10/20 08:17:07 INFO Starting HTTP server address=127.0.0.1:521816852026/10/20 08:17:07 INFO Starting HTTP server address=proxy.sock6862026/10/20 08:17:07 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6872026/10/20 08:17:07 INFO Shutdown signal received, draining in-flight requests timeout=10s688--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.24s)689=== RUN TestIsValidCachePath690=== PAUSE TestIsValidCachePath691=== RUN TestReadProxyNarinfo692=== PAUSE TestReadProxyNarinfo693=== RUN TestReadProxyNarinfoAlreadyDecompressed694=== PAUSE TestReadProxyNarinfoAlreadyDecompressed695=== RUN TestReadProxyContentNegotiation696=== PAUSE TestReadProxyContentNegotiation697=== RUN TestReadProxyNarStreaming698=== PAUSE TestReadProxyNarStreaming699=== RUN TestReadProxy404700=== PAUSE TestReadProxy404701=== RUN TestReadProxyInvalidPath702=== PAUSE TestReadProxyInvalidPath703=== RUN TestReadProxyHead704=== PAUSE TestReadProxyHead705=== RUN TestReadProxyOutlastsServerWriteTimeout706=== PAUSE TestReadProxyOutlastsServerWriteTimeout707=== RUN TestReadProxyConditionalGet708=== PAUSE TestReadProxyConditionalGet709=== RUN TestReadProxyRootRedirectsToIndexHTML710=== PAUSE TestReadProxyRootRedirectsToIndexHTML711=== RUN TestReadProxyDisabled712=== PAUSE TestReadProxyDisabled713=== RUN TestReadRedirectNar714=== PAUSE TestReadRedirectNar715=== RUN TestReadRedirectKeepsNarinfoProxied716=== PAUSE TestReadRedirectKeepsNarinfoProxied717=== RUN TestReadProxyRangeRequest718=== PAUSE TestReadProxyRangeRequest719=== RUN TestReadRedirectUsesPublicS3URL720=== PAUSE TestReadRedirectUsesPublicS3URL721=== RUN TestPush_OverlappingRootsStoreOneRowPerKey722=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey723=== RUN TestPush_CompleteCommitsEveryRoot724=== PAUSE TestPush_CompleteCommitsEveryRoot725=== RUN TestPush_RepeatedRootCommitsOnce726=== PAUSE TestPush_RepeatedRootCommitsOnce727=== RUN TestPush_CompleteWaitsForCleanupOfThePush728=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush729=== RUN TestPush_RootsAreLockedInByteOrder730=== PAUSE TestPush_RootsAreLockedInByteOrder731=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit732=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit733=== RUN TestPush_RejectsBadRequests734=== PAUSE TestPush_RejectsBadRequests735=== RUN TestPush_SignsNarinfosOfItsPendingObjects736=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects737=== RUN TestRedundantMultipartUpload738=== PAUSE TestRedundantMultipartUpload739=== RUN TestCompleteMultipartUpload_ErrorButObjectExists740=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists741=== RUN TestCompletedNarNotReofferedAcrossClosures742=== PAUSE TestCompletedNarNotReofferedAcrossClosures743=== RUN TestPresignedUploadRegisteredBeforeCommit744=== PAUSE TestPresignedUploadRegisteredBeforeCommit745=== RUN TestService_Rustfstest746=== PAUSE TestService_Rustfstest747=== RUN TestParseSize748=== PAUSE TestParseSize749=== RUN TestSkippedUploadsHandler750=== PAUSE TestSkippedUploadsHandler751=== RUN TestSystemdListenerNotActivated752--- PASS: TestSystemdListenerNotActivated (0.00s)753=== RUN TestWatchdogBeatsWhenHealthy754--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)755=== RUN TestWatchdogSkipsWhenUnhealthy7562026/10/20 08:17:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/20 08:17:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/20 08:17:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"766--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)767=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle768=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== RUN TestProxyWriteTimeout770=== PAUSE TestProxyWriteTimeout771=== RUN TestPendingClosureWriteTimeout772=== PAUSE TestPendingClosureWriteTimeout773=== RUN TestIsValidUploadKey774=== PAUSE TestIsValidUploadKey775=== RUN TestUploadHandlersRejectInvalidKeys776=== PAUSE TestUploadHandlersRejectInvalidKeys777=== RUN TestUploadHandlersRejectOversizedBody778=== PAUSE TestUploadHandlersRejectOversizedBody779=== RUN TestService_cleanupPendingClosuresHandler780=== PAUSE TestService_cleanupPendingClosuresHandler781=== RUN TestService_createPendingClosureHandler782=== PAUSE TestService_createPendingClosureHandler783=== RUN TestService_verifyS3Integrity784=== PAUSE TestService_verifyS3Integrity785=== RUN TestCompleteMultipartUnregistered786=== PAUSE TestCompleteMultipartUnregistered787=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT788=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT789=== CONT TestReadProxyRangeRequest790=== CONT TestGCTaskStore_DeduplicateSameParams791=== CONT TestFailedS3DeleteKeepsTombstone792=== CONT TestService_Rustfstest793=== CONT TestGCTaskStore_StartNew794=== CONT TestParseSize795=== CONT TestGCEndsOnShutdown796=== CONT TestReadRedirectKeepsNarinfoProxied797=== RUN TestGCEndsOnShutdown/before_the_run798=== CONT TestCommitRacingPendingCleanupKeepsObjects799=== CONT TestPushWaitsForSweepHoldingRow800=== CONT TestSweepRechecksPendingAfterLocking801=== CONT TestGetExistingObjectsLocksRows802=== CONT TestRegisterCompletedObjectNeedsPendingRow803=== CONT TestSweepSkipsRowsLockedByPush804=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT805=== CONT TestCompleteMultipartUnregistered806=== CONT TestService_verifyS3Integrity807=== CONT TestService_createPendingClosureHandler808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestUploadHandlersRejectInvalidKeys811=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info812=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info813=== CONT TestIsValidUploadKey814=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal815=== CONT TestPendingClosureWriteTimeout816=== CONT TestProxyWriteTimeout817=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle818=== CONT TestSkippedUploadsHandler819--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)820--- PASS: TestGCTaskStore_StartNew (0.00s)821=== CONT TestService_AuthMiddleware822=== PAUSE TestGCEndsOnShutdown/before_the_run823=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal824=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete825=== RUN TestIsValidUploadKey/narinfo826=== PAUSE TestIsValidUploadKey/narinfo827=== RUN TestPendingClosureWriteTimeout/empty8282026/10/20 08:17:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000829=== PAUSE TestPendingClosureWriteTimeout/empty830=== RUN TestProxyWriteTimeout/narinfo831=== RUN TestPendingClosureWriteTimeout/400_objects832=== PAUSE TestPendingClosureWriteTimeout/400_objects833=== PAUSE TestProxyWriteTimeout/narinfo834=== RUN TestProxyWriteTimeout/1_GiB_nar835=== PAUSE TestProxyWriteTimeout/1_GiB_nar836=== RUN TestProxyWriteTimeout/10_GiB_nar837=== PAUSE TestProxyWriteTimeout/10_GiB_nar838=== RUN TestProxyWriteTimeout/unknown_size839=== PAUSE TestProxyWriteTimeout/unknown_size840--- PASS: TestParseSize (0.00s)841=== RUN TestIsValidUploadKey/nar_zst842=== PAUSE TestIsValidUploadKey/nar_zst843=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete844=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key845=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark846=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key847=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key848=== RUN TestPendingClosureWriteTimeout/670k_objects849=== RUN TestIsValidUploadKey/nar_xz850=== CONT TestReadRedirectNar851--- PASS: TestSkippedUploadsHandler (0.00s)852=== CONT TestReadProxyDisabled853=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark854=== CONT TestReadProxyRootRedirectsToIndexHTML855=== PAUSE TestPendingClosureWriteTimeout/670k_objects856=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline857=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline858=== CONT TestReadProxyConditionalGet859=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key860=== PAUSE TestIsValidUploadKey/nar_xz861=== RUN TestIsValidUploadKey/nar_plain862=== PAUSE TestIsValidUploadKey/nar_plain863=== RUN TestIsValidUploadKey/listing864=== PAUSE TestIsValidUploadKey/listing865=== RUN TestIsValidUploadKey/build_log866=== PAUSE TestIsValidUploadKey/build_log867=== RUN TestIsValidUploadKey/build_log_home-manager_file868=== PAUSE TestIsValidUploadKey/build_log_home-manager_file869=== RUN TestIsValidUploadKey/build_log_plus_in_name870=== PAUSE TestIsValidUploadKey/build_log_plus_in_name871=== RUN TestIsValidUploadKey/build_log_question_mark872=== PAUSE TestIsValidUploadKey/build_log_question_mark873=== RUN TestIsValidUploadKey/build_log_equals874=== PAUSE TestIsValidUploadKey/build_log_equals875=== RUN TestIsValidUploadKey/realisation876=== PAUSE TestIsValidUploadKey/realisation877=== RUN TestIsValidUploadKey/realisation_plus_in_output878=== PAUSE TestIsValidUploadKey/realisation_plus_in_output879=== RUN TestIsValidUploadKey/nix-cache-info880=== PAUSE TestIsValidUploadKey/nix-cache-info881=== RUN TestIsValidUploadKey/index.html882=== PAUSE TestIsValidUploadKey/index.html883=== RUN TestIsValidUploadKey/narinfo_key,_nar_type884=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type885=== RUN TestIsValidUploadKey/nar_key,_narinfo_type886=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type887=== RUN TestIsValidUploadKey/listing_key,_narinfo_type888=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type889=== RUN TestIsValidUploadKey/traversal890=== PAUSE TestIsValidUploadKey/traversal891=== RUN TestIsValidUploadKey/traversal_nar892=== PAUSE TestIsValidUploadKey/traversal_nar893=== RUN TestIsValidUploadKey/absolute894=== PAUSE TestIsValidUploadKey/absolute895=== RUN TestIsValidUploadKey/empty_key896=== PAUSE TestIsValidUploadKey/empty_key897=== RUN TestIsValidUploadKey/unknown_type898=== PAUSE TestIsValidUploadKey/unknown_type899=== CONT TestReadProxyOutlastsServerWriteTimeout900=== CONT TestReadProxyHead901=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure902=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure903=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart904=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart905=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts906=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts907=== CONT TestDeleteClosuresRacingPins9082026/10/20 08:17:10 INFO Aborted multipart uploads count=0 kept=09092026/10/20 08:17:10 WARN Force mode enabled - objects will be deleted immediately without grace period9102026/10/20 08:17:10 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=09112026/10/20 08:17:10 INFO Vacuumed table table=pending_closures9122026/10/20 08:17:10 INFO Vacuumed table table=pending_objects9132026/10/20 08:17:10 INFO Vacuumed table table=multipart_uploads9142026/10/20 08:17:10 INFO Vacuumed table table=closures9152026/10/20 08:17:10 INFO Vacuumed table table=objects916--- PASS: TestSweepRechecksPendingAfterLocking (2.16s)917=== CONT TestReadProxyInvalidPath918--- PASS: TestService_Rustfstest (2.23s)919=== CONT TestReadProxy404920--- PASS: TestReadProxyRangeRequest (2.46s)921=== CONT TestForceGCDuringPushOffersSweptObject922=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows923=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows924=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check925=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check926=== CONT TestReadProxyNarStreaming9272026/10/20 08:17:10 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/20 08:17:10 INFO Aborted multipart uploads count=0 kept=09292026/10/20 08:17:10 WARN Force mode enabled - objects will be deleted immediately without grace period9302026/10/20 08:17:10 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9312026/10/20 08:17:10 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."932--- PASS: TestFailedS3DeleteKeepsTombstone (2.80s)933=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9342026/10/20 08:17:11 INFO Aborted multipart uploads count=0 kept=09352026/10/20 08:17:11 WARN Force mode enabled - objects will be deleted immediately without grace period9362026/10/20 08:17:11 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=09372026/10/20 08:17:11 INFO Vacuumed table table=pending_closures9382026/10/20 08:17:11 INFO Vacuumed table table=pending_objects9392026/10/20 08:17:11 INFO Vacuumed table table=multipart_uploads9402026/10/20 08:17:11 INFO Vacuumed table table=closures9412026/10/20 08:17:11 INFO Vacuumed table table=objects942--- PASS: TestCommitRacingPendingCleanupKeepsObjects (3.03s)943=== CONT TestReadProxyContentNegotiation9442026/10/20 08:17:11 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/20 08:17:11 INFO Aborted multipart uploads count=0 kept=09462026/10/20 08:17:11 WARN Force mode enabled - objects will be deleted immediately without grace period9472026/10/20 08:17:11 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=09482026/10/20 08:17:11 INFO Vacuumed table table=pending_closures9492026/10/20 08:17:11 INFO Vacuumed table table=pending_objects9502026/10/20 08:17:11 INFO Vacuumed table table=multipart_uploads9512026/10/20 08:17:11 INFO Vacuumed table table=closures9522026/10/20 08:17:11 INFO Vacuumed table table=objects9532026/10/20 08:17:11 INFO Aborted multipart uploads count=0 kept=09542026/10/20 08:17:11 WARN Force mode enabled - objects will be deleted immediately without grace period9552026/10/20 08:17:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9562026/10/20 08:17:11 INFO Aborted multipart uploads count=0 kept=09572026/10/20 08:17:11 INFO Received uploads request method=POST path=/api/pending_closures958--- PASS: TestPushWaitsForSweepHoldingRow (3.55s)959=== CONT TestGCSweepDeliversEachKeyOnce9602026/10/20 08:17:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9612026/10/20 08:17:11 INFO Aborted multipart uploads count=1 kept=09622026/10/20 08:17:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9632026-10-20 08:17:11.782 UTC [53196] ERROR: Closure does not exist: id=19642026-10-20 08:17:11.782 UTC [53196] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9652026-10-20 08:17:11.782 UTC [53196] STATEMENT: -- name: CommitPendingClosure :one966 SELECT commit_pending_closure($1::bigint)::bigint967 968--- PASS: TestService_cleanupPendingClosuresHandler (3.63s)969=== CONT TestReadProxyNarinfoAlreadyDecompressed9702026/10/20 08:17:11 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=09712026/10/20 08:17:11 INFO Vacuumed table table=pending_closures9722026/10/20 08:17:11 INFO Vacuumed table table=pending_objects9732026/10/20 08:17:11 INFO Vacuumed table table=multipart_uploads9742026/10/20 08:17:11 INFO Vacuumed table table=closures9752026/10/20 08:17:11 INFO Vacuumed table table=objects976--- PASS: TestSweepSkipsRowsLockedByPush (3.67s)977=== CONT TestReadProxyNarinfo9782026/10/20 08:17:11 INFO Received uploads request method=POST path=/api/pending_closures9792026/10/20 08:17:12 INFO Received uploads request method=POST path=/api/pending_closures980--- PASS: TestReadProxyConditionalGet (5.06s)981=== CONT TestIsValidCachePath982=== RUN TestIsValidCachePath/narinfo983=== PAUSE TestIsValidCachePath/narinfo984=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars985=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars986=== RUN TestIsValidCachePath/nar_zst987=== PAUSE TestIsValidCachePath/nar_zst988=== RUN TestIsValidCachePath/nar_xz989=== PAUSE TestIsValidCachePath/nar_xz990=== RUN TestIsValidCachePath/nar_bz2991=== PAUSE TestIsValidCachePath/nar_bz2992=== RUN TestIsValidCachePath/nar_uncompressed993=== PAUSE TestIsValidCachePath/nar_uncompressed994=== RUN TestIsValidCachePath/ls995=== PAUSE TestIsValidCachePath/ls996=== RUN TestIsValidCachePath/log997=== PAUSE TestIsValidCachePath/log998=== RUN TestIsValidCachePath/realisation999=== PAUSE TestIsValidCachePath/realisation1000=== RUN TestIsValidCachePath/nix-cache-info1001=== PAUSE TestIsValidCachePath/nix-cache-info1002=== RUN TestIsValidCachePath/index.html1003=== PAUSE TestIsValidCachePath/index.html1004=== RUN TestIsValidCachePath/traversal_parent1005=== PAUSE TestIsValidCachePath/traversal_parent1006=== RUN TestIsValidCachePath/traversal_in_middle1007=== PAUSE TestIsValidCachePath/traversal_in_middle1008=== RUN TestIsValidCachePath/invalid_char_e1009=== PAUSE TestIsValidCachePath/invalid_char_e1010=== RUN TestIsValidCachePath/invalid_char_u1011=== PAUSE TestIsValidCachePath/invalid_char_u1012=== RUN TestIsValidCachePath/random_path1013=== PAUSE TestIsValidCachePath/random_path1014=== RUN TestIsValidCachePath/empty1015=== PAUSE TestIsValidCachePath/empty1016=== RUN TestIsValidCachePath/leading_slash1017=== PAUSE TestIsValidCachePath/leading_slash1018=== RUN TestIsValidCachePath/wrong_extension1019=== PAUSE TestIsValidCachePath/wrong_extension1020=== RUN TestIsValidCachePath/short_hash1021=== PAUSE TestIsValidCachePath/short_hash1022=== CONT TestParseSingleRange1023=== RUN TestParseSingleRange/none1024=== PAUSE TestParseSingleRange/none1025=== RUN TestParseSingleRange/unknown_unit1026=== PAUSE TestParseSingleRange/unknown_unit1027=== RUN TestParseSingleRange/multi-range_ignored1028=== PAUSE TestParseSingleRange/multi-range_ignored1029=== RUN TestParseSingleRange/malformed_no_dash1030=== PAUSE TestParseSingleRange/malformed_no_dash1031=== RUN TestParseSingleRange/malformed_both_empty1032=== PAUSE TestParseSingleRange/malformed_both_empty1033=== RUN TestParseSingleRange/malformed_end_before_start1034=== PAUSE TestParseSingleRange/malformed_end_before_start1035=== RUN TestParseSingleRange/closed1036=== PAUSE TestParseSingleRange/closed1037=== RUN TestParseSingleRange/open-ended1038=== PAUSE TestParseSingleRange/open-ended1039=== RUN TestParseSingleRange/end_clamped_to_size1040=== PAUSE TestParseSingleRange/end_clamped_to_size1041=== RUN TestParseSingleRange/suffix1042=== PAUSE TestParseSingleRange/suffix1043=== RUN TestParseSingleRange/suffix_exceeds_size1044=== PAUSE TestParseSingleRange/suffix_exceeds_size1045=== RUN TestParseSingleRange/single_byte1046=== PAUSE TestParseSingleRange/single_byte1047=== RUN TestParseSingleRange/start_past_EOF1048=== PAUSE TestParseSingleRange/start_past_EOF1049=== RUN TestParseSingleRange/start_far_past_EOF1050=== PAUSE TestParseSingleRange/start_far_past_EOF1051=== CONT TestTombstonedObjectOfferedWithoutWaiting10522026/10/20 08:17:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1053--- PASS: TestReadRedirectNar (5.62s)1054=== CONT TestGCSweepSkipsPendingObjects1055--- PASS: TestReadRedirectKeepsNarinfoProxied (6.05s)1056=== CONT TestDeduplicatedObjectsRecordedAsPending10572026/10/20 08:17:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1058--- PASS: TestReadProxyDisabled (6.29s)1059=== CONT TestPushDedupSurvivesConcurrentGC10602026/10/20 08:17:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LmMyZGUzZjNmLWNhOWEtNGNhZi05OTNlLTNhZTY3MzgzYjczMXgxNzkyNDg0MjMxOTUzNjAyMDAw parts=1010612026/10/20 08:17:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10622026/10/20 08:17:14 INFO Completed upload id=1 objects=2 duration=18.026416ms10632026/10/20 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures10642026/10/20 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures10652026/10/20 08:17:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10662026/10/20 08:17:14 WARN Found objects in DB but missing from S3, will re-upload count=11067--- PASS: TestService_verifyS3Integrity (6.34s)1068=== CONT TestPresentNotReportedWhileGCDeletesClosure1069=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1070=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1071=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1072=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1073=== CONT TestPresentRefreshesOnlyStaleClosures1074--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.50s)1075=== CONT TestPresentReportsOnlyClosureRoots10762026/10/20 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/20 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures10782026/10/20 08:17:14 INFO Received uploads request method=POST path=/api/pending_closures1079--- PASS: TestReadProxyHead (6.95s)1080=== CONT TestCreatePin_ReservedPins10812026/10/20 08:17:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52256/oidc10822026/10/20 08:17:15 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1083--- PASS: TestService_AuthMiddleware (7.25s)1084=== CONT TestGCMetrics1085--- PASS: TestGetExistingObjectsLocksRows (7.54s)1086=== CONT TestGCBugBareHashReferences10872026/10/20 08:17:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10882026/10/20 08:17:16 INFO Received uploads request method=POST path=/api/pending_closures10892026/10/20 08:17:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LjhhYzRlMWI3LTQ5MzktNGI0NC04NDZmLTI5NjA3ZjdiM2I1NHgxNzkyNDg0MjM0ODc1MjI1MDAw parts=1010902026/10/20 08:17:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10912026/10/20 08:17:16 INFO Completed upload id=1 objects=2 duration=33.523458ms1092--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (8.04s)10932026/10/20 08:17:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001094=== CONT TestOrphanedObjectsGCStressTest10952026/10/20 08:17:16 INFO Received uploads request method=POST path=/api/pending_closures10962026/10/20 08:17:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures10972026/10/20 08:17:16 INFO Aborted multipart uploads count=0 kept=010982026/10/20 08:17:16 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=010992026/10/20 08:17:16 INFO Vacuumed table table=pending_closures11002026/10/20 08:17:16 INFO Vacuumed table table=pending_objects11012026/10/20 08:17:16 INFO Vacuumed table table=multipart_uploads11022026/10/20 08:17:16 INFO Vacuumed table table=closures11032026/10/20 08:17:16 INFO Vacuumed table table=objects1104--- PASS: TestReadProxyRootRedirectsToIndexHTML (8.20s)1105=== CONT TestGCAdvisoryLockBlocksConcurrentRun11062026/10/20 08:17:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001107--- PASS: TestService_createPendingClosureHandler (8.26s)1108=== CONT TestLeadEndsOnShutdown11092026/10/20 08:17:16 WARN Rate limiter enabled after throttle name=s3-test rate=511102026/10/20 08:17:16 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1111=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1112 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101113 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001114--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.30s)1115=== CONT TestLeadIncumbentAnnouncesAtOnce11162026/10/20 08:17:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11172026/10/20 08:17:16 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1118--- PASS: TestCompleteMultipartUnregistered (8.45s)1119=== CONT TestOrphanedObjectsGC1120--- PASS: TestReadProxyInvalidPath (7.07s)1121=== CONT TestObjectStatsLargeCommit1122--- PASS: TestReadProxy404 (7.22s)1123=== CONT TestObjectStatsTrigger1124--- PASS: TestReadProxyNarStreaming (7.11s)1125=== CONT TestPendingCleanupUsesOneCutoff11262026/10/20 08:17:18 INFO Received uploads request method=POST path=/api/pending_closures1127--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (7.43s)1128=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1129--- PASS: TestReadProxyContentNegotiation (7.72s)1130=== CONT TestMultipartCleanup11312026/10/20 08:17:19 INFO Aborted multipart uploads count=0 kept=011322026/10/20 08:17:19 WARN Force mode enabled - objects will be deleted immediately without grace period1133--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.60s)1134=== CONT TestServerTLSConfig1135=== RUN TestServerTLSConfig/no_client_CA1136=== PAUSE TestServerTLSConfig/no_client_CA1137=== RUN TestServerTLSConfig/missing_CA_file1138=== PAUSE TestServerTLSConfig/missing_CA_file1139=== RUN TestServerTLSConfig/not_a_PEM_file1140=== PAUSE TestServerTLSConfig/not_a_PEM_file1141=== CONT TestService_NativeMTLS11422026/10/20 08:17:19 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=011432026/10/20 08:17:19 INFO Vacuumed table table=pending_closures11442026/10/20 08:17:19 INFO Vacuumed table table=pending_objects11452026/10/20 08:17:19 INFO Vacuumed table table=multipart_uploads11462026/10/20 08:17:19 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>11472026/10/20 08:17:19 INFO Vacuumed table table=closures1148--- PASS: TestReadProxyNarinfo (8.02s)1149=== CONT TestLeadElectsOneAndHandsOver11502026/10/20 08:17:19 INFO Vacuumed table table=objects1151--- PASS: TestGCSweepDeliversEachKeyOnce (8.15s)1152=== CONT TestMetricsCommit11532026/10/20 08:17:19 INFO Received uploads request method=POST path=/api/pending_closures1154--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.73s)1155=== CONT TestConnectWaitsForAPeerMigration1156--- PASS: TestReadProxyOutlastsServerWriteTimeout (11.96s)1157=== CONT TestMetricsInventory11582026/10/20 08:17:20 INFO Received uploads request method=POST path=/api/pending_closures1159--- PASS: TestDeleteClosuresRacingPins (12.36s)1160=== CONT TestResolveDBConnectionString11612026/10/20 08:17:20 INFO Aborted multipart uploads count=0 kept=01162=== RUN TestResolveDBConnectionString/flag_wins1163=== PAUSE TestResolveDBConnectionString/flag_wins1164=== RUN TestResolveDBConnectionString/file_when_flag_empty1165=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1166=== RUN TestResolveDBConnectionString/missing_file_is_an_error1167=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1168=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1169=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1170=== RUN TestResolveDBConnectionString/nothing_configured1171=== PAUSE TestResolveDBConnectionString/nothing_configured1172=== CONT TestNARDeduplicationMetadataUploadBug11732026/10/20 08:17:20 WARN Force mode enabled - objects will be deleted immediately without grace period11742026/10/20 08:17:20 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=011752026/10/20 08:17:20 INFO Vacuumed table table=pending_closures11762026/10/20 08:17:20 INFO Vacuumed table table=pending_objects11772026/10/20 08:17:20 INFO Vacuumed table table=multipart_uploads11782026/10/20 08:17:20 INFO Vacuumed table table=closures11792026/10/20 08:17:20 INFO Vacuumed table table=objects1180--- PASS: TestGCSweepSkipsPendingObjects (7.08s)1181=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11822026/10/20 08:17:20 INFO Received uploads request method=POST path=/api/pending_closures1183--- PASS: TestDeduplicatedObjectsRecordedAsPending (6.83s)1184=== CONT TestCreatePendingClosureRejectsOversizedNAR11852026/10/20 08:17:21 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1187=== CONT TestGCTaskStore_Fail1188--- PASS: TestGCTaskStore_Fail (0.00s)1189=== CONT TestGCTaskStore_PhaseUpdates1190--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1191=== CONT TestGCTaskStore_CompletedAllowsNewTask1192--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1193=== CONT TestGCTaskStore_GetReturnsLatest1194--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1195=== CONT TestCacheConfigHandlerMaxNarSize1196--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1197=== CONT TestGCTaskStore_GetEmpty1198--- PASS: TestGCTaskStore_GetEmpty (0.00s)1199=== CONT TestGenerateLandingPage1200--- PASS: TestGenerateLandingPage (0.01s)1201=== CONT TestGCTaskStore_ConflictDifferentParams1202--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1203=== CONT TestService_readinessHandler12042026/10/20 08:17:21 INFO Received uploads request method=POST path=/api/pending_closures1205--- PASS: TestPresentRefreshesOnlyStaleClosures (7.47s)1206=== CONT TestService_healthCheckHandler12072026/10/20 08:17:22 INFO Aborted multipart uploads count=0 kept=012082026/10/20 08:17:22 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=012092026/10/20 08:17:22 INFO Vacuumed table table=pending_closures12102026/10/20 08:17:22 INFO Vacuumed table table=pending_objects12112026/10/20 08:17:22 INFO Vacuumed table table=multipart_uploads12122026/10/20 08:17:22 INFO Vacuumed table table=closures12132026/10/20 08:17:22 INFO Vacuumed table table=objects12142026/10/20 08:17:22 INFO Aborted multipart uploads count=0 kept=012152026/10/20 08:17:22 WARN Force mode enabled - objects will be deleted immediately without grace period12162026/10/20 08:17:22 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=012172026/10/20 08:17:22 INFO Vacuumed table table=pending_closures12182026/10/20 08:17:22 INFO Vacuumed table table=pending_objects12192026/10/20 08:17:22 INFO Vacuumed table table=multipart_uploads12202026/10/20 08:17:22 INFO Vacuumed table table=closures12212026/10/20 08:17:22 INFO Vacuumed table table=objects1222--- PASS: TestPushDedupSurvivesConcurrentGC (7.74s)1223=== CONT TestGracefulShutdownDrainsInflight12242026/10/20 08:17:22 INFO Starting HTTP server address=127.0.0.1:5232112252026/10/20 08:17:22 INFO Shutdown signal received, draining in-flight requests timeout=10s1226--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1227=== CONT TestClientCADerivations1228--- PASS: TestPresentReportsOnlyClosureRoots (7.67s)1229=== CONT TestClientFallsBackToClosures12302026/10/20 08:17:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12312026/10/20 08:17:22 WARN Refused reserved pin name=worker-x86_64-linux12322026/10/20 08:17:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12332026/10/20 08:17:22 INFO Received create pin request method=POST path=/api/pins/my-app12342026/10/20 08:17:22 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1235--- PASS: TestCreatePin_ReservedPins (7.41s)1236=== CONT TestService_RequireScope_OIDC12372026/10/20 08:17:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52328/oidc12382026/10/20 08:17:22 INFO Aborted multipart uploads count=0 kept=012392026/10/20 08:17:22 WARN Force mode enabled - objects will be deleted immediately without grace period12402026/10/20 08:17:22 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=012412026/10/20 08:17:22 INFO Vacuumed table table=pending_closures12422026/10/20 08:17:22 INFO Vacuumed table table=pending_objects12432026/10/20 08:17:22 INFO Vacuumed table table=multipart_uploads12442026/10/20 08:17:22 INFO Vacuumed table table=closures12452026/10/20 08:17:22 INFO Vacuumed table table=objects1246--- PASS: TestGCMetrics (7.53s)1247=== CONT TestClientPushesUseOnePush1248--- PASS: TestGCBugBareHashReferences (7.76s)1249=== CONT TestPinProtectsFromGC12502026/10/20 08:17:23 INFO lead: acquired remote=192.0.2.1:123412512026/10/20 08:17:23 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld4 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1252--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.39s)1253=== CONT TestClientSharedPathCommittedMidPush12542026/10/20 08:17:24 INFO lead: acquired remote=192.0.2.1:123412552026/10/20 08:17:24 INFO lead: released remote=192.0.2.1:12341256--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.76s)1257=== CONT TestClientWithDependencies1258--- PASS: TestObjectStatsTrigger (6.87s)1259=== CONT TestClientMultipleUploads12602026/10/20 08:17:24 INFO lead: released remote=192.0.2.1:12341261--- PASS: TestLeadEndsOnShutdown (8.17s)1262=== CONT TestClientIntegration12632026/10/20 08:17:24 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/20 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/20 08:17:25 INFO Received cleanup request method=DELETE path=/api/pending_closures12662026/10/20 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures1267--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.90s)1268=== CONT TestCacheStatsHandler12692026/10/20 08:17:25 INFO Received uploads request method=POST path=/api/pending_closures1270=== NAME TestOrphanedObjectsGC1271 orphaned_objects_gc_test.go:287: GC Test Summary:1272 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1273 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1274 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1275 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1276 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1277--- PASS: TestOrphanedObjectsGC (8.98s)1278=== CONT TestCacheConfigHandler1279=== RUN TestCacheConfigHandler/full_config,_no_issuer1280=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1281=== RUN TestCacheConfigHandler/no_cache_url_configured1282=== PAUSE TestCacheConfigHandler/no_cache_url_configured1283=== RUN TestCacheConfigHandler/no_signing_keys1284=== PAUSE TestCacheConfigHandler/no_signing_keys1285=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1286=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1287=== CONT TestClientErrorHandling1288=== RUN TestClientErrorHandling/InvalidStorePath1289=== PAUSE TestClientErrorHandling/InvalidStorePath1290=== RUN TestClientErrorHandling/InvalidAuthToken1291=== PAUSE TestClientErrorHandling/InvalidAuthToken1292=== RUN TestClientErrorHandling/ServerNotAvailable1293=== PAUSE TestClientErrorHandling/ServerNotAvailable1294=== CONT TestService_ReadScope_PublicByDefault12952026/10/20 08:17:25 INFO Received cleanup request method=DELETE path=/api/pending_closures12962026/10/20 08:17:25 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12972026/10/20 08:17:25 INFO Aborted multipart uploads count=0 kept=112982026/10/20 08:17:25 INFO Received cleanup request method=DELETE path=/api/pending_closures12992026/10/20 08:17:25 INFO Aborted multipart uploads count=1 kept=01300--- PASS: TestMultipartCleanup (6.85s)1301=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13022026/10/20 08:17:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13032026/10/20 08:17:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1304--- PASS: TestService_NativeMTLS (6.37s)1305=== CONT TestPush_RepeatedRootCommitsOnce13062026/10/20 08:17:26 INFO Received push request method=POST path=/api/pushes13072026/10/20 08:17:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/20 08:17:26 INFO Completed push id=1 objects=4 duration=27.571ms13092026/10/20 08:17:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13102026/10/20 08:17:26 INFO Completed upload id=2 objects=2 duration=6.849666ms1311--- PASS: TestMetricsCommit (6.37s)1312=== CONT TestPresignedUploadRegisteredBeforeCommit1313--- PASS: TestMetricsInventory (6.29s)1314=== CONT TestPush_RootsAreLockedInByteOrder1315--- PASS: TestConnectWaitsForAPeerMigration (6.81s)1316=== CONT TestCompletedNarNotReofferedAcrossClosures13172026/10/20 08:17:26 INFO lead: acquired remote=192.0.2.1:12341318=== NAME TestNARDeduplicationMetadataUploadBug1319 metadata_upload_test.go:48: First store path: /private/var/tb/4/scratch/961630a4308c198f/build/TestNARDeduplicationMetadataUploadBug3616243121/001/store/3dgz2jni02xinfzhwm7f0j6ckjf08glh-file1.txt13202026/10/20 08:17:27 INFO Received push request method=POST path=/api/pushes13212026/10/20 08:17:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13222026/10/20 08:17:27 INFO Uploading 3dgz2jni02xinfzhwm7f0j6ckjf08glh-file1.txt (160B)13232026/10/20 08:17:27 WARN Failed to register uploaded object key=3dgz2jni02xinfzhwm7f0j6ckjf08glh.ls error="server returned 404: 404 page not found\n"13242026/10/20 08:17:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13252026/10/20 08:17:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13262026/10/20 08:17:27 INFO Signed narinfos id=1 count=113272026/10/20 08:17:27 INFO Uploading 1 narinfos13282026/10/20 08:17:27 WARN readiness check failed error="closed pool"1329--- PASS: TestService_readinessHandler (6.87s)1330=== CONT TestPush_CompleteWaitsForCleanupOfThePush13312026/10/20 08:17:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13322026/10/20 08:17:28 WARN Failed to register uploaded object key=3dgz2jni02xinfzhwm7f0j6ckjf08glh.narinfo error="server returned 404: 404 page not found\n"13332026/10/20 08:17:28 INFO Completed push id=1 objects=3 duration=41.085458ms13342026/10/20 08:17:28 INFO Upload complete. (494ms)1335=== NAME TestNARDeduplicationMetadataUploadBug1336 metadata_upload_test.go:54: Retrieved narinfo from S3:1337 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestNARDeduplicationMetadataUploadBug3616243121/001/store/3dgz2jni02xinfzhwm7f0j6ckjf08glh-file1.txt1338 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1339 Compression: zstd1340 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1341 NarSize: 1601342 References: 1343 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1344 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1345 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1346 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13472026/10/20 08:17:28 INFO lead: released remote=192.0.2.1:123413482026/10/20 08:17:28 INFO lead: acquired remote=192.0.2.1:12341349 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/4/scratch/961630a4308c198f/build/TestNARDeduplicationMetadataUploadBug3616243121/001/store/n8k90ac8bvdz842gg6ddvyl8bmcmgzy0-file2.txt1350--- PASS: TestService_healthCheckHandler (6.70s)1351=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13522026/10/20 08:17:28 INFO Received push request method=POST path=/api/pushes13532026/10/20 08:17:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13542026/10/20 08:17:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13552026/10/20 08:17:29 INFO Signed narinfos id=2 count=113562026/10/20 08:17:29 WARN Failed to register uploaded object key=n8k90ac8bvdz842gg6ddvyl8bmcmgzy0.ls error="server returned 404: 404 page not found\n"13572026/10/20 08:17:29 INFO Uploading 1 narinfos1358--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.34s)1359=== CONT TestService_ReadAuthMiddleware13602026/10/20 08:17:29 INFO Received complete push request method=POST path=/api/pushes/2/complete13612026/10/20 08:17:29 WARN Failed to register uploaded object key=n8k90ac8bvdz842gg6ddvyl8bmcmgzy0.narinfo error="server returned 404: 404 page not found\n"13622026/10/20 08:17:29 INFO Completed push id=2 objects=3 duration=3.9375ms13632026/10/20 08:17:29 INFO lead: released remote=192.0.2.1:12341364--- PASS: TestLeadElectsOneAndHandsOver (9.44s)1365=== CONT TestRedundantMultipartUpload13662026/10/20 08:17:29 INFO Upload complete. (560ms)1367=== NAME TestNARDeduplicationMetadataUploadBug1368 metadata_upload_test.go:76: Retrieved narinfo from S3:1369 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestNARDeduplicationMetadataUploadBug3616243121/001/store/n8k90ac8bvdz842gg6ddvyl8bmcmgzy0-file2.txt1370 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1371 Compression: zstd1372 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1373 NarSize: 1601374 References: 1375 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1376 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1377 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1378 {"version":1,"root":{"type":"regular","size":44}}1379--- PASS: TestNARDeduplicationMetadataUploadBug (8.69s)1380=== CONT TestService_AuthMiddleware_OIDC13812026/10/20 08:17:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:52394/oidc1382=== NAME TestClientCADerivations1383 client_ca_test.go:136: Built CA derivation: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientCADerivations4181436826/001/store/4kimq2dc1pqsslqffhn6ypp9i71fqr5m-ca-test1384--- PASS: TestObjectStatsLargeCommit (13.42s)1385=== CONT TestPush_SignsNarinfosOfItsPendingObjects1386=== NAME TestClientCADerivations1387 client_ca_test.go:139: Found 1 dependencies (including self)1388=== RUN TestService_RequireScope_OIDC/builder_may_write1389=== PAUSE TestService_RequireScope_OIDC/builder_may_write1390=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1391=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1392=== RUN TestService_RequireScope_OIDC/ops_may_admin1393=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1394=== RUN TestService_RequireScope_OIDC/ops_may_not_write1395=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1396=== RUN TestService_RequireScope_OIDC/reader_may_not_write1397=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1398=== RUN TestService_RequireScope_OIDC/static_token_may_admin1399=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1400=== RUN TestService_RequireScope_OIDC/static_token_may_write1401=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1402=== RUN TestService_RequireScope_OIDC/reader_may_read1403=== PAUSE TestService_RequireScope_OIDC/reader_may_read1404=== RUN TestService_RequireScope_OIDC/writer_implies_read1405=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1406=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1407=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1408=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1409=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1410=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1411=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1412=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1413=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1414=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1415=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1416=== CONT TestPush_RejectsBadRequests14172026/10/20 08:17:31 INFO Aborted multipart uploads count=1 kept=014182026/10/20 08:17:31 INFO Received cleanup request method=DELETE path=/api/pending_closures14192026/10/20 08:17:31 INFO Aborted multipart uploads count=1 kept=01420--- PASS: TestPendingCleanupUsesOneCutoff (13.52s)1421=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14222026/10/20 08:17:31 INFO Received uploads request method=POST path=/api/pending_closures14232026/10/20 08:17:31 INFO Received uploads request method=POST path=/api/pending_closures14242026/10/20 08:17:31 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14252026/10/20 08:17:31 INFO Uploading pvdz0lfr9dr8s8k7j2hpgk58rm5xdail-b (256B)14262026/10/20 08:17:31 INFO Uploading ghcrgdxdqlixa2xlv0sp3pizry0zz8lf-shared-dep (136B)14272026/10/20 08:17:31 INFO Received push request method=POST path=/api/pushes14282026/10/20 08:17:31 WARN Failed to register uploaded object key=nar/1cbjrphmdcnaqzsm89m7rhiiwqp8rhxw8bdq3ai2yfnd7v4wwnk0.nar.zst error="server returned 404: 404 page not found\n"14292026/10/20 08:17:31 WARN Failed to register uploaded object key=8als1zdcc5g9yf52j3n5ghyrj1wmndnj.ls error="server returned 404: 404 page not found\n"14302026/10/20 08:17:31 WARN Failed to register uploaded object key=pvdz0lfr9dr8s8k7j2hpgk58rm5xdail.ls error="server returned 404: 404 page not found\n"14312026/10/20 08:17:31 WARN Failed to register uploaded object key=ghcrgdxdqlixa2xlv0sp3pizry0zz8lf.ls error="server returned 404: 404 page not found\n"14322026/10/20 08:17:31 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14332026/10/20 08:17:31 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14342026/10/20 08:17:32 INFO Signed narinfos id=2 count=214352026/10/20 08:17:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14362026/10/20 08:17:32 INFO Signed narinfos id=1 count=214372026/10/20 08:17:32 INFO Uploading 4 narinfos14382026/10/20 08:17:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/10/20 08:17:32 INFO Uploading 4kimq2dc1pqsslqffhn6ypp9i71fqr5m-ca-test (144B)14402026/10/20 08:17:32 WARN Failed to register uploaded object key=pvdz0lfr9dr8s8k7j2hpgk58rm5xdail.narinfo error="server returned 404: 404 page not found\n"14412026/10/20 08:17:32 WARN Failed to register uploaded object key=8als1zdcc5g9yf52j3n5ghyrj1wmndnj.narinfo error="server returned 404: 404 page not found\n"14422026/10/20 08:17:32 WARN Failed to register uploaded object key=4kimq2dc1pqsslqffhn6ypp9i71fqr5m.ls error="server returned 404: 404 page not found\n"14432026/10/20 08:17:32 WARN Failed to register uploaded object key=ghcrgdxdqlixa2xlv0sp3pizry0zz8lf.narinfo error="server returned 404: 404 page not found\n"14442026/10/20 08:17:32 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14452026/10/20 08:17:32 WARN Failed to register uploaded object key=log/4xsd53pd0xm3yf0vq1128ss6k9l5xs99-ca-test.drv error="server returned 404: 404 page not found\n"14462026/10/20 08:17:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14472026/10/20 08:17:32 INFO Signed narinfos id=1 count=114482026/10/20 08:17:32 INFO Uploading 1 narinfos14492026/10/20 08:17:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14502026/10/20 08:17:32 WARN Failed to register uploaded object key=ghcrgdxdqlixa2xlv0sp3pizry0zz8lf.narinfo error="server returned 404: 404 page not found\n"14512026/10/20 08:17:32 INFO Received complete push request method=POST path=/api/pushes/1/complete14522026/10/20 08:17:32 WARN Failed to register uploaded object key=4kimq2dc1pqsslqffhn6ypp9i71fqr5m.narinfo error="server returned 404: 404 page not found\n"14532026/10/20 08:17:32 INFO Completed upload id=1 objects=6 duration=55.84ms14542026/10/20 08:17:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14552026/10/20 08:17:32 INFO Completed upload id=2 objects=6 duration=1.325167ms14562026/10/20 08:17:32 INFO Upload complete. (995ms)1457=== NAME TestClientFallsBackToClosures1458 client_pushes_test.go:112: Retrieved narinfo from S3:1459 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientFallsBackToClosures2662330077/001/store/ghcrgdxdqlixa2xlv0sp3pizry0zz8lf-shared-dep1460 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1461 Compression: zstd1462 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821463 NarSize: 1361464 References: 14652026/10/20 08:17:32 INFO Completed push id=1 objects=4 duration=40.5925ms1466 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14672026/10/20 08:17:32 INFO Upload complete. (1.041s)1468 client_pushes_test.go:112: Retrieved narinfo from S3:1469 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientFallsBackToClosures2662330077/001/store/8als1zdcc5g9yf52j3n5ghyrj1wmndnj-a1470 URL: nar/1cbjrphmdcnaqzsm89m7rhiiwqp8rhxw8bdq3ai2yfnd7v4wwnk0.nar.zst1471 Compression: zstd1472 NarHash: sha256:1cbjrphmdcnaqzsm89m7rhiiwqp8rhxw8bdq3ai2yfnd7v4wwnk01473 NarSize: 2561474 References: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientFallsBackToClosures2662330077/001/store/ghcrgdxdqlixa2xlv0sp3pizry0zz8lf-shared-dep1475 CA: text:sha256:0zafjkaspap5snwnwzln6aiys22vdcihzddsjlxhyz30q6qvy49w1476=== NAME TestClientCADerivations1477 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientCADerivations4181436826/001/store/4kimq2dc1pqsslqffhn6ypp9i71fqr5m-ca-test1478 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1479 Compression: zstd1480 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1481 NarSize: 1441482 References: 1483 Deriver: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientCADerivations4181436826/001/store/4xsd53pd0xm3yf0vq1128ss6k9l5xs99-ca-test.drv1484 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1485 client_ca_test.go:185: Checking for realisation files in S3...1486 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1487 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1488=== NAME TestClientFallsBackToClosures1489 client_pushes_test.go:112: Retrieved narinfo from S3:1490 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientFallsBackToClosures2662330077/001/store/pvdz0lfr9dr8s8k7j2hpgk58rm5xdail-b1491 URL: nar/1cbjrphmdcnaqzsm89m7rhiiwqp8rhxw8bdq3ai2yfnd7v4wwnk0.nar.zst1492 Compression: zstd1493 NarHash: sha256:1cbjrphmdcnaqzsm89m7rhiiwqp8rhxw8bdq3ai2yfnd7v4wwnk01494 NarSize: 2561495 References: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientFallsBackToClosures2662330077/001/store/ghcrgdxdqlixa2xlv0sp3pizry0zz8lf-shared-dep1496 CA: text:sha256:0zafjkaspap5snwnwzln6aiys22vdcihzddsjlxhyz30q6qvy49w1497--- PASS: TestClientFallsBackToClosures (10.23s)1498=== CONT TestService_AuthMiddleware_MTLSProxyHeader1499=== NAME TestClientCADerivations1500 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket63?endpoint=http://localhost:52120®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/4/scratch/961630a4308c198f/build/TestClientCADerivations4181436826/001/store'1501 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11502--- PASS: TestClientCADerivations (10.52s)1503=== CONT TestPush_OverlappingRootsStoreOneRowPerKey15042026/10/20 08:17:32 INFO Received push request method=POST path=/api/pushes1505=== NAME TestPinProtectsFromGC1506 client_integration_test.go:731: Pinned store path: /private/var/tb/4/scratch/961630a4308c198f/build/TestPinProtectsFromGC4023950585/001/store/ldvg2icryrxfl1klx3raflgjrdm290na-pinned-file.txt1507 client_integration_test.go:732: Unpinned store path: /private/var/tb/4/scratch/961630a4308c198f/build/TestPinProtectsFromGC4023950585/001/store/gaa3nyxd13vm405iwfgpiz48nvrkn7bw-unpinned-file.txt15082026/10/20 08:17:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15092026/10/20 08:17:33 INFO Uploading mf4zm46gmm1494ml4c1rv18c6gdci6ks-shared-dep (136B)15102026/10/20 08:17:33 INFO Uploading cfkbc5gknzb81mcdcfy89m0ih71x19lk-b (256B)15112026/10/20 08:17:33 WARN Failed to register uploaded object key=nar/0ascqzmrhllb87h9yp2m70jvl7rbmy68037ghy9qpljpjk49zmg9.nar.zst error="server returned 404: 404 page not found\n"15122026/10/20 08:17:33 WARN Failed to register uploaded object key=lysarrz221j3d2r2xax4fhg8q4k81wmf.ls error="server returned 404: 404 page not found\n"15132026/10/20 08:17:33 WARN Failed to register uploaded object key=cfkbc5gknzb81mcdcfy89m0ih71x19lk.ls error="server returned 404: 404 page not found\n"15142026/10/20 08:17:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15152026/10/20 08:17:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15162026/10/20 08:17:33 WARN Failed to register uploaded object key=mf4zm46gmm1494ml4c1rv18c6gdci6ks.ls error="server returned 404: 404 page not found\n"15172026/10/20 08:17:33 INFO Signed narinfos id=1 count=315182026/10/20 08:17:33 INFO Uploading 3 narinfos15192026/10/20 08:17:33 WARN Failed to register uploaded object key=lysarrz221j3d2r2xax4fhg8q4k81wmf.narinfo error="server returned 404: 404 page not found\n"15202026/10/20 08:17:33 INFO Received push request method=POST path=/api/pushes15212026/10/20 08:17:33 WARN Failed to register uploaded object key=mf4zm46gmm1494ml4c1rv18c6gdci6ks.narinfo error="server returned 404: 404 page not found\n"15222026/10/20 08:17:33 INFO Received complete push request method=POST path=/api/pushes/1/complete15232026/10/20 08:17:33 WARN Failed to register uploaded object key=cfkbc5gknzb81mcdcfy89m0ih71x19lk.narinfo error="server returned 404: 404 page not found\n"15242026/10/20 08:17:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15252026/10/20 08:17:33 INFO Uploading ldvg2icryrxfl1klx3raflgjrdm290na-pinned-file.txt (128B)15262026/10/20 08:17:33 INFO Completed push id=1 objects=8 duration=37.139625ms15272026/10/20 08:17:33 INFO Upload complete. (517ms)1528=== NAME TestClientPushesUseOnePush1529 client_pushes_test.go:97: Retrieved narinfo from S3:1530 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientPushesUseOnePush2222507781/001/store/mf4zm46gmm1494ml4c1rv18c6gdci6ks-shared-dep1531 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1532 Compression: zstd1533 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821534 NarSize: 1361535 References: 1536 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1537 client_pushes_test.go:97: Retrieved narinfo from S3:1538 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientPushesUseOnePush2222507781/001/store/lysarrz221j3d2r2xax4fhg8q4k81wmf-a1539 URL: nar/0ascqzmrhllb87h9yp2m70jvl7rbmy68037ghy9qpljpjk49zmg9.nar.zst1540 Compression: zstd1541 NarHash: sha256:0ascqzmrhllb87h9yp2m70jvl7rbmy68037ghy9qpljpjk49zmg91542 NarSize: 2561543 References: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientPushesUseOnePush2222507781/001/store/mf4zm46gmm1494ml4c1rv18c6gdci6ks-shared-dep1544 CA: text:sha256:019ivprgynjdj8gkmxhh14i7xm2hd36vmbzr3dyxkha3z86q33z51545 client_pushes_test.go:97: Retrieved narinfo from S3:1546 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientPushesUseOnePush2222507781/001/store/cfkbc5gknzb81mcdcfy89m0ih71x19lk-b1547 URL: nar/0ascqzmrhllb87h9yp2m70jvl7rbmy68037ghy9qpljpjk49zmg9.nar.zst1548 Compression: zstd1549 NarHash: sha256:0ascqzmrhllb87h9yp2m70jvl7rbmy68037ghy9qpljpjk49zmg91550 NarSize: 2561551 References: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientPushesUseOnePush2222507781/001/store/mf4zm46gmm1494ml4c1rv18c6gdci6ks-shared-dep1552 CA: text:sha256:019ivprgynjdj8gkmxhh14i7xm2hd36vmbzr3dyxkha3z86q33z515532026/10/20 08:17:33 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15542026/10/20 08:17:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15552026/10/20 08:17:33 WARN Failed to register uploaded object key=ldvg2icryrxfl1klx3raflgjrdm290na.ls error="server returned 404: 404 page not found\n"15562026/10/20 08:17:33 INFO Signed narinfos id=1 count=115572026/10/20 08:17:33 INFO Uploading 1 narinfos15582026/10/20 08:17:33 INFO Received complete push request method=POST path=/api/pushes/1/complete15592026/10/20 08:17:33 WARN Failed to register uploaded object key=ldvg2icryrxfl1klx3raflgjrdm290na.narinfo error="server returned 404: 404 page not found\n"1560--- PASS: TestClientPushesUseOnePush (10.57s)1561=== CONT TestPush_CompleteCommitsEveryRoot15622026/10/20 08:17:33 INFO Completed push id=1 objects=3 duration=31.459334ms15632026/10/20 08:17:33 INFO Upload complete. (432ms)15642026/10/20 08:17:33 INFO Received push request method=POST path=/api/pushes15652026/10/20 08:17:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15662026/10/20 08:17:33 INFO Uploading gaa3nyxd13vm405iwfgpiz48nvrkn7bw-unpinned-file.txt (128B)15672026/10/20 08:17:33 WARN Failed to register uploaded object key=gaa3nyxd13vm405iwfgpiz48nvrkn7bw.ls error="server returned 404: 404 page not found\n"15682026/10/20 08:17:33 INFO Received push request method=POST path=/api/pushes15692026/10/20 08:17:33 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15702026/10/20 08:17:33 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15712026/10/20 08:17:33 INFO Signed narinfos id=2 count=115722026/10/20 08:17:33 INFO Uploading 1 narinfos15732026/10/20 08:17:33 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15742026/10/20 08:17:33 INFO Uploading sf0vxv1n6jyzdfwdq4jdr5wxmnxha88k-shared-dep (136B)15752026/10/20 08:17:33 INFO Uploading gxdlqcwbn8mhbn3x76rq5j9ydyaayy7i-top (264B)15762026/10/20 08:17:33 INFO Received complete push request method=POST path=/api/pushes/2/complete15772026/10/20 08:17:33 WARN Failed to register uploaded object key=gaa3nyxd13vm405iwfgpiz48nvrkn7bw.narinfo error="server returned 404: 404 page not found\n"15782026/10/20 08:17:33 INFO Completed push id=2 objects=3 duration=1.169334ms15792026/10/20 08:17:33 INFO Upload complete. (329ms)15802026/10/20 08:17:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15812026/10/20 08:17:33 WARN Failed to register uploaded object key=sf0vxv1n6jyzdfwdq4jdr5wxmnxha88k.ls error="server returned 404: 404 page not found\n"15822026/10/20 08:17:34 WARN Failed to register uploaded object key=nar/1ryd0mwi6gk81753qkqk9ynq9cn8aj0vc1a5q94pmhfp7v3qlqmh.nar.zst error="server returned 404: 404 page not found\n"15832026/10/20 08:17:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15842026/10/20 08:17:34 WARN Failed to register uploaded object key=gxdlqcwbn8mhbn3x76rq5j9ydyaayy7i.ls error="server returned 404: 404 page not found\n"15852026/10/20 08:17:34 INFO Signed narinfos id=1 count=215862026/10/20 08:17:34 INFO Uploading 2 narinfos15872026/10/20 08:17:34 INFO Starting cleanup of old closures method=DELETE path=/api/closures15882026/10/20 08:17:34 INFO Garbage collection started15892026/10/20 08:17:34 INFO Aborted multipart uploads count=0 kept=015902026/10/20 08:17:34 WARN Failed to register uploaded object key=gxdlqcwbn8mhbn3x76rq5j9ydyaayy7i.narinfo error="server returned 404: 404 page not found\n"15912026/10/20 08:17:34 WARN Force mode enabled - objects will be deleted immediately without grace period15922026/10/20 08:17:34 INFO Received complete push request method=POST path=/api/pushes/1/complete15932026/10/20 08:17:34 WARN Failed to register uploaded object key=sf0vxv1n6jyzdfwdq4jdr5wxmnxha88k.narinfo error="server returned 404: 404 page not found\n"1594=== NAME TestClientWithDependencies1595 client_integration_test.go:613: Built derivation: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientWithDependencies2591251088/001/store/yd2kn43bhq11c1mzm2hi52jrswvmf3iq-test-script15962026/10/20 08:17:34 INFO Completed push id=1 objects=6 duration=61.145458ms15972026/10/20 08:17:34 INFO Upload complete. (765ms)1598=== NAME TestClientSharedPathCommittedMidPush1599 client_integration_test.go:680: Retrieved narinfo from S3:1600 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientSharedPathCommittedMidPush2846191710/001/store/sf0vxv1n6jyzdfwdq4jdr5wxmnxha88k-shared-dep1601 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1602 Compression: zstd1603 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821604 NarSize: 1361605 References: 1606 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1607 client_integration_test.go:680: Retrieved narinfo from S3:1608 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientSharedPathCommittedMidPush2846191710/001/store/gxdlqcwbn8mhbn3x76rq5j9ydyaayy7i-top1609 URL: nar/1ryd0mwi6gk81753qkqk9ynq9cn8aj0vc1a5q94pmhfp7v3qlqmh.nar.zst1610 Compression: zstd1611 NarHash: sha256:1ryd0mwi6gk81753qkqk9ynq9cn8aj0vc1a5q94pmhfp7v3qlqmh1612 NarSize: 2641613 References: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientSharedPathCommittedMidPush2846191710/001/store/sf0vxv1n6jyzdfwdq4jdr5wxmnxha88k-shared-dep1614 CA: text:sha256:1jwpz3i291is42yzqvpkh6dmi2q8dxnmh6zdavqp2nydmv34aq4j1615=== NAME TestClientMultipleUploads1616 client_integration_test.go:358: Created store path 0: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientMultipleUploads3126281788/001/store/7ldpjznc6ibzlmrhjndhmlldc9x0sl5h-test-file-0.txt1617--- PASS: TestClientSharedPathCommittedMidPush (10.74s)1618=== CONT TestReadRedirectUsesPublicS3URL1619=== NAME TestClientWithDependencies1620 client_integration_test.go:615: Found 1 dependencies (including self)1621=== NAME TestClientMultipleUploads1622 client_integration_test.go:358: Created store path 1: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientMultipleUploads3126281788/001/store/6jjw8k07k0fyp3g6k3wjv1vkciy602f7-test-file-1.txt16232026/10/20 08:17:35 INFO Received push request method=POST path=/api/pushes16242026/10/20 08:17:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16252026/10/20 08:17:35 INFO Uploading yd2kn43bhq11c1mzm2hi52jrswvmf3iq-test-script (136B)16262026/10/20 08:17:35 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=01627 client_integration_test.go:358: Created store path 2: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientMultipleUploads3126281788/001/store/icm1hy9fkr8y9dinc6lsa5b3yajhfph0-test-file-2.txt16282026/10/20 08:17:35 INFO Vacuumed table table=pending_closures16292026/10/20 08:17:35 WARN Failed to register uploaded object key=log/rwcvjvl2xrmliahbvw82ha62saw8ma9c-test-script.drv error="server returned 404: 404 page not found\n"16302026/10/20 08:17:35 WARN Failed to register uploaded object key=yd2kn43bhq11c1mzm2hi52jrswvmf3iq.ls error="server returned 404: 404 page not found\n"16312026/10/20 08:17:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16322026/10/20 08:17:35 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16332026/10/20 08:17:35 INFO Signed narinfos id=1 count=116342026/10/20 08:17:35 INFO Uploading 1 narinfos16352026/10/20 08:17:35 INFO Vacuumed table table=pending_objects16362026/10/20 08:17:35 INFO Vacuumed table table=multipart_uploads1637=== NAME TestClientIntegration1638 client_integration_test.go:286: Created store path: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientIntegration417791557/002/store/bvxdx55ijdxaj6jw5yjbs9dmb1hnrpcx-test-file.txt16392026/10/20 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete16402026/10/20 08:17:35 WARN Failed to register uploaded object key=yd2kn43bhq11c1mzm2hi52jrswvmf3iq.narinfo error="server returned 404: 404 page not found\n"16412026/10/20 08:17:35 INFO Vacuumed table table=closures16422026/10/20 08:17:35 INFO Completed push id=1 objects=4 duration=51.935834ms16432026/10/20 08:17:35 INFO Upload complete. (584ms)1644=== NAME TestClientWithDependencies1645 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/4/scratch/961630a4308c198f/build/TestClientWithDependencies2591251088/001/store) requires matching store prefix16462026/10/20 08:17:35 INFO Received push request method=POST path=/api/pushes16472026/10/20 08:17:35 INFO Vacuumed table table=objects16482026/10/20 08:17:35 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16492026/10/20 08:17:35 INFO Uploading 7ldpjznc6ibzlmrhjndhmlldc9x0sl5h-test-file-0.txt (160B)16502026/10/20 08:17:35 INFO Uploading 6jjw8k07k0fyp3g6k3wjv1vkciy602f7-test-file-1.txt (160B)16512026/10/20 08:17:35 INFO Uploading icm1hy9fkr8y9dinc6lsa5b3yajhfph0-test-file-2.txt (160B)1652--- PASS: TestCacheStatsHandler (10.29s)1653=== CONT TestProxyWriteTimeout/narinfo1654=== CONT TestProxyWriteTimeout/unknown_size1655=== CONT TestProxyWriteTimeout/1_GiB_nar1656=== CONT TestProxyWriteTimeout/10_GiB_nar1657--- PASS: TestProxyWriteTimeout (0.00s)1658 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1659 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1660 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1661 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1662=== CONT TestGCEndsOnShutdown/before_the_run16632026/10/20 08:17:35 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16642026/10/20 08:17:35 WARN Failed to register uploaded object key=7ldpjznc6ibzlmrhjndhmlldc9x0sl5h.ls error="server returned 404: 404 page not found\n"16652026/10/20 08:17:35 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16662026/10/20 08:17:35 WARN Failed to register uploaded object key=6jjw8k07k0fyp3g6k3wjv1vkciy602f7.ls error="server returned 404: 404 page not found\n"16672026/10/20 08:17:35 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16682026/10/20 08:17:35 WARN Failed to register uploaded object key=icm1hy9fkr8y9dinc6lsa5b3yajhfph0.ls error="server returned 404: 404 page not found\n"16692026/10/20 08:17:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1670--- PASS: TestClientWithDependencies (11.50s)16712026/10/20 08:17:35 INFO Received push request method=POST path=/api/pushes1672=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark16732026/10/20 08:17:35 INFO Signed narinfos id=1 count=316742026/10/20 08:17:35 INFO Uploading 3 narinfos16752026/10/20 08:17:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16762026/10/20 08:17:35 INFO Uploading bvxdx55ijdxaj6jw5yjbs9dmb1hnrpcx-test-file.txt (152B)16772026/10/20 08:17:35 WARN Failed to register uploaded object key=icm1hy9fkr8y9dinc6lsa5b3yajhfph0.narinfo error="server returned 404: 404 page not found\n"16782026/10/20 08:17:35 WARN Failed to register uploaded object key=7ldpjznc6ibzlmrhjndhmlldc9x0sl5h.narinfo error="server returned 404: 404 page not found\n"16792026/10/20 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete16802026/10/20 08:17:35 WARN Failed to register uploaded object key=6jjw8k07k0fyp3g6k3wjv1vkciy602f7.narinfo error="server returned 404: 404 page not found\n"16812026/10/20 08:17:35 WARN Failed to register uploaded object key=bvxdx55ijdxaj6jw5yjbs9dmb1hnrpcx.ls error="server returned 404: 404 page not found\n"16822026/10/20 08:17:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16832026/10/20 08:17:35 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16842026/10/20 08:17:35 INFO Signed narinfos id=1 count=116852026/10/20 08:17:35 INFO Uploading 1 narinfos16862026/10/20 08:17:35 INFO Completed push id=1 objects=9 duration=69.906542ms16872026/10/20 08:17:35 INFO Upload complete. (587ms)1688=== NAME TestClientMultipleUploads1689 client_integration_test.go:369: Uploaded 3 paths in 667.724167ms16902026/10/20 08:17:35 INFO Received complete push request method=POST path=/api/pushes/1/complete16912026/10/20 08:17:35 WARN Failed to register uploaded object key=bvxdx55ijdxaj6jw5yjbs9dmb1hnrpcx.narinfo error="server returned 404: 404 page not found\n"16922026/10/20 08:17:36 INFO Completed push id=1 objects=3 duration=50.420917ms16932026/10/20 08:17:36 INFO Upload complete. (600ms)1694--- PASS: TestService_ReadScope_PublicByDefault (10.47s)1695=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16962026/10/20 08:17:36 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016972026/10/20 08:17:36 INFO All 1 paths already cached1698=== NAME TestClientIntegration1699 client_integration_test.go:312: Retrieved narinfo from S3:1700 StorePath: /private/var/tb/4/scratch/961630a4308c198f/build/TestClientIntegration417791557/002/store/bvxdx55ijdxaj6jw5yjbs9dmb1hnrpcx-test-file.txt1701 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1702 Compression: zstd1703 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11704 NarSize: 1521705 References: 1706 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11707 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1708 client_integration_test.go:313: Decompressed .ls content (64 bytes):1709 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1710 client_integration_test.go:316: Testing garbage collection...17112026/10/20 08:17:36 INFO Received create pin request method=POST path=/api/pins/myapp1712--- PASS: TestClientMultipleUploads (11.68s)1713=== CONT TestPendingClosureWriteTimeout/empty1714=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17152026/10/20 08:17:36 INFO Received uploads request method=POST path=/1716=== CONT TestIsValidUploadKey/narinfo1717=== CONT TestIsValidUploadKey/index.html1718=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17192026/10/20 08:17:36 INFO Received request for more parts method=POST path=/1720=== CONT TestIsValidUploadKey/absolute1721=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17222026/10/20 08:17:36 INFO Received uploads request method=POST path=/1723=== CONT TestIsValidUploadKey/unknown_type1724=== CONT TestIsValidUploadKey/empty_key1725=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17262026/10/20 08:17:36 INFO Received complete multipart upload request method=POST path=/1727--- PASS: TestUploadHandlersRejectInvalidKeys (0.04s)1728 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1729 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1730 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1731 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1732=== CONT TestIsValidUploadKey/traversal_nar1733=== CONT TestIsValidUploadKey/traversal1734=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1735=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1736=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1737=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17382026/10/20 08:17:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures17392026/10/20 08:17:36 INFO Garbage collection started17402026/10/20 08:17:36 INFO Created/updated pin name=myapp store_path=/private/var/tb/4/scratch/961630a4308c198f/build/TestPinProtectsFromGC4023950585/001/store/ldvg2icryrxfl1klx3raflgjrdm290na-pinned-file.txt narinfo_key=ldvg2icryrxfl1klx3raflgjrdm290na.narinfo17412026/10/20 08:17:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures17422026/10/20 08:17:36 INFO Garbage collection started17432026/10/20 08:17:36 INFO Aborted multipart uploads count=0 kept=017442026/10/20 08:17:36 INFO Aborted multipart uploads count=0 kept=017452026/10/20 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period17462026/10/20 08:17:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017472026/10/20 08:17:36 WARN Force mode enabled - objects will be deleted immediately without grace period17482026/10/20 08:17:36 INFO Vacuumed table table=pending_closures17492026/10/20 08:17:36 INFO Vacuumed table table=pending_objects17502026/10/20 08:17:36 INFO Vacuumed table table=multipart_uploads17512026/10/20 08:17:36 INFO Vacuumed table table=closures17522026/10/20 08:17:36 INFO Vacuumed table table=objects17532026/10/20 08:17:36 INFO Received push request method=POST path=/api/pushes17542026/10/20 08:17:36 INFO Received complete push request method=POST path=/api/pushes/1/complete17552026/10/20 08:17:36 INFO Completed push id=1 objects=4 duration=103.12475ms17562026/10/20 08:17:36 INFO Received push request method=POST path=/api/pushes17572026/10/20 08:17:37 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=017582026/10/20 08:17:37 INFO Aborted multipart uploads count=0 kept=017592026/10/20 08:17:37 WARN Force mode enabled - objects will be deleted immediately without grace period17602026/10/20 08:17:37 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=017612026/10/20 08:17:37 INFO Vacuumed table table=pending_closures17622026/10/20 08:17:37 INFO Vacuumed table table=pending_closures17632026/10/20 08:17:37 INFO Vacuumed table table=pending_objects17642026/10/20 08:17:37 INFO Vacuumed table table=pending_objects17652026/10/20 08:17:37 INFO Vacuumed table table=multipart_uploads17662026/10/20 08:17:37 INFO Vacuumed table table=multipart_uploads17672026/10/20 08:17:37 INFO Received push request method=POST path=/api/pushes17682026/10/20 08:17:37 INFO Vacuumed table table=closures17692026/10/20 08:17:37 INFO Vacuumed table table=closures17702026/10/20 08:17:37 INFO Vacuumed table table=objects17712026/10/20 08:17:37 INFO Vacuumed table table=objects17722026/10/20 08:17:37 INFO Received complete push request method=POST path=/api/pushes/2/complete17732026/10/20 08:17:37 INFO Completed push id=2 objects=4 duration=11.375334ms1774--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (11.60s)1775=== CONT TestPendingClosureWriteTimeout/400_objects1776=== CONT TestIsValidUploadKey/build_log_plus_in_name1777=== CONT TestIsValidUploadKey/nix-cache-info1778=== CONT TestIsValidUploadKey/realisation_plus_in_output1779=== CONT TestIsValidUploadKey/realisation1780=== CONT TestIsValidUploadKey/build_log_equals1781=== CONT TestIsValidUploadKey/build_log_question_mark1782=== CONT TestIsValidUploadKey/listing1783=== CONT TestIsValidUploadKey/build_log_home-manager_file1784=== CONT TestIsValidUploadKey/build_log1785=== CONT TestIsValidUploadKey/nar_xz1786=== CONT TestIsValidUploadKey/nar_plain1787=== CONT TestIsValidUploadKey/nar_zst1788--- PASS: TestIsValidUploadKey (0.04s)1789 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1790 --- PASS: TestIsValidUploadKey/index.html (0.00s)1791 --- PASS: TestIsValidUploadKey/absolute (0.00s)1792 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1793 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1794 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1795 --- PASS: TestIsValidUploadKey/traversal (0.00s)1796 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1797 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1798 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1799 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1800 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1801 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1802 --- PASS: TestIsValidUploadKey/realisation (0.00s)1803 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1804 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1805 --- PASS: TestIsValidUploadKey/listing (0.00s)1806 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1807 --- PASS: TestIsValidUploadKey/build_log (0.00s)1808 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1809 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1810 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1811=== CONT TestPendingClosureWriteTimeout/670k_objects1812=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18132026/10/20 08:17:37 INFO Received uploads request method=POST path=/18142026/10/20 08:17:37 INFO Received complete push request method=POST path=/api/pushes/1/complete18152026/10/20 08:17:37 INFO Completed push id=1 objects=4 duration=87.295542ms1816--- PASS: TestPush_RepeatedRootCommitsOnce (11.74s)1817=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18182026/10/20 08:17:37 INFO Received request for more parts method=POST path=/1819=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18202026/10/20 08:17:37 INFO Received complete multipart upload request method=POST path=/1821=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1822=== NAME TestPresignedUploadRegisteredBeforeCommit1823 reupload_uncommitted_test.go:86: unexpected error: Put "http://localhost:52120/bucket76/": context deadline exceeded1824 1825--- FAIL: TestPresignedUploadRegisteredBeforeCommit (11.55s)1826=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1827=== NAME TestPush_RootsAreLockedInByteOrder1828 pushes_test.go:198: unexpected error: Put "http://localhost:52120/bucket77/": context deadline exceeded1829 1830--- FAIL: TestPush_RootsAreLockedInByteOrder (11.52s)1831=== CONT TestIsValidCachePath/narinfo1832=== CONT TestIsValidCachePath/index.html1833=== CONT TestIsValidCachePath/short_hash1834=== CONT TestIsValidCachePath/wrong_extension1835=== CONT TestIsValidCachePath/leading_slash1836=== CONT TestIsValidCachePath/empty1837=== CONT TestIsValidCachePath/random_path1838=== CONT TestIsValidCachePath/invalid_char_u1839=== CONT TestIsValidCachePath/invalid_char_e1840=== CONT TestIsValidCachePath/traversal_in_middle1841=== CONT TestIsValidCachePath/traversal_parent1842=== CONT TestIsValidCachePath/nar_uncompressed1843=== CONT TestIsValidCachePath/nix-cache-info1844=== CONT TestIsValidCachePath/realisation1845=== CONT TestIsValidCachePath/log1846=== CONT TestIsValidCachePath/ls1847=== CONT TestIsValidCachePath/nar_xz1848=== CONT TestIsValidCachePath/nar_bz21849=== CONT TestIsValidCachePath/nar_zst1850=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1851--- PASS: TestIsValidCachePath (0.00s)1852 --- PASS: TestIsValidCachePath/narinfo (0.00s)1853 --- PASS: TestIsValidCachePath/index.html (0.00s)1854 --- PASS: TestIsValidCachePath/short_hash (0.00s)1855 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1856 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1857 --- PASS: TestIsValidCachePath/empty (0.00s)1858 --- PASS: TestIsValidCachePath/random_path (0.00s)1859 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1860 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1861 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1862 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1863 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1864 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1865 --- PASS: TestIsValidCachePath/realisation (0.00s)1866 --- PASS: TestIsValidCachePath/log (0.00s)1867 --- PASS: TestIsValidCachePath/ls (0.00s)1868 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1869 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1870 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1871 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1872=== CONT TestParseSingleRange/none1873=== CONT TestParseSingleRange/open-ended1874=== CONT TestParseSingleRange/start_far_past_EOF1875=== CONT TestParseSingleRange/start_past_EOF1876=== CONT TestParseSingleRange/single_byte1877=== CONT TestParseSingleRange/suffix_exceeds_size1878=== CONT TestParseSingleRange/suffix1879=== CONT TestParseSingleRange/end_clamped_to_size1880=== CONT TestParseSingleRange/malformed_both_empty1881=== CONT TestParseSingleRange/closed1882=== CONT TestParseSingleRange/malformed_end_before_start1883=== CONT TestParseSingleRange/multi-range_ignored1884=== CONT TestParseSingleRange/malformed_no_dash1885=== CONT TestParseSingleRange/unknown_unit1886--- PASS: TestParseSingleRange (0.02s)1887 --- PASS: TestParseSingleRange/none (0.00s)1888 --- PASS: TestParseSingleRange/open-ended (0.00s)1889 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1890 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1891 --- PASS: TestParseSingleRange/single_byte (0.00s)1892 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1893 --- PASS: TestParseSingleRange/suffix (0.00s)1894 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1895 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1896 --- PASS: TestParseSingleRange/closed (0.00s)1897 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1898 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1899 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1900 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1901=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1902=== NAME TestCompletedNarNotReofferedAcrossClosures1903 reupload_uncommitted_test.go:23: unexpected error: Put "http://localhost:52120/bucket78/": context deadline exceeded1904 1905--- FAIL: TestCompletedNarNotReofferedAcrossClosures (11.28s)1906=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19072026/10/20 08:17:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01908=== NAME TestClientIntegration1909 client_integration_test.go:323: Objects in database after GC:1910 client_integration_test.go:323: Successfully deleted all objects with GC --force1911=== NAME TestPinProtectsFromGC1912 client_integration_test.go:840: Pin successfully protected closure from garbage collection1913--- PASS: TestClientIntegration (13.74s)1914=== CONT TestServerTLSConfig/no_client_CA1915=== CONT TestServerTLSConfig/not_a_PEM_file1916=== CONT TestServerTLSConfig/missing_CA_file1917--- PASS: TestServerTLSConfig (0.01s)1918 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1919 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1920 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1921=== CONT TestResolveDBConnectionString/flag_wins1922=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1923=== CONT TestResolveDBConnectionString/nothing_configured1924=== CONT TestResolveDBConnectionString/missing_file_is_an_error1925=== CONT TestResolveDBConnectionString/file_when_flag_empty1926--- PASS: TestResolveDBConnectionString (0.02s)1927 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1928 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1929 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1930 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1931 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1932=== CONT TestCacheConfigHandler/full_config,_no_issuer1933=== CONT TestCacheConfigHandler/no_signing_keys1934=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1935=== CONT TestCacheConfigHandler/no_cache_url_configured1936--- PASS: TestCacheConfigHandler (0.00s)1937 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1938 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1939 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1940 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1941=== CONT TestClientErrorHandling/InvalidStorePath1942--- PASS: TestPinProtectsFromGC (14.94s)1943=== CONT TestClientErrorHandling/ServerNotAvailable1944--- PASS: TestUploadHandlersRejectOversizedBody (0.11s)1945 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1946 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1947 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.16s)1948=== CONT TestClientErrorHandling/InvalidAuthToken1949=== NAME TestPush_CompleteWaitsForCleanupOfThePush1950 pushes_test.go:155: unexpected error: Put "http://localhost:52120/bucket79/": context deadline exceeded1951 1952--- FAIL: TestPush_CompleteWaitsForCleanupOfThePush (10.72s)1953=== CONT TestService_RequireScope_OIDC/builder_may_write1954=== CONT TestService_RequireScope_OIDC/reader_may_read1955=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1956=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19572026/10/20 08:17:38 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]1958=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1959=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1960=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1961=== CONT TestService_RequireScope_OIDC/writer_implies_read1962=== CONT TestService_RequireScope_OIDC/reader_may_not_write1963=== CONT TestService_RequireScope_OIDC/static_token_may_write1964=== CONT TestService_RequireScope_OIDC/static_token_may_admin1965=== CONT TestService_RequireScope_OIDC/ops_may_admin1966=== CONT TestService_RequireScope_OIDC/ops_may_not_write1967=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1968--- PASS: TestService_RequireScope_OIDC (8.41s)1969 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1970 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1971 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1972 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1973 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1974 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1975 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1976 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1977 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1978 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1979 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1980 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1981 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1982 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19832026/10/20 08:17:39 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/present19842026/10/20 08:17:39 WARN Request failed, retrying attempt=2 backoff=188.700914ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19852026/10/20 08:17:39 INFO Received uploads request method=POST path=/api/pending_closures19862026/10/20 08:17:39 WARN Request failed, retrying attempt=3 backoff=386.078447ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19872026/10/20 08:17:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19882026/10/20 08:17:39 WARN Request failed, retrying attempt=4 backoff=742.432594ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19892026/10/20 08:17:39 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LmM4NGFlNDMzLTFlYWUtNDQwMi1iMGY3LTM0ZDZlMDBmZjBhOXgxNzkyNDg0MjU5MzI2NDI1MDAw1990--- PASS: TestService_ReadAuthMiddleware (10.57s)19912026/10/20 08:17:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LmM4NGFlNDMzLTFlYWUtNDQwMi1iMGY3LTM0ZDZlMDBmZjBhOXgxNzkyNDg0MjU5MzI2NDI1MDAw parts=11992--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (11.13s)19932026/10/20 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures19942026-10-20 08:17:40.306 UTC [48441] LOG: checkpoint starting: wal19952026/10/20 08:17:40 INFO Received uploads request method=POST path=/api/pending_closures1996=== NAME TestService_AuthMiddleware_OIDC1997 auth_test.go:269: unexpected error: Put "http://localhost:52120/bucket83/": context deadline exceeded1998 1999--- FAIL: TestService_AuthMiddleware_OIDC (11.12s)20002026/10/20 08:17:40 WARN Request failed, retrying attempt=5 backoff=1.561038201s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2001=== RUN TestPush_RejectsBadRequests/no_roots2002=== PAUSE TestPush_RejectsBadRequests/no_roots2003=== RUN TestPush_RejectsBadRequests/no_objects2004=== PAUSE TestPush_RejectsBadRequests/no_objects2005=== RUN TestPush_RejectsBadRequests/bad_root2006=== PAUSE TestPush_RejectsBadRequests/bad_root2007=== RUN TestPush_RejectsBadRequests/root_not_in_objects2008=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2009=== CONT TestPush_RejectsBadRequests/no_roots2010=== CONT TestPush_RejectsBadRequests/bad_root20112026/10/20 08:17:40 INFO Received push request method=POST path=/api/pushes2012=== CONT TestPush_RejectsBadRequests/no_objects20132026/10/20 08:17:40 INFO Received push request method=POST path=/api/pushes20142026/10/20 08:17:40 INFO Received push request method=POST path=/api/pushes2015=== CONT TestPush_RejectsBadRequests/root_not_in_objects20162026/10/20 08:17:40 INFO Received push request method=POST path=/api/pushes2017--- PASS: TestPush_RejectsBadRequests (9.98s)2018 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2019 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2020 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2021 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)20222026/10/20 08:17:41 INFO Received push request method=POST path=/api/pushes20232026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20242026/10/20 08:17:41 INFO Signed narinfos id=1 count=120252026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20262026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20272026/10/20 08:17:41 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"20282026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20292026/10/20 08:17:41 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"20302026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20312026/10/20 08:17:41 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=120322026/10/20 08:17:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20332026/10/20 08:17:41 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo2034--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (10.78s)20352026/10/20 08:17:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20362026/10/20 08:17:41 WARN mTLS auth: bound subjects configured but subject DN unavailable20372026/10/20 08:17:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2038--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (10.64s)2039=== NAME TestOrphanedObjectsGCStressTest2040 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2041 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20422026/10/20 08:17:42 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-config20432026/10/20 08:17:42 WARN Request failed, retrying attempt=2 backoff=202.336615ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2044--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (9.75s)20452026/10/20 08:17:42 WARN Request failed, retrying attempt=3 backoff=426.556625ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20462026/10/20 08:17:42 INFO Received push request method=POST path=/api/pushes20472026/10/20 08:17:42 WARN Request failed, retrying attempt=4 backoff=768.507119ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2048--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (10.20s)20492026/10/20 08:17:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20502026/10/20 08:17:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LjdkNjJlOGRhLTJiMTgtNDMyZC04M2Y2LTFhMmYyNzBhNDViM3gxNzkyNDg0MjYwMjQ3MTgwMDAw parts=1220512026/10/20 08:17:43 INFO Received uploads request method=POST path=/api/pending_closures20522026/10/20 08:17:43 INFO Received uploads request method=POST path=/api/pending_closures20532026/10/20 08:17:43 INFO Received push request method=POST path=/api/pushes20542026/10/20 08:17:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20552026/10/20 08:17:43 INFO Completed push id=1 objects=6 duration=39.373041ms2056--- PASS: TestPush_CompleteCommitsEveryRoot (10.07s)20572026/10/20 08:17:43 WARN Request failed, retrying attempt=5 backoff=1.650574375s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2058--- PASS: TestReadRedirectUsesPublicS3URL (9.42s)20592026/10/20 08:17:44 INFO Aborted multipart uploads count=0 kept=020602026/10/20 08:17:44 WARN Force mode enabled - objects will be deleted immediately without grace period20612026-10-20 08:17:44.829 UTC [67456] ERROR: canceling statement due to user request20622026-10-20 08:17:44.829 UTC [67456] STATEMENT: -- name: MarkStaleObjects :execrows2063 WITH RECURSIVE ct AS (2064 SELECT timezone('UTC', now()) AS now2065 ),2066 closure_reach AS (2067 -- Start with all closure keys2068 SELECT o.key, o.refs2069 FROM objects o2070 INNER JOIN closures c ON o.key = c.key2071 UNION2072 -- Recursively add all referenced objects2073 SELECT o.key, o.refs2074 FROM objects o2075 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2076 ),2077 reachable_objects AS (2078 SELECT DISTINCT key FROM closure_reach2079 ),2080 stale_objects AS (2081 SELECT o.key2082 FROM objects AS o, ct2083 WHERE2084 NOT EXISTS (2085 SELECT 12086 FROM reachable_objects ro2087 WHERE ro.key = o.key2088 )2089 AND NOT EXISTS (2090 SELECT 12091 FROM pending_objects AS po2092 WHERE po.key = o.key2093 )2094 AND o.deleted_at IS NULL -- Only mark fresh objects2095 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2096 FOR UPDATE2097 )2098 UPDATE objects2099 SET2100 deleted_at = ct.now,2101 first_deleted_at = COALESCE(first_deleted_at, ct.now)2102 FROM stale_objects, ct2103 WHERE objects.key = stale_objects.key2104 21052026/10/20 08:17:45 INFO Aborted multipart uploads count=0 kept=021062026/10/20 08:17:45 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/10/20 08:17:45 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:52120/bucket93/?delete=\": context canceled"2108--- PASS: TestGCEndsOnShutdown (0.00s)2109 --- PASS: TestGCEndsOnShutdown/before_the_run (8.81s)2110 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (9.14s)2111 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (9.21s)21122026/10/20 08:17:45 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"21132026/10/20 08:17:45 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-config21142026/10/20 08:17:45 WARN Request failed, retrying attempt=2 backoff=213.045245ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21152026/10/20 08:17:45 INFO Received uploads request method=POST path=/api/pending_closures21162026/10/20 08:17:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21172026/10/20 08:17:45 WARN Request failed, retrying attempt=3 backoff=413.875109ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21182026/10/20 08:17:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LjE2OGM0OGM2LWE3NjMtNDliOC1iNzBiLTYxYzA0YjdmOWM1ZHgxNzkyNDg0MjYzMjQzNDczMDAw error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21192026/10/20 08:17:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTFlMzMyOTEtOTI5NS00NWIwLTk2NWUtYzA5NmUzZDY0YTQ0LmYwOWJiNDM5LTc2NTMtNDM2My1hZTJiLTRkMDdiZGIxZjFkMngxNzkyNDg0MjYzMTg5MTc5MDAw parts=1221202026/10/20 08:17:45 INFO Received cleanup request method=DELETE path=/api/pending_closures21212026/10/20 08:17:45 INFO Aborted multipart uploads count=1 kept=02122--- PASS: TestRedundantMultipartUpload (16.46s)21232026/10/20 08:17:45 INFO Received uploads request method=POST path=/api/pending_closures21242026/10/20 08:17:45 INFO Aborted multipart uploads count=0 kept=021252026/10/20 08:17:45 WARN Force mode enabled - objects will be deleted immediately without grace period21262026/10/20 08:17:46 WARN Request failed, retrying attempt=4 backoff=788.303232ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21272026/10/20 08:17:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=021282026/10/20 08:17:46 INFO Vacuumed table table=pending_closures21292026/10/20 08:17:46 INFO Vacuumed table table=pending_objects21302026/10/20 08:17:46 INFO Vacuumed table table=multipart_uploads21312026/10/20 08:17:46 INFO Vacuumed table table=closures21322026/10/20 08:17:46 INFO Vacuumed table table=objects2133--- PASS: TestPendingClosureWriteTimeout (0.04s)2134 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2135 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2136 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2137 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (10.21s)21382026/10/20 08:17:46 INFO Received uploads request method=POST path=/api/pending_closures21392026/10/20 08:17:46 INFO Aborted multipart uploads count=0 kept=021402026/10/20 08:17:46 WARN Force mode enabled - objects will be deleted immediately without grace period21412026/10/20 08:17:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021422026/10/20 08:17:46 INFO Vacuumed table table=pending_closures21432026/10/20 08:17:46 INFO Vacuumed table table=pending_objects21442026/10/20 08:17:46 INFO Vacuumed table table=multipart_uploads21452026/10/20 08:17:46 INFO Vacuumed table table=closures21462026/10/20 08:17:46 INFO Vacuumed table table=objects2147--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2148 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (8.79s)2149 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (9.00s)21502026/10/20 08:17:46 WARN Request failed, retrying attempt=5 backoff=1.716876502s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21512026/10/20 08:17:47 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21522026/10/20 08:17:47 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2153--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2154 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (8.77s)2155 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (9.49s)21562026/10/20 08:17:48 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_closures21572026/10/20 08:17:48 WARN Request failed, retrying attempt=2 backoff=181.454298ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21582026/10/20 08:17:48 WARN Request failed, retrying attempt=3 backoff=400.670012ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21592026/10/20 08:17:49 WARN Request failed, retrying attempt=4 backoff=827.303916ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21602026/10/20 08:17:50 WARN Request failed, retrying attempt=5 backoff=1.651920448s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2161--- PASS: TestClientErrorHandling (0.00s)2162 --- PASS: TestClientErrorHandling/InvalidAuthToken (8.75s)2163 --- PASS: TestClientErrorHandling/InvalidStorePath (9.01s)2164 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.41s)2165=== NAME TestOrphanedObjectsGCStressTest2166 orphaned_objects_gc_test.go:503: Stress test completed successfully:2167 orphaned_objects_gc_test.go:504: - Active objects preserved: 202168 orphaned_objects_gc_test.go:505: - Objects deleted: 2102169 orphaned_objects_gc_test.go:506: - Total GC'd: 2102170--- PASS: TestOrphanedObjectsGCStressTest (43.28s)2171FAIL2172{"timestamp":"2026-10-20T08:17:59.482965Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52243","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}21732026-10-20 08:17:59.708 UTC [48425] LOG: received smart shutdown request21742026/10/20 08:18:09 INFO killed process group pgid=4842521752026-10-20 08:18:09.711 UTC [63349] FATAL: terminating connection due to unexpected postmaster exit21762026-10-20 08:18:09.711 UTC [63395] FATAL: terminating connection due to unexpected postmaster exit21772026-10-20 08:18:09.712 UTC [63548] FATAL: terminating connection due to unexpected postmaster exit21782026-10-20 08:18:09.715 UTC [63984] FATAL: terminating connection due to unexpected postmaster exit21792026/10/20 08:18:09 ERROR failed to wait for process error="signal: killed"21802026-10-20 08:18:09.711 UTC [63311] FATAL: terminating connection due to unexpected postmaster exit