niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #423
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestStaticToken118=== CONT TestSetClientTLSErrors119--- PASS: TestStaticToken (0.00s)120=== CONT TestConvertHashToNix32121=== RUN TestConvertHashToNix32/SRI_format_to_Nix32122=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32123=== RUN TestConvertHashToNix32/already_Nix32_format124=== CONT TestDumpPathWriterError125=== CONT TestSetClientTLS126=== CONT TestScriptTokenEmptyCommand127--- PASS: TestScriptTokenEmptyCommand (0.00s)128=== CONT TestEncodeNixBase32WithRealHash129--- PASS: TestEncodeNixBase32WithRealHash (0.00s)130=== CONT TestEncodeNixBase32131=== RUN TestEncodeNixBase32/test_string_hash132=== PAUSE TestEncodeNixBase32/test_string_hash133=== RUN TestEncodeNixBase32/empty_input134=== PAUSE TestEncodeNixBase32/empty_input135=== CONT TestUploadMultipart_PartsInParallel136=== CONT TestScriptTokenScriptFails137=== CONT TestScriptTokenBadJSON138=== CONT TestScriptTokenEmptyToken139=== CONT TestScriptTokenCachesUntilRefresh140=== CONT TestScriptTokenNoExpiryRerunsEveryCall141=== CONT TestFileTokenEmpty142=== CONT TestFileTokenMissing143=== CONT TestFileTokenReadsAndCaches144=== CONT TestResolveStorePath145=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer146=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess147=== CONT TestRateLimiterFeedback148=== CONT TestPathInfoCACompatibility149=== CONT TestParsePathInfoJSONMultiplePaths150=== CONT TestParsePathInfoJSON151=== CONT TestPathInfoHashCompatibility152=== CONT TestGetStorePathHash153=== PAUSE TestConvertHashToNix32/already_Nix32_format154=== RUN TestSetClientTLSErrors/missing_cert_file155=== PAUSE TestSetClientTLSErrors/missing_cert_file156=== RUN TestSetClientTLSErrors/missing_key_file157=== PAUSE TestSetClientTLSErrors/missing_key_file158=== RUN TestSetClientTLSErrors/missing_ca_file159=== RUN TestSetClientTLS/rejects_connection_without_client_cert160--- PASS: TestFileTokenEmpty (0.00s)161=== CONT TestDumpPathSingleFile162=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert163=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA164=== RUN TestConvertHashToNix32/invalid_format165=== PAUSE TestSetClientTLSErrors/missing_ca_file166=== RUN TestSetClientTLSErrors/invalid_ca_file167=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== RUN TestParsePathInfoJSON/Nix_format169=== PAUSE TestSetClientTLSErrors/invalid_ca_file170=== PAUSE TestParsePathInfoJSON/Nix_format171=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA173=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon175=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI1772026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=server-test rate=51782026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:57900179=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512180=== RUN TestParsePathInfoJSON/Lix_format181=== CONT TestDumpPathMatchesNix1822026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=server-test rate=5183=== RUN TestPathInfoCACompatibility/null_ca_field184=== PAUSE TestPathInfoCACompatibility/null_ca_field185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text187=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive189=== RUN TestPathInfoCACompatibility/new_structured_format_-_text190=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text191=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method192=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method193=== CONT TestSupersededNARStillUploadsListing194=== RUN TestSupersededNARStillUploadsListing/small_NAR195=== PAUSE TestSupersededNARStillUploadsListing/small_NAR196=== RUN TestSupersededNARStillUploadsListing/dump_cut_short197=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short198=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails199=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails200=== CONT TestUploadMultipart_SupersededByPeer201=== RUN TestUploadMultipart_SupersededByPeer/exists202=== PAUSE TestUploadMultipart_SupersededByPeer/exists203=== RUN TestUploadMultipart_SupersededByPeer/missing204=== PAUSE TestUploadMultipart_SupersededByPeer/missing205=== CONT TestPartSizeForNAR206=== RUN TestPartSizeForNAR/zero_stays_at_minimum207=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum208=== RUN TestPartSizeForNAR/small_stays_at_minimum209=== PAUSE TestPartSizeForNAR/small_stays_at_minimum210=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum211=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum212=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts213=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts214=== RUN TestPartSizeForNAR/1_TiB215=== PAUSE TestPartSizeForNAR/1_TiB216=== RUN TestPartSizeForNAR/5_TiB_S3_max_object217=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object218=== RUN TestPartSizeForNAR/capped_at_5_GiB219=== PAUSE TestPartSizeForNAR/capped_at_5_GiB220=== CONT TestUploadMultipart_FailedPartBufferNotReused221=== RUN TestGetStorePathHash/valid_store_path222=== CONT TestStreamPushReportsSkippedPaths223=== RUN TestSetClientTLS/preserves_debug_logging_transport224=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths225=== RUN TestRateLimiterFeedback/429_enables_limiter2262026/10/25 13:43:34 WARN Rate limiter backed off name=server-test rate=52272026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:57900228=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512229=== CONT TestClientSignaturesByStorePath230=== CONT TestCaseHackSuffix231=== PAUSE TestGetStorePathHash/valid_store_path232=== RUN TestGetStorePathHash/basename_without_hyphen_should_error233=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestRateLimiterFeedback/429_enables_limiter235=== RUN TestRateLimiterFeedback/503_enables_limiter236=== PAUSE TestRateLimiterFeedback/503_enables_limiter237=== CONT TestFilterOversizedClosures238=== RUN TestFilterOversizedClosures/no_limit_keeps_everything239=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything240=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped242=== RUN TestFilterOversizedClosures/all_closures_skipped243=== PAUSE TestFilterOversizedClosures/all_closures_skipped244=== CONT TestStreamPushStopsWhenCanceled245--- PASS: TestScriptTokenScriptFails (0.01s)246--- PASS: TestStreamPushReportsSkippedPaths (0.00s)247--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)248--- PASS: TestClientSignaturesByStorePath (0.00s)249=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths250=== PAUSE TestParsePathInfoJSON/Lix_format251=== PAUSE TestSetClientTLS/preserves_debug_logging_transport252=== PAUSE TestConvertHashToNix32/invalid_format253=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error254=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error255=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error256=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error257=== CONT TestRegisterUploadedObjectReusesConnections258=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter259=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter260=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter261=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter262=== CONT TestStreamPushGivesUpOnDeadServer263=== CONT TestStreamPushRequestLine2642026/10/25 13:43:34 ERROR Upload failed error="connection refused" count=202652026/10/25 13:43:34 ERROR Server seems unavailable, giving up on batch untried=17266--- PASS: TestStreamPushStopsWhenCanceled (0.00s)267--- PASS: TestDoServerRequestAttachesToken (0.02s)268=== CONT TestStreamPushReportsSignatures269=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2702026/10/25 13:43:34 ERROR Upload failed error=boom count=1271=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica272=== CONT TestRetryTimeoutOutlastsMaxRetries273=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths274=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths275=== RUN TestParsePathInfoJSON/empty_input276=== PAUSE TestParsePathInfoJSON/empty_input277=== RUN TestParsePathInfoJSON/whitespace_only2782026/10/25 13:43:34 ERROR Upload failed error=boom count=1279=== PAUSE TestParsePathInfoJSON/whitespace_only280=== CONT TestDoWithRetry_FinalResponseBodyReadable281=== CONT TestStreamPushIsolatesFailures2822026/10/25 13:43:34 ERROR Upload failed error="bad path" count=32832026/10/25 13:43:34 INFO Garbage collection started284=== CONT TestShellSplit285=== CONT TestEncodeNixBase32/empty_input286=== CONT TestSetClientTLSErrors/missing_cert_file287=== CONT TestSetClientTLSErrors/invalid_ca_file2882026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=server-test rate=52892026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:579782902026/10/25 13:43:34 WARN Rate limiter backed off name=server-test rate=5291=== CONT TestSetClientTLSErrors/missing_ca_file292=== CONT TestSetClientTLSErrors/missing_key_file2932026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:57976294=== CONT TestPathInfoCACompatibility/null_ca_field295=== CONT TestPathInfoCACompatibility/new_structured_format_-_text296=== CONT TestSupersededNARStillUploadsListing/small_NAR297=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method298=== CONT TestUploadMultipart_SupersededByPeer/exists299=== CONT TestStreamPushBatchesUnderLoad300=== CONT TestSetClientTLSDoesNotMutateDefaultTransport3012026/10/25 13:43:34 INFO Uploading abc-hello (1.0GB)302--- PASS: TestScriptTokenEmptyToken (0.02s)303--- PASS: TestScriptTokenBadJSON (0.02s)304--- PASS: TestFileTokenMissing (0.00s)305=== CONT TestStreamPushReportsEveryPath306=== RUN TestParsePathInfoJSON/invalid_JSON3072026/10/25 13:43:34 INFO Garbage collection started308=== CONT TestShellSplitErrors309=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry310=== CONT TestEncodeNixBase32/test_string_hash311--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)312=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails313=== PAUSE TestParsePathInfoJSON/invalid_JSON314=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3152026/10/25 13:43:34 INFO Uploading abc-hello (1.0GB)316=== CONT TestUploadMultipart_SupersededByPeer/missing317=== CONT TestPartSizeForNAR/zero_stays_at_minimum318--- PASS: TestStreamPushReportsSignatures (0.00s)319--- PASS: TestFileTokenReadsAndCaches (0.01s)320--- PASS: TestResolveStorePath (0.01s)321--- PASS: TestStreamPushIsolatesFailures (0.00s)322--- PASS: TestShellSplit (0.00s)323=== CONT TestPartSizeForNAR/capped_at_5_GiB324--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)325--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)326--- PASS: TestShellSplitErrors (0.00s)327--- PASS: TestStreamPushReportsEveryPath (0.00s)328=== CONT TestPartSizeForNAR/5_TiB_S3_max_object329--- PASS: TestEncodeNixBase32 (0.00s)330 --- PASS: TestEncodeNixBase32/empty_input (0.00s)331 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)332--- PASS: TestSetClientTLSErrors (0.01s)333 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)334 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)335 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)336 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.01s)337--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)338=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts339=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum340=== CONT TestPartSizeForNAR/small_stays_at_minimum341=== CONT TestPathInfoCACompatibility/old_string_format_-_text342=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)343=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512344=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI345=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon346--- PASS: TestPathInfoHashCompatibility (0.00s)347 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)349 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)350 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)351=== CONT TestFilterOversizedClosures/no_limit_keeps_everything352=== CONT TestFilterOversizedClosures/all_closures_skipped3532026/10/25 13:43:34 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=50354=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3552026/10/25 13:43:34 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=2000356--- PASS: TestFilterOversizedClosures (0.00s)357 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)358 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)359 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)360=== CONT TestSetClientTLS/rejects_connection_without_client_cert3612026/10/25 13:43:34 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=03622026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:57976363=== CONT TestConvertHashToNix32/SRI_format_to_Nix32364=== CONT TestSetClientTLS/preserves_debug_logging_transport365=== CONT TestPartSizeForNAR/1_TiB366--- PASS: TestPartSizeForNAR (0.00s)367 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)369 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)370 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)372 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)373 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)374=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA375=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive376--- PASS: TestPathInfoCACompatibility (0.00s)377 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)379 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)381 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)382=== CONT TestConvertHashToNix32/invalid_format383=== CONT TestConvertHashToNix32/already_Nix32_format384--- PASS: TestConvertHashToNix32 (0.01s)385 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)386 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)387 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)388=== CONT TestGetStorePathHash/valid_store_path389=== CONT TestRateLimiterFeedback/429_enables_limiter3902026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=s3-test rate=53912026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:579763922026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=server-test rate=53932026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:58005394--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)395 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)396 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3972026/10/25 13:43:34 WARN Rate limiter backed off name=server-test rate=5398=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error399=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error400=== CONT TestGetStorePathHash/basename_without_hyphen_should_error401--- PASS: TestGetStorePathHash (0.01s)402 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)403 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)404 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)405 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)406=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter407=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter408=== CONT TestRateLimiterFeedback/503_enables_limiter4092026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=server-test rate=54102026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:580144112026/10/25 13:43:34 WARN Garbage collection finished on another replica. Its statistics are not available here412--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)413=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths414=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths415--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)416 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)417 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)418=== CONT TestParsePathInfoJSON/Nix_format419=== CONT TestParsePathInfoJSON/invalid_JSON420=== CONT TestParsePathInfoJSON/whitespace_only421=== CONT TestParsePathInfoJSON/empty_input422=== CONT TestParsePathInfoJSON/Lix_format423--- PASS: TestParsePathInfoJSON (0.02s)424 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)425 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)426 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)427 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)428 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)4292026/10/25 13:43:34 WARN Rate limiter backed off name=server-test rate=5430--- PASS: TestStreamPushRequestLine (0.03s)4312026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:57976432--- PASS: TestRateLimiterFeedback (0.01s)433 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)434 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)435 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)436 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)4372026/10/25 13:43:34 WARN Rate limiter enabled after throttle name=s3-test rate=54382026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58007439--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)4402026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:579764412026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:579764422026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:579764432026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:579764442026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:57976445--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)4462026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:579764472026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:579764482026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:579764492026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:579764502026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:579764512026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:57976452--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)4532026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:57976454--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)4552026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:579764562026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:579764572026/10/25 13:43:34 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:57976458--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)4592026/10/25 13:43:34 http: TLS handshake error from 127.0.0.1:57998: remote error: tls: bad certificate460--- PASS: TestSetClientTLS (0.02s)461 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)462 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)463 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.04s)464--- PASS: TestDumpPathWriterError (0.10s)465--- PASS: TestDumpPathSingleFile (0.10s)4662026/10/25 13:43:34 INFO Uploading abc-hello (1.0GB)467--- PASS: TestCaseHackSuffix (0.10s)4682026/10/25 13:43:34 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:57995/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:57995/part/24692026/10/25 13:43:34 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"470--- PASS: TestStreamPushBatchesUnderLoad (0.10s)471--- PASS: TestDumpPathMatchesNix (0.13s)472--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.58s)473--- PASS: TestSupersededNARStillUploadsListing (0.00s)474 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)475 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)476 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.58s)477--- PASS: TestUploadMultipart_PartsInParallel (0.63s)4782026/10/25 13:43:35 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57906/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57906/api/uploads/complete4792026/10/25 13:43:35 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57906/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57906/api/uploads/complete4802026/10/25 13:43:35 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4812026/10/25 13:43:35 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:57906/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:57906/api/uploads/complete4822026/10/25 13:43:35 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"483--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4842026/10/25 13:43:35 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)486PASS487Running server tests...488The files belonging to this database system will be owned by user "_tribuchetbld3".489This user must also own the server process.490491The database cluster will be initialized with locale "C".492The default database encoding has accordingly been set to "SQL_ASCII".493The default text search configuration will be set to "english".494495Data page checksums are enabled.496497creating directory /private/var/tb/3/scratch/fc1b79881df5265f/build/postgres1578015898/data ... ok498creating subdirectories ... ok499selecting dynamic shared memory implementation ... posix500selecting default "max_connections" ... 100501selecting default "shared_buffers" ... 128MB502selecting default time zone ... UTC503creating configuration files ... ok504running bootstrap script ... ok505performing post-bootstrap initialization ... ok506syncing data to disk ... ok507508initdb: warning: enabling "trust" authentication for local connections509initdb: 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.510511Success. You can now start the database server using:512513 pg_ctl -D /private/var/tb/3/scratch/fc1b79881df5265f/build/postgres1578015898/data -l logfile start514515/private/var/tb/3/scratch/fc1b79881df5265f/build/postgres1578015898:5432 - no response5162026-10-25 13:43:36.460 UTC [37935] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5172026-10-25 13:43:36.461 UTC [37935] LOG: listening on Unix socket "/private/var/tb/3/scratch/fc1b79881df5265f/build/postgres1578015898/.s.PGSQL.5432"5182026-10-25 13:43:36.463 UTC [37942] LOG: database system was shut down at 2026-10-25 13:43:36 UTC5192026-10-25 13:43:36.463 UTC [37935] LOG: database system is ready to accept connections520/private/var/tb/3/scratch/fc1b79881df5265f/build/postgres1578015898:5432 - accepting connections521{"timestamp":"2026-10-25T13:43:36.679479Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"38289583-53fd-4198-b1e4-d4d59c6d77e9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}522=== RUN TestService_AuthMiddleware523=== PAUSE TestService_AuthMiddleware524=== RUN TestService_AuthMiddleware_MTLSProxyHeader525=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader526=== RUN TestService_AuthMiddleware_MTLSBoundSubjects527=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects528=== RUN TestService_ReadAuthMiddleware529=== PAUSE TestService_ReadAuthMiddleware530=== RUN TestService_AuthMiddleware_OIDC531=== PAUSE TestService_AuthMiddleware_OIDC532=== RUN TestService_RequireScope_OIDC533=== PAUSE TestService_RequireScope_OIDC534=== RUN TestService_ReadScope_PublicByDefault535=== PAUSE TestService_ReadScope_PublicByDefault536=== RUN TestCacheConfigHandler537=== PAUSE TestCacheConfigHandler538=== RUN TestCacheStatsHandler539=== PAUSE TestCacheStatsHandler540=== RUN TestClientCADerivations541=== PAUSE TestClientCADerivations542=== RUN TestClientErrorHandling543=== PAUSE TestClientErrorHandling544=== RUN TestClientIntegration545=== PAUSE TestClientIntegration546=== RUN TestClientMultipleUploads547=== PAUSE TestClientMultipleUploads548=== RUN TestClientWithDependencies549=== PAUSE TestClientWithDependencies550=== RUN TestClientSharedPathCommittedMidPush551=== PAUSE TestClientSharedPathCommittedMidPush552=== RUN TestPinProtectsFromGC553=== PAUSE TestPinProtectsFromGC554=== RUN TestClientPushesUseOnePush555=== PAUSE TestClientPushesUseOnePush556=== RUN TestClientFallsBackToClosures557=== PAUSE TestClientFallsBackToClosures558=== RUN TestDeleteClosuresRacingPins559=== PAUSE TestDeleteClosuresRacingPins560=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock562=== RUN TestResolveDBConnectionString563=== PAUSE TestResolveDBConnectionString564=== RUN TestConnectWaitsForAPeerMigration565=== PAUSE TestConnectWaitsForAPeerMigration566=== RUN TestLeadElectsOneAndHandsOver567=== PAUSE TestLeadElectsOneAndHandsOver568=== RUN TestLeadIncumbentWinsAfterRestart5692026/10/25 13:43:36 INFO lead: acquired remote=192.0.2.1:12345702026/10/25 13:43:37 INFO lead: released remote=192.0.2.1:12345712026/10/25 13:43:37 INFO lead: acquired remote=192.0.2.1:12345722026/10/25 13:43:38 INFO lead: released remote=192.0.2.1:1234573--- PASS: TestLeadIncumbentWinsAfterRestart (1.94s)574=== RUN TestLeadIncumbentAnnouncesAtOnce575=== PAUSE TestLeadIncumbentAnnouncesAtOnce576=== RUN TestLeadEndsOnShutdown577=== PAUSE TestLeadEndsOnShutdown578=== RUN TestLeadEndsWhenItsConnectionHangs5792026/10/25 13:43:38 INFO lead: acquired remote=192.0.2.1:12345802026-10-25 13:43:40.083 UTC [37992] FATAL: terminating connection due to administrator command5812026/10/25 13:43:40 INFO lead: acquired remote=192.0.2.1:12345822026/10/25 13:43:41 WARN lead: lock connection lost error="timeout: context deadline exceeded"5832026/10/25 13:43:41 INFO lead: released remote=192.0.2.1:12345842026/10/25 13:43:41 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadEndsWhenItsConnectionHangs (2.96s)586=== RUN TestGCAdvisoryLockBlocksConcurrentRun587=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun588=== RUN TestGCBugBareHashReferences589=== PAUSE TestGCBugBareHashReferences590=== RUN TestGCMetrics591=== PAUSE TestGCMetrics592=== RUN TestPushDedupSurvivesConcurrentGC593=== PAUSE TestPushDedupSurvivesConcurrentGC594=== RUN TestDeduplicatedObjectsRecordedAsPending595=== PAUSE TestDeduplicatedObjectsRecordedAsPending596=== RUN TestGCSweepSkipsPendingObjects597=== PAUSE TestGCSweepSkipsPendingObjects598=== RUN TestTombstonedObjectOfferedWithoutWaiting599=== PAUSE TestTombstonedObjectOfferedWithoutWaiting600=== RUN TestGCSweepDeliversEachKeyOnce601=== PAUSE TestGCSweepDeliversEachKeyOnce602=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection604=== RUN TestForceGCDuringPushOffersSweptObject605=== PAUSE TestForceGCDuringPushOffersSweptObject606=== RUN TestFailedS3DeleteKeepsTombstone607=== PAUSE TestFailedS3DeleteKeepsTombstone608=== RUN TestSweepSkipsRowsLockedByPush609=== PAUSE TestSweepSkipsRowsLockedByPush610=== RUN TestRegisterCompletedObjectNeedsPendingRow611=== PAUSE TestRegisterCompletedObjectNeedsPendingRow612=== RUN TestGetExistingObjectsLocksRows613=== PAUSE TestGetExistingObjectsLocksRows614=== RUN TestSweepRechecksPendingAfterLocking615=== PAUSE TestSweepRechecksPendingAfterLocking616=== RUN TestPushWaitsForSweepHoldingRow617=== PAUSE TestPushWaitsForSweepHoldingRow618=== RUN TestCommitRacingPendingCleanupKeepsObjects619=== PAUSE TestCommitRacingPendingCleanupKeepsObjects620=== RUN TestGCEndsOnShutdown621=== PAUSE TestGCEndsOnShutdown622=== RUN TestGCTaskStore_StartNew623=== PAUSE TestGCTaskStore_StartNew624=== RUN TestGCTaskStore_DeduplicateSameParams625=== PAUSE TestGCTaskStore_DeduplicateSameParams626=== RUN TestGCTaskStore_ConflictDifferentParams627=== PAUSE TestGCTaskStore_ConflictDifferentParams628=== RUN TestGCTaskStore_GetEmpty629=== PAUSE TestGCTaskStore_GetEmpty630=== RUN TestGCTaskStore_GetReturnsLatest631=== PAUSE TestGCTaskStore_GetReturnsLatest632=== RUN TestGCTaskStore_CompletedAllowsNewTask633=== PAUSE TestGCTaskStore_CompletedAllowsNewTask634=== RUN TestGCTaskStore_PhaseUpdates635=== PAUSE TestGCTaskStore_PhaseUpdates636=== RUN TestGCTaskStore_Fail637=== PAUSE TestGCTaskStore_Fail638=== RUN TestGracefulShutdownDrainsInflight639=== PAUSE TestGracefulShutdownDrainsInflight640=== RUN TestService_healthCheckHandler641=== PAUSE TestService_healthCheckHandler642=== RUN TestService_readinessHandler643=== PAUSE TestService_readinessHandler644=== RUN TestGenerateLandingPage645=== PAUSE TestGenerateLandingPage646=== RUN TestCacheConfigHandlerMaxNarSize647=== PAUSE TestCacheConfigHandlerMaxNarSize648=== RUN TestCreatePendingClosureRejectsOversizedNAR649=== PAUSE TestCreatePendingClosureRejectsOversizedNAR650=== RUN TestNARDeduplicationMetadataUploadBug651=== PAUSE TestNARDeduplicationMetadataUploadBug652=== RUN TestMetricsInventory653=== PAUSE TestMetricsInventory654=== RUN TestMetricsCommit655=== PAUSE TestMetricsCommit656=== RUN TestService_NativeMTLS657=== PAUSE TestService_NativeMTLS658=== RUN TestServerTLSConfig659=== PAUSE TestServerTLSConfig660=== RUN TestMultipartCleanup661=== PAUSE TestMultipartCleanup662=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded664=== RUN TestPendingCleanupUsesOneCutoff665=== PAUSE TestPendingCleanupUsesOneCutoff666=== RUN TestObjectStatsTrigger667=== PAUSE TestObjectStatsTrigger668=== RUN TestObjectStatsLargeCommit669=== PAUSE TestObjectStatsLargeCommit670=== RUN TestOrphanedObjectsGC671=== PAUSE TestOrphanedObjectsGC672=== RUN TestOrphanedObjectsGCStressTest673=== PAUSE TestOrphanedObjectsGCStressTest674=== RUN TestCreatePin_ReservedPins675=== PAUSE TestCreatePin_ReservedPins676=== RUN TestPresentReportsOnlyClosureRoots677=== PAUSE TestPresentReportsOnlyClosureRoots678=== RUN TestPresentRefreshesOnlyStaleClosures679=== PAUSE TestPresentRefreshesOnlyStaleClosures680=== RUN TestPresentNotReportedWhileGCDeletesClosure681=== PAUSE TestPresentNotReportedWhileGCDeletesClosure682=== RUN TestParseSingleRange683=== PAUSE TestParseSingleRange684=== RUN TestProxyHeadersOnlyTrustedOnSocket6852026/10/25 13:43:41 INFO Starting HTTP server address=127.0.0.1:580416862026/10/25 13:43:41 INFO Starting HTTP server address=proxy.sock6872026/10/25 13:43:41 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6882026/10/25 13:43:41 INFO Shutdown signal received, draining in-flight requests timeout=10s689--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)690=== RUN TestIsValidCachePath691=== PAUSE TestIsValidCachePath692=== RUN TestReadProxyNarinfo693=== PAUSE TestReadProxyNarinfo694=== RUN TestReadProxyNarinfoAlreadyDecompressed695=== PAUSE TestReadProxyNarinfoAlreadyDecompressed696=== RUN TestReadProxyContentNegotiation697=== PAUSE TestReadProxyContentNegotiation698=== RUN TestReadProxyNarStreaming699=== PAUSE TestReadProxyNarStreaming700=== RUN TestReadProxy404701=== PAUSE TestReadProxy404702=== RUN TestReadProxyInvalidPath703=== PAUSE TestReadProxyInvalidPath704=== RUN TestReadProxyHead705=== PAUSE TestReadProxyHead706=== RUN TestReadProxyOutlastsServerWriteTimeout707=== PAUSE TestReadProxyOutlastsServerWriteTimeout708=== RUN TestReadProxyConditionalGet709=== PAUSE TestReadProxyConditionalGet710=== RUN TestReadProxyRootRedirectsToIndexHTML711=== PAUSE TestReadProxyRootRedirectsToIndexHTML712=== RUN TestReadProxyDisabled713=== PAUSE TestReadProxyDisabled714=== RUN TestReadRedirectNar715=== PAUSE TestReadRedirectNar716=== RUN TestReadRedirectKeepsNarinfoProxied717=== PAUSE TestReadRedirectKeepsNarinfoProxied718=== RUN TestReadProxyRangeRequest719=== PAUSE TestReadProxyRangeRequest720=== RUN TestReadRedirectUsesPublicS3URL721=== PAUSE TestReadRedirectUsesPublicS3URL722=== RUN TestPush_OverlappingRootsStoreOneRowPerKey723=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey724=== RUN TestPush_CompleteCommitsEveryRoot725=== PAUSE TestPush_CompleteCommitsEveryRoot726=== RUN TestPush_RepeatedRootCommitsOnce727=== PAUSE TestPush_RepeatedRootCommitsOnce728=== RUN TestPush_CompleteWaitsForCleanupOfThePush729=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush730=== RUN TestPush_RootsAreLockedInByteOrder731=== PAUSE TestPush_RootsAreLockedInByteOrder732=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit733=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit734=== RUN TestPush_RejectsBadRequests735=== PAUSE TestPush_RejectsBadRequests736=== RUN TestPush_SignsNarinfosOfItsPendingObjects737=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects738=== RUN TestRedundantMultipartUpload739=== PAUSE TestRedundantMultipartUpload740=== RUN TestCompleteMultipartUpload_ErrorButObjectExists741=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists742=== RUN TestCompletedNarNotReofferedAcrossClosures743=== PAUSE TestCompletedNarNotReofferedAcrossClosures744=== RUN TestPresignedUploadRegisteredBeforeCommit745=== PAUSE TestPresignedUploadRegisteredBeforeCommit746=== RUN TestService_Rustfstest747=== PAUSE TestService_Rustfstest748=== RUN TestParseSize749=== PAUSE TestParseSize750=== RUN TestSkippedUploadsHandler751=== PAUSE TestSkippedUploadsHandler752=== RUN TestSystemdListenerNotActivated753--- PASS: TestSystemdListenerNotActivated (0.00s)754=== RUN TestWatchdogBeatsWhenHealthy755--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)756=== RUN TestWatchdogSkipsWhenUnhealthy7572026/10/25 13:43:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/25 13:43:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/25 13:43:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/25 13:43:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 13:43:41 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 13:43:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 13:43:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 13:43:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 13:43:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 13:43:42 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"767--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)768=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle770=== RUN TestProxyWriteTimeout771=== PAUSE TestProxyWriteTimeout772=== RUN TestPendingClosureWriteTimeout773=== PAUSE TestPendingClosureWriteTimeout774=== RUN TestIsValidUploadKey775=== PAUSE TestIsValidUploadKey776=== RUN TestUploadHandlersRejectInvalidKeys777=== PAUSE TestUploadHandlersRejectInvalidKeys778=== RUN TestUploadHandlersRejectOversizedBody779=== PAUSE TestUploadHandlersRejectOversizedBody780=== RUN TestService_cleanupPendingClosuresHandler781=== PAUSE TestService_cleanupPendingClosuresHandler782=== RUN TestService_createPendingClosureHandler783=== PAUSE TestService_createPendingClosureHandler784=== RUN TestService_verifyS3Integrity785=== PAUSE TestService_verifyS3Integrity786=== RUN TestCompleteMultipartUnregistered787=== PAUSE TestCompleteMultipartUnregistered788=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT789=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT790=== CONT TestOrphanedObjectsGC791=== CONT TestObjectStatsLargeCommit792=== CONT TestPinProtectsFromGC793=== CONT TestService_ReadScope_PublicByDefault794=== CONT TestClientCADerivations795=== CONT TestCacheConfigHandler796=== CONT TestService_AuthMiddleware797=== CONT TestDeduplicatedObjectsRecordedAsPending798=== CONT TestGCTaskStore_Fail799--- PASS: TestGCTaskStore_Fail (0.00s)800=== CONT TestObjectStatsTrigger801=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection802=== CONT TestPendingCleanupUsesOneCutoff803=== CONT TestTombstonedObjectOfferedWithoutWaiting804=== CONT TestGCBugBareHashReferences805=== CONT TestCacheStatsHandler806=== CONT TestClientWithDependencies807=== CONT TestGCSweepSkipsPendingObjects808=== CONT TestClientSharedPathCommittedMidPush809=== CONT TestClientMultipleUploads810=== CONT TestClientIntegration811=== CONT TestClientErrorHandling812=== RUN TestClientErrorHandling/InvalidStorePath813=== PAUSE TestClientErrorHandling/InvalidStorePath814=== RUN TestCacheConfigHandler/full_config,_no_issuer815=== CONT TestForceGCDuringPushOffersSweptObject816=== PAUSE TestCacheConfigHandler/full_config,_no_issuer817=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows818=== CONT TestPushDedupSurvivesConcurrentGC819=== RUN TestCacheConfigHandler/no_cache_url_configured820=== PAUSE TestCacheConfigHandler/no_cache_url_configured821=== RUN TestCacheConfigHandler/no_signing_keys822=== PAUSE TestCacheConfigHandler/no_signing_keys823=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator824=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator825=== CONT TestConnectWaitsForAPeerMigration826=== CONT TestGCMetrics827=== CONT TestGCSweepDeliversEachKeyOnce828=== RUN TestClientErrorHandling/InvalidAuthToken829=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows830=== PAUSE TestClientErrorHandling/InvalidAuthToken831=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check832=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check833=== CONT TestGCAdvisoryLockBlocksConcurrentRun834=== RUN TestClientErrorHandling/ServerNotAvailable835=== PAUSE TestClientErrorHandling/ServerNotAvailable836=== CONT TestLeadEndsOnShutdown8372026/10/25 13:43:43 INFO Received uploads request method=POST path=/api/pending_closures838--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.15s)839=== CONT TestLeadIncumbentAnnouncesAtOnce840--- PASS: TestGCBugBareHashReferences (2.08s)841=== CONT TestLeadElectsOneAndHandsOver842--- PASS: TestCacheStatsHandler (2.25s)843=== CONT TestNARDeduplicationMetadataUploadBug8442026/10/25 13:43:44 INFO Received uploads request method=POST path=/api/pending_closures8452026/10/25 13:43:44 INFO Aborted multipart uploads count=0 kept=08462026/10/25 13:43:44 WARN Force mode enabled - objects will be deleted immediately without grace period8472026/10/25 13:43:44 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=08482026/10/25 13:43:44 INFO Vacuumed table table=pending_closures8492026/10/25 13:43:44 INFO Vacuumed table table=pending_objects8502026/10/25 13:43:44 INFO Vacuumed table table=multipart_uploads8512026/10/25 13:43:44 INFO Vacuumed table table=closures8522026/10/25 13:43:44 INFO Vacuumed table table=objects853=== NAME TestOrphanedObjectsGC854 orphaned_objects_gc_test.go:287: GC Test Summary:855 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A856 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B857 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)858 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)859 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects860--- PASS: TestOrphanedObjectsGC (2.66s)861=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded862--- PASS: TestGCSweepSkipsPendingObjects (2.67s)863=== CONT TestMultipartCleanup8642026/10/25 13:43:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"865--- PASS: TestService_AuthMiddleware (2.84s)866=== CONT TestServerTLSConfig867=== RUN TestServerTLSConfig/no_client_CA868=== PAUSE TestServerTLSConfig/no_client_CA869=== RUN TestServerTLSConfig/missing_CA_file870=== PAUSE TestServerTLSConfig/missing_CA_file871=== RUN TestServerTLSConfig/not_a_PEM_file872=== PAUSE TestServerTLSConfig/not_a_PEM_file873=== CONT TestService_NativeMTLS8742026/10/25 13:43:45 INFO Received uploads request method=POST path=/api/pending_closures875--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.98s)876=== CONT TestMetricsCommit877=== NAME TestClientCADerivations878 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientCADerivations3986859094/001/store/aax6z7k0p3qzl71gs33cn11q2h6rqxnp-ca-test879 client_ca_test.go:139: Found 1 dependencies (including self)8802026/10/25 13:43:45 INFO Received push request method=POST path=/api/pushes8812026/10/25 13:43:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8822026/10/25 13:43:45 INFO Uploading aax6z7k0p3qzl71gs33cn11q2h6rqxnp-ca-test (144B)8832026/10/25 13:43:45 WARN Failed to register uploaded object key=aax6z7k0p3qzl71gs33cn11q2h6rqxnp.ls error="server returned 404: 404 page not found\n"8842026/10/25 13:43:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"8852026/10/25 13:43:45 WARN Failed to register uploaded object key=log/wnd31h9ynrcn8p19p6gpl9zlba67ny7l-ca-test.drv error="server returned 404: 404 page not found\n"8862026/10/25 13:43:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8872026/10/25 13:43:45 INFO Signed narinfos id=1 count=18882026/10/25 13:43:45 INFO Uploading 1 narinfos8892026/10/25 13:43:45 INFO Received complete push request method=POST path=/api/pushes/1/complete8902026/10/25 13:43:45 WARN Failed to register uploaded object key=aax6z7k0p3qzl71gs33cn11q2h6rqxnp.narinfo error="server returned 404: 404 page not found\n"8912026/10/25 13:43:45 INFO Completed push id=1 objects=4 duration=24.093542ms8922026/10/25 13:43:45 INFO Upload complete. (274ms)893 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientCADerivations3986859094/001/store/aax6z7k0p3qzl71gs33cn11q2h6rqxnp-ca-test894 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst895 Compression: zstd896=== NAME TestClientWithDependencies897 client_integration_test.go:613: Built derivation: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientWithDependencies2159530935/001/store/27x4mly5qf3mjj26v75wzdwcaibmdgqw-test-script898=== NAME TestClientCADerivations899 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n900 NarSize: 144901 References: 902 Deriver: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientCADerivations3986859094/001/store/wnd31h9ynrcn8p19p6gpl9zlba67ny7l-ca-test.drv903 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n904 client_ca_test.go:185: Checking for realisation files in S3...905 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations906 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache907=== NAME TestClientWithDependencies908 client_integration_test.go:615: Found 1 dependencies (including self)909=== NAME TestClientCADerivations910 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket9?endpoint=http://localhost:58021®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientCADerivations3986859094/001/store'911 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 19122026/10/25 13:43:45 INFO Received push request method=POST path=/api/pushes9132026/10/25 13:43:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9142026/10/25 13:43:45 INFO Uploading 27x4mly5qf3mjj26v75wzdwcaibmdgqw-test-script (136B)915--- PASS: TestClientCADerivations (3.63s)916=== CONT TestMetricsInventory9172026/10/25 13:43:45 INFO Aborted multipart uploads count=0 kept=09182026/10/25 13:43:45 WARN Failed to register uploaded object key=27x4mly5qf3mjj26v75wzdwcaibmdgqw.ls error="server returned 404: 404 page not found\n"9192026/10/25 13:43:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"9202026/10/25 13:43:45 WARN Force mode enabled - objects will be deleted immediately without grace period9212026/10/25 13:43:45 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=09222026/10/25 13:43:45 WARN Failed to register uploaded object key=log/8hv6jxv0qg1jr9hazq4zdk4di4rn9i97-test-script.drv error="server returned 404: 404 page not found\n"9232026/10/25 13:43:45 INFO Vacuumed table table=pending_closures9242026/10/25 13:43:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9252026/10/25 13:43:45 INFO Signed narinfos id=1 count=19262026/10/25 13:43:45 INFO Uploading 1 narinfos9272026/10/25 13:43:45 INFO Vacuumed table table=pending_objects9282026/10/25 13:43:45 INFO Vacuumed table table=multipart_uploads9292026/10/25 13:43:45 INFO Vacuumed table table=closures9302026/10/25 13:43:45 INFO Vacuumed table table=objects931--- PASS: TestGCMetrics (3.70s)932=== CONT TestPush_RepeatedRootCommitsOnce9332026/10/25 13:43:45 INFO Received complete push request method=POST path=/api/pushes/1/complete9342026/10/25 13:43:45 WARN Failed to register uploaded object key=27x4mly5qf3mjj26v75wzdwcaibmdgqw.narinfo error="server returned 404: 404 page not found\n"9352026/10/25 13:43:45 INFO Completed push id=1 objects=4 duration=26.233292ms9362026/10/25 13:43:45 INFO Upload complete. (235ms)937=== NAME TestClientWithDependencies938 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientWithDependencies2159530935/001/store) requires matching store prefix939=== NAME TestPinProtectsFromGC940 client_integration_test.go:731: Pinned store path: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestPinProtectsFromGC2875692118/001/store/h0ap9zg7dzicgxixlchs9my8q78asr8h-pinned-file.txt941 client_integration_test.go:732: Unpinned store path: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestPinProtectsFromGC2875692118/001/store/n3k5m90c3j4g0x25b84j29mjy08gkn9v-unpinned-file.txt942--- PASS: TestClientWithDependencies (3.83s)943=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9442026/10/25 13:43:45 INFO Received push request method=POST path=/api/pushes9452026/10/25 13:43:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9462026/10/25 13:43:46 INFO Uploading h0ap9zg7dzicgxixlchs9my8q78asr8h-pinned-file.txt (128B)947--- PASS: TestObjectStatsTrigger (3.95s)948=== CONT TestCompleteMultipartUnregistered9492026/10/25 13:43:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9502026/10/25 13:43:46 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"9512026/10/25 13:43:46 INFO Signed narinfos id=1 count=19522026/10/25 13:43:46 WARN Failed to register uploaded object key=h0ap9zg7dzicgxixlchs9my8q78asr8h.ls error="server returned 404: 404 page not found\n"9532026/10/25 13:43:46 INFO Uploading 1 narinfos9542026/10/25 13:43:46 INFO Received complete push request method=POST path=/api/pushes/1/complete9552026/10/25 13:43:46 WARN Failed to register uploaded object key=h0ap9zg7dzicgxixlchs9my8q78asr8h.narinfo error="server returned 404: 404 page not found\n"9562026/10/25 13:43:46 INFO Completed push id=1 objects=3 duration=14.878333ms9572026/10/25 13:43:46 INFO Upload complete. (224ms)9582026/10/25 13:43:46 INFO lead: acquired remote=192.0.2.1:12349592026/10/25 13:43:46 INFO Received push request method=POST path=/api/pushes9602026/10/25 13:43:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9612026/10/25 13:43:46 INFO Uploading n3k5m90c3j4g0x25b84j29mjy08gkn9v-unpinned-file.txt (128B)9622026/10/25 13:43:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9632026/10/25 13:43:46 INFO Signed narinfos id=2 count=19642026/10/25 13:43:46 WARN Failed to register uploaded object key=n3k5m90c3j4g0x25b84j29mjy08gkn9v.ls error="server returned 404: 404 page not found\n"9652026/10/25 13:43:46 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9662026/10/25 13:43:46 INFO Uploading 1 narinfos9672026/10/25 13:43:46 INFO Received complete push request method=POST path=/api/pushes/2/complete9682026/10/25 13:43:46 WARN Failed to register uploaded object key=n3k5m90c3j4g0x25b84j29mjy08gkn9v.narinfo error="server returned 404: 404 page not found\n"9692026/10/25 13:43:46 INFO Completed push id=2 objects=3 duration=743.833µs9702026/10/25 13:43:46 INFO Upload complete. (168ms)9712026/10/25 13:43:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures9722026/10/25 13:43:46 INFO Garbage collection started9732026/10/25 13:43:46 INFO Aborted multipart uploads count=0 kept=09742026/10/25 13:43:46 WARN Force mode enabled - objects will be deleted immediately without grace period975--- PASS: TestService_ReadScope_PublicByDefault (4.32s)976=== CONT TestService_verifyS3Integrity9772026/10/25 13:43:46 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=09782026/10/25 13:43:46 INFO Vacuumed table table=pending_closures9792026/10/25 13:43:46 INFO Vacuumed table table=pending_objects9802026/10/25 13:43:46 INFO Vacuumed table table=multipart_uploads9812026/10/25 13:43:46 INFO Vacuumed table table=closures9822026/10/25 13:43:46 INFO Vacuumed table table=objects983=== NAME TestClientIntegration984 client_integration_test.go:286: Created store path: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientIntegration4222888093/002/store/cdx21hszss6d5ry9110m0h0rx47zl25n-test-file.txt9852026/10/25 13:43:46 INFO Received push request method=POST path=/api/pushes9862026/10/25 13:43:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9872026/10/25 13:43:46 INFO Uploading cdx21hszss6d5ry9110m0h0rx47zl25n-test-file.txt (152B)9882026/10/25 13:43:46 WARN Failed to register uploaded object key=cdx21hszss6d5ry9110m0h0rx47zl25n.ls error="server returned 404: 404 page not found\n"9892026/10/25 13:43:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9902026/10/25 13:43:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9912026/10/25 13:43:46 INFO Signed narinfos id=1 count=19922026/10/25 13:43:46 INFO Uploading 1 narinfos993=== NAME TestClientMultipleUploads994 client_integration_test.go:358: Created store path 0: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientMultipleUploads1190980585/001/store/0w5s2y8aw27s96y9rwjdz2bhafmjx597-test-file-0.txt9952026/10/25 13:43:46 INFO Received complete push request method=POST path=/api/pushes/1/complete9962026/10/25 13:43:46 WARN Failed to register uploaded object key=cdx21hszss6d5ry9110m0h0rx47zl25n.narinfo error="server returned 404: 404 page not found\n"9972026/10/25 13:43:47 INFO Completed push id=1 objects=3 duration=30.486417ms9982026/10/25 13:43:47 INFO Upload complete. (213ms)9992026/10/25 13:43:47 INFO All 1 paths already cached1000=== NAME TestClientIntegration1001 client_integration_test.go:312: Retrieved narinfo from S3:1002 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientIntegration4222888093/002/store/cdx21hszss6d5ry9110m0h0rx47zl25n-test-file.txt1003 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1004 Compression: zstd1005 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11006 NarSize: 1521007 References: 1008 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11009 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1010=== NAME TestClientMultipleUploads1011 client_integration_test.go:358: Created store path 1: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientMultipleUploads1190980585/001/store/98pfk3zipvik0ryckssvf7lm0bn71q5d-test-file-1.txt1012=== NAME TestClientIntegration1013 client_integration_test.go:313: Decompressed .ls content (64 bytes):1014 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1015 client_integration_test.go:316: Testing garbage collection...10162026/10/25 13:43:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures10172026/10/25 13:43:47 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/25 13:43:47 INFO Garbage collection started10192026/10/25 13:43:47 INFO Aborted multipart uploads count=0 kept=010202026/10/25 13:43:47 WARN Force mode enabled - objects will be deleted immediately without grace period10212026/10/25 13:43:47 INFO Received uploads request method=POST path=/api/pending_closures1022=== NAME TestClientMultipleUploads1023 client_integration_test.go:358: Created store path 2: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientMultipleUploads1190980585/001/store/0msfirvb7pyv2kdi4gcsv2nxbah3xjk3-test-file-2.txt10242026/10/25 13:43:47 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=010252026/10/25 13:43:47 INFO Vacuumed table table=pending_closures10262026/10/25 13:43:47 INFO Aborted multipart uploads count=0 kept=010272026/10/25 13:43:47 INFO Vacuumed table table=pending_objects10282026/10/25 13:43:47 INFO Vacuumed table table=multipart_uploads10292026/10/25 13:43:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010302026/10/25 13:43:47 INFO Vacuumed table table=closures10312026/10/25 13:43:47 INFO Received push request method=POST path=/api/pushes10322026/10/25 13:43:47 INFO Vacuumed table table=pending_closures10332026/10/25 13:43:47 INFO lead: released remote=192.0.2.1:12341034--- PASS: TestLeadEndsOnShutdown (5.22s)1035=== CONT TestService_createPendingClosureHandler10362026/10/25 13:43:47 INFO Vacuumed table table=objects10372026/10/25 13:43:47 INFO Vacuumed table table=pending_objects10382026/10/25 13:43:47 INFO Vacuumed table table=multipart_uploads10392026/10/25 13:43:47 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)10402026/10/25 13:43:47 INFO Uploading 0msfirvb7pyv2kdi4gcsv2nxbah3xjk3-test-file-2.txt (160B)10412026/10/25 13:43:47 INFO Uploading 0w5s2y8aw27s96y9rwjdz2bhafmjx597-test-file-0.txt (160B)10422026/10/25 13:43:47 INFO Uploading 98pfk3zipvik0ryckssvf7lm0bn71q5d-test-file-1.txt (160B)10432026/10/25 13:43:47 INFO Vacuumed table table=closures10442026/10/25 13:43:47 INFO Vacuumed table table=objects10452026/10/25 13:43:47 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"10462026/10/25 13:43:47 WARN Failed to register uploaded object key=0w5s2y8aw27s96y9rwjdz2bhafmjx597.ls error="server returned 404: 404 page not found\n"10472026/10/25 13:43:47 WARN Failed to register uploaded object key=0msfirvb7pyv2kdi4gcsv2nxbah3xjk3.ls error="server returned 404: 404 page not found\n"10482026/10/25 13:43:47 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"10492026/10/25 13:43:47 INFO Aborted multipart uploads count=0 kept=010502026/10/25 13:43:47 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"10512026/10/25 13:43:47 WARN Failed to register uploaded object key=98pfk3zipvik0ryckssvf7lm0bn71q5d.ls error="server returned 404: 404 page not found\n"10522026/10/25 13:43:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10532026/10/25 13:43:47 WARN Force mode enabled - objects will be deleted immediately without grace period10542026/10/25 13:43:47 INFO Signed narinfos id=1 count=310552026/10/25 13:43:47 INFO Uploading 3 narinfos10562026/10/25 13:43:47 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=01057--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (5.33s)1058=== CONT TestService_cleanupPendingClosuresHandler10592026/10/25 13:43:47 INFO Vacuumed table table=pending_closures10602026/10/25 13:43:47 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1061--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.34s)1062=== CONT TestUploadHandlersRejectOversizedBody10632026/10/25 13:43:47 INFO Vacuumed table table=pending_objects10642026/10/25 13:43:47 INFO Vacuumed table table=multipart_uploads1065=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1066=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1067=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1068=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure10692026/10/25 13:43:47 WARN Failed to register uploaded object key=98pfk3zipvik0ryckssvf7lm0bn71q5d.narinfo error="server returned 404: 404 page not found\n"1070=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1071=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1072=== CONT TestUploadHandlersRejectInvalidKeys1073=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1074=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1075=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1076=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1077=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1078=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1079=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1080=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1081=== CONT TestIsValidUploadKey1082=== RUN TestIsValidUploadKey/narinfo1083=== PAUSE TestIsValidUploadKey/narinfo1084=== RUN TestIsValidUploadKey/nar_zst1085=== PAUSE TestIsValidUploadKey/nar_zst1086=== RUN TestIsValidUploadKey/nar_xz1087=== PAUSE TestIsValidUploadKey/nar_xz1088=== RUN TestIsValidUploadKey/nar_plain1089=== PAUSE TestIsValidUploadKey/nar_plain1090=== RUN TestIsValidUploadKey/listing1091=== PAUSE TestIsValidUploadKey/listing1092=== RUN TestIsValidUploadKey/build_log1093=== PAUSE TestIsValidUploadKey/build_log1094=== RUN TestIsValidUploadKey/build_log_home-manager_file1095=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1096=== RUN TestIsValidUploadKey/build_log_plus_in_name1097=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1098=== RUN TestIsValidUploadKey/build_log_question_mark1099=== PAUSE TestIsValidUploadKey/build_log_question_mark1100=== RUN TestIsValidUploadKey/build_log_equals1101=== PAUSE TestIsValidUploadKey/build_log_equals1102=== RUN TestIsValidUploadKey/realisation1103=== PAUSE TestIsValidUploadKey/realisation1104=== RUN TestIsValidUploadKey/realisation_plus_in_output1105=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1106=== RUN TestIsValidUploadKey/nix-cache-info1107=== PAUSE TestIsValidUploadKey/nix-cache-info1108=== RUN TestIsValidUploadKey/index.html1109=== PAUSE TestIsValidUploadKey/index.html1110=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1111=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1112=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1113=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1114=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1115=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1116=== RUN TestIsValidUploadKey/traversal1117=== PAUSE TestIsValidUploadKey/traversal1118=== RUN TestIsValidUploadKey/traversal_nar1119=== PAUSE TestIsValidUploadKey/traversal_nar1120=== RUN TestIsValidUploadKey/absolute1121=== PAUSE TestIsValidUploadKey/absolute1122=== RUN TestIsValidUploadKey/empty_key1123=== PAUSE TestIsValidUploadKey/empty_key1124=== RUN TestIsValidUploadKey/unknown_type1125=== PAUSE TestIsValidUploadKey/unknown_type1126=== CONT TestPendingClosureWriteTimeout1127=== RUN TestPendingClosureWriteTimeout/empty1128=== PAUSE TestPendingClosureWriteTimeout/empty1129=== RUN TestPendingClosureWriteTimeout/400_objects1130=== PAUSE TestPendingClosureWriteTimeout/400_objects1131=== RUN TestPendingClosureWriteTimeout/670k_objects1132=== PAUSE TestPendingClosureWriteTimeout/670k_objects1133=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1134=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1135=== CONT TestProxyWriteTimeout1136=== RUN TestProxyWriteTimeout/narinfo1137=== PAUSE TestProxyWriteTimeout/narinfo1138=== RUN TestProxyWriteTimeout/1_GiB_nar1139=== PAUSE TestProxyWriteTimeout/1_GiB_nar1140=== RUN TestProxyWriteTimeout/10_GiB_nar1141=== PAUSE TestProxyWriteTimeout/10_GiB_nar1142=== RUN TestProxyWriteTimeout/unknown_size11432026/10/25 13:43:47 INFO Vacuumed table table=closures11442026/10/25 13:43:47 INFO Received complete push request method=POST path=/api/pushes/1/complete11452026/10/25 13:43:47 WARN Failed to register uploaded object key=0msfirvb7pyv2kdi4gcsv2nxbah3xjk3.narinfo error="server returned 404: 404 page not found\n"11462026/10/25 13:43:47 WARN Failed to register uploaded object key=0w5s2y8aw27s96y9rwjdz2bhafmjx597.narinfo error="server returned 404: 404 page not found\n"1147=== PAUSE TestProxyWriteTimeout/unknown_size1148=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11492026/10/25 13:43:47 INFO Vacuumed table table=objects1150--- PASS: TestPushDedupSurvivesConcurrentGC (5.40s)1151=== CONT TestSkippedUploadsHandler11522026/10/25 13:43:47 INFO Client skipped oversized paths paths=3 nar_bytes=500000000011532026/10/25 13:43:47 INFO Completed push id=1 objects=9 duration=17.128375ms11542026/10/25 13:43:47 INFO Upload complete. (278ms)1155=== NAME TestClientMultipleUploads1156 client_integration_test.go:369: Uploaded 3 paths in 314.58675ms1157--- PASS: TestSkippedUploadsHandler (0.01s)1158=== CONT TestParseSize1159--- PASS: TestParseSize (0.00s)1160=== CONT TestService_Rustfstest1161--- PASS: TestClientMultipleUploads (5.46s)1162=== CONT TestPresignedUploadRegisteredBeforeCommit11632026/10/25 13:43:47 INFO Aborted multipart uploads count=0 kept=011642026/10/25 13:43:47 INFO Received uploads request method=POST path=/api/pending_closures11652026/10/25 13:43:47 WARN Force mode enabled - objects will be deleted immediately without grace period11662026/10/25 13:43:47 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=011672026/10/25 13:43:47 INFO Vacuumed table table=pending_closures11682026/10/25 13:43:47 INFO Vacuumed table table=pending_objects11692026/10/25 13:43:47 INFO Vacuumed table table=multipart_uploads11702026/10/25 13:43:47 INFO Vacuumed table table=closures11712026/10/25 13:43:48 INFO Vacuumed table table=objects11722026/10/25 13:43:48 INFO Received uploads request method=POST path=/api/pending_closures1173--- PASS: TestGCSweepDeliversEachKeyOnce (5.92s)1174=== CONT TestCompletedNarNotReofferedAcrossClosures11752026/10/25 13:43:48 INFO Received cleanup request method=DELETE path=/api/pending_closures11762026/10/25 13:43:48 INFO lead: acquired remote=192.0.2.1:123411772026/10/25 13:43:48 INFO lead: released remote=192.0.2.1:12341178--- PASS: TestLeadIncumbentAnnouncesAtOnce (5.04s)1179=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11802026/10/25 13:43:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011812026/10/25 13:43:48 INFO Received create pin request method=POST path=/api/pins/myapp11822026/10/25 13:43:48 INFO lead: acquired remote=192.0.2.1:123411832026/10/25 13:43:48 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestPinProtectsFromGC2875692118/001/store/h0ap9zg7dzicgxixlchs9my8q78asr8h-pinned-file.txt narinfo_key=h0ap9zg7dzicgxixlchs9my8q78asr8h.narinfo11842026/10/25 13:43:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures11852026/10/25 13:43:48 INFO Garbage collection started11862026/10/25 13:43:48 INFO Aborted multipart uploads count=0 kept=011872026/10/25 13:43:48 INFO Received push request method=POST path=/api/pushes11882026/10/25 13:43:48 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/25 13:43:48 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=011902026/10/25 13:43:48 INFO Vacuumed table table=pending_closures11912026/10/25 13:43:48 INFO Vacuumed table table=pending_objects11922026/10/25 13:43:48 INFO Vacuumed table table=multipart_uploads11932026/10/25 13:43:48 INFO Vacuumed table table=closures11942026/10/25 13:43:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11952026/10/25 13:43:48 INFO Uploading dmqvkxk6a3g14nbhpghyrg6i8i5wk08j-top (264B)11962026/10/25 13:43:48 INFO Vacuumed table table=objects11972026/10/25 13:43:48 INFO Uploading 9bg995yjn1bw2hp16cj2xaf09fdsqfcz-shared-dep (136B)11982026/10/25 13:43:48 WARN Failed to register uploaded object key=dmqvkxk6a3g14nbhpghyrg6i8i5wk08j.ls error="server returned 404: 404 page not found\n"11992026/10/25 13:43:48 WARN Failed to register uploaded object key=9bg995yjn1bw2hp16cj2xaf09fdsqfcz.ls error="server returned 404: 404 page not found\n"12002026/10/25 13:43:48 WARN Failed to register uploaded object key=nar/1i1zqkdj9kicn65wb48jvw8qxp32pm3rrp8d1hi6rbgfv97bl0zs.nar.zst error="server returned 404: 404 page not found\n"12012026/10/25 13:43:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12022026/10/25 13:43:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12032026/10/25 13:43:48 INFO Signed narinfos id=1 count=212042026/10/25 13:43:48 INFO Uploading 2 narinfos12052026/10/25 13:43:48 WARN Failed to register uploaded object key=dmqvkxk6a3g14nbhpghyrg6i8i5wk08j.narinfo error="server returned 404: 404 page not found\n"12062026/10/25 13:43:48 INFO Received complete push request method=POST path=/api/pushes/1/complete12072026/10/25 13:43:48 WARN Failed to register uploaded object key=9bg995yjn1bw2hp16cj2xaf09fdsqfcz.narinfo error="server returned 404: 404 page not found\n"12082026/10/25 13:43:48 INFO Completed push id=1 objects=6 duration=61.151709ms12092026/10/25 13:43:48 INFO Upload complete. (317ms)1210=== NAME TestClientSharedPathCommittedMidPush1211 client_integration_test.go:680: Retrieved narinfo from S3:1212 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientSharedPathCommittedMidPush2525871505/001/store/9bg995yjn1bw2hp16cj2xaf09fdsqfcz-shared-dep1213 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1214 Compression: zstd1215 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821216 NarSize: 1361217 References: 1218 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1219 client_integration_test.go:680: Retrieved narinfo from S3:1220 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientSharedPathCommittedMidPush2525871505/001/store/dmqvkxk6a3g14nbhpghyrg6i8i5wk08j-top1221 URL: nar/1i1zqkdj9kicn65wb48jvw8qxp32pm3rrp8d1hi6rbgfv97bl0zs.nar.zst1222 Compression: zstd1223 NarHash: sha256:1i1zqkdj9kicn65wb48jvw8qxp32pm3rrp8d1hi6rbgfv97bl0zs1224 NarSize: 2641225 References: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientSharedPathCommittedMidPush2525871505/001/store/9bg995yjn1bw2hp16cj2xaf09fdsqfcz-shared-dep1226 CA: text:sha256:1v844mvhcki9dgyk4kaydi94n9f8vwfcpixxqa4br7ippbdmq6bg1227--- PASS: TestClientSharedPathCommittedMidPush (6.68s)1228=== CONT TestRedundantMultipartUpload1229=== NAME TestNARDeduplicationMetadataUploadBug1230 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestNARDeduplicationMetadataUploadBug4248366634/001/store/f1r7zzakh5z7al5gilkzh51dqbim7bg1-file1.txt12312026/10/25 13:43:48 INFO Received uploads request method=POST path=/api/pending_closures1232--- PASS: TestConnectWaitsForAPeerMigration (6.87s)1233=== CONT TestPush_SignsNarinfosOfItsPendingObjects1234--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (4.24s)1235=== CONT TestPush_RejectsBadRequests12362026/10/25 13:43:49 INFO Received push request method=POST path=/api/pushes12372026/10/25 13:43:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12382026/10/25 13:43:49 INFO Uploading f1r7zzakh5z7al5gilkzh51dqbim7bg1-file1.txt (160B)12392026/10/25 13:43:49 WARN Failed to register uploaded object key=f1r7zzakh5z7al5gilkzh51dqbim7bg1.ls error="server returned 404: 404 page not found\n"12402026/10/25 13:43:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01241=== NAME TestClientIntegration1242 client_integration_test.go:323: Objects in database after GC:1243 client_integration_test.go:323: Successfully deleted all objects with GC --force12442026/10/25 13:43:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12452026/10/25 13:43:49 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12462026/10/25 13:43:49 INFO Signed narinfos id=1 count=112472026/10/25 13:43:49 INFO Uploading 1 narinfos12482026/10/25 13:43:49 INFO Received uploads request method=POST path=/api/pending_closures12492026/10/25 13:43:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12502026/10/25 13:43:49 WARN Failed to register uploaded object key=f1r7zzakh5z7al5gilkzh51dqbim7bg1.narinfo error="server returned 404: 404 page not found\n"12512026/10/25 13:43:49 INFO Completed push id=1 objects=3 duration=52.851792ms12522026/10/25 13:43:49 INFO Upload complete. (330ms)1253=== NAME TestNARDeduplicationMetadataUploadBug1254 metadata_upload_test.go:54: Retrieved narinfo from S3:1255 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestNARDeduplicationMetadataUploadBug4248366634/001/store/f1r7zzakh5z7al5gilkzh51dqbim7bg1-file1.txt1256 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1257 Compression: zstd1258 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1259 NarSize: 1601260 References: 1261 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1262 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1263 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1264 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1265--- PASS: TestClientIntegration (7.18s)1266=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1267=== NAME TestNARDeduplicationMetadataUploadBug1268 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/fc1b79881df5265f/build/TestNARDeduplicationMetadataUploadBug4248366634/001/store/971ii5yfac9gl1v8y9n3fb02q8x5kd6l-file2.txt12692026/10/25 13:43:49 INFO Received cleanup request method=DELETE path=/api/pending_closures12702026/10/25 13:43:49 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket31/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12712026/10/25 13:43:49 INFO Aborted multipart uploads count=0 kept=112722026/10/25 13:43:49 INFO Received cleanup request method=DELETE path=/api/pending_closures12732026/10/25 13:43:49 INFO Aborted multipart uploads count=1 kept=01274--- PASS: TestMultipartCleanup (4.68s)1275=== CONT TestPush_RootsAreLockedInByteOrder12762026/10/25 13:43:49 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12772026/10/25 13:43:49 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1278--- PASS: TestService_NativeMTLS (4.54s)1279=== CONT TestPush_CompleteWaitsForCleanupOfThePush12802026/10/25 13:43:49 INFO Received push request method=POST path=/api/pushes12812026/10/25 13:43:49 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12822026/10/25 13:43:49 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12832026/10/25 13:43:49 WARN Failed to register uploaded object key=971ii5yfac9gl1v8y9n3fb02q8x5kd6l.ls error="server returned 404: 404 page not found\n"12842026/10/25 13:43:49 INFO Signed narinfos id=2 count=112852026/10/25 13:43:49 INFO Uploading 1 narinfos12862026/10/25 13:43:49 INFO lead: released remote=192.0.2.1:123412872026/10/25 13:43:49 INFO Received complete push request method=POST path=/api/pushes/2/complete12882026/10/25 13:43:49 WARN Failed to register uploaded object key=971ii5yfac9gl1v8y9n3fb02q8x5kd6l.narinfo error="server returned 404: 404 page not found\n"12892026/10/25 13:43:49 INFO Completed push id=2 objects=3 duration=934.375µs12902026/10/25 13:43:49 INFO Upload complete. (229ms)1291=== NAME TestNARDeduplicationMetadataUploadBug1292 metadata_upload_test.go:76: Retrieved narinfo from S3:1293 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestNARDeduplicationMetadataUploadBug4248366634/001/store/971ii5yfac9gl1v8y9n3fb02q8x5kd6l-file2.txt1294 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1295 Compression: zstd1296 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1297 NarSize: 1601298 References: 1299 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1300 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1301 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1302 {"version":1,"root":{"type":"regular","size":44}}13032026/10/25 13:43:49 INFO lead: acquired remote=192.0.2.1:123413042026/10/25 13:43:49 INFO Received push request method=POST path=/api/pushes1305--- PASS: TestNARDeduplicationMetadataUploadBug (5.45s)1306=== CONT TestService_ReadAuthMiddleware13072026/10/25 13:43:49 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/25 13:43:49 INFO Completed push id=1 objects=4 duration=48.526208ms13092026/10/25 13:43:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13102026/10/25 13:43:49 INFO Completed upload id=2 objects=2 duration=1.734375ms1311--- PASS: TestMetricsCommit (4.89s)1312=== CONT TestService_RequireScope_OIDC13132026/10/25 13:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58199/oidc1314--- PASS: TestMetricsInventory (4.44s)1315=== CONT TestService_AuthMiddleware_OIDC13162026/10/25 13:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58203/oidc13172026/10/25 13:43:50 INFO Received uploads request method=POST path=/api/pending_closures1318=== NAME TestPinProtectsFromGC1319 client_integration_test.go:840: Pin successfully protected closure from garbage collection1320--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.61s)1321=== CONT TestReadProxyInvalidPath1322--- PASS: TestPinProtectsFromGC (8.51s)1323=== CONT TestPush_CompleteCommitsEveryRoot13242026/10/25 13:43:50 INFO Received push request method=POST path=/api/pushes13252026/10/25 13:43:50 INFO Received complete push request method=POST path=/api/pushes/1/complete13262026/10/25 13:43:50 INFO lead: released remote=192.0.2.1:12341327--- PASS: TestLeadElectsOneAndHandsOver (6.61s)1328=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13292026/10/25 13:43:50 INFO Completed push id=1 objects=4 duration=42.627292ms1330--- PASS: TestPush_RepeatedRootCommitsOnce (5.00s)1331=== CONT TestReadRedirectUsesPublicS3URL13322026/10/25 13:43:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13332026/10/25 13:43:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1334--- PASS: TestCompleteMultipartUnregistered (4.89s)1335=== CONT TestReadProxyRangeRequest13362026/10/25 13:43:51 INFO Received uploads request method=POST path=/api/pending_closures1337--- PASS: TestService_Rustfstest (4.11s)1338=== CONT TestReadRedirectKeepsNarinfoProxied13392026/10/25 13:43:51 INFO Received uploads request method=POST path=/api/pending_closures13402026/10/25 13:43:51 INFO Received uploads request method=POST path=/api/pending_closures13412026/10/25 13:43:51 INFO Received uploads request method=POST path=/api/pending_closures13422026/10/25 13:43:52 INFO Received cleanup request method=DELETE path=/api/pending_closures13432026/10/25 13:43:52 INFO Aborted multipart uploads count=0 kept=013442026/10/25 13:43:52 INFO Received uploads request method=POST path=/api/pending_closures13452026/10/25 13:43:52 INFO Received cleanup request method=DELETE path=/api/pending_closures13462026/10/25 13:43:52 INFO Aborted multipart uploads count=1 kept=013472026/10/25 13:43:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13482026-10-25 13:43:52.552 UTC [38223] ERROR: Closure does not exist: id=113492026-10-25 13:43:52.552 UTC [38223] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE13502026-10-25 13:43:52.552 UTC [38223] STATEMENT: -- name: CommitPendingClosure :one1351 SELECT commit_pending_closure($1::bigint)::bigint1352 1353--- PASS: TestService_cleanupPendingClosuresHandler (5.12s)1354=== CONT TestReadRedirectNar13552026/10/25 13:43:52 INFO Received uploads request method=POST path=/api/pending_closures13562026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures13572026/10/25 13:43:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13582026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures13592026/10/25 13:43:53 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13602026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures1361--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.94s)1362=== CONT TestReadProxyDisabled13632026/10/25 13:43:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13642026/10/25 13:43:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLjllYWRjZjEwLTE3ZTMtNDBhMy1hNDNjLTA0OGNhN2U1NjIxOHgxNzkyOTM1ODMxMzA2NjQ0MDAw parts=1013652026/10/25 13:43:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13662026/10/25 13:43:53 INFO Completed upload id=1 objects=2 duration=13.574542ms13672026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures13682026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures13692026/10/25 13:43:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13702026/10/25 13:43:53 WARN Found objects in DB but missing from S3, will re-upload count=11371--- PASS: TestService_verifyS3Integrity (7.24s)1372=== CONT TestReadProxyRootRedirectsToIndexHTML13732026/10/25 13:43:53 INFO Received uploads request method=POST path=/api/pending_closures13742026/10/25 13:43:54 INFO Aborted multipart uploads count=1 kept=013752026/10/25 13:43:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13762026/10/25 13:43:54 INFO Received uploads request method=POST path=/api/pending_closures13772026/10/25 13:43:54 INFO Received cleanup request method=DELETE path=/api/pending_closures13782026/10/25 13:43:54 INFO Aborted multipart uploads count=1 kept=01379--- PASS: TestPendingCleanupUsesOneCutoff (12.27s)1380=== CONT TestReadProxyConditionalGet13812026/10/25 13:43:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13822026/10/25 13:43:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLjhlYTMxN2NhLWVkMTctNGUwNS1iNjUyLTI1NTI3Njk0OTZjMXgxNzkyOTM1ODMzOTAyNzgwMDAw13832026/10/25 13:43:54 INFO Received uploads request method=POST path=/api/pending_closures13842026/10/25 13:43:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLjhlYTMxN2NhLWVkMTctNGUwNS1iNjUyLTI1NTI3Njk0OTZjMXgxNzkyOTM1ODMzOTAyNzgwMDAw parts=113852026/10/25 13:43:54 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLjBhZTg0ODJkLWE0YWUtNGRiNy1hMDA4LTE5ZDM3MjBmNzNhOXgxNzkyOTM1ODMyMDc2MjgyMDAw parts=1013862026/10/25 13:43:54 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1387--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.20s)1388=== CONT TestReadProxyOutlastsServerWriteTimeout13892026/10/25 13:43:54 INFO Received push request method=POST path=/api/pushes13902026/10/25 13:43:54 INFO Completed upload id=1 objects=2 duration=184.038708ms13912026/10/25 13:43:54 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013922026/10/25 13:43:54 INFO Received uploads request method=POST path=/api/pending_closures13932026/10/25 13:43:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures13942026/10/25 13:43:54 INFO Aborted multipart uploads count=0 kept=013952026/10/25 13:43:54 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=013962026/10/25 13:43:54 INFO Vacuumed table table=pending_closures13972026/10/25 13:43:54 INFO Vacuumed table table=pending_objects13982026/10/25 13:43:54 INFO Received complete push request method=POST path=/api/pushes/1/complete13992026/10/25 13:43:54 INFO Completed push id=1 objects=4 duration=49.410958ms14002026/10/25 13:43:54 INFO Received push request method=POST path=/api/pushes14012026/10/25 13:43:54 INFO Vacuumed table table=multipart_uploads14022026/10/25 13:43:55 INFO Vacuumed table table=closures14032026/10/25 13:43:55 INFO Aborted multipart uploads count=0 kept=014042026/10/25 13:43:55 INFO Vacuumed table table=objects14052026/10/25 13:43:55 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001406--- PASS: TestService_createPendingClosureHandler (7.76s)14072026/10/25 13:43:55 WARN Force mode enabled - objects will be deleted immediately without grace period1408=== CONT TestReadProxyHead14092026/10/25 13:43:55 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=014102026/10/25 13:43:55 INFO Received push request method=POST path=/api/pushes14112026/10/25 13:43:55 INFO Vacuumed table table=pending_closures14122026/10/25 13:43:55 INFO Vacuumed table table=pending_objects1413--- PASS: TestObjectStatsLargeCommit (13.17s)1414=== CONT TestGenerateLandingPage1415--- PASS: TestGenerateLandingPage (0.00s)1416=== CONT TestCreatePendingClosureRejectsOversizedNAR14172026/10/25 13:43:55 INFO Received uploads request method=POST path=/api/pending_closures1418--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1419=== CONT TestCacheConfigHandlerMaxNarSize1420--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1421=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14222026/10/25 13:43:55 INFO Vacuumed table table=multipart_uploads14232026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14242026/10/25 13:43:55 INFO Signed narinfos id=1 count=114252026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14262026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14272026/10/25 13:43:55 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14282026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14292026/10/25 13:43:55 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14302026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14312026/10/25 13:43:55 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114322026/10/25 13:43:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14332026/10/25 13:43:55 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1434--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (6.42s)14352026/10/25 13:43:55 INFO Vacuumed table table=closures1436=== CONT TestDeleteClosuresRacingPins14372026/10/25 13:43:55 INFO Vacuumed table table=objects14382026/10/25 13:43:55 INFO Received complete push request method=POST path=/api/pushes/2/complete14392026/10/25 13:43:55 INFO Completed push id=2 objects=4 duration=9.765375ms1440--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (6.18s)1441=== CONT TestResolveDBConnectionString1442=== RUN TestResolveDBConnectionString/flag_wins1443=== PAUSE TestResolveDBConnectionString/flag_wins1444=== RUN TestResolveDBConnectionString/file_when_flag_empty1445=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1446=== RUN TestResolveDBConnectionString/missing_file_is_an_error1447=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1448=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1449=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1450=== RUN TestResolveDBConnectionString/nothing_configured1451=== PAUSE TestResolveDBConnectionString/nothing_configured1452=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1453=== RUN TestPush_RejectsBadRequests/bad_root1454=== PAUSE TestPush_RejectsBadRequests/bad_root1455=== RUN TestPush_RejectsBadRequests/root_not_in_objects1456=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1457=== RUN TestPush_RejectsBadRequests/no_roots1458=== PAUSE TestPush_RejectsBadRequests/no_roots1459=== RUN TestPush_RejectsBadRequests/no_objects1460=== PAUSE TestPush_RejectsBadRequests/no_objects1461=== CONT TestGCEndsOnShutdown1462=== RUN TestGCEndsOnShutdown/before_the_run1463=== PAUSE TestGCEndsOnShutdown/before_the_run1464=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1465=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1466=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1467=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1468=== CONT TestGCTaskStore_PhaseUpdates1469--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1470=== CONT TestGCTaskStore_CompletedAllowsNewTask1471--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1472=== CONT TestGCTaskStore_GetReturnsLatest1473--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1474=== CONT TestGCTaskStore_GetEmpty1475--- PASS: TestGCTaskStore_GetEmpty (0.00s)1476=== CONT TestGCTaskStore_ConflictDifferentParams1477--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1478=== CONT TestGCTaskStore_DeduplicateSameParams1479--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1480=== CONT TestGCTaskStore_StartNew1481--- PASS: TestGCTaskStore_StartNew (0.00s)1482=== CONT TestService_healthCheckHandler14832026/10/25 13:43:56 INFO Received push request method=POST path=/api/pushes14842026-10-25 13:43:56.232 UTC [38300] ERROR: could not obtain lock on row in relation "closures"14852026-10-25 13:43:56.232 UTC [38300] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14862026-10-25 13:43:56.237 UTC [38300] ERROR: could not obtain lock on row in relation "closures"14872026-10-25 13:43:56.237 UTC [38300] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14882026-10-25 13:43:56.237 UTC [38300] ERROR: could not obtain lock on row in relation "closures"14892026-10-25 13:43:56.237 UTC [38300] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14902026-10-25 13:43:56.237 UTC [38300] ERROR: could not obtain lock on row in relation "closures"14912026-10-25 13:43:56.237 UTC [38300] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14922026-10-25 13:43:56.237 UTC [38300] ERROR: could not obtain lock on row in relation "closures"14932026-10-25 13:43:56.237 UTC [38300] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1494--- PASS: TestPush_RootsAreLockedInByteOrder (6.81s)1495=== CONT TestService_readinessHandler14962026/10/25 13:43:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14972026/10/25 13:43:56 INFO Received push request method=POST path=/api/pushes14982026/10/25 13:43:56 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLmM4N2FlOGQ3LWEwNzYtNGExZS1iZGUyLWM3YzE1ZDk2NDg5OHgxNzkyOTM1ODMzNTM0NzI5MDAw parts=1214992026/10/25 13:43:56 INFO Received uploads request method=POST path=/api/pending_closures1500--- PASS: TestCompletedNarNotReofferedAcrossClosures (8.47s)1501=== CONT TestGetExistingObjectsLocksRows1502--- PASS: TestService_ReadAuthMiddleware (7.02s)1503=== CONT TestCommitRacingPendingCleanupKeepsObjects15042026-10-25 13:43:56.902 UTC [38306] ERROR: Push does not exist: id=115052026-10-25 13:43:56.902 UTC [38306] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15062026-10-25 13:43:56.902 UTC [38306] STATEMENT: SELECT commit_push($1)1507--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (7.43s)1508=== CONT TestPushWaitsForSweepHoldingRow1509=== RUN TestService_RequireScope_OIDC/builder_may_write1510=== PAUSE TestService_RequireScope_OIDC/builder_may_write1511=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1512=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1513=== RUN TestService_RequireScope_OIDC/ops_may_admin1514=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1515=== RUN TestService_RequireScope_OIDC/ops_may_not_write1516=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1517=== RUN TestService_RequireScope_OIDC/reader_may_not_write1518=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1519=== RUN TestService_RequireScope_OIDC/static_token_may_admin1520=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1521=== RUN TestService_RequireScope_OIDC/static_token_may_write1522=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1523=== RUN TestService_RequireScope_OIDC/reader_may_read1524=== PAUSE TestService_RequireScope_OIDC/reader_may_read1525=== RUN TestService_RequireScope_OIDC/writer_implies_read1526=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1527=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1528=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1529=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1530=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1531=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1532=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1533=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1534=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1535=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1536=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1537=== CONT TestSweepRechecksPendingAfterLocking15382026/10/25 13:43:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15392026/10/25 13:43:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLjg5YzM5MzBmLTJlY2UtNDVhMy04NGIyLWNkMmE0YjMyMzFlMHgxNzkyOTM1ODM0MzkwNjY3MDAw parts=1215402026/10/25 13:43:57 INFO Received uploads request method=POST path=/api/pending_closures15412026/10/25 13:43:57 INFO Received uploads request method=POST path=/api/pending_closures1542=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1543=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1544=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1545=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1546=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1547=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1548=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1549=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1550=== CONT TestClientFallsBackToClosures1551--- PASS: TestReadProxyInvalidPath (7.37s)1552=== CONT TestService_AuthMiddleware_MTLSProxyHeader1553--- PASS: TestReadRedirectUsesPublicS3URL (7.57s)1554=== CONT TestIsValidCachePath1555=== RUN TestIsValidCachePath/narinfo1556=== PAUSE TestIsValidCachePath/narinfo1557=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1558=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1559=== RUN TestIsValidCachePath/nar_zst1560=== PAUSE TestIsValidCachePath/nar_zst1561=== RUN TestIsValidCachePath/nar_xz1562=== PAUSE TestIsValidCachePath/nar_xz1563=== RUN TestIsValidCachePath/nar_bz21564=== PAUSE TestIsValidCachePath/nar_bz21565=== RUN TestIsValidCachePath/nar_uncompressed1566=== PAUSE TestIsValidCachePath/nar_uncompressed1567=== RUN TestIsValidCachePath/ls1568=== PAUSE TestIsValidCachePath/ls1569=== RUN TestIsValidCachePath/log1570=== PAUSE TestIsValidCachePath/log1571=== RUN TestIsValidCachePath/realisation1572=== PAUSE TestIsValidCachePath/realisation1573=== RUN TestIsValidCachePath/nix-cache-info1574=== PAUSE TestIsValidCachePath/nix-cache-info1575=== RUN TestIsValidCachePath/index.html1576=== PAUSE TestIsValidCachePath/index.html1577=== RUN TestIsValidCachePath/traversal_parent1578=== PAUSE TestIsValidCachePath/traversal_parent1579=== RUN TestIsValidCachePath/traversal_in_middle1580=== PAUSE TestIsValidCachePath/traversal_in_middle1581=== RUN TestIsValidCachePath/invalid_char_e1582=== PAUSE TestIsValidCachePath/invalid_char_e1583=== RUN TestIsValidCachePath/invalid_char_u1584=== PAUSE TestIsValidCachePath/invalid_char_u1585=== RUN TestIsValidCachePath/random_path1586=== PAUSE TestIsValidCachePath/random_path1587=== RUN TestIsValidCachePath/empty1588=== PAUSE TestIsValidCachePath/empty1589=== RUN TestIsValidCachePath/leading_slash1590=== PAUSE TestIsValidCachePath/leading_slash1591=== RUN TestIsValidCachePath/wrong_extension1592=== PAUSE TestIsValidCachePath/wrong_extension1593=== RUN TestIsValidCachePath/short_hash1594=== PAUSE TestIsValidCachePath/short_hash1595=== CONT TestReadProxy40415962026/10/25 13:43:58 INFO Received push request method=POST path=/api/pushes15972026/10/25 13:43:58 WARN Rate limiter enabled after throttle name=s3-test rate=515982026/10/25 13:43:58 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1599=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1600 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101601 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001602--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.35s)1603=== CONT TestReadProxyNarStreaming16042026/10/25 13:43:58 INFO Received complete push request method=POST path=/api/pushes/1/complete16052026/10/25 13:43:58 INFO Completed push id=1 objects=6 duration=51.811416ms1606--- PASS: TestPush_CompleteCommitsEveryRoot (8.31s)1607=== CONT TestReadProxyContentNegotiation16082026/10/25 13:43:59 INFO Received push request method=POST path=/api/pushes1609--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (8.46s)1610=== CONT TestReadProxyNarinfoAlreadyDecompressed1611--- PASS: TestReadProxyRangeRequest (8.59s)1612=== CONT TestReadProxyNarinfo16132026/10/25 13:43:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16142026/10/25 13:43:59 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLmRlZGQ5MWUxLWRkMWYtNDU2MC04NDIzLWJiYjk0Y2FmODVlZngxNzkyOTM1ODM3NDQzMjM1MDAw error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"16152026/10/25 13:43:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ODZlYjI5OTctNmI0Ni00Nzk2LWI4MDEtZWZjMjgxYmNiNGIyLmNiYTQxN2QwLWZhNzUtNGVmYy1hYjhhLTRkZDM1NWJjZjRjOXgxNzkyOTM1ODM3Mzg5MzMwMDAw parts=1216162026/10/25 13:43:59 INFO Received cleanup request method=DELETE path=/api/pending_closures16172026/10/25 13:43:59 INFO Aborted multipart uploads count=1 kept=01618--- PASS: TestRedundantMultipartUpload (10.94s)1619=== CONT TestClientPushesUseOnePush1620--- PASS: TestReadRedirectKeepsNarinfoProxied (8.31s)1621=== CONT TestGracefulShutdownDrainsInflight16222026/10/25 13:43:59 INFO Starting HTTP server address=127.0.0.1:5830716232026/10/25 13:43:59 INFO Shutdown signal received, draining in-flight requests timeout=10s1624--- PASS: TestGracefulShutdownDrainsInflight (0.09s)1625=== CONT TestSweepSkipsRowsLockedByPush1626--- PASS: TestReadRedirectNar (7.63s)1627=== CONT TestRegisterCompletedObjectNeedsPendingRow1628--- PASS: TestReadProxyDisabled (6.91s)1629=== CONT TestFailedS3DeleteKeepsTombstone1630--- PASS: TestReadProxyRootRedirectsToIndexHTML (7.21s)1631=== CONT TestPresentRefreshesOnlyStaleClosures1632--- PASS: TestReadProxyConditionalGet (6.92s)1633=== CONT TestParseSingleRange1634=== RUN TestParseSingleRange/none1635=== PAUSE TestParseSingleRange/none1636=== RUN TestParseSingleRange/unknown_unit1637=== PAUSE TestParseSingleRange/unknown_unit1638=== RUN TestParseSingleRange/multi-range_ignored1639=== PAUSE TestParseSingleRange/multi-range_ignored1640=== RUN TestParseSingleRange/malformed_no_dash1641=== PAUSE TestParseSingleRange/malformed_no_dash1642=== RUN TestParseSingleRange/malformed_both_empty1643=== PAUSE TestParseSingleRange/malformed_both_empty1644=== RUN TestParseSingleRange/malformed_end_before_start1645=== PAUSE TestParseSingleRange/malformed_end_before_start1646=== RUN TestParseSingleRange/closed1647=== PAUSE TestParseSingleRange/closed1648=== RUN TestParseSingleRange/open-ended1649=== PAUSE TestParseSingleRange/open-ended1650=== RUN TestParseSingleRange/end_clamped_to_size1651=== PAUSE TestParseSingleRange/end_clamped_to_size1652=== RUN TestParseSingleRange/suffix1653=== PAUSE TestParseSingleRange/suffix1654=== RUN TestParseSingleRange/suffix_exceeds_size1655=== PAUSE TestParseSingleRange/suffix_exceeds_size1656=== RUN TestParseSingleRange/single_byte1657=== PAUSE TestParseSingleRange/single_byte1658=== RUN TestParseSingleRange/start_past_EOF1659=== PAUSE TestParseSingleRange/start_past_EOF1660=== RUN TestParseSingleRange/start_far_past_EOF1661=== PAUSE TestParseSingleRange/start_far_past_EOF1662=== CONT TestPresentNotReportedWhileGCDeletesClosure1663=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1664=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1665=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1666=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1667=== CONT TestCreatePin_ReservedPins16682026/10/25 13:44:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58328/oidc1669--- PASS: TestReadProxyHead (7.07s)1670=== CONT TestPresentReportsOnlyClosureRoots16712026/10/25 13:44:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16722026/10/25 13:44:02 WARN mTLS auth: bound subjects configured but subject DN unavailable16732026/10/25 13:44:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1674--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.18s)1675=== CONT TestOrphanedObjectsGCStressTest1676--- PASS: TestService_healthCheckHandler (7.93s)1677=== CONT TestCacheConfigHandler/full_config,_no_issuer1678=== CONT TestCacheConfigHandler/no_signing_keys1679=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1680=== CONT TestCacheConfigHandler/no_cache_url_configured1681--- PASS: TestCacheConfigHandler (0.00s)1682 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1683 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1684 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1685 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1686=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows16872026/10/25 13:44:03 WARN readiness check failed error="closed pool"1688--- PASS: TestService_readinessHandler (7.57s)1689=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1690--- PASS: TestGetExistingObjectsLocksRows (7.66s)1691=== CONT TestClientErrorHandling/InvalidStorePath1692--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.81s)1693=== CONT TestClientErrorHandling/ServerNotAvailable16942026/10/25 13:44:04 INFO Aborted multipart uploads count=0 kept=016952026/10/25 13:44:04 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/present16962026/10/25 13:44:04 WARN Force mode enabled - objects will be deleted immediately without grace period16972026/10/25 13:44:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016982026/10/25 13:44:04 INFO Vacuumed table table=pending_closures16992026/10/25 13:44:04 INFO Vacuumed table table=pending_objects17002026/10/25 13:44:04 INFO Vacuumed table table=multipart_uploads17012026/10/25 13:44:04 INFO Vacuumed table table=closures17022026/10/25 13:44:04 INFO Vacuumed table table=objects17032026/10/25 13:44:04 WARN Request failed, retrying attempt=2 backoff=184.677929ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17042026/10/25 13:44:04 INFO Received uploads request method=POST path=/api/pending_closures1705--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.02s)1706=== CONT TestClientErrorHandling/InvalidAuthToken17072026/10/25 13:44:05 WARN Request failed, retrying attempt=3 backoff=380.871706ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17082026/10/25 13:44:05 INFO Aborted multipart uploads count=0 kept=017092026/10/25 13:44:05 WARN Force mode enabled - objects will be deleted immediately without grace period17102026/10/25 13:44:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01711--- PASS: TestPushWaitsForSweepHoldingRow (8.44s)1712=== CONT TestServerTLSConfig/no_client_CA1713=== CONT TestServerTLSConfig/not_a_PEM_file17142026/10/25 13:44:05 INFO Vacuumed table table=pending_closures1715=== CONT TestServerTLSConfig/missing_CA_file1716--- PASS: TestServerTLSConfig (0.00s)1717 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1718 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1719 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1720=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17212026/10/25 13:44:05 INFO Received request for more parts method=POST path=/17222026/10/25 13:44:05 WARN Request failed, retrying attempt=4 backoff=723.899728ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17232026/10/25 13:44:05 INFO Vacuumed table table=pending_objects17242026/10/25 13:44:05 INFO Vacuumed table table=multipart_uploads17252026/10/25 13:44:05 INFO Vacuumed table table=closures1726=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17272026/10/25 13:44:05 INFO Received complete multipart upload request method=POST path=/17282026/10/25 13:44:05 INFO Vacuumed table table=objects1729=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17302026/10/25 13:44:05 INFO Received uploads request method=POST path=/1731--- PASS: TestSweepRechecksPendingAfterLocking (8.28s)1732=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17332026/10/25 13:44:05 INFO Received uploads request method=POST path=/1734=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17352026/10/25 13:44:05 INFO Received complete multipart upload request method=POST path=/1736=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17372026/10/25 13:44:05 INFO Received request for more parts method=POST path=/1738=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17392026/10/25 13:44:05 INFO Received uploads request method=POST path=/1740--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1741 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1742 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1743 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1744 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1745=== CONT TestIsValidUploadKey/narinfo1746=== CONT TestPendingClosureWriteTimeout/empty1747=== CONT TestIsValidUploadKey/unknown_type1748=== CONT TestIsValidUploadKey/empty_key1749=== CONT TestIsValidUploadKey/absolute1750=== CONT TestIsValidUploadKey/traversal_nar1751=== CONT TestIsValidUploadKey/traversal1752=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1753=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1754=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1755=== CONT TestIsValidUploadKey/index.html1756=== CONT TestIsValidUploadKey/nix-cache-info1757=== CONT TestIsValidUploadKey/realisation_plus_in_output1758=== CONT TestIsValidUploadKey/realisation1759=== CONT TestIsValidUploadKey/build_log_equals1760=== CONT TestIsValidUploadKey/build_log_question_mark1761=== CONT TestIsValidUploadKey/build_log_plus_in_name1762=== CONT TestIsValidUploadKey/build_log_home-manager_file1763=== CONT TestIsValidUploadKey/build_log1764=== CONT TestIsValidUploadKey/listing1765=== CONT TestIsValidUploadKey/nar_plain1766=== CONT TestIsValidUploadKey/nar_xz1767=== CONT TestIsValidUploadKey/nar_zst1768--- PASS: TestIsValidUploadKey (0.00s)1769 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1770 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1771 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1772 --- PASS: TestIsValidUploadKey/absolute (0.00s)1773 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1774 --- PASS: TestIsValidUploadKey/traversal (0.00s)1775 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1776 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1777 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1778 --- PASS: TestIsValidUploadKey/index.html (0.00s)1779 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1780 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1781 --- PASS: TestIsValidUploadKey/realisation (0.00s)1782 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1783 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1784 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1785 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1786 --- PASS: TestIsValidUploadKey/build_log (0.00s)1787 --- PASS: TestIsValidUploadKey/listing (0.00s)1788 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1789 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1790 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1791=== CONT TestPendingClosureWriteTimeout/670k_objects1792=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1793--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1794 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.06s)1795 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1796 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1797=== CONT TestPendingClosureWriteTimeout/400_objects1798=== CONT TestProxyWriteTimeout/narinfo1799=== CONT TestProxyWriteTimeout/10_GiB_nar1800=== CONT TestProxyWriteTimeout/unknown_size1801=== CONT TestProxyWriteTimeout/1_GiB_nar1802--- PASS: TestProxyWriteTimeout (0.01s)1803 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1804 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1805 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1806 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1807=== CONT TestResolveDBConnectionString/flag_wins1808=== CONT TestResolveDBConnectionString/nothing_configured1809=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1810=== CONT TestResolveDBConnectionString/file_when_flag_empty1811=== CONT TestResolveDBConnectionString/missing_file_is_an_error1812=== CONT TestPush_RejectsBadRequests/bad_root18132026/10/25 13:44:05 INFO Received push request method=POST path=/api/pushes1814=== CONT TestPush_RejectsBadRequests/no_roots18152026/10/25 13:44:05 INFO Received push request method=POST path=/api/pushes1816=== CONT TestPush_RejectsBadRequests/no_objects18172026/10/25 13:44:05 INFO Received push request method=POST path=/api/pushes1818=== CONT TestPush_RejectsBadRequests/root_not_in_objects18192026/10/25 13:44:05 INFO Received push request method=POST path=/api/pushes1820=== CONT TestGCEndsOnShutdown/before_the_run1821--- PASS: TestPush_RejectsBadRequests (6.61s)1822 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1823 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1824 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1825 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1826--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.85s)1827--- PASS: TestResolveDBConnectionString (0.04s)1828 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1829 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1830 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1831 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1832 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1833=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1834--- PASS: TestReadProxyOutlastsServerWriteTimeout (11.43s)1835=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18362026/10/25 13:44:06 INFO Received uploads request method=POST path=/api/pending_closures18372026/10/25 13:44:06 INFO Received uploads request method=POST path=/api/pending_closures18382026/10/25 13:44:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18392026/10/25 13:44:06 INFO Uploading gzqajwm28mdqf8ncsw2wzf251p45hmq3-a (256B)18402026/10/25 13:44:06 INFO Uploading 9ad1bdkbd619h6mml8696fds06647q7c-shared-dep (136B)18412026/10/25 13:44:06 WARN Request failed, retrying attempt=5 backoff=1.728284294s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18422026/10/25 13:44:06 WARN Failed to register uploaded object key=gzqajwm28mdqf8ncsw2wzf251p45hmq3.ls error="server returned 404: 404 page not found\n"18432026/10/25 13:44:06 WARN Failed to register uploaded object key=0rrzb9slyqkf93158ll0x2br81s3kxfh.ls error="server returned 404: 404 page not found\n"18442026/10/25 13:44:06 WARN Failed to register uploaded object key=9ad1bdkbd619h6mml8696fds06647q7c.ls error="server returned 404: 404 page not found\n"18452026/10/25 13:44:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18462026/10/25 13:44:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18472026/10/25 13:44:06 WARN Failed to register uploaded object key=nar/0lmsdci7rnh2025ard6psqvbhag1i6y8xc66gnpghz49dvjlqchn.nar.zst error="server returned 404: 404 page not found\n"18482026/10/25 13:44:06 INFO Signed narinfos id=2 count=218492026/10/25 13:44:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18502026/10/25 13:44:06 INFO Signed narinfos id=1 count=218512026/10/25 13:44:06 INFO Uploading 4 narinfos18522026/10/25 13:44:06 WARN Failed to register uploaded object key=gzqajwm28mdqf8ncsw2wzf251p45hmq3.narinfo error="server returned 404: 404 page not found\n"18532026/10/25 13:44:06 WARN Failed to register uploaded object key=9ad1bdkbd619h6mml8696fds06647q7c.narinfo error="server returned 404: 404 page not found\n"18542026/10/25 13:44:06 WARN Failed to register uploaded object key=0rrzb9slyqkf93158ll0x2br81s3kxfh.narinfo error="server returned 404: 404 page not found\n"1855--- PASS: TestReadProxy404 (7.93s)1856=== CONT TestService_RequireScope_OIDC/builder_may_write1857=== CONT TestService_RequireScope_OIDC/reader_may_read1858=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read18592026/10/25 13:44:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1860=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18612026/10/25 13:44:06 WARN Failed to register uploaded object key=9ad1bdkbd619h6mml8696fds06647q7c.narinfo error="server returned 404: 404 page not found\n"18622026/10/25 13:44:06 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]1863=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1864=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1865=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1866=== CONT TestService_RequireScope_OIDC/writer_implies_read1867=== CONT TestService_RequireScope_OIDC/reader_may_not_write1868=== CONT TestService_RequireScope_OIDC/static_token_may_write1869=== CONT TestService_RequireScope_OIDC/static_token_may_admin1870=== CONT TestService_RequireScope_OIDC/ops_may_admin1871=== CONT TestService_RequireScope_OIDC/ops_may_not_write1872=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1873=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1874=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18752026/10/25 13:44:06 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]1876=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1877=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18782026/10/25 13:44:06 INFO Completed upload id=1 objects=6 duration=29.177125ms1879--- PASS: TestService_RequireScope_OIDC (7.24s)1880 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1881 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1884 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1885 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1886 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1887 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18942026/10/25 13:44:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18952026/10/25 13:44:06 WARN Authentication failed token_preview=eyJhbGciOi...f5tf8JwlFA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1896=== CONT TestIsValidCachePath/narinfo1897=== CONT TestIsValidCachePath/index.html1898=== CONT TestIsValidCachePath/short_hash1899=== CONT TestIsValidCachePath/wrong_extension1900=== CONT TestIsValidCachePath/leading_slash1901=== CONT TestIsValidCachePath/empty19022026/10/25 13:44:06 INFO Completed upload id=2 objects=6 duration=2.6695ms1903=== CONT TestIsValidCachePath/random_path1904=== CONT TestIsValidCachePath/invalid_char_u1905=== CONT TestIsValidCachePath/invalid_char_e1906=== CONT TestIsValidCachePath/traversal_in_middle1907=== CONT TestIsValidCachePath/traversal_parent1908=== CONT TestIsValidCachePath/nar_uncompressed1909=== CONT TestIsValidCachePath/nix-cache-info19102026/10/25 13:44:06 INFO Upload complete. (428ms)1911=== CONT TestIsValidCachePath/realisation1912--- PASS: TestService_AuthMiddleware_OIDC (7.38s)1913 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1914 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)1915 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1916 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1917=== NAME TestClientFallsBackToClosures1918 client_pushes_test.go:112: Retrieved narinfo from S3:1919 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientFallsBackToClosures1297998918/001/store/9ad1bdkbd619h6mml8696fds06647q7c-shared-dep1920 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1921 Compression: zstd1922 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821923 NarSize: 1361924 References: 1925 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1926=== CONT TestIsValidCachePath/log1927=== CONT TestIsValidCachePath/ls1928=== CONT TestIsValidCachePath/nar_xz1929=== CONT TestIsValidCachePath/nar_bz21930=== CONT TestIsValidCachePath/nar_zst1931=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1932=== CONT TestParseSingleRange/none1933=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1934--- PASS: TestIsValidCachePath (0.00s)1935 --- PASS: TestIsValidCachePath/narinfo (0.00s)1936 --- PASS: TestIsValidCachePath/index.html (0.00s)1937 --- PASS: TestIsValidCachePath/short_hash (0.00s)1938 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1939 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1940 --- PASS: TestIsValidCachePath/empty (0.00s)1941 --- PASS: TestIsValidCachePath/random_path (0.00s)1942 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1943 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1944 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1945 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1946 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1947 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1948 --- PASS: TestIsValidCachePath/realisation (0.00s)1949 --- PASS: TestIsValidCachePath/log (0.00s)1950 --- PASS: TestIsValidCachePath/ls (0.00s)1951 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1952 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1953 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1954 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1955=== NAME TestClientFallsBackToClosures1956 client_pushes_test.go:112: Retrieved narinfo from S3:1957 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientFallsBackToClosures1297998918/001/store/gzqajwm28mdqf8ncsw2wzf251p45hmq3-a1958 URL: nar/0lmsdci7rnh2025ard6psqvbhag1i6y8xc66gnpghz49dvjlqchn.nar.zst1959 Compression: zstd1960 NarHash: sha256:0lmsdci7rnh2025ard6psqvbhag1i6y8xc66gnpghz49dvjlqchn1961 NarSize: 2561962 References: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientFallsBackToClosures1297998918/001/store/9ad1bdkbd619h6mml8696fds06647q7c-shared-dep1963 CA: text:sha256:0kqcnycyi0aislfh7rkckdvw5ad4sfb0042ghc56gfzzq1m9cdhc1964 client_pushes_test.go:112: Retrieved narinfo from S3:1965 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientFallsBackToClosures1297998918/001/store/0rrzb9slyqkf93158ll0x2br81s3kxfh-b1966 URL: nar/0lmsdci7rnh2025ard6psqvbhag1i6y8xc66gnpghz49dvjlqchn.nar.zst1967 Compression: zstd1968 NarHash: sha256:0lmsdci7rnh2025ard6psqvbhag1i6y8xc66gnpghz49dvjlqchn1969 NarSize: 2561970 References: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientFallsBackToClosures1297998918/001/store/9ad1bdkbd619h6mml8696fds06647q7c-shared-dep1971 CA: text:sha256:0kqcnycyi0aislfh7rkckdvw5ad4sfb0042ghc56gfzzq1m9cdhc1972--- PASS: TestClientFallsBackToClosures (8.95s)1973=== CONT TestParseSingleRange/start_far_past_EOF1974=== CONT TestParseSingleRange/start_past_EOF1975=== CONT TestParseSingleRange/single_byte1976=== CONT TestParseSingleRange/suffix_exceeds_size1977=== CONT TestParseSingleRange/suffix1978=== CONT TestParseSingleRange/end_clamped_to_size1979=== CONT TestParseSingleRange/open-ended1980=== CONT TestParseSingleRange/closed1981=== CONT TestParseSingleRange/malformed_end_before_start1982=== CONT TestParseSingleRange/malformed_both_empty1983=== CONT TestParseSingleRange/malformed_no_dash1984=== CONT TestParseSingleRange/multi-range_ignored1985=== CONT TestParseSingleRange/unknown_unit1986--- PASS: TestParseSingleRange (0.02s)1987 --- PASS: TestParseSingleRange/none (0.00s)1988 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1989 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1990 --- PASS: TestParseSingleRange/single_byte (0.00s)1991 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1992 --- PASS: TestParseSingleRange/suffix (0.00s)1993 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1994 --- PASS: TestParseSingleRange/open-ended (0.00s)1995 --- PASS: TestParseSingleRange/closed (0.00s)1996 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1997 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1998 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1999 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2000 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2001=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2002--- PASS: TestReadProxyNarStreaming (7.69s)2003--- PASS: TestReadProxyContentNegotiation (8.13s)2004--- PASS: TestReadProxyNarinfoAlreadyDecompressed (8.00s)20052026-10-25 13:44:07.595 UTC [37940] LOG: checkpoint starting: wal20062026/10/25 13:44:07 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2007--- PASS: TestReadProxyNarinfo (8.10s)2008--- PASS: TestDeleteClosuresRacingPins (12.33s)20092026/10/25 13:44:07 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-config20102026/10/25 13:44:08 WARN Request failed, retrying attempt=2 backoff=219.565463ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20112026/10/25 13:44:08 WARN Request failed, retrying attempt=3 backoff=403.635755ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20122026/10/25 13:44:08 INFO Aborted multipart uploads count=0 kept=020132026/10/25 13:44:08 WARN Force mode enabled - objects will be deleted immediately without grace period20142026/10/25 13:44:08 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=020152026/10/25 13:44:08 INFO Vacuumed table table=pending_closures20162026/10/25 13:44:08 INFO Vacuumed table table=pending_objects20172026/10/25 13:44:08 INFO Vacuumed table table=multipart_uploads20182026/10/25 13:44:08 INFO Vacuumed table table=closures20192026/10/25 13:44:08 INFO Vacuumed table table=objects20202026/10/25 13:44:08 INFO Aborted multipart uploads count=0 kept=020212026/10/25 13:44:08 WARN Force mode enabled - objects will be deleted immediately without grace period20222026/10/25 13:44:08 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=020232026/10/25 13:44:08 INFO Vacuumed table table=pending_closures20242026/10/25 13:44:08 INFO Vacuumed table table=pending_objects20252026/10/25 13:44:08 INFO Vacuumed table table=multipart_uploads2026--- PASS: TestRegisterCompletedObjectNeedsPendingRow (8.32s)20272026/10/25 13:44:08 INFO Vacuumed table table=closures20282026/10/25 13:44:08 INFO Vacuumed table table=objects2029--- PASS: TestSweepSkipsRowsLockedByPush (8.52s)20302026/10/25 13:44:08 INFO Received push request method=POST path=/api/pushes20312026/10/25 13:44:08 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20322026/10/25 13:44:08 INFO Uploading xyzc755ngdn3g792gs0rsmw1dhfm5rb8-shared-dep (136B)20332026/10/25 13:44:08 INFO Uploading xmlq8nfy29gid1637473phi4dq9kwffr-a (256B)20342026/10/25 13:44:08 WARN Request failed, retrying attempt=4 backoff=841.560521ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20352026/10/25 13:44:08 WARN Failed to register uploaded object key=xmlq8nfy29gid1637473phi4dq9kwffr.ls error="server returned 404: 404 page not found\n"20362026/10/25 13:44:08 WARN Failed to register uploaded object key=2m4gk87ns0brg8n83wp6dm3b4aaghcml.ls error="server returned 404: 404 page not found\n"20372026/10/25 13:44:08 WARN Failed to register uploaded object key=nar/1zrja88xj7slsjmvim659b7mhf3646rx9528vw3kyxi0s7zngbgl.nar.zst error="server returned 404: 404 page not found\n"20382026/10/25 13:44:08 WARN Failed to register uploaded object key=xyzc755ngdn3g792gs0rsmw1dhfm5rb8.ls error="server returned 404: 404 page not found\n"20392026/10/25 13:44:08 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20402026/10/25 13:44:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20412026/10/25 13:44:08 INFO Signed narinfos id=1 count=320422026/10/25 13:44:08 INFO Uploading 3 narinfos20432026/10/25 13:44:08 WARN Failed to register uploaded object key=xyzc755ngdn3g792gs0rsmw1dhfm5rb8.narinfo error="server returned 404: 404 page not found\n"20442026/10/25 13:44:08 WARN Failed to register uploaded object key=2m4gk87ns0brg8n83wp6dm3b4aaghcml.narinfo error="server returned 404: 404 page not found\n"20452026/10/25 13:44:08 INFO Received complete push request method=POST path=/api/pushes/1/complete20462026/10/25 13:44:08 WARN Failed to register uploaded object key=xmlq8nfy29gid1637473phi4dq9kwffr.narinfo error="server returned 404: 404 page not found\n"20472026/10/25 13:44:08 INFO Received uploads request method=POST path=/api/pending_closures20482026/10/25 13:44:08 INFO Completed push id=1 objects=8 duration=18.471833ms20492026/10/25 13:44:08 INFO Upload complete. (344ms)2050=== NAME TestClientPushesUseOnePush2051 client_pushes_test.go:97: Retrieved narinfo from S3:2052 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientPushesUseOnePush3360538394/001/store/xyzc755ngdn3g792gs0rsmw1dhfm5rb8-shared-dep2053 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2054 Compression: zstd2055 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822056 NarSize: 1362057 References: 2058 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2059 client_pushes_test.go:97: Retrieved narinfo from S3:2060 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientPushesUseOnePush3360538394/001/store/xmlq8nfy29gid1637473phi4dq9kwffr-a2061 URL: nar/1zrja88xj7slsjmvim659b7mhf3646rx9528vw3kyxi0s7zngbgl.nar.zst2062 Compression: zstd2063 NarHash: sha256:1zrja88xj7slsjmvim659b7mhf3646rx9528vw3kyxi0s7zngbgl2064 NarSize: 2562065 References: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientPushesUseOnePush3360538394/001/store/xyzc755ngdn3g792gs0rsmw1dhfm5rb8-shared-dep2066 CA: text:sha256:1dybdlr2pfdzzjlvlscy3pjqfrl55l0c664vr442n8mfnpsvxrzc2067 client_pushes_test.go:97: Retrieved narinfo from S3:2068 StorePath: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientPushesUseOnePush3360538394/001/store/2m4gk87ns0brg8n83wp6dm3b4aaghcml-b2069 URL: nar/1zrja88xj7slsjmvim659b7mhf3646rx9528vw3kyxi0s7zngbgl.nar.zst2070 Compression: zstd2071 NarHash: sha256:1zrja88xj7slsjmvim659b7mhf3646rx9528vw3kyxi0s7zngbgl2072 NarSize: 2562073 References: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestClientPushesUseOnePush3360538394/001/store/xyzc755ngdn3g792gs0rsmw1dhfm5rb8-shared-dep2074 CA: text:sha256:1dybdlr2pfdzzjlvlscy3pjqfrl55l0c664vr442n8mfnpsvxrzc2075--- PASS: TestClientPushesUseOnePush (9.28s)20762026/10/25 13:44:09 INFO Aborted multipart uploads count=0 kept=020772026/10/25 13:44:09 WARN Force mode enabled - objects will be deleted immediately without grace period20782026/10/25 13:44:09 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."20792026/10/25 13:44:09 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."2080--- PASS: TestFailedS3DeleteKeepsTombstone (8.73s)2081--- PASS: TestPresentRefreshesOnlyStaleClosures (8.40s)20822026/10/25 13:44:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20832026/10/25 13:44:09 WARN Refused reserved pin name=worker-x86_64-linux20842026/10/25 13:44:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20852026/10/25 13:44:09 INFO Received create pin request method=POST path=/api/pins/my-app20862026/10/25 13:44:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux2087--- PASS: TestCreatePin_ReservedPins (8.21s)20882026/10/25 13:44:09 WARN Request failed, retrying attempt=5 backoff=1.500750812s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2089--- PASS: TestPresentReportsOnlyClosureRoots (7.59s)20902026/10/25 13:44:10 INFO Received uploads request method=POST path=/api/pending_closures20912026/10/25 13:44:10 INFO Aborted multipart uploads count=0 kept=020922026/10/25 13:44:10 WARN Force mode enabled - objects will be deleted immediately without grace period20932026/10/25 13:44:10 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=020942026/10/25 13:44:10 INFO Vacuumed table table=pending_closures20952026/10/25 13:44:10 INFO Vacuumed table table=pending_objects20962026/10/25 13:44:10 INFO Vacuumed table table=multipart_uploads20972026/10/25 13:44:10 INFO Vacuumed table table=closures20982026/10/25 13:44:10 INFO Vacuumed table table=objects20992026/10/25 13:44:10 INFO Received uploads request method=POST path=/api/pending_closures21002026/10/25 13:44:10 INFO Aborted multipart uploads count=0 kept=021012026/10/25 13:44:10 WARN Force mode enabled - objects will be deleted immediately without grace period21022026/10/25 13:44:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021032026/10/25 13:44:10 INFO Vacuumed table table=pending_closures21042026/10/25 13:44:10 INFO Vacuumed table table=pending_objects21052026/10/25 13:44:10 INFO Vacuumed table table=multipart_uploads21062026/10/25 13:44:10 INFO Vacuumed table table=closures21072026/10/25 13:44:10 INFO Vacuumed table table=objects2108--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2109 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.86s)2110 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.75s)21112026/10/25 13:44:11 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"21122026/10/25 13:44:11 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-config21132026/10/25 13:44:11 INFO Received uploads request method=POST path=/api/pending_closures21142026/10/25 13:44:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21152026/10/25 13:44:11 WARN Request failed, retrying attempt=2 backoff=202.428978ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/25 13:44:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21172026/10/25 13:44:11 WARN Request failed, retrying attempt=3 backoff=415.331602ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21182026/10/25 13:44:11 INFO Aborted multipart uploads count=0 kept=021192026/10/25 13:44:11 WARN Force mode enabled - objects will be deleted immediately without grace period21202026-10-25 13:44:11.439 UTC [38473] ERROR: canceling statement due to user request21212026-10-25 13:44:11.439 UTC [38473] STATEMENT: -- name: MarkStaleObjects :execrows2122 WITH RECURSIVE ct AS (2123 SELECT timezone('UTC', now()) AS now2124 ),2125 closure_reach AS (2126 -- Start with all closure keys2127 SELECT o.key, o.refs2128 FROM objects o2129 INNER JOIN closures c ON o.key = c.key2130 UNION2131 -- Recursively add all referenced objects2132 SELECT o.key, o.refs2133 FROM objects o2134 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2135 ),2136 reachable_objects AS (2137 SELECT DISTINCT key FROM closure_reach2138 ),2139 stale_objects AS (2140 SELECT o.key2141 FROM objects AS o, ct2142 WHERE2143 NOT EXISTS (2144 SELECT 12145 FROM reachable_objects ro2146 WHERE ro.key = o.key2147 )2148 AND NOT EXISTS (2149 SELECT 12150 FROM pending_objects AS po2151 WHERE po.key = o.key2152 )2153 AND o.deleted_at IS NULL -- Only mark fresh objects2154 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2155 FOR UPDATE2156 )2157 UPDATE objects2158 SET2159 deleted_at = ct.now,2160 first_deleted_at = COALESCE(first_deleted_at, ct.now)2161 FROM stale_objects, ct2162 WHERE objects.key = stale_objects.key2163 21642026/10/25 13:44:11 WARN Request failed, retrying attempt=4 backoff=730.348721ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2165--- PASS: TestPendingClosureWriteTimeout (0.00s)2166 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2167 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2168 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2169 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.48s)21702026/10/25 13:44:12 INFO Aborted multipart uploads count=0 kept=021712026/10/25 13:44:12 WARN Force mode enabled - objects will be deleted immediately without grace period21722026/10/25 13:44:12 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58021/bucket98/?delete=\": context canceled"2173--- PASS: TestGCEndsOnShutdown (0.01s)2174 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.69s)2175 --- PASS: TestGCEndsOnShutdown/before_the_run (5.96s)2176 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.13s)21772026/10/25 13:44:12 WARN Request failed, retrying attempt=5 backoff=1.456098186s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2178--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2179 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.39s)2180 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.59s)21812026/10/25 13:44:13 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_closures21822026/10/25 13:44:14 WARN Request failed, retrying attempt=2 backoff=217.495528ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21832026/10/25 13:44:14 WARN Request failed, retrying attempt=3 backoff=428.315517ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21842026/10/25 13:44:14 WARN Request failed, retrying attempt=4 backoff=723.082487ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21852026/10/25 13:44:15 WARN Request failed, retrying attempt=5 backoff=1.533981442s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2186--- PASS: TestClientErrorHandling (0.00s)2187 --- PASS: TestClientErrorHandling/InvalidStorePath (6.53s)2188 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.45s)2189 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.74s)2190=== NAME TestOrphanedObjectsGCStressTest2191 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2192 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2193 orphaned_objects_gc_test.go:503: Stress test completed successfully:2194 orphaned_objects_gc_test.go:504: - Active objects preserved: 202195 orphaned_objects_gc_test.go:505: - Objects deleted: 2102196 orphaned_objects_gc_test.go:506: - Total GC'd: 2102197--- PASS: TestOrphanedObjectsGCStressTest (15.19s)2198PASS2199{"timestamp":"2026-10-25T13:44:17.649488Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58237","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}22002026-10-25 13:44:17.742 UTC [37935] LOG: received smart shutdown request22012026-10-25 13:44:17.743 UTC [37935] LOG: background worker "logical replication launcher" (PID 37945) exited with exit code 122022026-10-25 13:44:18.987 UTC [37940] LOG: checkpoint complete: wrote 11076 buffers (67.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=10.571 s, sync=0.664 s, total=11.393 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=532974 kB, estimate=532974 kB; lsn=0/2287F468, redo lsn=0/22008B1022032026-10-25 13:44:18.988 UTC [37940] LOG: shutting down22042026-10-25 13:44:18.988 UTC [37940] LOG: checkpoint starting: shutdown immediate22052026-10-25 13:44:19.046 UTC [37940] LOG: checkpoint complete: wrote 1205 buffers (7.4%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.036 s, sync=0.022 s, total=0.058 s; sync files=476, longest=0.001 s, average=0.001 s; distance=8666 kB, estimate=480544 kB; lsn=0/2287F4E0, redo lsn=0/2287F4E022062026-10-25 13:44:19.052 UTC [37935] LOG: database system is shut down2207Running OIDC tests...2208=== RUN TestAudienceForIssuer2209=== PAUSE TestAudienceForIssuer2210=== RUN TestGlobMatch2211=== PAUSE TestGlobMatch2212=== RUN TestValidateToken_ValidToken2213=== PAUSE TestValidateToken_ValidToken2214=== RUN TestValidateToken_WrongAudience2215=== PAUSE TestValidateToken_WrongAudience2216=== RUN TestValidateToken_Expired2217=== PAUSE TestValidateToken_Expired2218=== RUN TestValidateToken_BoundClaimsMismatch2219=== PAUSE TestValidateToken_BoundClaimsMismatch2220=== RUN TestValidateToken_BoundSubjectMismatch2221=== PAUSE TestValidateToken_BoundSubjectMismatch2222=== RUN TestValidateToken_MultipleProviders2223=== PAUSE TestValidateToken_MultipleProviders2224=== RUN TestValidateToken_NoMatchingProvider2225=== PAUSE TestValidateToken_NoMatchingProvider2226=== RUN TestValidateToken_KubernetesServiceAccount2227=== PAUSE TestValidateToken_KubernetesServiceAccount2228=== RUN TestNewValidator_KubernetesRequiresCA2229=== PAUSE TestNewValidator_KubernetesRequiresCA2230=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2231=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2232=== RUN TestPins_ReservedForMatchingRule2233=== PAUSE TestPins_ReservedForMatchingRule2234=== RUN TestPins_TopLevelShorthand2235=== PAUSE TestPins_TopLevelShorthand2236=== RUN TestPins_ConfigValidation2237=== PAUSE TestPins_ConfigValidation2238=== RUN TestScopes_LegacyProviderDefaultsToWrite2239=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2240=== RUN TestScopes_Rules2241=== PAUSE TestScopes_Rules2242=== RUN TestScopes_ConfigValidation2243=== PAUSE TestScopes_ConfigValidation2244=== CONT TestAudienceForIssuer2245--- PASS: TestAudienceForIssuer (0.00s)2246=== CONT TestValidateToken_Expired2247=== CONT TestValidateToken_BoundClaimsMismatch2248=== CONT TestValidateToken_ValidToken2249=== CONT TestValidateToken_KubernetesServiceAccount2250=== CONT TestScopes_ConfigValidation2251=== CONT TestScopes_Rules2252=== CONT TestScopes_LegacyProviderDefaultsToWrite2253=== CONT TestPins_ConfigValidation2254--- PASS: TestScopes_ConfigValidation (0.00s)2255=== CONT TestPins_TopLevelShorthand2256=== CONT TestPins_ReservedForMatchingRule2257=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2258--- PASS: TestPins_ConfigValidation (0.00s)2259=== CONT TestNewValidator_KubernetesRequiresCA2260=== CONT TestValidateToken_WrongAudience2261=== CONT TestGlobMatch2262=== RUN TestGlobMatch/foo_foo2263=== PAUSE TestGlobMatch/foo_foo2264=== RUN TestGlobMatch/foo_bar2265=== PAUSE TestGlobMatch/foo_bar2266=== RUN TestGlobMatch/*_2267=== PAUSE TestGlobMatch/*_2268=== RUN TestGlobMatch/*_anything2269=== PAUSE TestGlobMatch/*_anything2270=== RUN TestGlobMatch/foo*_foo2271=== PAUSE TestGlobMatch/foo*_foo2272=== RUN TestGlobMatch/foo*_foobar2273=== PAUSE TestGlobMatch/foo*_foobar2274=== RUN TestGlobMatch/foo*_bar2275=== PAUSE TestGlobMatch/foo*_bar2276=== RUN TestGlobMatch/*bar_bar2277=== PAUSE TestGlobMatch/*bar_bar2278=== RUN TestGlobMatch/*bar_foobar2279=== PAUSE TestGlobMatch/*bar_foobar2280=== RUN TestGlobMatch/*bar_foo2281=== PAUSE TestGlobMatch/*bar_foo2282=== RUN TestGlobMatch/foo*bar_foobar2283=== PAUSE TestGlobMatch/foo*bar_foobar2284=== RUN TestGlobMatch/foo*bar_foo123bar2285=== PAUSE TestGlobMatch/foo*bar_foo123bar2286=== RUN TestGlobMatch/foo*bar_foobarbaz2287=== PAUSE TestGlobMatch/foo*bar_foobarbaz2288=== RUN TestGlobMatch/*/*_foo/bar2289=== PAUSE TestGlobMatch/*/*_foo/bar2290=== RUN TestGlobMatch/*/*_foo2291=== PAUSE TestGlobMatch/*/*_foo2292=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2293=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2294=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02295=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02296=== RUN TestGlobMatch/refs/*/main_refs/heads/main2297=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2298=== RUN TestGlobMatch/fo?_foo2299=== PAUSE TestGlobMatch/fo?_foo2300=== RUN TestGlobMatch/fo?_fo2301=== PAUSE TestGlobMatch/fo?_fo2302=== RUN TestGlobMatch/fo?_fooo2303=== PAUSE TestGlobMatch/fo?_fooo2304=== RUN TestGlobMatch/?oo_foo2305=== PAUSE TestGlobMatch/?oo_foo2306=== RUN TestGlobMatch/?oo_boo2307=== PAUSE TestGlobMatch/?oo_boo2308=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2309=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2310=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2311=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2312=== CONT TestGlobMatch/foo_foo2313=== CONT TestValidateToken_MultipleProviders2314=== CONT TestGlobMatch/*/*_foo/bar2315=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2316=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2317=== CONT TestGlobMatch/?oo_boo2318=== CONT TestGlobMatch/?oo_foo2319=== CONT TestGlobMatch/fo?_fooo2320=== CONT TestGlobMatch/fo?_fo2321=== CONT TestGlobMatch/fo?_foo2322=== CONT TestGlobMatch/refs/*/main_refs/heads/main2323=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02324=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2325=== CONT TestGlobMatch/*/*_foo2326=== CONT TestGlobMatch/*bar_bar2327=== CONT TestGlobMatch/foo*bar_foobarbaz2328=== CONT TestGlobMatch/foo*bar_foo123bar2329=== CONT TestGlobMatch/foo*bar_foobar2330=== CONT TestGlobMatch/*bar_foo2331=== CONT TestGlobMatch/*bar_foobar2332=== CONT TestGlobMatch/foo*_foo2333=== CONT TestGlobMatch/foo*_bar2334=== CONT TestGlobMatch/foo*_foobar2335=== CONT TestGlobMatch/*_2336=== CONT TestGlobMatch/*_anything2337=== CONT TestGlobMatch/foo_bar2338--- PASS: TestGlobMatch (0.00s)2339 --- PASS: TestGlobMatch/foo_foo (0.00s)2340 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2341 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2342 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2343 --- PASS: TestGlobMatch/?oo_boo (0.00s)2344 --- PASS: TestGlobMatch/?oo_foo (0.00s)2345 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2346 --- PASS: TestGlobMatch/fo?_fo (0.00s)2347 --- PASS: TestGlobMatch/fo?_foo (0.00s)2348 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2349 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2350 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2351 --- PASS: TestGlobMatch/*/*_foo (0.00s)2352 --- PASS: TestGlobMatch/*bar_bar (0.00s)2353 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2354 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2355 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2356 --- PASS: TestGlobMatch/*bar_foo (0.00s)2357 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2358 --- PASS: TestGlobMatch/foo*_foo (0.00s)2359 --- PASS: TestGlobMatch/foo*_bar (0.00s)2360 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2361 --- PASS: TestGlobMatch/*_ (0.00s)2362 --- PASS: TestGlobMatch/*_anything (0.00s)2363 --- PASS: TestGlobMatch/foo_bar (0.00s)2364=== CONT TestValidateToken_NoMatchingProvider2365=== CONT TestValidateToken_BoundSubjectMismatch23662026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58506/oidc2367--- PASS: TestValidateToken_Expired (0.08s)23682026/10/25 13:44:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5850723692026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58510/oidc2370--- PASS: TestValidateToken_ValidToken (0.09s)2371--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)23722026/10/25 13:44:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323732026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58514/oidc2374--- PASS: TestValidateToken_WrongAudience (0.08s)2375--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)23762026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58516/oidc2377--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)23782026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58518/oidc2379--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)23802026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58521/oidc2381--- PASS: TestPins_ReservedForMatchingRule (0.13s)23822026/10/25 13:44:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58520/oidc2383--- PASS: TestValidateToken_NoMatchingProvider (0.14s)23842026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58528/oidc2385--- PASS: TestPins_TopLevelShorthand (0.15s)23862026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58530/oidc23872026/10/25 13:44:20 http: TLS handshake error from 127.0.0.1:58525: read tcp 127.0.0.1:58524->127.0.0.1:58525: use of closed network connection2388--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)2389--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)23902026/10/25 13:44:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58523/oidc23912026/10/25 13:44:20 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:58533/oidc2392--- PASS: TestValidateToken_MultipleProviders (0.17s)23932026/10/25 13:44:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58536/oidc2394--- PASS: TestScopes_Rules (0.18s)2395PASS2396Running hook tests...2397=== RUN TestSendPathsEmpty2398=== PAUSE TestSendPathsEmpty2399=== RUN TestQueueEnqueueAndFetch2400=== PAUSE TestQueueEnqueueAndFetch2401=== RUN TestQueueDeduplication2402=== PAUSE TestQueueDeduplication2403=== RUN TestQueueRemove2404=== PAUSE TestQueueRemove2405=== RUN TestQueueFetchBatchLimit2406=== PAUSE TestQueueFetchBatchLimit2407=== RUN TestQueueRetryMovesToBack2408=== PAUSE TestQueueRetryMovesToBack2409=== RUN TestQueueFetchRemoveLifecycle2410=== PAUSE TestQueueFetchRemoveLifecycle2411=== RUN TestQueueConcurrentWriters2412=== PAUSE TestQueueConcurrentWriters2413=== RUN TestQueueRemoveLargeClosure2414=== PAUSE TestQueueRemoveLargeClosure2415=== RUN TestServerClientIntegration2416--- PASS: TestServerClientIntegration (0.00s)2417=== RUN TestServerQueueError24182026/10/25 13:44:21 ERROR Failed to queue paths error="permission denied" count=12419--- PASS: TestServerQueueError (0.00s)2420=== RUN TestGetListenerSocketActivation2421 server_test.go:146: systemd socket activation does not exist on darwin2422--- SKIP: TestGetListenerSocketActivation (0.00s)2423=== RUN TestDrainIsolatesPoisonPath2424=== PAUSE TestDrainIsolatesPoisonPath2425=== RUN TestRunNotBlockedByPoisonHead2426=== PAUSE TestRunNotBlockedByPoisonHead2427=== RUN TestDrainGivesUpWhenServerDown2428=== PAUSE TestDrainGivesUpWhenServerDown2429=== RUN TestFailedPathPrunedByLaterClosure2430=== PAUSE TestFailedPathPrunedByLaterClosure2431=== RUN TestWorkerUploadsAndRemoves2432=== PAUSE TestWorkerUploadsAndRemoves2433=== RUN TestWorkerSkipsGCdPaths2434=== PAUSE TestWorkerSkipsGCdPaths2435=== RUN TestWorkerPrunesClosureDeps2436=== PAUSE TestWorkerPrunesClosureDeps2437=== RUN TestDrainTimeout2438=== PAUSE TestDrainTimeout2439=== RUN TestWorkerRemoveFailureIsNotProgress2440=== PAUSE TestWorkerRemoveFailureIsNotProgress2441=== RUN TestWorkerKeepsPathItCannotStat2442=== PAUSE TestWorkerKeepsPathItCannotStat2443=== CONT TestSendPathsEmpty2444=== CONT TestQueueRetryMovesToBack2445--- PASS: TestSendPathsEmpty (0.00s)2446=== CONT TestWorkerKeepsPathItCannotStat2447=== CONT TestWorkerRemoveFailureIsNotProgress2448=== CONT TestDrainTimeout2449=== CONT TestWorkerPrunesClosureDeps2450=== CONT TestWorkerSkipsGCdPaths2451=== CONT TestWorkerUploadsAndRemoves2452=== CONT TestFailedPathPrunedByLaterClosure2453=== CONT TestDrainGivesUpWhenServerDown2454=== CONT TestRunNotBlockedByPoisonHead2455=== CONT TestQueueFetchBatchLimit2456=== CONT TestQueueRemoveLargeClosure2457=== CONT TestQueueRemove2458=== CONT TestDrainIsolatesPoisonPath2459=== CONT TestQueueDeduplication2460=== CONT TestQueueConcurrentWriters2461=== CONT TestQueueEnqueueAndFetch2462=== CONT TestQueueFetchRemoveLifecycle24632026/10/25 13:44:21 INFO Upload queue status pending=324642026/10/25 13:44:21 INFO Uploading batch count=424652026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=424662026/10/25 13:44:21 INFO Upload queue status pending=22467--- PASS: TestQueueFetchBatchLimit (0.01s)24682026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainIsolatesPoisonPath2825461363/002/bbb24692026/10/25 13:44:21 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa error="stat /private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa: permission denied"24702026/10/25 13:44:21 INFO Upload queue status pending=224712026/10/25 13:44:21 INFO Uploading batch count=12472--- PASS: TestQueueRemove (0.01s)24732026/10/25 13:44:21 INFO Uploading batch count=124742026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=124752026/10/25 13:44:21 INFO Uploading batch count=124762026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=124772026/10/25 13:44:21 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa error="stat /private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa: permission denied"24782026/10/25 13:44:21 INFO Uploading batch count=224792026/10/25 13:44:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerSkipsGCdPaths699306413/002/nonexistent24802026/10/25 13:44:21 INFO Upload queue status pending=224812026/10/25 13:44:21 INFO Uploading batch count=224822026/10/25 13:44:21 INFO Uploading batch count=224832026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=22484--- PASS: TestQueueEnqueueAndFetch (0.01s)24852026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/a24862026/10/25 13:44:21 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa error="stat /private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerKeepsPathItCannotStat1394622121/002/locked/aaa: permission denied"24872026/10/25 13:44:21 INFO Uploading batch count=124882026/10/25 13:44:21 INFO Uploading batch count=124892026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=124902026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/b24912026/10/25 13:44:21 ERROR Drain finished with paths left in queue remaining=12492--- PASS: TestQueueDeduplication (0.01s)24932026/10/25 13:44:21 INFO Uploading batch count=124942026/10/25 13:44:21 INFO Uploading batch count=224952026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=224962026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/c24972026/10/25 13:44:21 INFO Uploading batch count=124982026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=12499--- PASS: TestQueueRetryMovesToBack (0.02s)25002026/10/25 13:44:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerRemoveFailureIsNotProgress2363304644/002/nonexistent25012026/10/25 13:44:21 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125022026/10/25 13:44:21 INFO Uploading batch count=125032026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/d2504--- PASS: TestQueueFetchRemoveLifecycle (0.01s)25052026/10/25 13:44:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerRemoveFailureIsNotProgress2363304644/002/nonexistent25062026/10/25 13:44:21 INFO Uploading batch count=125072026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=125082026/10/25 13:44:21 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125092026/10/25 13:44:21 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestWorkerRemoveFailureIsNotProgress2363304644/002/nonexistent25102026/10/25 13:44:21 INFO Uploading batch count=225112026/10/25 13:44:21 ERROR Upload failed error="upload failed" count=225122026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/e25132026/10/25 13:44:21 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125142026/10/25 13:44:21 ERROR Drain finished with paths left in queue remaining=125152026/10/25 13:44:21 ERROR Drain finished with paths left in queue remaining=125162026/10/25 13:44:21 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/fc1b79881df5265f/build/TestDrainGivesUpWhenServerDown3812321018/002/f2517--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25182026/10/25 13:44:21 ERROR Drain finished with paths left in queue remaining=102519--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2520--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)2521--- PASS: TestDrainIsolatesPoisonPath (0.02s)2522--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2523--- PASS: TestWorkerSkipsGCdPaths (0.03s)2524--- PASS: TestWorkerPrunesClosureDeps (0.03s)2525--- PASS: TestWorkerUploadsAndRemoves (0.03s)2526--- PASS: TestQueueRemoveLargeClosure (0.05s)2527--- PASS: TestQueueConcurrentWriters (0.15s)25282026/10/25 13:44:21 ERROR Upload failed error="context deadline exceeded" count=225292026/10/25 13:44:21 ERROR Drain finished with paths left in queue remaining=42530--- PASS: TestDrainTimeout (0.22s)25312026/10/25 13:44:22 INFO Uploading batch count=125322026/10/25 13:44:22 INFO Uploading batch count=125332026/10/25 13:44:22 INFO Uploading batch count=125342026/10/25 13:44:22 ERROR Upload failed error="upload failed" count=125352026/10/25 13:44:22 INFO Uploading batch count=125362026/10/25 13:44:22 ERROR Upload failed error="upload failed" count=125372026/10/25 13:44:22 INFO Uploading batch count=125382026/10/25 13:44:22 ERROR Upload failed error="upload failed" count=125392026/10/25 13:44:22 INFO Uploading batch count=125402026/10/25 13:44:22 ERROR Upload failed error="upload failed" count=125412026/10/25 13:44:22 ERROR Drain finished with paths left in queue remaining=12542--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2543PASS2544Running signing tests...2545=== RUN TestExternalSigner2546=== PAUSE TestExternalSigner2547=== RUN TestExternalSignerWrongPublicKey2548=== PAUSE TestExternalSignerWrongPublicKey2549=== RUN TestExternalSignerErrors2550=== PAUSE TestExternalSignerErrors2551=== RUN TestExternalSignerRestartsAfterCrash2552=== PAUSE TestExternalSignerRestartsAfterCrash2553=== RUN TestExternalSignerProgramErrorKeepsProcess2554=== PAUSE TestExternalSignerProgramErrorKeepsProcess2555=== RUN TestExternalSignerClose2556=== PAUSE TestExternalSignerClose2557=== RUN TestExternalSignerRejectsInvalidPublicKey2558=== PAUSE TestExternalSignerRejectsInvalidPublicKey2559=== RUN TestExternalSignerCancellation2560=== PAUSE TestExternalSignerCancellation2561=== RUN TestGenerateFingerprint2562=== PAUSE TestGenerateFingerprint2563=== RUN TestParseSigningKey2564=== PAUSE TestParseSigningKey2565=== RUN TestSign2566=== PAUSE TestSign2567=== RUN TestSignBatch2568=== PAUSE TestSignBatch2569=== RUN TestNilKeyPublicKey2570=== PAUSE TestNilKeyPublicKey2571=== RUN TestSignErrors2572=== PAUSE TestSignErrors2573=== CONT TestExternalSigner2574=== CONT TestExternalSignerProgramErrorKeepsProcess2575=== CONT TestSignBatch2576=== CONT TestExternalSignerCancellation2577=== CONT TestSign2578=== CONT TestParseSigningKey2579=== RUN TestParseSigningKey/valid_32-byte_key2580=== CONT TestGenerateFingerprint2581=== PAUSE TestParseSigningKey/valid_32-byte_key2582=== RUN TestGenerateFingerprint/basic_with_references2583=== PAUSE TestGenerateFingerprint/basic_with_references2584=== RUN TestGenerateFingerprint/no_references2585=== PAUSE TestGenerateFingerprint/no_references2586=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2587=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2588=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2589=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2590=== RUN TestGenerateFingerprint/invalid_nar_hash_length2591=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2592=== CONT TestSignErrors2593=== CONT TestNilKeyPublicKey2594--- PASS: TestNilKeyPublicKey (0.00s)2595=== CONT TestExternalSignerClose2596=== CONT TestExternalSignerErrors2597=== RUN TestExternalSignerErrors/missing_signature_name2598=== PAUSE TestExternalSignerErrors/missing_signature_name2599=== RUN TestExternalSignerErrors/exit_at_startup2600=== CONT TestExternalSignerRestartsAfterCrash2601=== PAUSE TestExternalSignerErrors/exit_at_startup2602=== RUN TestExternalSignerErrors/missing_signatures2603=== PAUSE TestExternalSignerErrors/missing_signatures2604=== RUN TestExternalSignerErrors/wrong_signatures_shape2605=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2606=== CONT TestExternalSignerWrongPublicKey2607=== CONT TestExternalSignerRejectsInvalidPublicKey2608=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2609=== RUN TestGenerateFingerprint/invalid_store_path_prefix2610=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2611=== RUN TestGenerateFingerprint/invalid_reference_prefix2612=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2613=== CONT TestGenerateFingerprint/basic_with_references2614=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2615=== RUN TestParseSigningKey/no_colon2616=== PAUSE TestParseSigningKey/no_colon2617=== RUN TestParseSigningKey/empty_name2618=== PAUSE TestParseSigningKey/empty_name2619=== RUN TestExternalSignerRejectsInvalidPublicKey/#002620=== RUN TestParseSigningKey/invalid_base642621=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002622=== PAUSE TestParseSigningKey/invalid_base642623=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2624=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2625=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2626=== CONT TestGenerateFingerprint/invalid_reference_prefix2627=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2628=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2629=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2630=== CONT TestGenerateFingerprint/invalid_store_path_prefix2631=== CONT TestGenerateFingerprint/invalid_nar_hash_length2632=== CONT TestGenerateFingerprint/no_references2633=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2634--- PASS: TestGenerateFingerprint (0.00s)2635 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2636 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2637 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2638 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2639 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2640 --- PASS: TestGenerateFingerprint/no_references (0.00s)2641 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2642=== RUN TestExternalSignerErrors/null2643=== PAUSE TestExternalSignerErrors/null2644=== RUN TestExternalSignerErrors/too_few_signatures2645=== PAUSE TestExternalSignerErrors/too_few_signatures2646=== RUN TestExternalSignerErrors/wrong_signature_length2647=== PAUSE TestExternalSignerErrors/wrong_signature_length2648=== RUN TestExternalSignerErrors/program_error2649=== PAUSE TestExternalSignerErrors/program_error2650=== RUN TestExternalSignerErrors/invalid_JSON2651=== PAUSE TestExternalSignerErrors/invalid_JSON2652=== RUN TestExternalSignerErrors/wrong_shape2653=== RUN TestParseSigningKey/wrong_length2654=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2655=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2656=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2657=== CONT TestExternalSignerRejectsInvalidPublicKey/#002658=== PAUSE TestExternalSignerErrors/wrong_shape2659=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2660=== PAUSE TestParseSigningKey/wrong_length2661=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2662=== CONT TestParseSigningKey/invalid_base642663=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2664=== RUN TestExternalSignerErrors/wrong_id2665=== PAUSE TestExternalSignerErrors/wrong_id2666=== RUN TestExternalSignerErrors/unrequested_key2667=== PAUSE TestExternalSignerErrors/unrequested_key2668=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2669=== RUN TestExternalSignerErrors/wrong_signature_name2670=== CONT TestParseSigningKey/empty_name2671=== PAUSE TestExternalSignerErrors/wrong_signature_name2672--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2673 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2674 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2675 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2676 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2677 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2678=== RUN TestExternalSignerErrors/invalid_signature_base642679=== CONT TestParseSigningKey/wrong_length2680=== CONT TestParseSigningKey/no_colon2681=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2682=== CONT TestParseSigningKey/valid_32-byte_key2683--- PASS: TestParseSigningKey (0.00s)2684 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2685 --- PASS: TestParseSigningKey/empty_name (0.00s)2686 --- PASS: TestParseSigningKey/wrong_length (0.00s)2687 --- PASS: TestParseSigningKey/no_colon (0.00s)2688 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2689 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2690--- PASS: TestSign (0.00s)2691=== PAUSE TestExternalSignerErrors/invalid_signature_base642692=== RUN TestExternalSignerErrors/exit_on_request2693=== PAUSE TestExternalSignerErrors/exit_on_request2694=== RUN TestSignErrors/nil_key2695=== PAUSE TestSignErrors/nil_key2696=== RUN TestSignErrors/nil_narinfo2697=== PAUSE TestSignErrors/nil_narinfo2698=== RUN TestSignErrors/invalid_narinfo2699=== PAUSE TestSignErrors/invalid_narinfo2700=== RUN TestSignErrors/canceled2701=== PAUSE TestSignErrors/canceled2702=== CONT TestSignErrors/nil_key2703=== RUN TestExternalSignerErrors/null_signatures2704=== PAUSE TestExternalSignerErrors/null_signatures2705=== CONT TestSignErrors/canceled2706=== CONT TestSignErrors/nil_narinfo2707=== CONT TestExternalSignerErrors/unrequested_key2708=== CONT TestExternalSignerErrors/wrong_shape2709=== CONT TestExternalSignerErrors/missing_signature_name2710--- PASS: TestSignBatch (0.00s)2711=== CONT TestExternalSignerErrors/invalid_JSON2712=== CONT TestExternalSignerErrors/wrong_signatures_shape2713=== CONT TestExternalSignerErrors/wrong_signature_length2714=== CONT TestSignErrors/invalid_narinfo2715=== CONT TestExternalSignerErrors/null_signatures2716--- PASS: TestSignErrors (0.00s)2717 --- PASS: TestSignErrors/nil_key (0.00s)2718 --- PASS: TestSignErrors/canceled (0.00s)2719 --- PASS: TestSignErrors/nil_narinfo (0.00s)2720 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2721=== CONT TestExternalSignerErrors/exit_on_request2722=== CONT TestExternalSignerErrors/invalid_signature_base642723=== CONT TestExternalSignerErrors/wrong_signature_name2724=== CONT TestExternalSignerErrors/wrong_id2725=== CONT TestExternalSignerErrors/missing_signatures2726=== CONT TestExternalSignerErrors/program_error2727=== CONT TestExternalSignerErrors/too_few_signatures2728=== CONT TestExternalSignerErrors/null2729=== CONT TestExternalSignerErrors/exit_at_startup2730--- PASS: TestExternalSignerCancellation (0.24s)2731--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.41s)2732--- PASS: TestExternalSigner (0.61s)2733--- PASS: TestExternalSignerRestartsAfterCrash (2.31s)2734/private/var/tb/3/scratch/fc1b79881df5265f/build/TestExternalSignerRestartsAfterCrash304921962/001/sign program: line 7: /private/var/tb/3/scratch/fc1b79881df5265f/build/TestExternalSignerRestartsAfterCrash304921962/001/sign program.starts: No such file or directory2735--- PASS: TestExternalSignerClose (2.47s)2736--- PASS: TestExternalSignerWrongPublicKey (2.66s)2737--- PASS: TestExternalSignerErrors (0.00s)2738 --- PASS: TestExternalSignerErrors/invalid_JSON (0.78s)2739 --- PASS: TestExternalSignerErrors/wrong_shape (0.97s)2740 --- PASS: TestExternalSignerErrors/null (1.15s)2741 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.34s)2742 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.53s)2743 --- PASS: TestExternalSignerErrors/exit_on_request (1.72s)2744 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.91s)2745 --- PASS: TestExternalSignerErrors/unrequested_key (2.09s)2746 --- PASS: TestExternalSignerErrors/missing_signature_name (2.95s)2747 --- PASS: TestExternalSignerErrors/wrong_id (3.14s)2748 --- PASS: TestExternalSignerErrors/program_error (3.33s)2749 --- PASS: TestExternalSignerErrors/missing_signatures (3.53s)2750 --- PASS: TestExternalSignerErrors/null_signatures (3.72s)2751 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.90s)2752 --- PASS: TestExternalSignerErrors/too_few_signatures (4.09s)2753 --- PASS: TestExternalSignerErrors/exit_at_startup (4.28s)2754PASS2755Running OpenBao signer tests...2756=== RUN TestSign2757=== PAUSE TestSign2758=== RUN TestSignErrors2759=== PAUSE TestSignErrors2760=== RUN TestServe2761=== PAUSE TestServe2762=== RUN TestServeRejectsGarbage2763=== PAUSE TestServeRejectsGarbage2764=== CONT TestSign2765=== CONT TestSignErrors2766=== RUN TestSignErrors/no_prefix2767=== CONT TestServeRejectsGarbage2768=== CONT TestServe2769=== PAUSE TestSignErrors/no_prefix2770=== RUN TestSignErrors/invalid_base642771=== PAUSE TestSignErrors/invalid_base642772=== RUN TestSignErrors/http_error2773--- PASS: TestServeRejectsGarbage (0.00s)2774=== PAUSE TestSignErrors/http_error2775=== RUN TestSignErrors/invalid_json2776=== PAUSE TestSignErrors/invalid_json2777=== CONT TestSignErrors/no_prefix2778=== CONT TestSignErrors/http_error2779=== CONT TestSignErrors/invalid_base642780=== CONT TestSignErrors/invalid_json2781--- PASS: TestServe (0.00s)2782--- PASS: TestSign (0.00s)2783--- PASS: TestSignErrors (0.00s)2784 --- PASS: TestSignErrors/http_error (0.00s)2785 --- PASS: TestSignErrors/no_prefix (0.00s)2786 --- PASS: TestSignErrors/invalid_base64 (0.00s)2787 --- PASS: TestSignErrors/invalid_json (0.00s)2788PASS