niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #413
· raw
1tribuchet: building on jamie2Running 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 (0.03s)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 TestStreamPushIsolatesFailures115=== CONT TestGetStorePathHash116=== RUN TestGetStorePathHash/valid_store_path117=== PAUSE TestGetStorePathHash/valid_store_path118=== RUN TestGetStorePathHash/basename_without_hyphen_should_error119=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error120=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error121=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error122=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error123=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error124=== CONT TestStreamPushBatchesUnderLoad125=== CONT TestDumpPathMatchesNix1262026/10/14 16:42:04 ERROR Upload failed error="bad path" count=3127=== CONT TestStreamPushReportsEveryPath128=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess129=== CONT TestRateLimiterFeedback130=== RUN TestRateLimiterFeedback/429_enables_limiter131=== PAUSE TestRateLimiterFeedback/429_enables_limiter132=== CONT TestPathInfoCACompatibility133=== RUN TestPathInfoCACompatibility/null_ca_field134=== PAUSE TestPathInfoCACompatibility/null_ca_field135=== RUN TestPathInfoCACompatibility/old_string_format_-_text136=== CONT TestParsePathInfoJSONMultiplePaths137=== CONT TestParsePathInfoJSON138=== CONT TestPathInfoHashCompatibility139=== CONT TestDoWithRetry_FinalResponseBodyReadable140=== CONT TestShellSplitErrors141=== CONT TestShellSplit1422026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=server-test rate=5143=== CONT TestUploadMultipart_SupersededByPeer144=== CONT TestConvertHashToNix32145=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer146=== CONT TestEncodeNixBase32WithRealHash147=== CONT TestRetryTimeoutOutlastsMaxRetries148=== CONT TestEncodeNixBase32149=== CONT TestDoWithRetry_BodyReplayedViaGetBody150=== CONT TestDumpPathWriterError151=== CONT TestDumpPathSingleFile152=== CONT TestResolveStorePath153=== RUN TestRateLimiterFeedback/503_enables_limiter154=== PAUSE TestRateLimiterFeedback/503_enables_limiter155=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter156=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter157=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter158=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter159=== RUN TestEncodeNixBase32/test_string_hash160=== PAUSE TestEncodeNixBase32/test_string_hash161=== RUN TestEncodeNixBase32/empty_input162=== PAUSE TestEncodeNixBase32/empty_input163=== CONT TestFilterOversizedClosures164=== RUN TestFilterOversizedClosures/no_limit_keeps_everything165=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything166=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped167=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped168=== RUN TestFilterOversizedClosures/all_closures_skipped169=== PAUSE TestFilterOversizedClosures/all_closures_skipped170=== CONT TestPartSizeForNAR171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172--- PASS: TestStreamPushIsolatesFailures (0.00s)173=== CONT TestUploadMultipart_PartsInParallel174--- PASS: TestStreamPushReportsEveryPath (0.00s)175--- PASS: TestShellSplitErrors (0.00s)176=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text177=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths178=== RUN TestParsePathInfoJSON/Nix_format179=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)180=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica181=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun182=== RUN TestUploadMultipart_SupersededByPeer/exists183=== RUN TestConvertHashToNix32/SRI_format_to_Nix32184=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum185=== RUN TestPartSizeForNAR/small_stays_at_minimum186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== CONT TestCaseHackSuffix188=== CONT TestSupersededNARStillUploadsListing189--- PASS: TestEncodeNixBase32WithRealHash (0.00s)190--- PASS: TestShellSplit (0.01s)191=== PAUSE TestPartSizeForNAR/small_stays_at_minimum192=== CONT TestRegisterUploadedObjectReusesConnections193=== RUN TestConvertHashToNix32/already_Nix32_format194=== RUN TestSupersededNARStillUploadsListing/small_NAR195=== PAUSE TestSupersededNARStillUploadsListing/small_NAR196=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths197=== PAUSE TestConvertHashToNix32/already_Nix32_format198=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum200=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive201=== RUN TestSupersededNARStillUploadsListing/dump_cut_short202=== PAUSE TestParsePathInfoJSON/Nix_format203=== RUN TestParsePathInfoJSON/Lix_format2042026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=server-test rate=52052026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:40275206--- PASS: TestResolveStorePath (0.00s)207=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry208=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)209=== RUN TestConvertHashToNix32/invalid_format210=== PAUSE TestConvertHashToNix32/invalid_format2112026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=server-test rate=5212=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short213=== CONT TestStaticToken2142026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43793215=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive216--- PASS: TestStaticToken (0.00s)217=== CONT TestClientSignaturesByStorePath218--- PASS: TestClientSignaturesByStorePath (0.00s)219=== CONT TestScriptTokenCachesUntilRefresh220=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum221=== PAUSE TestUploadMultipart_SupersededByPeer/exists2222026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39629223=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths2242026/10/14 16:42:04 WARN Rate limiter backed off name=server-test rate=5225=== CONT TestSetClientTLSErrors226--- PASS: TestDoServerRequestAttachesToken (0.04s)227=== CONT TestScriptTokenNoExpiryRerunsEveryCall2282026/10/14 16:42:04 INFO Garbage collection started229=== CONT TestSetClientTLSDoesNotMutateDefaultTransport230--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.04s)231=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon232=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon233=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI235=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512236=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails237=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails238=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts239=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts240=== RUN TestPartSizeForNAR/1_TiB241=== PAUSE TestPartSizeForNAR/1_TiB242=== RUN TestPartSizeForNAR/5_TiB_S3_max_object243=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object244=== RUN TestPartSizeForNAR/capped_at_5_GiB245=== PAUSE TestPartSizeForNAR/capped_at_5_GiB246=== RUN TestUploadMultipart_SupersededByPeer/missing247=== PAUSE TestUploadMultipart_SupersededByPeer/missing248=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== CONT TestFileTokenMissing250=== CONT TestStreamPushStopsWhenCanceled251--- PASS: TestStreamPushStopsWhenCanceled (0.00s)2522026/10/14 16:42:04 INFO Garbage collection started253=== CONT TestFileTokenReadsAndCaches254=== RUN TestPathInfoCACompatibility/new_structured_format_-_text255=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text256=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method257=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method258=== CONT TestFileTokenEmpty259=== CONT TestScriptTokenEmptyCommand260--- PASS: TestScriptTokenEmptyCommand (0.00s)261=== CONT TestScriptTokenScriptFails2622026/10/14 16:42:04 WARN Rate limiter backed off name=server-test rate=5263=== PAUSE TestParsePathInfoJSON/Lix_format2642026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:43793265=== RUN TestParsePathInfoJSON/empty_input266=== PAUSE TestParsePathInfoJSON/empty_input267=== RUN TestParsePathInfoJSON/whitespace_only268=== PAUSE TestParsePathInfoJSON/whitespace_only269=== CONT TestScriptTokenEmptyToken270=== CONT TestScriptTokenBadJSON271=== CONT TestSetClientTLS272=== CONT TestStreamPushReportsSkippedPaths273=== CONT TestStreamPushRequestLine274=== CONT TestStreamPushGivesUpOnDeadServer2752026/10/14 16:42:04 ERROR Upload failed error=boom count=12762026/10/14 16:42:04 ERROR Upload failed error="connection refused" count=202772026/10/14 16:42:04 ERROR Server seems unavailable, giving up on batch untried=172782026/10/14 16:42:04 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=0279=== CONT TestStreamPushReportsSignatures280=== CONT TestGetStorePathHash/valid_store_path281=== CONT TestGetStorePathHash/basename_without_hyphen_should_error282=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error283=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error284=== CONT TestRateLimiterFeedback/429_enables_limiter2852026/10/14 16:42:04 ERROR Upload failed error=boom count=1286--- PASS: TestFileTokenMissing (0.00s)287=== CONT TestEncodeNixBase32/test_string_hash288--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.04s)289--- PASS: TestFileTokenEmpty (0.00s)290--- PASS: TestStreamPushReportsSkippedPaths (0.00s)291--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)292--- PASS: TestFileTokenReadsAndCaches (0.00s)293--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)294=== CONT TestFilterOversizedClosures/no_limit_keeps_everything295=== CONT TestFilterOversizedClosures/all_closures_skipped2962026/10/14 16:42:04 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=50297=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2982026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=server-test rate=52992026/10/14 16:42:04 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=2000300--- PASS: TestFilterOversizedClosures (0.00s)301 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)302 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)303 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)304--- PASS: TestGetStorePathHash (0.00s)305 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)306 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)307 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)308 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)3092026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:46377310=== RUN TestSetClientTLSErrors/missing_cert_file311=== PAUSE TestSetClientTLSErrors/missing_cert_file312=== RUN TestSetClientTLSErrors/missing_key_file313=== PAUSE TestSetClientTLSErrors/missing_key_file314=== RUN TestSetClientTLSErrors/missing_ca_file315=== PAUSE TestSetClientTLSErrors/missing_ca_file316=== RUN TestSetClientTLSErrors/invalid_ca_file317=== PAUSE TestSetClientTLSErrors/invalid_ca_file318=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3192026/10/14 16:42:04 WARN Garbage collection finished on another replica. Its statistics are not available here320=== CONT TestEncodeNixBase32/empty_input321=== CONT TestConvertHashToNix32/invalid_format3222026/10/14 16:42:04 WARN Rate limiter backed off name=server-test rate=5323=== CONT TestConvertHashToNix32/already_Nix32_format324=== RUN TestParsePathInfoJSON/invalid_JSON325=== CONT TestRateLimiterFeedback/503_enables_limiter326--- PASS: TestStreamPushReportsSignatures (0.00s)327=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter328=== CONT TestConvertHashToNix32/SRI_format_to_Nix32329=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths3302026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=s3-test rate=5331--- PASS: TestScriptTokenScriptFails (0.00s)332--- PASS: TestScriptTokenBadJSON (0.00s)3332026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:46085334=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths335=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3362026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39629337=== CONT TestPartSizeForNAR/zero_stays_at_minimum3382026/10/14 16:42:04 INFO Uploading abc-hello (1.0GB)339=== CONT TestPartSizeForNAR/capped_at_5_GiB340=== CONT TestPartSizeForNAR/1_TiB341=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts342=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum3432026/10/14 16:42:04 WARN Rate limiter enabled after throttle name=server-test rate=5344=== CONT TestPartSizeForNAR/small_stays_at_minimum3452026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43689346=== CONT TestSupersededNARStillUploadsListing/dump_cut_short347--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)348--- PASS: TestEncodeNixBase32 (0.00s)349 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)350 --- PASS: TestEncodeNixBase32/empty_input (0.00s)351=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)352=== CONT TestUploadMultipart_SupersededByPeer/exists353--- PASS: TestDumpPathSingleFile (0.04s)354=== PAUSE TestParsePathInfoJSON/invalid_JSON3552026/10/14 16:42:04 WARN Rate limiter backed off name=server-test rate=5356=== CONT TestUploadMultipart_SupersededByPeer/missing357=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI358=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512359=== CONT TestPartSizeForNAR/5_TiB_S3_max_object360=== CONT TestSupersededNARStillUploadsListing/small_NAR361--- PASS: TestScriptTokenEmptyToken (0.01s)362--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)363=== CONT TestPathInfoCACompatibility/new_structured_format_-_text364=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method365=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive366=== CONT TestPathInfoCACompatibility/null_ca_field367--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.04s)368--- PASS: TestRateLimiterFeedback (0.00s)369 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)370 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)371 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)372 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)373--- PASS: TestCaseHackSuffix (0.06s)3742026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:39629375--- PASS: TestPartSizeForNAR (0.04s)376 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)377 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)378 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)379 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)380 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)381 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)382 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)383=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon384=== CONT TestSetClientTLSErrors/missing_ca_file3852026/10/14 16:42:04 INFO Uploading abc-hello (1.0GB)386=== RUN TestSetClientTLS/rejects_connection_without_client_cert387=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert388=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA389=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA390=== RUN TestSetClientTLS/preserves_debug_logging_transport391=== PAUSE TestSetClientTLS/preserves_debug_logging_transport392=== CONT TestSetClientTLS/rejects_connection_without_client_cert393=== CONT TestSetClientTLS/preserves_debug_logging_transport3942026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:39629395=== CONT TestSetClientTLSErrors/missing_cert_file396=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA397=== CONT TestParsePathInfoJSON/whitespace_only398=== CONT TestPathInfoCACompatibility/old_string_format_-_text399=== CONT TestSetClientTLSErrors/invalid_ca_file400=== CONT TestSetClientTLSErrors/missing_key_file401--- PASS: TestConvertHashToNix32 (0.33s)402 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)403 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)404 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)405--- PASS: TestParsePathInfoJSONMultiplePaths (0.36s)406 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)407 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)408--- PASS: TestStreamPushBatchesUnderLoad (0.38s)409--- PASS: TestPathInfoHashCompatibility (0.04s)410 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)411 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)412 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)414=== CONT TestParsePathInfoJSON/Nix_format415=== CONT TestParsePathInfoJSON/invalid_JSON416=== CONT TestParsePathInfoJSON/empty_input417=== CONT TestParsePathInfoJSON/Lix_format418--- PASS: TestUploadMultipart_SupersededByPeer (0.04s)419 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.33s)420 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.33s)421--- PASS: TestParsePathInfoJSON (0.05s)422 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)423 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)424 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)425 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)426 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)427--- PASS: TestPathInfoCACompatibility (0.04s)428 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)429 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)430 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)431 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)432 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)4332026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:39629434--- PASS: TestSetClientTLSErrors (0.00s)435 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)436 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)437 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)438 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4392026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:396294402026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:39629441--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.35s)442--- PASS: TestScriptTokenCachesUntilRefresh (0.35s)4432026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:396294442026/10/14 16:42:04 http: TLS handshake error from 127.0.0.1:57296: remote error: tls: bad certificate4452026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:39629446--- PASS: TestSetClientTLS (0.34s)447 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)448 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)449 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)450--- PASS: TestStreamPushRequestLine (0.35s)4512026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:396294522026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:396294532026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:396294542026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:396294552026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:39629456--- PASS: TestRegisterUploadedObjectReusesConnections (0.39s)4572026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:39629458--- PASS: TestDumpPathWriterError (0.39s)4592026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:396294602026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:396294612026/10/14 16:42:04 INFO Uploading abc-hello (1.0GB)4622026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:396294632026/10/14 16:42:04 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:39629464--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.40s)465--- PASS: TestDumpPathMatchesNix (0.44s)4662026/10/14 16:42:04 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:34131/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:34131/part/24672026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:34131/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:34131/part/34682026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:34131/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:34131/part/44692026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:34131/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:34131/part/54702026/10/14 16:42:05 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"471--- PASS: TestSupersededNARStillUploadsListing (0.03s)472 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.34s)473 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)474 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.88s)475--- PASS: TestUploadMultipart_PartsInParallel (0.97s)4762026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46543/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46543/api/uploads/complete477--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4782026/10/14 16:42:05 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4792026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46543/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46543/api/uploads/complete4802026/10/14 16:42:05 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4812026/10/14 16:42:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46543/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:46543/api/uploads/complete4822026/10/14 16:42:05 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"483--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)484PASS485Running server tests...486The files belonging to this database system will be owned by user "nixbld".487This user must also own the server process.488489The database cluster will be initialized with locale "C".490The default database encoding has accordingly been set to "SQL_ASCII".491The default text search configuration will be set to "english".492493Data page checksums are enabled.494495creating directory /build/postgres1181464662/data ... ok496creating subdirectories ... ok497selecting dynamic shared memory implementation ... posix498selecting default "max_connections" ... 100499selecting default "shared_buffers" ... 128MB500selecting default time zone ... UTC501creating configuration files ... ok502running bootstrap script ... ok503performing post-bootstrap initialization ... ok504syncing data to disk ... ok505506initdb: warning: enabling "trust" authentication for local connections507initdb: 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.508509Success. You can now start the database server using:510511 pg_ctl -D /build/postgres1181464662/data -l logfile start512513/build/postgres1181464662:5432 - no response5142026-10-14 16:42:06.471 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5152026-10-14 16:42:06.471 UTC [129] LOG: listening on Unix socket "/build/postgres1181464662/.s.PGSQL.5432"5162026-10-14 16:42:06.476 UTC [136] LOG: database system was shut down at 2026-10-14 16:42:06 UTC5172026-10-14 16:42:06.482 UTC [129] LOG: database system is ready to accept connections518/build/postgres1181464662:5432 - accepting connections519{"timestamp":"2026-10-14T16:42:06.883670205Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ddbf27cb-890e-40c4-a713-af43494eb783","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":501,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}520=== RUN TestService_AuthMiddleware521=== PAUSE TestService_AuthMiddleware522=== RUN TestService_AuthMiddleware_MTLSProxyHeader523=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader524=== RUN TestService_AuthMiddleware_MTLSBoundSubjects525=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects526=== RUN TestService_ReadAuthMiddleware527=== PAUSE TestService_ReadAuthMiddleware528=== RUN TestService_AuthMiddleware_OIDC529=== PAUSE TestService_AuthMiddleware_OIDC530=== RUN TestService_RequireScope_OIDC531=== PAUSE TestService_RequireScope_OIDC532=== RUN TestService_ReadScope_PublicByDefault533=== PAUSE TestService_ReadScope_PublicByDefault534=== RUN TestCacheConfigHandler535=== PAUSE TestCacheConfigHandler536=== RUN TestCacheStatsHandler537=== PAUSE TestCacheStatsHandler538=== RUN TestClientCADerivations539=== PAUSE TestClientCADerivations540=== RUN TestClientErrorHandling541=== PAUSE TestClientErrorHandling542=== RUN TestClientIntegration543=== PAUSE TestClientIntegration544=== RUN TestClientMultipleUploads545=== PAUSE TestClientMultipleUploads546=== RUN TestClientWithDependencies547=== PAUSE TestClientWithDependencies548=== RUN TestClientSharedPathCommittedMidPush549=== PAUSE TestClientSharedPathCommittedMidPush550=== RUN TestPinProtectsFromGC551=== PAUSE TestPinProtectsFromGC552=== RUN TestClientPushesUseOnePush553=== PAUSE TestClientPushesUseOnePush554=== RUN TestClientFallsBackToClosures555=== PAUSE TestClientFallsBackToClosures556=== RUN TestDeleteClosuresRacingPins557=== PAUSE TestDeleteClosuresRacingPins558=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock559=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock560=== RUN TestResolveDBConnectionString561=== PAUSE TestResolveDBConnectionString562=== RUN TestConnectWaitsForAPeerMigration563=== PAUSE TestConnectWaitsForAPeerMigration564=== RUN TestLeadElectsOneAndHandsOver565=== PAUSE TestLeadElectsOneAndHandsOver566=== RUN TestLeadIncumbentWinsAfterRestart5672026/10/14 16:42:07 INFO lead: acquired remote=192.0.2.1:12345682026/10/14 16:42:07 INFO lead: released remote=192.0.2.1:12345692026/10/14 16:42:07 INFO lead: acquired remote=192.0.2.1:12345702026/10/14 16:42:08 INFO lead: released remote=192.0.2.1:1234571--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)572=== RUN TestLeadIncumbentAnnouncesAtOnce573=== PAUSE TestLeadIncumbentAnnouncesAtOnce574=== RUN TestLeadEndsOnShutdown575=== PAUSE TestLeadEndsOnShutdown576=== RUN TestLeadEndsWhenItsConnectionHangs5772026/10/14 16:42:09 INFO lead: acquired remote=192.0.2.1:12345782026-10-14 16:42:10.402 UTC [574] FATAL: terminating connection due to administrator command5792026/10/14 16:42:10 INFO lead: acquired remote=192.0.2.1:12345802026/10/14 16:42:11 WARN lead: lock connection lost error="timeout: context deadline exceeded"5812026/10/14 16:42:11 INFO lead: released remote=192.0.2.1:12345822026/10/14 16:42:11 INFO lead: released remote=192.0.2.1:1234583--- PASS: TestLeadEndsWhenItsConnectionHangs (2.90s)584=== RUN TestGCAdvisoryLockBlocksConcurrentRun585=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun586=== RUN TestGCBugBareHashReferences587=== PAUSE TestGCBugBareHashReferences588=== RUN TestGCMetrics589=== PAUSE TestGCMetrics590=== RUN TestPushDedupSurvivesConcurrentGC591=== PAUSE TestPushDedupSurvivesConcurrentGC592=== RUN TestDeduplicatedObjectsRecordedAsPending593=== PAUSE TestDeduplicatedObjectsRecordedAsPending594=== RUN TestGCSweepSkipsPendingObjects595=== PAUSE TestGCSweepSkipsPendingObjects596=== RUN TestTombstonedObjectOfferedWithoutWaiting597=== PAUSE TestTombstonedObjectOfferedWithoutWaiting598=== RUN TestGCSweepDeliversEachKeyOnce599=== PAUSE TestGCSweepDeliversEachKeyOnce600=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection601=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection602=== RUN TestForceGCDuringPushOffersSweptObject603=== PAUSE TestForceGCDuringPushOffersSweptObject604=== RUN TestFailedS3DeleteKeepsTombstone605=== PAUSE TestFailedS3DeleteKeepsTombstone606=== RUN TestSweepSkipsRowsLockedByPush607=== PAUSE TestSweepSkipsRowsLockedByPush608=== RUN TestRegisterCompletedObjectNeedsPendingRow609=== PAUSE TestRegisterCompletedObjectNeedsPendingRow610=== RUN TestGetExistingObjectsLocksRows611=== PAUSE TestGetExistingObjectsLocksRows612=== RUN TestSweepRechecksPendingAfterLocking613=== PAUSE TestSweepRechecksPendingAfterLocking614=== RUN TestPushWaitsForSweepHoldingRow615=== PAUSE TestPushWaitsForSweepHoldingRow616=== RUN TestCommitRacingPendingCleanupKeepsObjects617=== PAUSE TestCommitRacingPendingCleanupKeepsObjects618=== RUN TestGCEndsOnShutdown619=== PAUSE TestGCEndsOnShutdown620=== RUN TestGCTaskStore_StartNew621=== PAUSE TestGCTaskStore_StartNew622=== RUN TestGCTaskStore_DeduplicateSameParams623=== PAUSE TestGCTaskStore_DeduplicateSameParams624=== RUN TestGCTaskStore_ConflictDifferentParams625=== PAUSE TestGCTaskStore_ConflictDifferentParams626=== RUN TestGCTaskStore_GetEmpty627=== PAUSE TestGCTaskStore_GetEmpty628=== RUN TestGCTaskStore_GetReturnsLatest629=== PAUSE TestGCTaskStore_GetReturnsLatest630=== RUN TestGCTaskStore_CompletedAllowsNewTask631=== PAUSE TestGCTaskStore_CompletedAllowsNewTask632=== RUN TestGCTaskStore_PhaseUpdates633=== PAUSE TestGCTaskStore_PhaseUpdates634=== RUN TestGCTaskStore_Fail635=== PAUSE TestGCTaskStore_Fail636=== RUN TestGracefulShutdownDrainsInflight637=== PAUSE TestGracefulShutdownDrainsInflight638=== RUN TestService_healthCheckHandler639=== PAUSE TestService_healthCheckHandler640=== RUN TestService_readinessHandler641=== PAUSE TestService_readinessHandler642=== RUN TestGenerateLandingPage643=== PAUSE TestGenerateLandingPage644=== RUN TestCacheConfigHandlerMaxNarSize645=== PAUSE TestCacheConfigHandlerMaxNarSize646=== RUN TestCreatePendingClosureRejectsOversizedNAR647=== PAUSE TestCreatePendingClosureRejectsOversizedNAR648=== RUN TestNARDeduplicationMetadataUploadBug649=== PAUSE TestNARDeduplicationMetadataUploadBug650=== RUN TestMetricsInventory651=== PAUSE TestMetricsInventory652=== RUN TestMetricsCommit653=== PAUSE TestMetricsCommit654=== RUN TestService_NativeMTLS655=== PAUSE TestService_NativeMTLS656=== RUN TestServerTLSConfig657=== PAUSE TestServerTLSConfig658=== RUN TestMultipartCleanup659=== PAUSE TestMultipartCleanup660=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded661=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded662=== RUN TestPendingCleanupUsesOneCutoff663=== PAUSE TestPendingCleanupUsesOneCutoff664=== RUN TestObjectStatsTrigger665=== PAUSE TestObjectStatsTrigger666=== RUN TestObjectStatsLargeCommit667=== PAUSE TestObjectStatsLargeCommit668=== RUN TestOrphanedObjectsGC669=== PAUSE TestOrphanedObjectsGC670=== RUN TestOrphanedObjectsGCStressTest671=== PAUSE TestOrphanedObjectsGCStressTest672=== RUN TestCreatePin_ReservedPins673=== PAUSE TestCreatePin_ReservedPins674=== RUN TestPresentReportsOnlyClosureRoots675=== PAUSE TestPresentReportsOnlyClosureRoots676=== RUN TestPresentRefreshesOnlyStaleClosures677=== PAUSE TestPresentRefreshesOnlyStaleClosures678=== RUN TestPresentNotReportedWhileGCDeletesClosure679=== PAUSE TestPresentNotReportedWhileGCDeletesClosure680=== RUN TestParseSingleRange681=== PAUSE TestParseSingleRange682=== RUN TestProxyHeadersOnlyTrustedOnSocket6832026/10/14 16:42:11 INFO Starting HTTP server address=proxy.sock6842026/10/14 16:42:11 INFO Starting HTTP server address=127.0.0.1:426516852026/10/14 16:42:11 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6862026/10/14 16:42:11 INFO Shutdown signal received, draining in-flight requests timeout=10s687--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)688=== RUN TestIsValidCachePath689=== PAUSE TestIsValidCachePath690=== RUN TestReadProxyNarinfo691=== PAUSE TestReadProxyNarinfo692=== RUN TestReadProxyNarinfoAlreadyDecompressed693=== PAUSE TestReadProxyNarinfoAlreadyDecompressed694=== RUN TestReadProxyContentNegotiation695=== PAUSE TestReadProxyContentNegotiation696=== RUN TestReadProxyNarStreaming697=== PAUSE TestReadProxyNarStreaming698=== RUN TestReadProxy404699=== PAUSE TestReadProxy404700=== RUN TestReadProxyInvalidPath701=== PAUSE TestReadProxyInvalidPath702=== RUN TestReadProxyHead703=== PAUSE TestReadProxyHead704=== RUN TestReadProxyOutlastsServerWriteTimeout705=== PAUSE TestReadProxyOutlastsServerWriteTimeout706=== RUN TestReadProxyConditionalGet707=== PAUSE TestReadProxyConditionalGet708=== RUN TestReadProxyRootRedirectsToIndexHTML709=== PAUSE TestReadProxyRootRedirectsToIndexHTML710=== RUN TestReadProxyDisabled711=== PAUSE TestReadProxyDisabled712=== RUN TestReadRedirectNar713=== PAUSE TestReadRedirectNar714=== RUN TestReadRedirectKeepsNarinfoProxied715=== PAUSE TestReadRedirectKeepsNarinfoProxied716=== RUN TestReadProxyRangeRequest717=== PAUSE TestReadProxyRangeRequest718=== RUN TestReadRedirectUsesPublicS3URL719=== PAUSE TestReadRedirectUsesPublicS3URL720=== RUN TestPush_OverlappingRootsStoreOneRowPerKey721=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey722=== RUN TestPush_CompleteCommitsEveryRoot723=== PAUSE TestPush_CompleteCommitsEveryRoot724=== RUN TestPush_RepeatedRootCommitsOnce725=== PAUSE TestPush_RepeatedRootCommitsOnce726=== RUN TestPush_CompleteWaitsForCleanupOfThePush727=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush728=== RUN TestPush_RootsAreLockedInByteOrder729=== PAUSE TestPush_RootsAreLockedInByteOrder730=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit731=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit732=== RUN TestPush_RejectsBadRequests733=== PAUSE TestPush_RejectsBadRequests734=== RUN TestPush_SignsNarinfosOfItsPendingObjects735=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects736=== RUN TestRedundantMultipartUpload737=== PAUSE TestRedundantMultipartUpload738=== RUN TestCompleteMultipartUpload_ErrorButObjectExists739=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists740=== RUN TestCompletedNarNotReofferedAcrossClosures741=== PAUSE TestCompletedNarNotReofferedAcrossClosures742=== RUN TestPresignedUploadRegisteredBeforeCommit743=== PAUSE TestPresignedUploadRegisteredBeforeCommit744=== RUN TestService_Rustfstest745=== PAUSE TestService_Rustfstest746=== RUN TestParseSize747=== PAUSE TestParseSize748=== RUN TestSkippedUploadsHandler749=== PAUSE TestSkippedUploadsHandler750=== RUN TestSystemdListenerNotActivated751--- PASS: TestSystemdListenerNotActivated (0.00s)752=== RUN TestWatchdogBeatsWhenHealthy753--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)754=== RUN TestWatchdogSkipsWhenUnhealthy7552026/10/14 16:42:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7562026/10/14 16:42:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7572026/10/14 16:42:11 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/14 16:42:12 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"765--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)766=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle767=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle768=== RUN TestProxyWriteTimeout769=== PAUSE TestProxyWriteTimeout770=== RUN TestPendingClosureWriteTimeout771=== PAUSE TestPendingClosureWriteTimeout772=== RUN TestIsValidUploadKey773=== PAUSE TestIsValidUploadKey774=== RUN TestUploadHandlersRejectInvalidKeys775=== PAUSE TestUploadHandlersRejectInvalidKeys776=== RUN TestUploadHandlersRejectOversizedBody777=== PAUSE TestUploadHandlersRejectOversizedBody778=== RUN TestService_cleanupPendingClosuresHandler779=== PAUSE TestService_cleanupPendingClosuresHandler780=== RUN TestService_createPendingClosureHandler781=== PAUSE TestService_createPendingClosureHandler782=== RUN TestService_verifyS3Integrity783=== PAUSE TestService_verifyS3Integrity784=== RUN TestCompleteMultipartUnregistered785=== PAUSE TestCompleteMultipartUnregistered786=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT787=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT788=== CONT TestService_AuthMiddleware789=== CONT TestMetricsInventory790=== CONT TestDeduplicatedObjectsRecordedAsPending791=== CONT TestNARDeduplicationMetadataUploadBug792=== CONT TestCreatePendingClosureRejectsOversizedNAR793=== CONT TestCacheConfigHandlerMaxNarSize7942026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures795=== CONT TestGenerateLandingPage796=== CONT TestService_readinessHandler797=== CONT TestService_healthCheckHandler798=== CONT TestGracefulShutdownDrainsInflight799=== CONT TestGCTaskStore_Fail800=== CONT TestForceGCDuringPushOffersSweptObject801=== CONT TestGCTaskStore_PhaseUpdates8022026/10/14 16:42:12 INFO Starting HTTP server address=127.0.0.1:39647803=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection804=== CONT TestGCTaskStore_CompletedAllowsNewTask805=== CONT TestReadRedirectKeepsNarinfoProxied806=== CONT TestGCTaskStore_GetReturnsLatest8072026/10/14 16:42:12 INFO Shutdown signal received, draining in-flight requests timeout=10s808=== CONT TestGCTaskStore_GetEmpty809=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT810=== CONT TestGCTaskStore_ConflictDifferentParams811=== CONT TestGCTaskStore_DeduplicateSameParams812=== CONT TestGCTaskStore_StartNew813=== CONT TestGCEndsOnShutdown814=== CONT TestCommitRacingPendingCleanupKeepsObjects815=== CONT TestPushWaitsForSweepHoldingRow816=== CONT TestSweepRechecksPendingAfterLocking817=== CONT TestGetExistingObjectsLocksRows818=== CONT TestRegisterCompletedObjectNeedsPendingRow819--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)820=== CONT TestFailedS3DeleteKeepsTombstone821=== CONT TestSweepSkipsRowsLockedByPush822=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows823=== CONT TestGCSweepDeliversEachKeyOnce824=== CONT TestTombstonedObjectOfferedWithoutWaiting825=== CONT TestGCSweepSkipsPendingObjects826--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)827--- PASS: TestGCTaskStore_Fail (0.00s)828--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)829--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)830--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)831--- PASS: TestGCTaskStore_GetEmpty (0.00s)832--- PASS: TestGCTaskStore_StartNew (0.00s)833--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)834--- PASS: TestGenerateLandingPage (0.00s)835=== RUN TestGCEndsOnShutdown/before_the_run836=== PAUSE TestGCEndsOnShutdown/before_the_run837=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete838--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)839=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete840=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark841=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows842=== CONT TestCompleteMultipartUnregistered843=== CONT TestService_verifyS3Integrity844=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark845=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check846=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check847=== CONT TestPinProtectsFromGC848=== CONT TestService_createPendingClosureHandler849--- PASS: TestGracefulShutdownDrainsInflight (0.07s)850=== CONT TestPushDedupSurvivesConcurrentGC851--- PASS: TestMetricsInventory (0.37s)852=== CONT TestService_cleanupPendingClosuresHandler8532026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures854--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.39s)855=== CONT TestGCMetrics8562026/10/14 16:42:12 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"857--- PASS: TestService_AuthMiddleware (0.41s)858=== CONT TestUploadHandlersRejectOversizedBody859--- PASS: TestService_healthCheckHandler (0.43s)860=== CONT TestUploadHandlersRejectInvalidKeys861=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info862=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info863=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal864=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal865=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key866=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key867=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key868=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key869=== CONT TestGCBugBareHashReferences870=== NAME TestNARDeduplicationMetadataUploadBug871 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4001316123/001/store/14xwkvdz1bx9a91q0mqmjmjzwzx7aa0h-file1.txt872=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart873=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart874=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts875=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts876=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure877=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure878=== CONT TestIsValidUploadKey879=== RUN TestIsValidUploadKey/narinfo880=== PAUSE TestIsValidUploadKey/narinfo881=== RUN TestIsValidUploadKey/nar_zst882=== PAUSE TestIsValidUploadKey/nar_zst8832026/10/14 16:42:12 WARN readiness check failed error="closed pool"884=== RUN TestIsValidUploadKey/nar_xz885=== CONT TestGCAdvisoryLockBlocksConcurrentRun886--- PASS: TestService_readinessHandler (0.57s)887=== PAUSE TestIsValidUploadKey/nar_xz888=== RUN TestIsValidUploadKey/nar_plain889=== PAUSE TestIsValidUploadKey/nar_plain890=== RUN TestIsValidUploadKey/listing891=== PAUSE TestIsValidUploadKey/listing892=== RUN TestIsValidUploadKey/build_log893=== PAUSE TestIsValidUploadKey/build_log894=== RUN TestIsValidUploadKey/build_log_home-manager_file895=== PAUSE TestIsValidUploadKey/build_log_home-manager_file896=== RUN TestIsValidUploadKey/build_log_plus_in_name897=== PAUSE TestIsValidUploadKey/build_log_plus_in_name898=== RUN TestIsValidUploadKey/build_log_question_mark899=== PAUSE TestIsValidUploadKey/build_log_question_mark900=== RUN TestIsValidUploadKey/build_log_equals901=== PAUSE TestIsValidUploadKey/build_log_equals902=== RUN TestIsValidUploadKey/realisation903=== PAUSE TestIsValidUploadKey/realisation904=== RUN TestIsValidUploadKey/realisation_plus_in_output905=== PAUSE TestIsValidUploadKey/realisation_plus_in_output906=== RUN TestIsValidUploadKey/nix-cache-info907=== PAUSE TestIsValidUploadKey/nix-cache-info908=== RUN TestIsValidUploadKey/index.html909=== PAUSE TestIsValidUploadKey/index.html910=== RUN TestIsValidUploadKey/narinfo_key,_nar_type911=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type912=== RUN TestIsValidUploadKey/nar_key,_narinfo_type913=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type914=== RUN TestIsValidUploadKey/listing_key,_narinfo_type915=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type916=== RUN TestIsValidUploadKey/traversal917=== PAUSE TestIsValidUploadKey/traversal918=== RUN TestIsValidUploadKey/traversal_nar919=== PAUSE TestIsValidUploadKey/traversal_nar920=== RUN TestIsValidUploadKey/absolute921=== PAUSE TestIsValidUploadKey/absolute922=== RUN TestIsValidUploadKey/empty_key923=== PAUSE TestIsValidUploadKey/empty_key924=== RUN TestIsValidUploadKey/unknown_type925=== PAUSE TestIsValidUploadKey/unknown_type926=== CONT TestPendingClosureWriteTimeout927=== RUN TestPendingClosureWriteTimeout/empty928=== PAUSE TestPendingClosureWriteTimeout/empty929=== RUN TestPendingClosureWriteTimeout/400_objects930=== PAUSE TestPendingClosureWriteTimeout/400_objects931=== RUN TestPendingClosureWriteTimeout/670k_objects932=== PAUSE TestPendingClosureWriteTimeout/670k_objects933=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline934=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline935=== CONT TestProxyWriteTimeout936=== RUN TestProxyWriteTimeout/narinfo937=== PAUSE TestProxyWriteTimeout/narinfo938=== RUN TestProxyWriteTimeout/1_GiB_nar939=== PAUSE TestProxyWriteTimeout/1_GiB_nar940=== RUN TestProxyWriteTimeout/10_GiB_nar941=== PAUSE TestProxyWriteTimeout/10_GiB_nar942=== RUN TestProxyWriteTimeout/unknown_size943=== PAUSE TestProxyWriteTimeout/unknown_size944=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle945--- PASS: TestReadRedirectKeepsNarinfoProxied (0.58s)946=== CONT TestLeadEndsOnShutdown9472026/10/14 16:42:12 INFO Received push request method=POST path=/api/pushes9482026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures9492026/10/14 16:42:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9502026/10/14 16:42:12 INFO Uploading 14xwkvdz1bx9a91q0mqmjmjzwzx7aa0h-file1.txt (160B)9512026/10/14 16:42:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9522026/10/14 16:42:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9532026/10/14 16:42:12 WARN Failed to register uploaded object key=14xwkvdz1bx9a91q0mqmjmjzwzx7aa0h.ls error="server returned 404: 404 page not found\n"9542026/10/14 16:42:12 INFO Signed narinfos id=1 count=19552026/10/14 16:42:12 INFO Uploading 1 narinfos9562026/10/14 16:42:12 INFO Received complete push request method=POST path=/api/pushes/1/complete9572026/10/14 16:42:12 WARN Failed to register uploaded object key=14xwkvdz1bx9a91q0mqmjmjzwzx7aa0h.narinfo error="server returned 404: 404 page not found\n"9582026/10/14 16:42:12 INFO Completed push id=1 objects=3 duration=11.108082ms9592026/10/14 16:42:12 INFO Upload complete. (77ms)960=== NAME TestNARDeduplicationMetadataUploadBug961 metadata_upload_test.go:54: Retrieved narinfo from S3:962 StorePath: /build/TestNARDeduplicationMetadataUploadBug4001316123/001/store/14xwkvdz1bx9a91q0mqmjmjzwzx7aa0h-file1.txt963 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst964 Compression: zstd965 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf966 NarSize: 160967 References: 968 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf969 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)970 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):971 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9722026/10/14 16:42:12 INFO Aborted multipart uploads count=0 kept=09732026/10/14 16:42:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9742026/10/14 16:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period9752026/10/14 16:42:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst976--- PASS: TestCompleteMultipartUnregistered (0.68s)977=== CONT TestSkippedUploadsHandler9782026/10/14 16:42:12 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000979--- PASS: TestSkippedUploadsHandler (0.01s)980=== CONT TestLeadIncumbentAnnouncesAtOnce981=== NAME TestNARDeduplicationMetadataUploadBug982 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4001316123/001/store/88g768kwf20nyj9133shsj5kaw87n2ki-file2.txt9832026/10/14 16:42:12 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=09842026/10/14 16:42:12 INFO Vacuumed table table=pending_closures9852026/10/14 16:42:12 INFO Vacuumed table table=pending_objects9862026/10/14 16:42:12 INFO Vacuumed table table=multipart_uploads9872026/10/14 16:42:12 INFO Vacuumed table table=closures9882026/10/14 16:42:12 INFO Vacuumed table table=objects989--- PASS: TestGCSweepDeliversEachKeyOnce (0.70s)990=== CONT TestLeadElectsOneAndHandsOver9912026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/14 16:42:12 INFO Aborted multipart uploads count=0 kept=09932026/10/14 16:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period9942026/10/14 16:42:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09952026/10/14 16:42:12 INFO Vacuumed table table=pending_closures9962026/10/14 16:42:12 INFO Vacuumed table table=pending_objects9972026/10/14 16:42:12 INFO Vacuumed table table=multipart_uploads998--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.73s)999=== CONT TestParseSize10002026/10/14 16:42:12 INFO Vacuumed table table=closures1001--- PASS: TestParseSize (0.00s)1002=== CONT TestService_Rustfstest10032026/10/14 16:42:12 INFO Vacuumed table table=objects1004--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.74s)1005=== CONT TestConnectWaitsForAPeerMigration10062026/10/14 16:42:12 INFO Received push request method=POST path=/api/pushes10072026/10/14 16:42:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1008--- PASS: TestGetExistingObjectsLocksRows (0.77s)1009=== CONT TestPresignedUploadRegisteredBeforeCommit10102026/10/14 16:42:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10112026/10/14 16:42:12 INFO Signed narinfos id=2 count=110122026/10/14 16:42:12 WARN Failed to register uploaded object key=88g768kwf20nyj9133shsj5kaw87n2ki.ls error="server returned 404: 404 page not found\n"10132026/10/14 16:42:12 INFO Uploading 1 narinfos10142026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/14 16:42:12 INFO Received complete push request method=POST path=/api/pushes/2/complete10162026/10/14 16:42:12 WARN Failed to register uploaded object key=88g768kwf20nyj9133shsj5kaw87n2ki.narinfo error="server returned 404: 404 page not found\n"10172026/10/14 16:42:12 INFO Completed push id=2 objects=3 duration=2.768478ms10182026/10/14 16:42:12 INFO Upload complete. (72ms)1019=== NAME TestNARDeduplicationMetadataUploadBug1020 metadata_upload_test.go:76: Retrieved narinfo from S3:1021 StorePath: /build/TestNARDeduplicationMetadataUploadBug4001316123/001/store/88g768kwf20nyj9133shsj5kaw87n2ki-file2.txt1022 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1023 Compression: zstd1024 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1025 NarSize: 1601026 References: 1027 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1028 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1029 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1030 {"version":1,"root":{"type":"regular","size":44}}1031--- PASS: TestNARDeduplicationMetadataUploadBug (0.81s)1032=== CONT TestResolveDBConnectionString1033=== RUN TestResolveDBConnectionString/flag_wins1034=== PAUSE TestResolveDBConnectionString/flag_wins1035=== RUN TestResolveDBConnectionString/file_when_flag_empty1036=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1037=== RUN TestResolveDBConnectionString/missing_file_is_an_error1038=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1039=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1040=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1041=== RUN TestResolveDBConnectionString/nothing_configured1042=== PAUSE TestResolveDBConnectionString/nothing_configured1043=== CONT TestCompletedNarNotReofferedAcrossClosures10442026/10/14 16:42:12 INFO Aborted multipart uploads count=0 kept=010452026/10/14 16:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period10462026/10/14 16:42:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010472026/10/14 16:42:12 INFO Vacuumed table table=pending_closures10482026/10/14 16:42:12 INFO Vacuumed table table=pending_objects10492026/10/14 16:42:12 INFO Vacuumed table table=multipart_uploads10502026/10/14 16:42:12 INFO Vacuumed table table=closures10512026/10/14 16:42:12 INFO Vacuumed table table=objects10522026/10/14 16:42:12 INFO Received uploads request method=POST path=/api/pending_closures10532026/10/14 16:42:12 INFO Aborted multipart uploads count=0 kept=010542026/10/14 16:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period10552026/10/14 16:42:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010562026/10/14 16:42:12 INFO Vacuumed table table=pending_closures10572026/10/14 16:42:12 INFO Vacuumed table table=pending_objects10582026/10/14 16:42:12 INFO Vacuumed table table=multipart_uploads10592026/10/14 16:42:12 INFO Vacuumed table table=closures1060--- PASS: TestGCSweepSkipsPendingObjects (0.84s)1061=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10622026/10/14 16:42:12 INFO Vacuumed table table=objects10632026/10/14 16:42:12 INFO Aborted multipart uploads count=0 kept=010642026/10/14 16:42:12 WARN Force mode enabled - objects will be deleted immediately without grace period1065--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.86s)1066=== CONT TestDeleteClosuresRacingPins10672026/10/14 16:42:12 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=010682026/10/14 16:42:12 INFO Vacuumed table table=pending_closures10692026/10/14 16:42:12 INFO Vacuumed table table=pending_objects10702026/10/14 16:42:12 INFO Vacuumed table table=multipart_uploads10712026/10/14 16:42:12 INFO Vacuumed table table=closures10722026/10/14 16:42:13 INFO Vacuumed table table=objects1073--- PASS: TestSweepSkipsRowsLockedByPush (0.87s)1074=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10752026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=010762026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures10782026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures1079--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.91s)1080=== CONT TestClientFallsBackToClosures10812026/10/14 16:42:13 WARN Force mode enabled - objects will be deleted immediately without grace period10822026/10/14 16:42:13 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=010832026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures1084=== NAME TestPinProtectsFromGC1085 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC640297676/001/store/d2f1fziyczicmnbfydyabmb7sspx570g-pinned-file.txt1086 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC640297676/001/store/j0qnmc5yg4k0hdgvxf5zdgssl1725ya1-unpinned-file.txt10872026/10/14 16:42:13 INFO Vacuumed table table=pending_closures10882026/10/14 16:42:13 INFO Vacuumed table table=pending_objects10892026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads10902026/10/14 16:42:13 INFO Vacuumed table table=closures10912026/10/14 16:42:13 INFO Vacuumed table table=objects1092--- PASS: TestSweepRechecksPendingAfterLocking (0.95s)1093=== CONT TestRedundantMultipartUpload10942026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures1095--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.98s)1096=== CONT TestClientPushesUseOnePush10972026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes10982026/10/14 16:42:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10992026/10/14 16:42:13 INFO Uploading d2f1fziyczicmnbfydyabmb7sspx570g-pinned-file.txt (128B)11002026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures11012026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11022026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11032026/10/14 16:42:13 WARN Failed to register uploaded object key=d2f1fziyczicmnbfydyabmb7sspx570g.ls error="server returned 404: 404 page not found\n"11042026/10/14 16:42:13 INFO Signed narinfos id=1 count=111052026/10/14 16:42:13 INFO Uploading 1 narinfos11062026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/1/complete11072026/10/14 16:42:13 WARN Failed to register uploaded object key=d2f1fziyczicmnbfydyabmb7sspx570g.narinfo error="server returned 404: 404 page not found\n"11082026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011092026/10/14 16:42:13 WARN Force mode enabled - objects will be deleted immediately without grace period11102026/10/14 16:42:13 INFO Completed push id=1 objects=3 duration=10.128604ms11112026/10/14 16:42:13 INFO Upload complete. (71ms)11122026/10/14 16:42:13 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11132026/10/14 16:42:13 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11142026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures1115--- PASS: TestFailedS3DeleteKeepsTombstone (1.06s)1116=== CONT TestPush_SignsNarinfosOfItsPendingObjects11172026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011182026/10/14 16:42:13 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=011192026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes11202026/10/14 16:42:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11212026/10/14 16:42:13 INFO Vacuumed table table=pending_closures11222026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011232026/10/14 16:42:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11242026/10/14 16:42:13 INFO Uploading j0qnmc5yg4k0hdgvxf5zdgssl1725ya1-unpinned-file.txt (128B)11252026/10/14 16:42:13 INFO Vacuumed table table=pending_objects11262026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads1127--- PASS: TestPushWaitsForSweepHoldingRow (1.12s)1128=== CONT TestPush_CompleteCommitsEveryRoot11292026/10/14 16:42:13 INFO Vacuumed table table=closures11302026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11322026/10/14 16:42:13 WARN Failed to register uploaded object key=j0qnmc5yg4k0hdgvxf5zdgssl1725ya1.ls error="server returned 404: 404 page not found\n"11332026/10/14 16:42:13 INFO Signed narinfos id=2 count=111342026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11352026/10/14 16:42:13 INFO Vacuumed table table=objects11362026/10/14 16:42:13 INFO Uploading 1 narinfos11372026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011382026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/2/complete11392026/10/14 16:42:13 WARN Failed to register uploaded object key=j0qnmc5yg4k0hdgvxf5zdgssl1725ya1.narinfo error="server returned 404: 404 page not found\n"11402026/10/14 16:42:13 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/14 16:42:13 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=011422026/10/14 16:42:13 INFO Completed push id=2 objects=3 duration=2.274619ms11432026/10/14 16:42:13 INFO Upload complete. (57ms)11442026/10/14 16:42:13 INFO Vacuumed table table=pending_closures11452026/10/14 16:42:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11462026/10/14 16:42:13 INFO Vacuumed table table=pending_objects11472026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads11482026/10/14 16:42:13 INFO Vacuumed table table=closures11492026/10/14 16:42:13 INFO Aborted multipart uploads count=1 kept=011502026/10/14 16:42:13 INFO Vacuumed table table=objects11512026/10/14 16:42:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1152--- PASS: TestPushDedupSurvivesConcurrentGC (1.08s)1153=== CONT TestPush_RepeatedRootCommitsOnce11542026-10-14 16:42:13.271 UTC [715] ERROR: Closure does not exist: id=111552026-10-14 16:42:13.271 UTC [715] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11562026-10-14 16:42:13.271 UTC [715] STATEMENT: -- name: CommitPendingClosure :one1157 SELECT commit_pending_closure($1::bigint)::bigint1158 1159--- PASS: TestService_cleanupPendingClosuresHandler (0.77s)1160=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11612026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011622026/10/14 16:42:13 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/10/14 16:42:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures11642026/10/14 16:42:13 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=011652026/10/14 16:42:13 INFO Garbage collection started11662026/10/14 16:42:13 INFO Vacuumed table table=pending_closures11672026/10/14 16:42:13 INFO Vacuumed table table=pending_objects11682026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads11692026/10/14 16:42:13 INFO Vacuumed table table=closures11702026/10/14 16:42:13 INFO Vacuumed table table=objects1171--- PASS: TestGCMetrics (0.80s)1172=== CONT TestPush_RejectsBadRequests11732026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=011742026/10/14 16:42:13 WARN Force mode enabled - objects will be deleted immediately without grace period11752026/10/14 16:42:13 INFO lead: acquired remote=192.0.2.1:123411762026/10/14 16:42:13 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=011772026/10/14 16:42:13 INFO Vacuumed table table=pending_closures11782026/10/14 16:42:13 INFO Vacuumed table table=pending_objects11792026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads11802026/10/14 16:42:13 INFO Vacuumed table table=closures11812026/10/14 16:42:13 INFO Vacuumed table table=objects11822026/10/14 16:42:13 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1183--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.68s)1184=== CONT TestReadRedirectUsesPublicS3URL11852026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/14 16:42:13 INFO lead: acquired remote=192.0.2.1:123411872026/10/14 16:42:13 INFO lead: released remote=192.0.2.1:12341188--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.61s)1189=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11902026/10/14 16:42:13 INFO lead: acquired remote=192.0.2.1:123411912026/10/14 16:42:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1192--- PASS: TestService_Rustfstest (0.64s)1193=== CONT TestReadProxyRangeRequest11942026/10/14 16:42:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11952026/10/14 16:42:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLmVkZTQyM2MwLWE0ZTYtNDQ4MC1hMTczLTYyOTU1YjEwZjc0MHgxNzkxOTk2MTMzMDUwODkzMDY3 parts=1011962026/10/14 16:42:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11972026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures11982026/10/14 16:42:13 INFO Completed upload id=1 objects=2 duration=5.526906ms11992026/10/14 16:42:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012002026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12012026/10/14 16:42:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures12022026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=012032026/10/14 16:42:13 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12042026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12052026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures1206--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.64s)1207=== CONT TestPush_RootsAreLockedInByteOrder12082026/10/14 16:42:13 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=01209--- PASS: TestGCBugBareHashReferences (0.99s)1210=== CONT TestPush_CompleteWaitsForCleanupOfThePush12112026/10/14 16:42:13 INFO Vacuumed table table=pending_closures12122026/10/14 16:42:13 INFO Vacuumed table table=pending_objects12132026/10/14 16:42:13 INFO Vacuumed table table=multipart_uploads12142026/10/14 16:42:13 INFO Vacuumed table table=closures12152026/10/14 16:42:13 INFO Vacuumed table table=objects12162026/10/14 16:42:13 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001217--- PASS: TestService_createPendingClosureHandler (1.45s)1218=== CONT TestObjectStatsLargeCommit12192026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/14 16:42:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12212026/10/14 16:42:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12222026/10/14 16:42:13 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLjA2NGY2MWM3LTM0NzgtNDc5MS1iZDc0LTFjMzZhZjdmYjFkNHgxNzkxOTk2MTMzNjA4NTgyMTgw12232026/10/14 16:42:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLmExYzM1MDJjLWMyMmEtNDc4Yi1iMDZhLWNlNDZiNWQ5MWZjM3gxNzkxOTk2MTMzMTkwNzc4MDY1 parts=1012242026/10/14 16:42:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12252026/10/14 16:42:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLjA2NGY2MWM3LTM0NzgtNDc5MS1iZDc0LTFjMzZhZjdmYjFkNHgxNzkxOTk2MTMzNjA4NTgyMTgw parts=11226--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)1227=== CONT TestParseSingleRange1228=== RUN TestParseSingleRange/none1229=== PAUSE TestParseSingleRange/none1230=== RUN TestParseSingleRange/unknown_unit1231=== PAUSE TestParseSingleRange/unknown_unit1232=== RUN TestParseSingleRange/multi-range_ignored1233=== PAUSE TestParseSingleRange/multi-range_ignored1234=== RUN TestParseSingleRange/malformed_no_dash1235=== PAUSE TestParseSingleRange/malformed_no_dash1236=== RUN TestParseSingleRange/malformed_both_empty1237=== PAUSE TestParseSingleRange/malformed_both_empty1238=== RUN TestParseSingleRange/malformed_end_before_start1239=== PAUSE TestParseSingleRange/malformed_end_before_start1240=== RUN TestParseSingleRange/closed1241=== PAUSE TestParseSingleRange/closed1242=== RUN TestParseSingleRange/open-ended1243=== PAUSE TestParseSingleRange/open-ended1244=== RUN TestParseSingleRange/end_clamped_to_size1245=== PAUSE TestParseSingleRange/end_clamped_to_size1246=== RUN TestParseSingleRange/suffix1247=== PAUSE TestParseSingleRange/suffix1248=== RUN TestParseSingleRange/suffix_exceeds_size1249=== PAUSE TestParseSingleRange/suffix_exceeds_size1250=== RUN TestParseSingleRange/single_byte1251=== PAUSE TestParseSingleRange/single_byte1252=== RUN TestParseSingleRange/start_past_EOF1253=== PAUSE TestParseSingleRange/start_past_EOF1254=== RUN TestParseSingleRange/start_far_past_EOF1255=== PAUSE TestParseSingleRange/start_far_past_EOF1256=== CONT TestPresentNotReportedWhileGCDeletesClosure1257=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1258=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1259=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1260=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1261=== CONT TestReadRedirectNar12622026/10/14 16:42:13 INFO Completed upload id=1 objects=2 duration=6.010036ms12632026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12662026/10/14 16:42:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12672026/10/14 16:42:13 WARN Found objects in DB but missing from S3, will re-upload count=11268--- PASS: TestService_verifyS3Integrity (1.54s)1269=== CONT TestPresentRefreshesOnlyStaleClosures12702026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12712026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes12722026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12732026/10/14 16:42:13 INFO Signed narinfos id=1 count=112742026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12752026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12762026/10/14 16:42:13 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12772026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12782026/10/14 16:42:13 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12792026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12802026/10/14 16:42:13 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112812026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12822026/10/14 16:42:13 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1283--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.56s)1284=== CONT TestReadProxyDisabled12852026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes12862026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes12872026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1288--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.82s)1289=== CONT TestPresentReportsOnlyClosureRoots12902026/10/14 16:42:13 INFO Completed push id=1 objects=6 duration=7.887275ms1291--- PASS: TestPush_CompleteCommitsEveryRoot (0.55s)1292=== CONT TestReadProxyRootRedirectsToIndexHTML1293--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.54s)1294=== CONT TestReadProxyConditionalGet12952026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes12962026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12972026/10/14 16:42:13 INFO Received uploads request method=POST path=/api/pending_closures12982026/10/14 16:42:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12992026/10/14 16:42:13 INFO Uploading 2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj-shared-dep (136B)13002026/10/14 16:42:13 INFO Uploading 0rwg36zjnnxsv97d15i49kq7r4kv4pg3-b (216B)13012026/10/14 16:42:13 WARN Failed to register uploaded object key=3w7kz2md05a1yin6kb4pwaqfv4bypb3s.ls error="server returned 404: 404 page not found\n"13022026/10/14 16:42:13 WARN Failed to register uploaded object key=0rwg36zjnnxsv97d15i49kq7r4kv4pg3.ls error="server returned 404: 404 page not found\n"13032026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13042026/10/14 16:42:13 WARN Failed to register uploaded object key=2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj.ls error="server returned 404: 404 page not found\n"13052026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13062026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/0kw5i6na97vyq56qyvwdpwgvsp0p0i9z3r5dkdjfc2pany3ba1f8.nar.zst error="server returned 404: 404 page not found\n"13072026/10/14 16:42:13 INFO Signed narinfos id=1 count=213082026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13092026/10/14 16:42:13 INFO Signed narinfos id=2 count=213102026/10/14 16:42:13 INFO Uploading 4 narinfos13112026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/1/complete13122026/10/14 16:42:13 WARN Failed to register uploaded object key=0rwg36zjnnxsv97d15i49kq7r4kv4pg3.narinfo error="server returned 404: 404 page not found\n"13132026/10/14 16:42:13 WARN Failed to register uploaded object key=3w7kz2md05a1yin6kb4pwaqfv4bypb3s.narinfo error="server returned 404: 404 page not found\n"13142026/10/14 16:42:13 WARN Failed to register uploaded object key=2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj.narinfo error="server returned 404: 404 page not found\n"1315=== RUN TestPush_RejectsBadRequests/no_objects1316=== PAUSE TestPush_RejectsBadRequests/no_objects1317=== RUN TestPush_RejectsBadRequests/bad_root1318=== PAUSE TestPush_RejectsBadRequests/bad_root1319=== RUN TestPush_RejectsBadRequests/root_not_in_objects1320=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1321=== RUN TestPush_RejectsBadRequests/no_roots1322=== PAUSE TestPush_RejectsBadRequests/no_roots1323=== CONT TestCreatePin_ReservedPins13242026/10/14 16:42:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13252026/10/14 16:42:13 WARN Failed to register uploaded object key=2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj.narinfo error="server returned 404: 404 page not found\n"13262026/10/14 16:42:13 INFO Completed push id=1 objects=4 duration=8.980504ms1327--- PASS: TestPush_RepeatedRootCommitsOnce (0.58s)1328=== CONT TestReadProxyOutlastsServerWriteTimeout13292026/10/14 16:42:13 INFO Completed upload id=1 objects=6 duration=8.518424ms13302026/10/14 16:42:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13312026/10/14 16:42:13 INFO Completed upload id=2 objects=6 duration=2.864198ms13322026/10/14 16:42:13 INFO Upload complete. (73ms)1333=== NAME TestClientFallsBackToClosures1334 client_pushes_test.go:112: Retrieved narinfo from S3:1335 StorePath: /build/TestClientFallsBackToClosures1427559320/001/store/2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj-shared-dep1336 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1337 Compression: zstd1338 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821339 NarSize: 1361340 References: 1341 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1342 client_pushes_test.go:112: Retrieved narinfo from S3:1343 StorePath: /build/TestClientFallsBackToClosures1427559320/001/store/3w7kz2md05a1yin6kb4pwaqfv4bypb3s-a1344 URL: nar/0kw5i6na97vyq56qyvwdpwgvsp0p0i9z3r5dkdjfc2pany3ba1f8.nar.zst1345 Compression: zstd1346 NarHash: sha256:0kw5i6na97vyq56qyvwdpwgvsp0p0i9z3r5dkdjfc2pany3ba1f81347 NarSize: 2161348 References: /build/TestClientFallsBackToClosures1427559320/001/store/2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj-shared-dep1349 CA: text:sha256:155fvmqjlfw233l8vls6yq3n5bcj8cgzvlddkw8m8vg9bgwj76w91350 client_pushes_test.go:112: Retrieved narinfo from S3:1351 StorePath: /build/TestClientFallsBackToClosures1427559320/001/store/0rwg36zjnnxsv97d15i49kq7r4kv4pg3-b1352 URL: nar/0kw5i6na97vyq56qyvwdpwgvsp0p0i9z3r5dkdjfc2pany3ba1f8.nar.zst1353 Compression: zstd1354 NarHash: sha256:0kw5i6na97vyq56qyvwdpwgvsp0p0i9z3r5dkdjfc2pany3ba1f81355 NarSize: 2161356 References: /build/TestClientFallsBackToClosures1427559320/001/store/2ahvlkh7nwvyzgaqm17mxsdy8fqxkmjj-shared-dep1357 CA: text:sha256:155fvmqjlfw233l8vls6yq3n5bcj8cgzvlddkw8m8vg9bgwj76w91358--- PASS: TestClientFallsBackToClosures (0.83s)1359=== CONT TestOrphanedObjectsGCStressTest1360--- PASS: TestReadRedirectUsesPublicS3URL (0.51s)1361=== CONT TestReadProxyHead13622026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes13632026/10/14 16:42:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13642026/10/14 16:42:13 INFO Uploading kaf8yyswcw373i8hfm24jim39ix27jkm-a (208B)13652026/10/14 16:42:13 INFO Uploading xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs-shared-dep (136B)13662026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes13672026/10/14 16:42:13 WARN Failed to register uploaded object key=xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs.ls error="server returned 404: 404 page not found\n"13682026/10/14 16:42:13 WARN Failed to register uploaded object key=i1z3rr3fpksp1nbpkvy5cifw9i6wacsm.ls error="server returned 404: 404 page not found\n"13692026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13702026/10/14 16:42:13 WARN Failed to register uploaded object key=kaf8yyswcw373i8hfm24jim39ix27jkm.ls error="server returned 404: 404 page not found\n"13712026/10/14 16:42:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13722026/10/14 16:42:13 WARN Failed to register uploaded object key=nar/1pc1m2g2yv975bya7nrkrbwd58c3dgbwj6pa8wcyw0jq91z17dhw.nar.zst error="server returned 404: 404 page not found\n"13732026/10/14 16:42:13 INFO Signed narinfos id=1 count=313742026/10/14 16:42:13 INFO Uploading 3 narinfos13752026/10/14 16:42:13 WARN Failed to register uploaded object key=xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs.narinfo error="server returned 404: 404 page not found\n"13762026/10/14 16:42:13 WARN Failed to register uploaded object key=i1z3rr3fpksp1nbpkvy5cifw9i6wacsm.narinfo error="server returned 404: 404 page not found\n"13772026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/1/complete13782026/10/14 16:42:13 WARN Failed to register uploaded object key=kaf8yyswcw373i8hfm24jim39ix27jkm.narinfo error="server returned 404: 404 page not found\n"13792026/10/14 16:42:13 INFO Completed push id=1 objects=8 duration=5.717347ms13802026/10/14 16:42:13 INFO Upload complete. (70ms)1381=== NAME TestClientPushesUseOnePush1382 client_pushes_test.go:97: Retrieved narinfo from S3:1383 StorePath: /build/TestClientPushesUseOnePush335455132/001/store/xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs-shared-dep1384 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1385 Compression: zstd1386 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821387 NarSize: 1361388 References: 1389 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1390 client_pushes_test.go:97: Retrieved narinfo from S3:1391 StorePath: /build/TestClientPushesUseOnePush335455132/001/store/kaf8yyswcw373i8hfm24jim39ix27jkm-a1392 URL: nar/1pc1m2g2yv975bya7nrkrbwd58c3dgbwj6pa8wcyw0jq91z17dhw.nar.zst1393 Compression: zstd1394 NarHash: sha256:1pc1m2g2yv975bya7nrkrbwd58c3dgbwj6pa8wcyw0jq91z17dhw1395 NarSize: 2081396 References: /build/TestClientPushesUseOnePush335455132/001/store/xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs-shared-dep1397 CA: text:sha256:0vbismgxjzfhs6mmynv0haciczwxpq3x5ghia5kwszi0qmhggbds13982026/10/14 16:42:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1399 client_pushes_test.go:97: Retrieved narinfo from S3:1400 StorePath: /build/TestClientPushesUseOnePush335455132/001/store/i1z3rr3fpksp1nbpkvy5cifw9i6wacsm-b1401 URL: nar/1pc1m2g2yv975bya7nrkrbwd58c3dgbwj6pa8wcyw0jq91z17dhw.nar.zst1402 Compression: zstd1403 NarHash: sha256:1pc1m2g2yv975bya7nrkrbwd58c3dgbwj6pa8wcyw0jq91z17dhw1404 NarSize: 2081405 References: /build/TestClientPushesUseOnePush335455132/001/store/xz3yvnzfnfi8nrmqc2xjwqapdcq0fyjs-shared-dep1406 CA: text:sha256:0vbismgxjzfhs6mmynv0haciczwxpq3x5ghia5kwszi0qmhggbds1407--- PASS: TestClientPushesUseOnePush (0.82s)1408=== CONT TestOrphanedObjectsGC14092026/10/14 16:42:13 INFO Completed push id=1 objects=4 duration=9.820243ms14102026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes1411--- PASS: TestReadProxyRangeRequest (0.44s)1412=== CONT TestReadProxyInvalidPath14132026/10/14 16:42:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38025/oidc14142026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes14152026/10/14 16:42:13 INFO Received push request method=POST path=/api/pushes14162026-10-14 16:42:13.994 UTC [1253] ERROR: could not obtain lock on row in relation "closures"14172026-10-14 16:42:13.994 UTC [1253] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14182026-10-14 16:42:13.995 UTC [1253] ERROR: could not obtain lock on row in relation "closures"14192026-10-14 16:42:13.995 UTC [1253] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14202026-10-14 16:42:13.995 UTC [1253] ERROR: could not obtain lock on row in relation "closures"14212026-10-14 16:42:13.995 UTC [1253] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14222026-10-14 16:42:13.995 UTC [1253] ERROR: could not obtain lock on row in relation "closures"14232026-10-14 16:42:13.995 UTC [1253] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14242026-10-14 16:42:13.996 UTC [1253] ERROR: could not obtain lock on row in relation "closures"14252026-10-14 16:42:13.996 UTC [1253] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14262026/10/14 16:42:13 INFO Aborted multipart uploads count=0 kept=014272026/10/14 16:42:14 WARN Force mode enabled - objects will be deleted immediately without grace period1428--- PASS: TestPush_RootsAreLockedInByteOrder (0.46s)1429=== CONT TestMultipartCleanup14302026/10/14 16:42:14 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=014312026/10/14 16:42:14 INFO Vacuumed table table=pending_closures14322026/10/14 16:42:14 INFO Vacuumed table table=pending_objects14332026/10/14 16:42:14 INFO Vacuumed table table=multipart_uploads14342026/10/14 16:42:14 INFO Vacuumed table table=closures14352026/10/14 16:42:14 INFO Vacuumed table table=objects14362026/10/14 16:42:14 INFO Received complete push request method=POST path=/api/pushes/2/complete14372026/10/14 16:42:14 INFO Completed push id=2 objects=4 duration=3.693768ms1438--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.61s)1439=== CONT TestReadProxy4041440--- PASS: TestReadRedirectNar (0.39s)1441=== CONT TestObjectStatsTrigger1442--- PASS: TestPresentRefreshesOnlyStaleClosures (0.41s)1443=== CONT TestReadProxyNarStreaming1444--- PASS: TestReadProxyDisabled (0.34s)1445=== CONT TestPendingCleanupUsesOneCutoff14462026/10/14 16:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1447--- PASS: TestDeleteClosuresRacingPins (1.13s)1448=== CONT TestReadProxyContentNegotiation14492026/10/14 16:42:14 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLjM3NTdiNTNmLTZmMjQtNDA1Yi05MjdiLTQ5NGM4Njc5ZmMyZXgxNzkxOTk2MTMzNTUyMDE0Njc3 parts=1214502026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures1451--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.33s)1452=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1453--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.20s)1454=== CONT TestReadProxyNarinfoAlreadyDecompressed1455--- PASS: TestReadProxyConditionalGet (0.35s)1456=== CONT TestReadProxyNarinfo1457--- PASS: TestPresentReportsOnlyClosureRoots (0.40s)1458=== CONT TestIsValidCachePath1459=== RUN TestIsValidCachePath/narinfo1460=== PAUSE TestIsValidCachePath/narinfo1461=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1462=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1463=== RUN TestIsValidCachePath/nar_zst1464=== PAUSE TestIsValidCachePath/nar_zst1465=== RUN TestIsValidCachePath/nar_xz1466=== PAUSE TestIsValidCachePath/nar_xz1467=== RUN TestIsValidCachePath/nar_bz21468=== PAUSE TestIsValidCachePath/nar_bz21469=== RUN TestIsValidCachePath/nar_uncompressed1470=== PAUSE TestIsValidCachePath/nar_uncompressed1471=== RUN TestIsValidCachePath/ls1472=== PAUSE TestIsValidCachePath/ls1473=== RUN TestIsValidCachePath/log1474=== PAUSE TestIsValidCachePath/log1475=== RUN TestIsValidCachePath/realisation1476=== PAUSE TestIsValidCachePath/realisation1477=== RUN TestIsValidCachePath/nix-cache-info1478=== PAUSE TestIsValidCachePath/nix-cache-info1479=== RUN TestIsValidCachePath/index.html1480=== PAUSE TestIsValidCachePath/index.html1481=== RUN TestIsValidCachePath/traversal_parent1482=== PAUSE TestIsValidCachePath/traversal_parent1483=== RUN TestIsValidCachePath/traversal_in_middle1484=== PAUSE TestIsValidCachePath/traversal_in_middle1485=== RUN TestIsValidCachePath/invalid_char_e1486=== PAUSE TestIsValidCachePath/invalid_char_e1487=== RUN TestIsValidCachePath/invalid_char_u1488=== PAUSE TestIsValidCachePath/invalid_char_u1489=== RUN TestIsValidCachePath/random_path1490=== PAUSE TestIsValidCachePath/random_path1491=== RUN TestIsValidCachePath/empty1492=== PAUSE TestIsValidCachePath/empty1493=== RUN TestIsValidCachePath/leading_slash1494=== PAUSE TestIsValidCachePath/leading_slash1495=== RUN TestIsValidCachePath/wrong_extension1496=== PAUSE TestIsValidCachePath/wrong_extension1497=== RUN TestIsValidCachePath/short_hash1498=== PAUSE TestIsValidCachePath/short_hash1499=== CONT TestService_NativeMTLS15002026/10/14 16:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15012026/10/14 16:42:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLmU1NjhiZjlhLTA3M2EtNDEzNi1iZDcxLTNiMWY1NGMxZDllZHgxNzkxOTk2MTMzNjcyMDEzMjI4 parts=1215022026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures15032026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures15042026-10-14 16:42:14.298 UTC [1257] ERROR: Push does not exist: id=115052026-10-14 16:42:14.298 UTC [1257] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15062026-10-14 16:42:14.298 UTC [1257] STATEMENT: SELECT commit_push($1)1507--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.75s)1508=== CONT TestServerTLSConfig1509=== RUN TestServerTLSConfig/no_client_CA1510=== PAUSE TestServerTLSConfig/no_client_CA1511=== RUN TestServerTLSConfig/missing_CA_file1512=== PAUSE TestServerTLSConfig/missing_CA_file1513=== RUN TestServerTLSConfig/not_a_PEM_file1514=== PAUSE TestServerTLSConfig/not_a_PEM_file1515=== CONT TestCacheStatsHandler1516--- PASS: TestReadProxyHead (0.43s)1517=== CONT TestClientSharedPathCommittedMidPush1518--- PASS: TestReadProxyInvalidPath (0.40s)1519=== CONT TestService_AuthMiddleware_OIDC15202026/10/14 16:42:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35419/oidc15212026/10/14 16:42:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15222026/10/14 16:42:14 WARN Refused reserved pin name=worker-x86_64-linux15232026/10/14 16:42:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15242026/10/14 16:42:14 INFO Received create pin request method=POST path=/api/pins/my-app15252026/10/14 16:42:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1526--- PASS: TestCreatePin_ReservedPins (0.53s)1527=== CONT TestClientWithDependencies15282026/10/14 16:42:14 INFO lead: released remote=192.0.2.1:12341529--- PASS: TestLeadEndsOnShutdown (1.68s)1530=== CONT TestCacheConfigHandler1531=== RUN TestCacheConfigHandler/full_config,_no_issuer1532=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1533=== RUN TestCacheConfigHandler/no_cache_url_configured1534=== PAUSE TestCacheConfigHandler/no_cache_url_configured1535=== RUN TestCacheConfigHandler/no_signing_keys1536=== PAUSE TestCacheConfigHandler/no_signing_keys1537=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1538=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1539=== CONT TestService_ReadScope_PublicByDefault15402026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures1541--- PASS: TestReadProxy404 (0.40s)1542=== CONT TestClientMultipleUploads1543--- PASS: TestObjectStatsTrigger (0.42s)1544=== CONT TestClientIntegration1545--- PASS: TestReadProxyNarStreaming (0.40s)1546=== CONT TestService_RequireScope_OIDC15472026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures15482026/10/14 16:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures15492026/10/14 16:42:14 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket68/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15502026/10/14 16:42:14 INFO Aborted multipart uploads count=0 kept=115512026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures15522026/10/14 16:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures15532026/10/14 16:42:14 INFO Aborted multipart uploads count=1 kept=01554--- PASS: TestMultipartCleanup (0.53s)1555=== CONT TestClientErrorHandling1556=== RUN TestClientErrorHandling/InvalidStorePath1557=== PAUSE TestClientErrorHandling/InvalidStorePath1558=== RUN TestClientErrorHandling/InvalidAuthToken1559=== PAUSE TestClientErrorHandling/InvalidAuthToken1560=== RUN TestClientErrorHandling/ServerNotAvailable1561=== PAUSE TestClientErrorHandling/ServerNotAvailable1562=== CONT TestClientCADerivations15632026/10/14 16:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures1564--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.44s)1565=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15662026/10/14 16:42:14 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45895/oidc15672026/10/14 16:42:14 INFO Received uploads request method=POST path=/api/pending_closures1568--- PASS: TestReadProxyContentNegotiation (0.47s)1569=== CONT TestService_ReadAuthMiddleware1570--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.48s)1571=== CONT TestService_AuthMiddleware_MTLSProxyHeader15722026/10/14 16:42:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15732026/10/14 16:42:14 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1574--- PASS: TestService_NativeMTLS (0.44s)1575=== CONT TestMetricsCommit1576=== NAME TestOrphanedObjectsGC1577 orphaned_objects_gc_test.go:287: GC Test Summary:1578 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1579 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1580 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1581 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1582 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1583--- PASS: TestOrphanedObjectsGC (0.75s)1584=== CONT TestGCEndsOnShutdown/before_the_run1585--- PASS: TestCacheStatsHandler (0.39s)1586=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15872026/10/14 16:42:14 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1588--- PASS: TestReadProxyNarinfo (0.55s)1589=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15902026/10/14 16:42:14 INFO lead: released remote=192.0.2.1:12341591=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1592=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1593=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1594=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1595=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1596=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1597=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1598=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1599=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16002026/10/14 16:42:14 INFO lead: acquired remote=192.0.2.1:12341601--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1602=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16032026/10/14 16:42:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1604=== NAME TestClientWithDependencies1605 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies488022590/001/store/gz9ywq28b5q5a3h0slmdwshmfbfvbwrx-test-script16062026/10/14 16:42:14 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLjBhNDI2Njg1LWRiY2EtNDU5MS1iNTU3LTc1MWNmMGUyMWU5MngxNzkxOTk2MTM0Mjc3MTM0OTIw error="Get \"http://127.0.0.1:1/bucket43/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"16072026/10/14 16:42:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODlkODM4YmQtYmNhNy00M2Q4LTk5ODEtZmM4M2JlMWFhMjAxLjRkYzY2MTdkLTVlMWItNGFjZC04M2FkLWI3MTQ5Nzk0ZWM0NXgxNzkxOTk2MTM0MjU4MDkwNzYy parts=1216082026/10/14 16:42:14 INFO Received cleanup request method=DELETE path=/api/pending_closures16092026/10/14 16:42:14 INFO Aborted multipart uploads count=1 kept=01610--- PASS: TestRedundantMultipartUpload (1.77s)1611=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16122026/10/14 16:42:14 INFO Received uploads request method=POST path=/1613=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key16142026/10/14 16:42:14 INFO Received complete multipart upload request method=POST path=/1615=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16162026/10/14 16:42:14 INFO Received uploads request method=POST path=/1617=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16182026/10/14 16:42:14 INFO Received request for more parts method=POST path=/1619--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1620 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1621 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1622 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1623 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1624=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16252026/10/14 16:42:14 INFO Received complete multipart upload request method=POST path=/1626=== NAME TestClientMultipleUploads1627 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2549568477/001/store/laspv6gagrrqyivzqnfr2lpiyq7s1rzy-test-file-0.txt16282026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes16292026/10/14 16:42:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16302026/10/14 16:42:14 INFO Uploading k9jdw41k1wfw60nxms9gkpqdq8iingbl-top (224B)16312026/10/14 16:42:14 INFO Uploading wj4dwxmi49zjfz2bpkqjr44zjsnfxxsh-shared-dep (136B)1632=== NAME TestClientWithDependencies1633 client_integration_test.go:615: Found 1 dependencies (including self)16342026/10/14 16:42:14 WARN Failed to register uploaded object key=wj4dwxmi49zjfz2bpkqjr44zjsnfxxsh.ls error="server returned 404: 404 page not found\n"16352026/10/14 16:42:14 WARN Failed to register uploaded object key=k9jdw41k1wfw60nxms9gkpqdq8iingbl.ls error="server returned 404: 404 page not found\n"16362026/10/14 16:42:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16372026/10/14 16:42:14 WARN Failed to register uploaded object key=nar/1xwawq3in6knsnapiw3nvvk2h4wl3rvjrdlkqpnl0x6sipxbjiyh.nar.zst error="server returned 404: 404 page not found\n"16382026/10/14 16:42:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16392026/10/14 16:42:14 INFO Signed narinfos id=1 count=216402026/10/14 16:42:14 INFO Uploading 2 narinfos16412026/10/14 16:42:14 WARN Failed to register uploaded object key=k9jdw41k1wfw60nxms9gkpqdq8iingbl.narinfo error="server returned 404: 404 page not found\n"16422026/10/14 16:42:14 INFO Received complete push request method=POST path=/api/pushes/1/complete16432026/10/14 16:42:14 WARN Failed to register uploaded object key=wj4dwxmi49zjfz2bpkqjr44zjsnfxxsh.narinfo error="server returned 404: 404 page not found\n"1644=== NAME TestClientIntegration1645 client_integration_test.go:286: Created store path: /build/TestClientIntegration1400385757/002/store/nrzyxz43jkgc98ifwn70sf0rha4lrcsn-test-file.txt16462026/10/14 16:42:14 INFO Completed push id=1 objects=6 duration=5.247476ms16472026/10/14 16:42:14 INFO Upload complete. (71ms)1648=== NAME TestClientSharedPathCommittedMidPush1649 client_integration_test.go:680: Retrieved narinfo from S3:1650 StorePath: /build/TestClientSharedPathCommittedMidPush1780566976/001/store/wj4dwxmi49zjfz2bpkqjr44zjsnfxxsh-shared-dep1651 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1652 Compression: zstd1653 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821654 NarSize: 1361655 References: 1656 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1657=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16582026/10/14 16:42:14 INFO Received uploads request method=POST path=/1659--- PASS: TestObjectStatsLargeCommit (1.31s)1660=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16612026/10/14 16:42:14 INFO Received request for more parts method=POST path=/1662=== NAME TestClientSharedPathCommittedMidPush1663 client_integration_test.go:680: Retrieved narinfo from S3:1664 StorePath: /build/TestClientSharedPathCommittedMidPush1780566976/001/store/k9jdw41k1wfw60nxms9gkpqdq8iingbl-top1665 URL: nar/1xwawq3in6knsnapiw3nvvk2h4wl3rvjrdlkqpnl0x6sipxbjiyh.nar.zst1666 Compression: zstd1667 NarHash: sha256:1xwawq3in6knsnapiw3nvvk2h4wl3rvjrdlkqpnl0x6sipxbjiyh1668 NarSize: 2241669 References: /build/TestClientSharedPathCommittedMidPush1780566976/001/store/wj4dwxmi49zjfz2bpkqjr44zjsnfxxsh-shared-dep1670 CA: text:sha256:1y6j52dsrx8n7yjbzwwzg6m51fyj8wi80swkqs02h3lyf8cdcchn1671=== NAME TestClientMultipleUploads1672 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2549568477/001/store/n9vgsnfcvs5mkbph958dlqdljlahvhn0-test-file-1.txt16732026/10/14 16:42:14 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16742026/10/14 16:42:14 WARN mTLS auth: bound subjects configured but subject DN unavailable16752026/10/14 16:42:14 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1676--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1677=== CONT TestIsValidUploadKey/narinfo1678=== CONT TestIsValidUploadKey/empty_key1679=== CONT TestIsValidUploadKey/absolute1680=== CONT TestIsValidUploadKey/traversal_nar1681=== CONT TestIsValidUploadKey/traversal1682=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1683=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1684=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1685=== CONT TestIsValidUploadKey/index.html1686=== CONT TestIsValidUploadKey/nix-cache-info1687=== CONT TestIsValidUploadKey/realisation_plus_in_output1688=== CONT TestIsValidUploadKey/realisation1689=== CONT TestIsValidUploadKey/build_log_equals1690=== CONT TestIsValidUploadKey/build_log_question_mark1691=== CONT TestIsValidUploadKey/build_log_plus_in_name1692=== CONT TestIsValidUploadKey/build_log_home-manager_file1693=== CONT TestIsValidUploadKey/unknown_type1694=== CONT TestIsValidUploadKey/build_log1695=== CONT TestIsValidUploadKey/listing1696=== CONT TestIsValidUploadKey/nar_plain1697=== CONT TestIsValidUploadKey/nar_xz1698=== CONT TestIsValidUploadKey/nar_zst1699=== CONT TestPendingClosureWriteTimeout/empty1700=== CONT TestPendingClosureWriteTimeout/670k_objects1701=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1702--- PASS: TestIsValidUploadKey (0.00s)1703 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1704 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1705 --- PASS: TestIsValidUploadKey/absolute (0.00s)1706 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1707 --- PASS: TestIsValidUploadKey/traversal (0.00s)1708 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1709 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1710 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1711 --- PASS: TestIsValidUploadKey/index.html (0.00s)1712 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1713 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1714 --- PASS: TestIsValidUploadKey/realisation (0.00s)1715 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1716 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1717 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1718 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1719 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1720 --- PASS: TestIsValidUploadKey/build_log (0.00s)1721 --- PASS: TestIsValidUploadKey/listing (0.00s)1722 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1723 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1724 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1725--- PASS: TestClientSharedPathCommittedMidPush (0.58s)1726=== CONT TestPendingClosureWriteTimeout/400_objects1727=== CONT TestProxyWriteTimeout/narinfo1728=== CONT TestProxyWriteTimeout/10_GiB_nar1729=== CONT TestProxyWriteTimeout/unknown_size1730=== CONT TestProxyWriteTimeout/1_GiB_nar1731--- PASS: TestProxyWriteTimeout (0.00s)1732 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1733 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1734 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1735 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1736=== CONT TestResolveDBConnectionString/flag_wins1737=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1738=== CONT TestResolveDBConnectionString/nothing_configured1739=== CONT TestResolveDBConnectionString/missing_file_is_an_error1740=== CONT TestResolveDBConnectionString/file_when_flag_empty1741=== CONT TestParseSingleRange/none1742=== CONT TestParseSingleRange/open-ended1743=== CONT TestParseSingleRange/start_far_past_EOF1744=== CONT TestParseSingleRange/start_past_EOF1745=== CONT TestParseSingleRange/single_byte1746=== CONT TestParseSingleRange/suffix_exceeds_size1747=== CONT TestParseSingleRange/suffix1748=== CONT TestParseSingleRange/end_clamped_to_size1749=== CONT TestParseSingleRange/malformed_both_empty1750=== CONT TestParseSingleRange/closed1751=== CONT TestParseSingleRange/malformed_end_before_start1752=== CONT TestParseSingleRange/multi-range_ignored1753=== CONT TestParseSingleRange/malformed_no_dash1754=== CONT TestParseSingleRange/unknown_unit1755=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1756--- PASS: TestResolveDBConnectionString (0.00s)1757 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1758 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1759 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1760 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1761 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1762--- PASS: TestParseSingleRange (0.00s)1763 --- PASS: TestParseSingleRange/none (0.00s)1764 --- PASS: TestParseSingleRange/open-ended (0.00s)1765 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1766 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1767 --- PASS: TestParseSingleRange/single_byte (0.00s)1768 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1769 --- PASS: TestParseSingleRange/suffix (0.00s)1770 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1771 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1772 --- PASS: TestParseSingleRange/closed (0.00s)1773 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1774 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1775 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1776 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1777=== NAME TestClientMultipleUploads1778 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2549568477/001/store/rm6dq8jry3bspdamcimnk7mjnv62zrah-test-file-2.txt1779=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1780=== RUN TestService_RequireScope_OIDC/builder_may_write1781=== PAUSE TestService_RequireScope_OIDC/builder_may_write1782=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1783=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1784=== RUN TestService_RequireScope_OIDC/ops_may_admin1785=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1786=== RUN TestService_RequireScope_OIDC/ops_may_not_write1787=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1788=== RUN TestService_RequireScope_OIDC/reader_may_not_write1789=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1790=== RUN TestService_RequireScope_OIDC/static_token_may_admin1791=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1792=== RUN TestService_RequireScope_OIDC/static_token_may_write1793=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1794=== RUN TestService_RequireScope_OIDC/reader_may_read1795=== PAUSE TestService_RequireScope_OIDC/reader_may_read1796=== RUN TestService_RequireScope_OIDC/writer_implies_read1797=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1798=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1799=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1800=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1801=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1802=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1803=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1804=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1805=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1806=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1807=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1808=== CONT TestPush_RejectsBadRequests/no_objects18092026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1810=== CONT TestPush_RejectsBadRequests/root_not_in_objects18112026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1812=== CONT TestPush_RejectsBadRequests/no_roots18132026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1814=== CONT TestPush_RejectsBadRequests/bad_root18152026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1816=== CONT TestIsValidCachePath/narinfo1817--- PASS: TestPush_RejectsBadRequests (0.54s)1818 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1819 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1820 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1821 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1822=== CONT TestIsValidCachePath/index.html1823=== CONT TestIsValidCachePath/short_hash1824=== CONT TestIsValidCachePath/wrong_extension1825=== CONT TestIsValidCachePath/leading_slash1826=== CONT TestIsValidCachePath/empty1827=== CONT TestIsValidCachePath/random_path1828=== CONT TestIsValidCachePath/invalid_char_u1829=== CONT TestIsValidCachePath/invalid_char_e1830=== CONT TestIsValidCachePath/traversal_in_middle1831=== CONT TestIsValidCachePath/traversal_parent1832=== CONT TestIsValidCachePath/nar_uncompressed1833=== CONT TestIsValidCachePath/nix-cache-info18342026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1835=== CONT TestIsValidCachePath/realisation1836=== CONT TestIsValidCachePath/log1837=== CONT TestIsValidCachePath/nar_xz1838--- PASS: TestService_ReadAuthMiddleware (0.35s)1839=== CONT TestIsValidCachePath/ls1840=== CONT TestIsValidCachePath/nar_zst1841=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1842=== CONT TestServerTLSConfig/no_client_CA1843=== CONT TestIsValidCachePath/nar_bz21844--- PASS: TestIsValidCachePath (0.00s)1845 --- PASS: TestIsValidCachePath/narinfo (0.00s)1846 --- PASS: TestIsValidCachePath/index.html (0.00s)1847 --- PASS: TestIsValidCachePath/short_hash (0.00s)1848 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1849 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1850 --- PASS: TestIsValidCachePath/empty (0.00s)1851 --- PASS: TestIsValidCachePath/random_path (0.00s)1852 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1853 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1854 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1855 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1856 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1857 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1858 --- PASS: TestIsValidCachePath/realisation (0.00s)1859 --- PASS: TestIsValidCachePath/log (0.00s)1860 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1861 --- PASS: TestIsValidCachePath/ls (0.00s)1862 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1863 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1864 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1865=== CONT TestServerTLSConfig/not_a_PEM_file1866=== CONT TestServerTLSConfig/missing_CA_file1867=== CONT TestCacheConfigHandler/full_config,_no_issuer1868=== CONT TestCacheConfigHandler/no_signing_keys1869=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1870=== CONT TestCacheConfigHandler/no_cache_url_configured1871=== CONT TestClientErrorHandling/InvalidStorePath1872--- PASS: TestCacheConfigHandler (0.00s)1873 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1874 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1875 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1876 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1877=== CONT TestClientErrorHandling/ServerNotAvailable1878--- PASS: TestServerTLSConfig (0.00s)1879 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1880 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1881 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)18822026/10/14 16:42:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18832026/10/14 16:42:14 INFO Uploading gz9ywq28b5q5a3h0slmdwshmfbfvbwrx-test-script (136B)18842026/10/14 16:42:14 WARN Failed to register uploaded object key=log/b3wklfpbb106d67kqvpzpln2qc0pdxkr-test-script.drv error="server returned 404: 404 page not found\n"18852026/10/14 16:42:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18862026/10/14 16:42:14 WARN Failed to register uploaded object key=gz9ywq28b5q5a3h0slmdwshmfbfvbwrx.ls error="server returned 404: 404 page not found\n"18872026/10/14 16:42:14 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18882026/10/14 16:42:14 INFO Signed narinfos id=1 count=118892026/10/14 16:42:14 INFO Uploading 1 narinfos1890=== NAME TestClientCADerivations1891 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2070426063/001/store/f93xm30qb5359zmizs4a463m1vkwdf9q-ca-test18922026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes18932026/10/14 16:42:14 INFO Received complete push request method=POST path=/api/pushes/1/complete18942026/10/14 16:42:14 WARN Failed to register uploaded object key=gz9ywq28b5q5a3h0slmdwshmfbfvbwrx.narinfo error="server returned 404: 404 page not found\n"1895--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)1896=== CONT TestClientErrorHandling/InvalidAuthToken18972026/10/14 16:42:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18982026/10/14 16:42:14 INFO Uploading nrzyxz43jkgc98ifwn70sf0rha4lrcsn-test-file.txt (152B)18992026/10/14 16:42:14 WARN Failed to register uploaded object key=nrzyxz43jkgc98ifwn70sf0rha4lrcsn.ls error="server returned 404: 404 page not found\n"19002026/10/14 16:42:14 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19012026/10/14 16:42:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19022026/10/14 16:42:14 INFO Signed narinfos id=1 count=119032026/10/14 16:42:14 INFO Uploading 1 narinfos19042026/10/14 16:42:14 INFO Received complete push request method=POST path=/api/pushes/1/complete19052026/10/14 16:42:14 WARN Failed to register uploaded object key=nrzyxz43jkgc98ifwn70sf0rha4lrcsn.narinfo error="server returned 404: 404 page not found\n"19062026/10/14 16:42:14 INFO Completed push id=1 objects=4 duration=23.433945ms19072026/10/14 16:42:14 INFO Upload complete. (82ms)1908=== NAME TestClientCADerivations1909 client_ca_test.go:139: Found 1 dependencies (including self)1910=== NAME TestClientWithDependencies1911 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies488022590/001/store) requires matching store prefix19122026/10/14 16:42:14 INFO Completed push id=1 objects=3 duration=10.549693ms19132026/10/14 16:42:14 INFO Upload complete. (77ms)19142026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes1915--- PASS: TestClientWithDependencies (0.62s)1916=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1917=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19182026/10/14 16:42:14 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1919=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1920=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19212026/10/14 16:42:14 INFO Received push request method=POST path=/api/pushes19222026/10/14 16:42:15 WARN Authentication failed token_preview=eyJhbGciOi...6W7YSP9nxg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1923=== CONT TestService_RequireScope_OIDC/builder_may_write1924--- PASS: TestService_AuthMiddleware_OIDC (0.39s)1925 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1926 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1927 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1928 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1929=== CONT TestService_RequireScope_OIDC/reader_may_read1930=== CONT TestService_RequireScope_OIDC/static_token_may_write1931=== CONT TestService_RequireScope_OIDC/static_token_may_admin1932=== CONT TestService_RequireScope_OIDC/reader_may_not_write1933=== CONT TestService_RequireScope_OIDC/ops_may_not_write1934=== CONT TestService_RequireScope_OIDC/ops_may_admin1935=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1936=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19372026/10/14 16:42:15 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]1938=== CONT TestService_RequireScope_OIDC/writer_implies_read1939=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1940=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1941=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1942=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1943--- PASS: TestService_RequireScope_OIDC (0.46s)1944 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1949 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1950 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1951 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1952 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1953 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1954 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1955 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)19582026/10/14 16:42:15 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19592026/10/14 16:42:15 INFO Uploading rm6dq8jry3bspdamcimnk7mjnv62zrah-test-file-2.txt (160B)19602026/10/14 16:42:15 INFO Uploading laspv6gagrrqyivzqnfr2lpiyq7s1rzy-test-file-0.txt (160B)19612026/10/14 16:42:15 INFO Uploading n9vgsnfcvs5mkbph958dlqdljlahvhn0-test-file-1.txt (160B)19622026/10/14 16:42:15 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19632026/10/14 16:42:15 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19642026/10/14 16:42:15 WARN Failed to register uploaded object key=laspv6gagrrqyivzqnfr2lpiyq7s1rzy.ls error="server returned 404: 404 page not found\n"19652026/10/14 16:42:15 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19662026/10/14 16:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete19672026/10/14 16:42:15 WARN Failed to register uploaded object key=rm6dq8jry3bspdamcimnk7mjnv62zrah.ls error="server returned 404: 404 page not found\n"19682026/10/14 16:42:15 WARN Failed to register uploaded object key=n9vgsnfcvs5mkbph958dlqdljlahvhn0.ls error="server returned 404: 404 page not found\n"19692026/10/14 16:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19702026/10/14 16:42:15 INFO Signed narinfos id=1 count=319712026/10/14 16:42:15 INFO Uploading 3 narinfos19722026/10/14 16:42:15 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/present19732026/10/14 16:42:15 WARN Failed to register uploaded object key=laspv6gagrrqyivzqnfr2lpiyq7s1rzy.narinfo error="server returned 404: 404 page not found\n"19742026/10/14 16:42:15 WARN Failed to register uploaded object key=n9vgsnfcvs5mkbph958dlqdljlahvhn0.narinfo error="server returned 404: 404 page not found\n"19752026/10/14 16:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete19762026/10/14 16:42:15 WARN Failed to register uploaded object key=rm6dq8jry3bspdamcimnk7mjnv62zrah.narinfo error="server returned 404: 404 page not found\n"19772026/10/14 16:42:15 INFO Completed push id=1 objects=4 duration=7.843234ms19782026/10/14 16:42:15 INFO All 1 paths already cached19792026/10/14 16:42:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1980=== NAME TestClientIntegration1981 client_integration_test.go:312: Retrieved narinfo from S3:1982 StorePath: /build/TestClientIntegration1400385757/002/store/nrzyxz43jkgc98ifwn70sf0rha4lrcsn-test-file.txt1983 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1984 Compression: zstd1985 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11986 NarSize: 1521987 References: 1988 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119892026/10/14 16:42:15 INFO Completed upload id=2 objects=2 duration=2.153759ms1990 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1991 client_integration_test.go:313: Decompressed .ls content (64 bytes):1992 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1993 client_integration_test.go:316: Testing garbage collection...19942026/10/14 16:42:15 INFO Completed push id=1 objects=9 duration=9.844323ms19952026/10/14 16:42:15 INFO Upload complete. (72ms)1996=== NAME TestClientMultipleUploads1997 client_integration_test.go:369: Uploaded 3 paths in 105.98112ms1998--- PASS: TestMetricsCommit (0.40s)1999--- PASS: TestClientMultipleUploads (0.61s)20002026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020012026/10/14 16:42:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20022026/10/14 16:42:15 INFO Garbage collection started20032026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period20042026/10/14 16:42:15 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40593/bucket92/?delete=\": context canceled"20052026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020062026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period20072026/10/14 16:42:15 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=020082026/10/14 16:42:15 INFO Vacuumed table table=pending_closures20092026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020102026/10/14 16:42:15 INFO Vacuumed table table=pending_objects20112026/10/14 16:42:15 INFO Vacuumed table table=multipart_uploads20122026/10/14 16:42:15 INFO Vacuumed table table=closures20132026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period20142026/10/14 16:42:15 INFO Vacuumed table table=objects20152026/10/14 16:42:15 INFO Received push request method=POST path=/api/pushes20162026/10/14 16:42:15 INFO Received uploads request method=POST path=/api/pending_closures20172026/10/14 16:42:15 WARN Request failed, retrying attempt=2 backoff=189.153089ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20182026/10/14 16:42:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20192026/10/14 16:42:15 INFO Uploading f93xm30qb5359zmizs4a463m1vkwdf9q-ca-test (144B)20202026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020212026/10/14 16:42:15 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20222026/10/14 16:42:15 WARN Failed to register uploaded object key=f93xm30qb5359zmizs4a463m1vkwdf9q.ls error="server returned 404: 404 page not found\n"20232026/10/14 16:42:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20242026/10/14 16:42:15 WARN Failed to register uploaded object key=log/mcrzynfddw5mdb2isv902zwflhrdxb24-ca-test.drv error="server returned 404: 404 page not found\n"20252026/10/14 16:42:15 INFO Signed narinfos id=1 count=120262026/10/14 16:42:15 INFO Uploading 1 narinfos20272026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period2028--- PASS: TestGCEndsOnShutdown (0.00s)2029 --- PASS: TestGCEndsOnShutdown/before_the_run (0.36s)2030 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.39s)2031 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.42s)20322026/10/14 16:42:15 INFO Received complete push request method=POST path=/api/pushes/1/complete20332026/10/14 16:42:15 WARN Failed to register uploaded object key=f93xm30qb5359zmizs4a463m1vkwdf9q.narinfo error="server returned 404: 404 page not found\n"20342026/10/14 16:42:15 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=020352026/10/14 16:42:15 INFO Vacuumed table table=pending_closures20362026/10/14 16:42:15 INFO Completed push id=1 objects=4 duration=8.336045ms20372026/10/14 16:42:15 INFO Received uploads request method=POST path=/api/pending_closures20382026/10/14 16:42:15 INFO Vacuumed table table=pending_objects20392026/10/14 16:42:15 INFO Upload complete. (119ms)20402026/10/14 16:42:15 INFO Vacuumed table table=multipart_uploads20412026/10/14 16:42:15 INFO Vacuumed table table=closures20422026/10/14 16:42:15 INFO Vacuumed table table=objects2043=== NAME TestClientCADerivations2044 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2070426063/001/store/f93xm30qb5359zmizs4a463m1vkwdf9q-ca-test2045 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2046 Compression: zstd2047 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2048 NarSize: 1442049 References: 2050 Deriver: /build/TestClientCADerivations2070426063/001/store/mcrzynfddw5mdb2isv902zwflhrdxb24-ca-test.drv2051 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2052 client_ca_test.go:185: Checking for realisation files in S3...2053 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2054 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20552026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020562026/10/14 16:42:15 INFO Received uploads request method=POST path=/api/pending_closures20572026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period20582026/10/14 16:42:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020592026/10/14 16:42:15 INFO Vacuumed table table=pending_closures20602026/10/14 16:42:15 INFO Vacuumed table table=pending_objects20612026/10/14 16:42:15 INFO Vacuumed table table=multipart_uploads20622026/10/14 16:42:15 INFO Vacuumed table table=closures20632026/10/14 16:42:15 INFO Vacuumed table table=objects2064--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2065 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.44s)2066 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.49s)2067=== NAME TestClientCADerivations2068 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2069 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2070 error: binary cache 's3://bucket85?endpoint=http://localhost:40593®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2070426063/001/store'2071 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12072--- PASS: TestClientCADerivations (0.76s)20732026/10/14 16:42:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020742026/10/14 16:42:15 INFO Received create pin request method=POST path=/api/pins/myapp20752026/10/14 16:42:15 WARN Request failed, retrying attempt=3 backoff=434.206447ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20762026/10/14 16:42:15 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC640297676/001/store/d2f1fziyczicmnbfydyabmb7sspx570g-pinned-file.txt narinfo_key=d2f1fziyczicmnbfydyabmb7sspx570g.narinfo20772026/10/14 16:42:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures20782026/10/14 16:42:15 INFO Garbage collection started20792026/10/14 16:42:15 INFO Aborted multipart uploads count=0 kept=020802026/10/14 16:42:15 WARN Force mode enabled - objects will be deleted immediately without grace period20812026/10/14 16:42:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020822026/10/14 16:42:15 INFO Vacuumed table table=pending_closures20832026/10/14 16:42:15 INFO Vacuumed table table=pending_objects20842026/10/14 16:42:15 INFO Vacuumed table table=multipart_uploads20852026/10/14 16:42:15 INFO Vacuumed table table=closures20862026/10/14 16:42:15 INFO Vacuumed table table=objects20872026/10/14 16:42:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20882026/10/14 16:42:15 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2089--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2090 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2091 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2092 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.65s)20932026/10/14 16:42:15 WARN Request failed, retrying attempt=4 backoff=781.468726ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2094--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2095 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.84s)2096 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.86s)20972026/10/14 16:42:15 INFO lead: released remote=192.0.2.1:12342098--- PASS: TestLeadElectsOneAndHandsOver (2.99s)2099--- PASS: TestPendingClosureWriteTimeout (0.00s)2100 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2101 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2102 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2103 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)2104=== NAME TestOrphanedObjectsGCStressTest2105 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2106 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2107 orphaned_objects_gc_test.go:503: Stress test completed successfully:2108 orphaned_objects_gc_test.go:504: - Active objects preserved: 202109 orphaned_objects_gc_test.go:505: - Objects deleted: 2102110 orphaned_objects_gc_test.go:506: - Total GC'd: 2102111--- PASS: TestOrphanedObjectsGCStressTest (2.61s)21122026/10/14 16:42:16 WARN Request failed, retrying attempt=5 backoff=1.688357924s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21132026/10/14 16:42:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02114=== NAME TestClientIntegration2115 client_integration_test.go:323: Objects in database after GC:2116 client_integration_test.go:323: Successfully deleted all objects with GC --force2117--- PASS: TestClientIntegration (2.62s)2118=== NAME TestPinProtectsFromGC2119 client_integration_test.go:840: Pin successfully protected closure from garbage collection2120--- PASS: TestPinProtectsFromGC (5.19s)21212026/10/14 16:42:17 WARN Rate limiter enabled after throttle name=s3-test rate=521222026/10/14 16:42:17 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2123=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2124 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102125 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002126--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.82s)2127--- PASS: TestConnectWaitsForAPeerMigration (5.18s)21282026/10/14 16:42:18 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-config21292026/10/14 16:42:18 WARN Request failed, retrying attempt=2 backoff=186.216177ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2130--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.57s)21312026/10/14 16:42:18 WARN Request failed, retrying attempt=3 backoff=388.727533ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21322026/10/14 16:42:18 WARN Request failed, retrying attempt=4 backoff=768.188383ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21332026/10/14 16:42:19 WARN Request failed, retrying attempt=5 backoff=1.709915022s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21342026/10/14 16:42:20 INFO Aborted multipart uploads count=1 kept=021352026/10/14 16:42:20 INFO Received cleanup request method=DELETE path=/api/pending_closures21362026/10/14 16:42:20 INFO Aborted multipart uploads count=1 kept=02137--- PASS: TestPendingCleanupUsesOneCutoff (6.46s)21382026/10/14 16:42:21 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"21392026/10/14 16:42:21 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-config21402026/10/14 16:42:21 WARN Request failed, retrying attempt=2 backoff=207.518687ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/14 16:42:21 WARN Request failed, retrying attempt=3 backoff=412.507344ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/14 16:42:22 WARN Request failed, retrying attempt=4 backoff=781.935478ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21432026/10/14 16:42:22 WARN Request failed, retrying attempt=5 backoff=1.490923406s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21442026/10/14 16:42:24 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_closures21452026/10/14 16:42:24 WARN Request failed, retrying attempt=2 backoff=219.072695ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/14 16:42:24 WARN Request failed, retrying attempt=3 backoff=401.611766ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21472026/10/14 16:42:25 WARN Request failed, retrying attempt=4 backoff=795.350278ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21482026/10/14 16:42:25 WARN Request failed, retrying attempt=5 backoff=1.485987858s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2149--- PASS: TestClientErrorHandling (0.00s)2150 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)2151 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.49s)2152 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.49s)2153PASS21542026-10-14 16:42:27.762 UTC [129] LOG: received smart shutdown request21552026-10-14 16:42:27.766 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 121562026-10-14 16:42:27.779 UTC [134] LOG: shutting down21572026-10-14 16:42:27.779 UTC [134] LOG: checkpoint starting: shutdown immediate21582026-10-14 16:42:28.871 UTC [134] LOG: checkpoint complete: wrote 10912 buffers (66.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.217 s, sync=0.828 s, total=1.093 s; sync files=34045, longest=0.005 s, average=0.001 s; distance=531515 kB, estimate=531515 kB; lsn=0/21E74C20, redo lsn=0/21E74C2021592026-10-14 16:42:28.950 UTC [129] LOG: database system is shut down2160Running OIDC tests...2161=== RUN TestAudienceForIssuer2162=== PAUSE TestAudienceForIssuer2163=== RUN TestGlobMatch2164=== PAUSE TestGlobMatch2165=== RUN TestValidateToken_ValidToken2166=== PAUSE TestValidateToken_ValidToken2167=== RUN TestValidateToken_WrongAudience2168=== PAUSE TestValidateToken_WrongAudience2169=== RUN TestValidateToken_Expired2170=== PAUSE TestValidateToken_Expired2171=== RUN TestValidateToken_BoundClaimsMismatch2172=== PAUSE TestValidateToken_BoundClaimsMismatch2173=== RUN TestValidateToken_BoundSubjectMismatch2174=== PAUSE TestValidateToken_BoundSubjectMismatch2175=== RUN TestValidateToken_MultipleProviders2176=== PAUSE TestValidateToken_MultipleProviders2177=== RUN TestValidateToken_NoMatchingProvider2178=== PAUSE TestValidateToken_NoMatchingProvider2179=== RUN TestValidateToken_KubernetesServiceAccount2180=== PAUSE TestValidateToken_KubernetesServiceAccount2181=== RUN TestNewValidator_KubernetesRequiresCA2182=== PAUSE TestNewValidator_KubernetesRequiresCA2183=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2184=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2185=== RUN TestPins_ReservedForMatchingRule2186=== PAUSE TestPins_ReservedForMatchingRule2187=== RUN TestPins_TopLevelShorthand2188=== PAUSE TestPins_TopLevelShorthand2189=== RUN TestPins_ConfigValidation2190=== PAUSE TestPins_ConfigValidation2191=== RUN TestScopes_LegacyProviderDefaultsToWrite2192=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2193=== RUN TestScopes_Rules2194=== PAUSE TestScopes_Rules2195=== RUN TestScopes_ConfigValidation2196=== PAUSE TestScopes_ConfigValidation2197=== CONT TestAudienceForIssuer2198=== CONT TestValidateToken_BoundClaimsMismatch2199=== CONT TestValidateToken_KubernetesServiceAccount2200--- PASS: TestAudienceForIssuer (0.00s)2201=== CONT TestValidateToken_Expired2202=== CONT TestPins_TopLevelShorthand2203=== CONT TestValidateToken_WrongAudience2204=== CONT TestPins_ReservedForMatchingRule2205=== CONT TestValidateToken_ValidToken2206=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2207=== CONT TestGlobMatch2208=== CONT TestNewValidator_KubernetesRequiresCA2209=== CONT TestValidateToken_MultipleProviders2210=== CONT TestValidateToken_BoundSubjectMismatch2211=== CONT TestValidateToken_NoMatchingProvider2212=== CONT TestScopes_Rules2213=== CONT TestScopes_ConfigValidation2214=== CONT TestScopes_LegacyProviderDefaultsToWrite2215=== CONT TestPins_ConfigValidation2216=== RUN TestGlobMatch/foo_foo2217=== PAUSE TestGlobMatch/foo_foo2218=== RUN TestGlobMatch/foo_bar2219=== PAUSE TestGlobMatch/foo_bar2220=== RUN TestGlobMatch/*_2221=== PAUSE TestGlobMatch/*_2222=== RUN TestGlobMatch/*_anything2223=== PAUSE TestGlobMatch/*_anything2224=== RUN TestGlobMatch/foo*_foo2225=== PAUSE TestGlobMatch/foo*_foo2226=== RUN TestGlobMatch/foo*_foobar2227=== PAUSE TestGlobMatch/foo*_foobar2228=== RUN TestGlobMatch/foo*_bar2229=== PAUSE TestGlobMatch/foo*_bar2230=== RUN TestGlobMatch/*bar_bar2231=== PAUSE TestGlobMatch/*bar_bar2232=== RUN TestGlobMatch/*bar_foobar2233=== PAUSE TestGlobMatch/*bar_foobar2234=== RUN TestGlobMatch/*bar_foo2235=== PAUSE TestGlobMatch/*bar_foo2236=== RUN TestGlobMatch/foo*bar_foobar2237=== PAUSE TestGlobMatch/foo*bar_foobar2238=== RUN TestGlobMatch/foo*bar_foo123bar2239=== PAUSE TestGlobMatch/foo*bar_foo123bar2240=== RUN TestGlobMatch/foo*bar_foobarbaz2241=== PAUSE TestGlobMatch/foo*bar_foobarbaz2242=== RUN TestGlobMatch/*/*_foo/bar2243=== PAUSE TestGlobMatch/*/*_foo/bar2244=== RUN TestGlobMatch/*/*_foo2245=== PAUSE TestGlobMatch/*/*_foo2246=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2247=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2248--- PASS: TestScopes_ConfigValidation (0.01s)2249=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02250=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02251--- PASS: TestPins_ConfigValidation (0.00s)2252=== RUN TestGlobMatch/refs/*/main_refs/heads/main2253=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2254=== RUN TestGlobMatch/fo?_foo2255=== PAUSE TestGlobMatch/fo?_foo2256=== RUN TestGlobMatch/fo?_fo2257=== PAUSE TestGlobMatch/fo?_fo2258=== RUN TestGlobMatch/fo?_fooo2259=== PAUSE TestGlobMatch/fo?_fooo2260=== RUN TestGlobMatch/?oo_foo2261=== PAUSE TestGlobMatch/?oo_foo2262=== RUN TestGlobMatch/?oo_boo2263=== PAUSE TestGlobMatch/?oo_boo2264=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2265=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2266=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2267=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2268=== CONT TestGlobMatch/foo_foo2269=== CONT TestGlobMatch/?oo_foo2270=== CONT TestGlobMatch/*bar_bar2271=== CONT TestGlobMatch/foo*_bar2272=== CONT TestGlobMatch/foo*_foobar2273=== CONT TestGlobMatch/foo*bar_foobarbaz2274=== CONT TestGlobMatch/*_anything2275=== CONT TestGlobMatch/*_2276=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2277=== CONT TestGlobMatch/refs/*/main_refs/heads/main2278=== CONT TestGlobMatch/fo?_fooo2279=== CONT TestGlobMatch/fo?_fo2280=== CONT TestGlobMatch/fo?_foo2281=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2282=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02283=== CONT TestGlobMatch/*/*_foo2284=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2285=== CONT TestGlobMatch/?oo_boo2286=== CONT TestGlobMatch/foo*bar_foo123bar2287=== CONT TestGlobMatch/foo*bar_foobar2288=== CONT TestGlobMatch/*bar_foo2289=== CONT TestGlobMatch/*bar_foobar2290=== CONT TestGlobMatch/*/*_foo/bar2291=== CONT TestGlobMatch/foo*_foo2292=== CONT TestGlobMatch/foo_bar2293--- PASS: TestGlobMatch (0.01s)2294 --- PASS: TestGlobMatch/foo_foo (0.00s)2295 --- PASS: TestGlobMatch/?oo_foo (0.00s)2296 --- PASS: TestGlobMatch/*bar_bar (0.00s)2297 --- PASS: TestGlobMatch/foo*_bar (0.00s)2298 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2299 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2300 --- PASS: TestGlobMatch/*_anything (0.00s)2301 --- PASS: TestGlobMatch/*_ (0.00s)2302 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2303 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2304 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2305 --- PASS: TestGlobMatch/fo?_fo (0.00s)2306 --- PASS: TestGlobMatch/fo?_foo (0.00s)2307 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2308 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2309 --- PASS: TestGlobMatch/*/*_foo (0.00s)2310 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2311 --- PASS: TestGlobMatch/?oo_boo (0.00s)2312 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2313 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2314 --- PASS: TestGlobMatch/*bar_foo (0.00s)2315 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2316 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2317 --- PASS: TestGlobMatch/foo*_foo (0.00s)2318 --- PASS: TestGlobMatch/foo_bar (0.00s)23192026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38065/oidc2320--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)23212026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43353/oidc2322--- PASS: TestValidateToken_WrongAudience (0.03s)23232026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32835/oidc2324--- PASS: TestPins_TopLevelShorthand (0.04s)23252026/10/14 16:42:31 http: TLS handshake error from 127.0.0.1:53744: remote error: tls: bad certificate2326--- PASS: TestNewValidator_KubernetesRequiresCA (0.03s)23272026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43033/oidc2328--- PASS: TestScopes_Rules (0.05s)23292026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37709/oidc2330--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23312026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40181/oidc23322026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39273/oidc2333--- PASS: TestValidateToken_ValidToken (0.08s)2334--- PASS: TestPins_ReservedForMatchingRule (0.08s)23352026/10/14 16:42:31 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232336--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)23372026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34129/oidc2338--- PASS: TestValidateToken_Expired (0.12s)23392026/10/14 16:42:31 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:392752340--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)23412026/10/14 16:42:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44971/oidc2342--- PASS: TestValidateToken_NoMatchingProvider (0.13s)23432026/10/14 16:42:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44421/oidc2344--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.14s)23452026/10/14 16:42:31 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44069/oidc23462026/10/14 16:42:31 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33053/oidc2347--- PASS: TestValidateToken_MultipleProviders (0.16s)2348PASS2349Running hook tests...2350=== RUN TestSendPathsEmpty2351=== PAUSE TestSendPathsEmpty2352=== RUN TestQueueEnqueueAndFetch2353=== PAUSE TestQueueEnqueueAndFetch2354=== RUN TestQueueDeduplication2355=== PAUSE TestQueueDeduplication2356=== RUN TestQueueRemove2357=== PAUSE TestQueueRemove2358=== RUN TestQueueFetchBatchLimit2359=== PAUSE TestQueueFetchBatchLimit2360=== RUN TestQueueRetryMovesToBack2361=== PAUSE TestQueueRetryMovesToBack2362=== RUN TestQueueFetchRemoveLifecycle2363=== PAUSE TestQueueFetchRemoveLifecycle2364=== RUN TestQueueConcurrentWriters2365=== PAUSE TestQueueConcurrentWriters2366=== RUN TestQueueRemoveLargeClosure2367=== PAUSE TestQueueRemoveLargeClosure2368=== RUN TestServerClientIntegration2369--- PASS: TestServerClientIntegration (0.00s)2370=== RUN TestServerQueueError23712026/10/14 16:42:31 ERROR Failed to queue paths error="permission denied" count=12372--- PASS: TestServerQueueError (0.00s)2373=== RUN TestGetListenerSocketActivation2374 server_test.go:219: === RUN TestGetListenerSocketActivation2375 --- PASS: TestGetListenerSocketActivation (0.00s)2376 PASS2377 2378--- PASS: TestGetListenerSocketActivation (0.01s)2379=== RUN TestDrainIsolatesPoisonPath2380=== PAUSE TestDrainIsolatesPoisonPath2381=== RUN TestRunNotBlockedByPoisonHead2382=== PAUSE TestRunNotBlockedByPoisonHead2383=== RUN TestDrainGivesUpWhenServerDown2384=== PAUSE TestDrainGivesUpWhenServerDown2385=== RUN TestFailedPathPrunedByLaterClosure2386=== PAUSE TestFailedPathPrunedByLaterClosure2387=== RUN TestWorkerUploadsAndRemoves2388=== PAUSE TestWorkerUploadsAndRemoves2389=== RUN TestWorkerSkipsGCdPaths2390=== PAUSE TestWorkerSkipsGCdPaths2391=== RUN TestWorkerPrunesClosureDeps2392=== PAUSE TestWorkerPrunesClosureDeps2393=== RUN TestDrainTimeout2394=== PAUSE TestDrainTimeout2395=== CONT TestSendPathsEmpty2396=== CONT TestDrainIsolatesPoisonPath2397--- PASS: TestSendPathsEmpty (0.00s)2398=== CONT TestWorkerUploadsAndRemoves2399=== CONT TestQueueRemoveLargeClosure2400=== CONT TestDrainTimeout2401=== CONT TestQueueConcurrentWriters2402=== CONT TestWorkerPrunesClosureDeps2403=== CONT TestQueueRemove2404=== CONT TestQueueDeduplication2405=== CONT TestWorkerSkipsGCdPaths2406=== CONT TestQueueEnqueueAndFetch2407=== CONT TestQueueFetchBatchLimit2408=== CONT TestQueueFetchRemoveLifecycle2409=== CONT TestDrainGivesUpWhenServerDown2410=== CONT TestQueueRetryMovesToBack2411=== CONT TestRunNotBlockedByPoisonHead2412=== CONT TestFailedPathPrunedByLaterClosure24132026/10/14 16:42:31 INFO Uploading batch count=124142026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=124152026/10/14 16:42:31 INFO Uploading batch count=224162026/10/14 16:42:31 INFO Uploading batch count=424172026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=424182026/10/14 16:42:31 INFO Upload queue status pending=324192026/10/14 16:42:31 INFO Uploading batch count=224202026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=224212026/10/14 16:42:31 INFO Uploading batch count=124222026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=124232026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/a24242026/10/14 16:42:31 INFO Uploading batch count=124252026/10/14 16:42:31 INFO Upload queue status pending=224262026/10/14 16:42:31 INFO Uploading batch count=12427--- PASS: TestQueueEnqueueAndFetch (0.02s)24282026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/b2429--- PASS: TestQueueFetchBatchLimit (0.02s)24302026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3970174368/002/bbb24312026/10/14 16:42:31 INFO Uploading batch count=12432--- PASS: TestQueueFetchRemoveLifecycle (0.02s)24332026/10/14 16:42:31 INFO Upload queue status pending=224342026/10/14 16:42:31 INFO Uploading batch count=224352026/10/14 16:42:31 INFO Upload queue status pending=22436--- PASS: TestQueueRetryMovesToBack (0.02s)24372026/10/14 16:42:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2363979030/002/nonexistent24382026/10/14 16:42:31 INFO Uploading batch count=224392026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=224402026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/c2441--- PASS: TestQueueDeduplication (0.02s)2442--- PASS: TestQueueRemove (0.02s)24432026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/d24442026/10/14 16:42:31 INFO Uploading batch count=124452026/10/14 16:42:31 INFO Uploading batch count=124462026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=124472026/10/14 16:42:31 INFO Uploading batch count=224482026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=224492026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/e24502026/10/14 16:42:31 INFO Uploading batch count=124512026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=124522026/10/14 16:42:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4248848519/002/f24532026/10/14 16:42:31 INFO Uploading batch count=124542026/10/14 16:42:31 ERROR Upload failed error="upload failed" count=12455--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)24562026/10/14 16:42:31 ERROR Drain finished with paths left in queue remaining=1024572026/10/14 16:42:31 ERROR Drain finished with paths left in queue remaining=12458--- PASS: TestDrainIsolatesPoisonPath (0.03s)2459--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2460--- PASS: TestWorkerPrunesClosureDeps (0.04s)2461--- PASS: TestWorkerSkipsGCdPaths (0.04s)2462--- PASS: TestWorkerUploadsAndRemoves (0.04s)2463--- PASS: TestQueueRemoveLargeClosure (0.08s)24642026/10/14 16:42:31 ERROR Upload failed error="context deadline exceeded" count=224652026/10/14 16:42:31 ERROR Drain finished with paths left in queue remaining=42466--- PASS: TestDrainTimeout (0.22s)2467--- PASS: TestQueueConcurrentWriters (0.28s)24682026/10/14 16:42:32 INFO Uploading batch count=124692026/10/14 16:42:32 INFO Uploading batch count=124702026/10/14 16:42:32 INFO Uploading batch count=124712026/10/14 16:42:32 ERROR Upload failed error="upload failed" count=124722026/10/14 16:42:32 INFO Uploading batch count=124732026/10/14 16:42:32 ERROR Upload failed error="upload failed" count=124742026/10/14 16:42:32 INFO Uploading batch count=124752026/10/14 16:42:32 ERROR Upload failed error="upload failed" count=124762026/10/14 16:42:32 INFO Uploading batch count=124772026/10/14 16:42:32 ERROR Upload failed error="upload failed" count=124782026/10/14 16:42:32 ERROR Drain finished with paths left in queue remaining=12479--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2480PASS2481Running signing tests...2482=== RUN TestExternalSigner2483=== PAUSE TestExternalSigner2484=== RUN TestExternalSignerWrongPublicKey2485=== PAUSE TestExternalSignerWrongPublicKey2486=== RUN TestExternalSignerErrors2487=== PAUSE TestExternalSignerErrors2488=== RUN TestExternalSignerRestartsAfterCrash2489=== PAUSE TestExternalSignerRestartsAfterCrash2490=== RUN TestExternalSignerProgramErrorKeepsProcess2491=== PAUSE TestExternalSignerProgramErrorKeepsProcess2492=== RUN TestExternalSignerClose2493=== PAUSE TestExternalSignerClose2494=== RUN TestExternalSignerRejectsInvalidPublicKey2495=== PAUSE TestExternalSignerRejectsInvalidPublicKey2496=== RUN TestExternalSignerCancellation2497=== PAUSE TestExternalSignerCancellation2498=== RUN TestGenerateFingerprint2499=== PAUSE TestGenerateFingerprint2500=== RUN TestParseSigningKey2501=== PAUSE TestParseSigningKey2502=== RUN TestSign2503=== PAUSE TestSign2504=== RUN TestSignBatch2505=== PAUSE TestSignBatch2506=== RUN TestNilKeyPublicKey2507=== PAUSE TestNilKeyPublicKey2508=== RUN TestSignErrors2509=== PAUSE TestSignErrors2510=== CONT TestExternalSigner2511=== CONT TestExternalSignerCancellation2512=== CONT TestExternalSignerProgramErrorKeepsProcess2513=== CONT TestExternalSignerRejectsInvalidPublicKey2514=== CONT TestSignErrors2515=== CONT TestNilKeyPublicKey2516=== CONT TestSignBatch2517=== CONT TestSign2518=== CONT TestParseSigningKey2519=== RUN TestParseSigningKey/valid_32-byte_key2520=== PAUSE TestParseSigningKey/valid_32-byte_key2521=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2522=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2523=== RUN TestParseSigningKey/no_colon2524=== PAUSE TestParseSigningKey/no_colon2525=== RUN TestParseSigningKey/empty_name2526=== PAUSE TestParseSigningKey/empty_name2527=== RUN TestParseSigningKey/invalid_base642528=== PAUSE TestParseSigningKey/invalid_base642529=== CONT TestGenerateFingerprint2530=== CONT TestExternalSignerErrors2531=== CONT TestExternalSignerRestartsAfterCrash2532=== CONT TestExternalSignerWrongPublicKey2533=== CONT TestExternalSignerClose2534=== RUN TestExternalSignerRejectsInvalidPublicKey/#002535=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002536=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2537=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2538=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2539=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2540=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2541=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2542=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2543=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2544=== RUN TestGenerateFingerprint/basic_with_references2545=== CONT TestExternalSignerRejectsInvalidPublicKey/#002546=== RUN TestParseSigningKey/wrong_length2547=== PAUSE TestParseSigningKey/wrong_length2548=== CONT TestParseSigningKey/valid_32-byte_key2549=== CONT TestParseSigningKey/invalid_base642550=== CONT TestParseSigningKey/empty_name2551=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2552=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2553=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2554=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2555=== RUN TestExternalSignerErrors/wrong_signature_name2556=== PAUSE TestExternalSignerErrors/wrong_signature_name2557=== RUN TestExternalSignerErrors/wrong_signature_length2558=== PAUSE TestExternalSignerErrors/wrong_signature_length2559=== RUN TestExternalSignerErrors/wrong_id2560=== PAUSE TestExternalSignerErrors/wrong_id2561=== RUN TestExternalSignerErrors/unrequested_key2562=== PAUSE TestExternalSignerErrors/unrequested_key2563=== RUN TestExternalSignerErrors/wrong_shape2564=== PAUSE TestGenerateFingerprint/basic_with_references2565=== RUN TestGenerateFingerprint/no_references2566=== PAUSE TestGenerateFingerprint/no_references2567=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2568=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2569=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2570=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2571=== RUN TestGenerateFingerprint/invalid_nar_hash_length2572=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2573=== RUN TestSignErrors/nil_key2574=== PAUSE TestSignErrors/nil_key2575=== RUN TestSignErrors/nil_narinfo2576=== PAUSE TestSignErrors/nil_narinfo2577=== RUN TestGenerateFingerprint/invalid_store_path_prefix2578=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2579=== CONT TestParseSigningKey/no_colon2580=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2581--- PASS: TestNilKeyPublicKey (0.00s)2582=== CONT TestParseSigningKey/wrong_length2583=== PAUSE TestExternalSignerErrors/wrong_shape2584--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2585 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2586 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2587 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2588 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2589 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2590=== RUN TestSignErrors/invalid_narinfo2591=== PAUSE TestSignErrors/invalid_narinfo2592=== RUN TestSignErrors/canceled2593=== PAUSE TestSignErrors/canceled2594=== CONT TestSignErrors/nil_key2595=== CONT TestSignErrors/nil_narinfo2596=== RUN TestGenerateFingerprint/invalid_reference_prefix2597=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2598=== CONT TestGenerateFingerprint/basic_with_references2599=== CONT TestGenerateFingerprint/invalid_nar_hash_length2600=== CONT TestSignErrors/canceled2601=== CONT TestGenerateFingerprint/invalid_store_path_prefix2602=== RUN TestExternalSignerErrors/invalid_signature_base642603--- PASS: TestSign (0.00s)2604=== CONT TestSignErrors/invalid_narinfo2605=== CONT TestGenerateFingerprint/invalid_reference_prefix2606=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2607=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2608=== CONT TestGenerateFingerprint/no_references2609=== PAUSE TestExternalSignerErrors/invalid_signature_base642610=== RUN TestExternalSignerErrors/program_error2611=== PAUSE TestExternalSignerErrors/program_error2612=== RUN TestExternalSignerErrors/invalid_JSON2613=== PAUSE TestExternalSignerErrors/invalid_JSON2614=== RUN TestExternalSignerErrors/null2615=== PAUSE TestExternalSignerErrors/null2616=== RUN TestExternalSignerErrors/missing_signatures2617=== PAUSE TestExternalSignerErrors/missing_signatures2618=== RUN TestExternalSignerErrors/null_signatures2619=== PAUSE TestExternalSignerErrors/null_signatures2620=== RUN TestExternalSignerErrors/too_few_signatures2621=== PAUSE TestExternalSignerErrors/too_few_signatures2622=== RUN TestExternalSignerErrors/missing_signature_name2623=== PAUSE TestExternalSignerErrors/missing_signature_name2624=== RUN TestExternalSignerErrors/exit_at_startup2625=== PAUSE TestExternalSignerErrors/exit_at_startup2626=== RUN TestExternalSignerErrors/exit_on_request2627=== PAUSE TestExternalSignerErrors/exit_on_request2628=== RUN TestExternalSignerErrors/wrong_signatures_shape2629=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2630--- PASS: TestParseSigningKey (0.00s)2631 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2632 --- PASS: TestParseSigningKey/empty_name (0.00s)2633 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2634 --- PASS: TestParseSigningKey/no_colon (0.00s)2635 --- PASS: TestParseSigningKey/wrong_length (0.00s)2636 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2637--- PASS: TestSignBatch (0.00s)2638=== CONT TestExternalSignerErrors/wrong_signature_name2639--- PASS: TestSignErrors (0.00s)2640 --- PASS: TestSignErrors/nil_key (0.00s)2641 --- PASS: TestSignErrors/nil_narinfo (0.00s)2642 --- PASS: TestSignErrors/canceled (0.00s)2643 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2644=== CONT TestExternalSignerErrors/invalid_JSON2645=== CONT TestExternalSignerErrors/program_error2646=== CONT TestExternalSignerErrors/invalid_signature_base642647=== CONT TestExternalSignerErrors/wrong_shape2648=== CONT TestExternalSignerErrors/unrequested_key2649=== CONT TestExternalSignerErrors/wrong_id2650=== CONT TestExternalSignerErrors/null2651=== CONT TestExternalSignerErrors/too_few_signatures2652=== CONT TestExternalSignerErrors/wrong_signature_length2653=== CONT TestExternalSignerErrors/null_signatures2654=== CONT TestExternalSignerErrors/missing_signature_name2655=== CONT TestExternalSignerErrors/exit_on_request2656=== CONT TestExternalSignerErrors/missing_signatures2657=== CONT TestExternalSignerErrors/exit_at_startup2658=== CONT TestExternalSignerErrors/wrong_signatures_shape2659--- PASS: TestGenerateFingerprint (0.00s)2660 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2661 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2662 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2663 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2664 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2665 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2666 --- PASS: TestGenerateFingerprint/no_references (0.00s)2667--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2668--- PASS: TestExternalSignerClose (0.01s)2669--- PASS: TestExternalSignerWrongPublicKey (0.01s)2670--- PASS: TestExternalSigner (0.01s)2671--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2672--- PASS: TestExternalSignerErrors (0.00s)2673 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2674 --- PASS: TestExternalSignerErrors/program_error (0.00s)2675 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2676 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2677 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2678 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2679 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2680 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2681 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2682 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2683 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2684 --- PASS: TestExternalSignerErrors/null (0.01s)2685 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2686 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2687 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2688 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2689--- PASS: TestExternalSignerCancellation (0.02s)2690PASS2691Running OpenBao signer tests...2692=== RUN TestSign2693=== PAUSE TestSign2694=== RUN TestSignErrors2695=== PAUSE TestSignErrors2696=== RUN TestServe2697=== PAUSE TestServe2698=== RUN TestServeRejectsGarbage2699=== PAUSE TestServeRejectsGarbage2700=== CONT TestSign2701=== CONT TestServeRejectsGarbage2702=== CONT TestSignErrors2703=== CONT TestServe2704=== RUN TestSignErrors/http_error2705=== PAUSE TestSignErrors/http_error2706=== RUN TestSignErrors/invalid_json2707=== PAUSE TestSignErrors/invalid_json2708=== RUN TestSignErrors/no_prefix2709=== PAUSE TestSignErrors/no_prefix2710=== RUN TestSignErrors/invalid_base642711=== PAUSE TestSignErrors/invalid_base642712--- PASS: TestServeRejectsGarbage (0.00s)2713=== CONT TestSignErrors/http_error2714--- PASS: TestServe (0.00s)2715=== CONT TestSignErrors/invalid_base642716=== CONT TestSignErrors/no_prefix2717=== CONT TestSignErrors/invalid_json2718--- PASS: TestSign (0.00s)2719--- PASS: TestSignErrors (0.00s)2720 --- PASS: TestSignErrors/http_error (0.00s)2721 --- PASS: TestSignErrors/invalid_base64 (0.00s)2722 --- PASS: TestSignErrors/no_prefix (0.00s)2723 --- PASS: TestSignErrors/invalid_json (0.00s)2724PASS