niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #443
· 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.04s)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 TestFileTokenReadsAndCaches117=== CONT TestRateLimiterFeedback118=== CONT TestScriptTokenEmptyToken119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestScriptTokenEmptyCommand121--- PASS: TestScriptTokenEmptyCommand (0.00s)122=== CONT TestSetClientTLS123=== CONT TestScriptTokenScriptFails124=== CONT TestScriptTokenBadJSON125=== CONT TestScriptTokenCachesUntilRefresh126=== CONT TestDumpPathMatchesNix127=== CONT TestPathInfoCACompatibility128=== RUN TestPathInfoCACompatibility/null_ca_field129=== CONT TestParsePathInfoJSONMultiplePaths130=== CONT TestParsePathInfoJSON131=== CONT TestPathInfoHashCompatibility132=== CONT TestGetStorePathHash133=== CONT TestConvertHashToNix32134=== CONT TestEncodeNixBase32WithRealHash135=== CONT TestEncodeNixBase32136=== CONT TestDumpPathWriterError137=== CONT TestDumpPathSingleFile138=== CONT TestStreamPushIsolatesFailures139--- PASS: TestFileTokenReadsAndCaches (0.00s)140=== PAUSE TestPathInfoCACompatibility/null_ca_field141=== CONT TestStaticToken142=== CONT TestSetClientTLSErrors143=== CONT TestSetClientTLSDoesNotMutateDefaultTransport144=== RUN TestRateLimiterFeedback/429_enables_limiter145=== CONT TestStreamPushStopsWhenCanceled146--- PASS: TestStreamPushStopsWhenCanceled (0.00s)147=== CONT TestClientSignaturesByStorePath148--- PASS: TestClientSignaturesByStorePath (0.00s)149=== CONT TestStreamPushReportsSkippedPaths150--- PASS: TestEncodeNixBase32WithRealHash (0.00s)151=== CONT TestStreamPushReportsSignatures1522026/10/27 08:54:49 ERROR Upload failed error="bad path" count=3153=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157--- PASS: TestStaticToken (0.00s)158=== CONT TestFileTokenEmpty159--- PASS: TestStreamPushIsolatesFailures (0.00s)160=== CONT TestFilterOversizedClosures161=== RUN TestFilterOversizedClosures/no_limit_keeps_everything162=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything163=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped164=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped165=== RUN TestFilterOversizedClosures/all_closures_skipped166=== PAUSE TestFilterOversizedClosures/all_closures_skipped167--- PASS: TestFileTokenEmpty (0.00s)168=== CONT TestStreamPushGivesUpOnDeadServer169=== CONT TestUploadMultipart_SupersededByPeer170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)1712026/10/27 08:54:49 ERROR Upload failed error=boom count=11722026/10/27 08:54:49 ERROR Upload failed error="connection refused" count=201732026/10/27 08:54:49 ERROR Server seems unavailable, giving up on batch untried=17174=== RUN TestSetClientTLSErrors/missing_cert_file175--- PASS: TestStreamPushReportsSkippedPaths (0.00s)176=== PAUSE TestSetClientTLSErrors/missing_cert_file177--- PASS: TestStreamPushReportsSignatures (0.00s)178=== RUN TestGetStorePathHash/valid_store_path179=== PAUSE TestGetStorePathHash/valid_store_path180=== RUN TestGetStorePathHash/basename_without_hyphen_should_error181=== CONT TestPartSizeForNAR182=== RUN TestSetClientTLSErrors/missing_key_file183=== CONT TestSupersededNARStillUploadsListing184=== RUN TestUploadMultipart_SupersededByPeer/exists185=== PAUSE TestUploadMultipart_SupersededByPeer/exists186=== RUN TestUploadMultipart_SupersededByPeer/missing187=== PAUSE TestUploadMultipart_SupersededByPeer/missing188--- PASS: TestScriptTokenScriptFails (0.01s)189--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)190=== CONT TestCaseHackSuffix191--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)192=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun193--- PASS: TestDoServerRequestAttachesToken (0.01s)194=== CONT TestDoWithRetry_FinalResponseBodyReadable195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)196=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon197=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon198=== PAUSE TestRateLimiterFeedback/429_enables_limiter199=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error200=== RUN TestParsePathInfoJSON/Nix_format201=== RUN TestEncodeNixBase32/test_string_hash202=== RUN TestPathInfoCACompatibility/old_string_format_-_text203=== RUN TestConvertHashToNix32/SRI_format_to_Nix32204=== RUN TestPartSizeForNAR/zero_stays_at_minimum205=== PAUSE TestParsePathInfoJSON/Nix_format206=== RUN TestParsePathInfoJSON/Lix_format207=== PAUSE TestParsePathInfoJSON/Lix_format208=== RUN TestParsePathInfoJSON/empty_input209=== PAUSE TestParsePathInfoJSON/empty_input210=== RUN TestParsePathInfoJSON/whitespace_only211=== PAUSE TestParsePathInfoJSON/whitespace_only212=== RUN TestParsePathInfoJSON/invalid_JSON213=== RUN TestSupersededNARStillUploadsListing/small_NAR214=== CONT TestUploadMultipart_FailedPartBufferNotReused215=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica216=== CONT TestUploadMultipart_PartsInParallel217=== RUN TestRateLimiterFeedback/503_enables_limiter218=== PAUSE TestRateLimiterFeedback/503_enables_limiter219=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter220=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter221=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter222=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter223=== PAUSE TestParsePathInfoJSON/invalid_JSON224=== PAUSE TestSupersededNARStillUploadsListing/small_NAR225=== RUN TestSupersededNARStillUploadsListing/dump_cut_short226=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short227=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails228=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails229=== CONT TestStreamPushReportsEveryPath230=== CONT TestShellSplitErrors231--- PASS: TestShellSplitErrors (0.00s)232=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error233=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== PAUSE TestEncodeNixBase32/test_string_hash235=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text2362026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=server-test rate=52372026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:49357238=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum239=== RUN TestPartSizeForNAR/small_stays_at_minimum240=== PAUSE TestPartSizeForNAR/small_stays_at_minimum241=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum242=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum243=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts244=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts245=== PAUSE TestSetClientTLSErrors/missing_key_file246=== RUN TestSetClientTLSErrors/missing_ca_file247=== PAUSE TestSetClientTLSErrors/missing_ca_file248=== RUN TestSetClientTLSErrors/invalid_ca_file249=== PAUSE TestSetClientTLSErrors/invalid_ca_file250=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32251=== RUN TestConvertHashToNix32/already_Nix32_format252=== PAUSE TestConvertHashToNix32/already_Nix32_format253=== RUN TestConvertHashToNix32/invalid_format254=== PAUSE TestConvertHashToNix32/invalid_format255=== CONT TestRegisterUploadedObjectReusesConnections256=== CONT TestStreamPushBatchesUnderLoad257--- PASS: TestStreamPushReportsEveryPath (0.00s)258=== CONT TestFileTokenMissing259=== RUN TestPartSizeForNAR/1_TiB260=== CONT TestShellSplit261--- PASS: TestShellSplit (0.00s)262=== CONT TestRetryTimeoutOutlastsMaxRetries263=== CONT TestResolveStorePath2642026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:49366265--- PASS: TestScriptTokenEmptyToken (0.01s)266=== CONT TestDoWithRetry_BodyReplayedViaGetBody267=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI2682026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:49366269=== RUN TestEncodeNixBase32/empty_input270=== PAUSE TestEncodeNixBase32/empty_input271=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive272=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive273=== RUN TestPathInfoCACompatibility/new_structured_format_-_text274=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text275=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method276=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method277=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2782026/10/27 08:54:49 INFO Garbage collection started279=== RUN TestSetClientTLS/rejects_connection_without_client_cert280=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert281=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA282=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA283=== RUN TestSetClientTLS/preserves_debug_logging_transport284=== PAUSE TestSetClientTLS/preserves_debug_logging_transport285=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer286=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess2872026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=server-test rate=5288=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false289=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false290=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true291=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true292=== CONT TestStreamPushRequestLine293--- PASS: TestResolveStorePath (0.01s)294=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths295=== CONT TestFilterOversizedClosures/no_limit_keeps_everything296=== CONT TestFilterOversizedClosures/all_closures_skipped2972026/10/27 08:54:49 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50298=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2992026/10/27 08:54:49 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000300--- PASS: TestFilterOversizedClosures (0.00s)301 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)302 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)303 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305=== CONT TestUploadMultipart_SupersededByPeer/exists3062026/10/27 08:54:49 ERROR Upload failed error=boom count=13072026/10/27 08:54:49 INFO Garbage collection started308=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512309=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestUploadMultipart_SupersededByPeer/missing311--- PASS: TestFileTokenMissing (0.00s)312=== CONT TestRateLimiterFeedback/429_enables_limiter313--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)316=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error317=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error318=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error319=== CONT TestParsePathInfoJSON/Nix_format320=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter321=== PAUSE TestPartSizeForNAR/1_TiB322=== RUN TestPartSizeForNAR/5_TiB_S3_max_object323=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object324=== RUN TestPartSizeForNAR/capped_at_5_GiB325=== PAUSE TestPartSizeForNAR/capped_at_5_GiB326=== CONT TestSupersededNARStillUploadsListing/small_NAR327--- PASS: TestScriptTokenBadJSON (0.02s)328=== CONT TestRateLimiterFeedback/503_enables_limiter3292026/10/27 08:54:49 INFO Uploading abc-hello (1.0GB)3302026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=s3-test rate=53312026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:494083322026/10/27 08:54:49 WARN Rate limiter backed off name=server-test rate=5333--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)334=== CONT TestParsePathInfoJSON/invalid_JSON335=== CONT TestParsePathInfoJSON/whitespace_only336=== CONT TestParsePathInfoJSON/empty_input337=== CONT TestParsePathInfoJSON/Lix_format338--- PASS: TestParsePathInfoJSON (0.01s)339 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)341 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)342 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)343 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)344=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3452026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=server-test rate=53462026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:49374347--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)348=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails349=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3502026/10/27 08:54:49 WARN Rate limiter backed off name=server-test rate=53512026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:493743522026/10/27 08:54:49 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0353=== CONT TestSetClientTLSErrors/missing_cert_file3542026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=server-test rate=53552026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:49442356--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)357 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)358 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)359=== CONT TestConvertHashToNix32/SRI_format_to_Nix32360=== CONT TestSetClientTLSErrors/invalid_ca_file361--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)362=== CONT TestSetClientTLSErrors/missing_ca_file363=== CONT TestSetClientTLSErrors/missing_key_file364=== CONT TestConvertHashToNix32/invalid_format365=== CONT TestConvertHashToNix32/already_Nix32_format366--- PASS: TestConvertHashToNix32 (0.01s)367 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)368 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)369 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)370=== CONT TestEncodeNixBase32/test_string_hash371=== CONT TestEncodeNixBase32/empty_input372--- PASS: TestEncodeNixBase32 (0.02s)373 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)374 --- PASS: TestEncodeNixBase32/empty_input (0.00s)375=== CONT TestPathInfoCACompatibility/null_ca_field376=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378=== CONT TestSetClientTLS/preserves_debug_logging_transport379--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)380=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA381--- PASS: TestSetClientTLSErrors (0.01s)382 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)383 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386=== CONT TestPathInfoCACompatibility/new_structured_format_-_text387=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive388=== CONT TestPathInfoCACompatibility/old_string_format_-_text389=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false390--- PASS: TestPathInfoCACompatibility (0.02s)391 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)392 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)393 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)395 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)396=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true397--- PASS: TestStreamPushBatchesUnderLoad (0.01s)398 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)399 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)400=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)401=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512402=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI403=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon404--- PASS: TestPathInfoHashCompatibility (0.02s)405 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)406 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)407 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)408 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)409=== CONT TestGetStorePathHash/valid_store_path410=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error411=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error412=== CONT TestGetStorePathHash/basename_without_hyphen_should_error413--- PASS: TestGetStorePathHash (0.02s)414 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)415 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)416 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)417 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)418=== CONT TestPartSizeForNAR/zero_stays_at_minimum419=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts420=== CONT TestPartSizeForNAR/capped_at_5_GiB421=== CONT TestPartSizeForNAR/5_TiB_S3_max_object422=== CONT TestPartSizeForNAR/1_TiB423=== CONT TestPartSizeForNAR/small_stays_at_minimum424=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum425--- PASS: TestPartSizeForNAR (0.02s)426 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)427 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)428 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)429 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)430 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)431 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)432 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)4332026/10/27 08:54:49 WARN Garbage collection finished on another replica. Its statistics are not available here434--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)4352026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:493664362026/10/27 08:54:49 WARN Rate limiter backed off name=server-test rate=54372026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=server-test rate=54382026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:494514392026/10/27 08:54:49 WARN Rate limiter backed off name=server-test rate=5440--- PASS: TestRateLimiterFeedback (0.01s)441 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)442 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)443 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)444 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)4452026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:49366446--- PASS: TestStreamPushRequestLine (0.01s)4472026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:493664482026/10/27 08:54:49 WARN Rate limiter enabled after throttle name=s3-test rate=54492026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:493664502026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:493664512026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:493664522026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:493664532026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:493664542026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:493664552026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:493664562026/10/27 08:54:49 INFO Uploading abc-hello (1.0GB)4572026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:49366458--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4592026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:493664602026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:493664612026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:49366462--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)4632026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:493664642026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:493664652026/10/27 08:54:49 http: TLS handshake error from 127.0.0.1:49456: remote error: tls: bad certificate4662026/10/27 08:54:49 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:49366467--- PASS: TestSetClientTLS (0.02s)468 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)469 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)470 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)471--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)472--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.04s)473--- PASS: TestDumpPathSingleFile (0.05s)474--- PASS: TestCaseHackSuffix (0.06s)4752026/10/27 08:54:49 INFO Uploading abc-hello (1.0GB)476--- PASS: TestDumpPathWriterError (0.07s)4772026/10/27 08:54:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:49453/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:49453/part/24782026/10/27 08:54:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:49453/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:49453/part/34792026/10/27 08:54:49 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"480--- PASS: TestDumpPathMatchesNix (0.11s)481--- PASS: TestSupersededNARStillUploadsListing (0.00s)482 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)483 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)484 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.55s)485--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.58s)486--- PASS: TestUploadMultipart_PartsInParallel (0.63s)4872026/10/27 08:54:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49390/api/uploads/complete4882026/10/27 08:54:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49390/api/uploads/complete4892026/10/27 08:54:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4902026/10/27 08:54:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4912026/10/27 08:54:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49390/api/uploads/complete4922026/10/27 08:54:50 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"493--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)494--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)495PASS496Running server tests...497The files belonging to this database system will be owned by user "_tribuchetbld8".498This user must also own the server process.499500The database cluster will be initialized with locale "C".501The default database encoding has accordingly been set to "SQL_ASCII".502The default text search configuration will be set to "english".503504Data page checksums are enabled.505506creating directory /private/var/tb/8/scratch/651f346cfe2ac1bb/build/postgres488174848/data ... ok507creating subdirectories ... ok508selecting dynamic shared memory implementation ... posix509selecting default "max_connections" ... 100510selecting default "shared_buffers" ... 128MB511selecting default time zone ... UTC512creating configuration files ... ok513running bootstrap script ... ok514performing post-bootstrap initialization ... ok515syncing data to disk ... ok516517initdb: warning: enabling "trust" authentication for local connections518initdb: 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.519520Success. You can now start the database server using:521522 pg_ctl -D /private/var/tb/8/scratch/651f346cfe2ac1bb/build/postgres488174848/data -l logfile start523524/private/var/tb/8/scratch/651f346cfe2ac1bb/build/postgres488174848:5432 - no response5252026-10-27 08:54:51.291 UTC [89485] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5262026-10-27 08:54:51.292 UTC [89485] LOG: listening on Unix socket "/private/var/tb/8/scratch/651f346cfe2ac1bb/build/postgres488174848/.s.PGSQL.5432"5272026-10-27 08:54:51.294 UTC [89492] LOG: database system was shut down at 2026-10-27 08:54:51 UTC5282026-10-27 08:54:51.295 UTC [89485] LOG: database system is ready to accept connections529/private/var/tb/8/scratch/651f346cfe2ac1bb/build/postgres488174848:5432 - accepting connections530{"timestamp":"2026-10-27T08:54:51.510763Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8e490984-6416-4aaa-ba11-b44ef64b6480","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}531=== RUN TestService_AuthMiddleware532=== PAUSE TestService_AuthMiddleware533=== RUN TestService_AuthMiddleware_MTLSProxyHeader534=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader535=== RUN TestService_AuthMiddleware_MTLSBoundSubjects536=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects537=== RUN TestService_ReadAuthMiddleware538=== PAUSE TestService_ReadAuthMiddleware539=== RUN TestService_AuthMiddleware_OIDC540=== PAUSE TestService_AuthMiddleware_OIDC541=== RUN TestService_RequireScope_OIDC542=== PAUSE TestService_RequireScope_OIDC543=== RUN TestService_ReadScope_PublicByDefault544=== PAUSE TestService_ReadScope_PublicByDefault545=== RUN TestCacheConfigHandler546=== PAUSE TestCacheConfigHandler547=== RUN TestCacheStatsHandler548=== PAUSE TestCacheStatsHandler549=== RUN TestClientCADerivations550=== PAUSE TestClientCADerivations551=== RUN TestClientErrorHandling552=== PAUSE TestClientErrorHandling553=== RUN TestClientIntegration554=== PAUSE TestClientIntegration555=== RUN TestClientMultipleUploads556=== PAUSE TestClientMultipleUploads557=== RUN TestClientWithDependencies558=== PAUSE TestClientWithDependencies559=== RUN TestClientSharedPathCommittedMidPush560=== PAUSE TestClientSharedPathCommittedMidPush561=== RUN TestPinProtectsFromGC562=== PAUSE TestPinProtectsFromGC563=== RUN TestClientPushesUseOnePush564=== PAUSE TestClientPushesUseOnePush565=== RUN TestClientFallsBackToClosures566=== PAUSE TestClientFallsBackToClosures567=== RUN TestDeleteClosuresRacingPins568=== PAUSE TestDeleteClosuresRacingPins569=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock571=== RUN TestResolveDBConnectionString572=== PAUSE TestResolveDBConnectionString573=== RUN TestConnectWaitsForAPeerMigration574=== PAUSE TestConnectWaitsForAPeerMigration575=== RUN TestLeadElectsOneAndHandsOver576=== PAUSE TestLeadElectsOneAndHandsOver577=== RUN TestLeadIncumbentWinsAfterRestart5782026/10/27 08:54:51 INFO lead: acquired remote=192.0.2.1:12345792026/10/27 08:54:52 INFO lead: released remote=192.0.2.1:12345802026/10/27 08:54:52 INFO lead: acquired remote=192.0.2.1:12345812026/10/27 08:54:53 INFO lead: released remote=192.0.2.1:1234582--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)583=== RUN TestLeadIncumbentAnnouncesAtOnce584=== PAUSE TestLeadIncumbentAnnouncesAtOnce585=== RUN TestLeadEndsOnShutdown586=== PAUSE TestLeadEndsOnShutdown587=== RUN TestLeadEndsWhenItsConnectionHangs5882026/10/27 08:54:53 INFO lead: acquired remote=192.0.2.1:12345892026-10-27 08:54:55.003 UTC [89528] FATAL: terminating connection due to administrator command5902026/10/27 08:54:55 INFO lead: acquired remote=192.0.2.1:12345912026/10/27 08:54:56 WARN lead: lock connection lost error="timeout: context deadline exceeded"5922026/10/27 08:54:56 INFO lead: released remote=192.0.2.1:12345932026/10/27 08:54:56 INFO lead: released remote=192.0.2.1:1234594--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)595=== RUN TestGCAdvisoryLockBlocksConcurrentRun596=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun597=== RUN TestGCBugBareHashReferences598=== PAUSE TestGCBugBareHashReferences599=== RUN TestGCMetrics600=== PAUSE TestGCMetrics601=== RUN TestPushDedupSurvivesConcurrentGC602=== PAUSE TestPushDedupSurvivesConcurrentGC603=== RUN TestDeduplicatedObjectsRecordedAsPending604=== PAUSE TestDeduplicatedObjectsRecordedAsPending605=== RUN TestGCSweepSkipsPendingObjects606=== PAUSE TestGCSweepSkipsPendingObjects607=== RUN TestTombstonedObjectOfferedWithoutWaiting608=== PAUSE TestTombstonedObjectOfferedWithoutWaiting609=== RUN TestGCSweepDeliversEachKeyOnce610=== PAUSE TestGCSweepDeliversEachKeyOnce611=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection613=== RUN TestForceGCDuringPushOffersSweptObject614=== PAUSE TestForceGCDuringPushOffersSweptObject615=== RUN TestFailedS3DeleteKeepsTombstone616=== PAUSE TestFailedS3DeleteKeepsTombstone617=== RUN TestSweepSkipsRowsLockedByPush618=== PAUSE TestSweepSkipsRowsLockedByPush619=== RUN TestRegisterCompletedObjectNeedsPendingRow620=== PAUSE TestRegisterCompletedObjectNeedsPendingRow621=== RUN TestGetExistingObjectsLocksRows622=== PAUSE TestGetExistingObjectsLocksRows623=== RUN TestSweepRechecksPendingAfterLocking624=== PAUSE TestSweepRechecksPendingAfterLocking625=== RUN TestPushWaitsForSweepHoldingRow626=== PAUSE TestPushWaitsForSweepHoldingRow627=== RUN TestCommitRacingPendingCleanupKeepsObjects628=== PAUSE TestCommitRacingPendingCleanupKeepsObjects629=== RUN TestGCEndsOnShutdown630=== PAUSE TestGCEndsOnShutdown631=== RUN TestGCTaskStore_StartNew632=== PAUSE TestGCTaskStore_StartNew633=== RUN TestGCTaskStore_DeduplicateSameParams634=== PAUSE TestGCTaskStore_DeduplicateSameParams635=== RUN TestGCTaskStore_ConflictDifferentParams636=== PAUSE TestGCTaskStore_ConflictDifferentParams637=== RUN TestGCTaskStore_GetEmpty638=== PAUSE TestGCTaskStore_GetEmpty639=== RUN TestGCTaskStore_GetReturnsLatest640=== PAUSE TestGCTaskStore_GetReturnsLatest641=== RUN TestGCTaskStore_CompletedAllowsNewTask642=== PAUSE TestGCTaskStore_CompletedAllowsNewTask643=== RUN TestGCTaskStore_PhaseUpdates644=== PAUSE TestGCTaskStore_PhaseUpdates645=== RUN TestGCTaskStore_Fail646=== PAUSE TestGCTaskStore_Fail647=== RUN TestGracefulShutdownDrainsInflight648=== PAUSE TestGracefulShutdownDrainsInflight649=== RUN TestService_healthCheckHandler650=== PAUSE TestService_healthCheckHandler651=== RUN TestService_readinessHandler652=== PAUSE TestService_readinessHandler653=== RUN TestGenerateLandingPage654=== PAUSE TestGenerateLandingPage655=== RUN TestCacheConfigHandlerMaxNarSize656=== PAUSE TestCacheConfigHandlerMaxNarSize657=== RUN TestCreatePendingClosureRejectsOversizedNAR658=== PAUSE TestCreatePendingClosureRejectsOversizedNAR659=== RUN TestNARDeduplicationMetadataUploadBug660=== PAUSE TestNARDeduplicationMetadataUploadBug661=== RUN TestMetricsInventory662=== PAUSE TestMetricsInventory663=== RUN TestMetricsCommit664=== PAUSE TestMetricsCommit665=== RUN TestService_NativeMTLS666=== PAUSE TestService_NativeMTLS667=== RUN TestServerTLSConfig668=== PAUSE TestServerTLSConfig669=== RUN TestMultipartCleanup670=== PAUSE TestMultipartCleanup671=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded673=== RUN TestPendingCleanupUsesOneCutoff674=== PAUSE TestPendingCleanupUsesOneCutoff675=== RUN TestObjectStatsTrigger676=== PAUSE TestObjectStatsTrigger677=== RUN TestObjectStatsUpdatedOncePerCommit678=== PAUSE TestObjectStatsUpdatedOncePerCommit679=== RUN TestOrphanedObjectsGC680=== PAUSE TestOrphanedObjectsGC681=== RUN TestOrphanedObjectsGCStressTest682=== PAUSE TestOrphanedObjectsGCStressTest683=== RUN TestCreatePin_ReservedPins684=== PAUSE TestCreatePin_ReservedPins685=== RUN TestPresentReportsOnlyClosureRoots686=== PAUSE TestPresentReportsOnlyClosureRoots687=== RUN TestPresentRefreshesOnlyStaleClosures688=== PAUSE TestPresentRefreshesOnlyStaleClosures689=== RUN TestPresentNotReportedWhileGCDeletesClosure690=== PAUSE TestPresentNotReportedWhileGCDeletesClosure691=== RUN TestParseSingleRange692=== PAUSE TestParseSingleRange693=== RUN TestProxyHeadersOnlyTrustedOnSocket6942026/10/27 08:54:56 INFO Starting HTTP server address=127.0.0.1:494966952026/10/27 08:54:56 INFO Starting HTTP server address=proxy.sock6962026/10/27 08:54:56 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6972026/10/27 08:54:56 INFO Shutdown signal received, draining in-flight requests timeout=10s698--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)699=== RUN TestIsValidCachePath700=== PAUSE TestIsValidCachePath701=== RUN TestReadProxyNarinfo702=== PAUSE TestReadProxyNarinfo703=== RUN TestReadProxyNarinfoAlreadyDecompressed704=== PAUSE TestReadProxyNarinfoAlreadyDecompressed705=== RUN TestReadProxyContentNegotiation706=== PAUSE TestReadProxyContentNegotiation707=== RUN TestReadProxyNarStreaming708=== PAUSE TestReadProxyNarStreaming709=== RUN TestReadProxy404710=== PAUSE TestReadProxy404711=== RUN TestReadProxyInvalidPath712=== PAUSE TestReadProxyInvalidPath713=== RUN TestReadProxyHead714=== PAUSE TestReadProxyHead715=== RUN TestReadProxyOutlastsServerWriteTimeout716=== PAUSE TestReadProxyOutlastsServerWriteTimeout717=== RUN TestReadProxyConditionalGet718=== PAUSE TestReadProxyConditionalGet719=== RUN TestReadProxyRootRedirectsToIndexHTML720=== PAUSE TestReadProxyRootRedirectsToIndexHTML721=== RUN TestReadProxyDisabled722=== PAUSE TestReadProxyDisabled723=== RUN TestReadRedirectNar724=== PAUSE TestReadRedirectNar725=== RUN TestReadRedirectKeepsNarinfoProxied726=== PAUSE TestReadRedirectKeepsNarinfoProxied727=== RUN TestReadProxyRangeRequest728=== PAUSE TestReadProxyRangeRequest729=== RUN TestReadRedirectUsesPublicS3URL730=== PAUSE TestReadRedirectUsesPublicS3URL731=== RUN TestPush_OverlappingRootsStoreOneRowPerKey732=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey733=== RUN TestPush_CompleteCommitsEveryRoot734=== PAUSE TestPush_CompleteCommitsEveryRoot735=== RUN TestPush_RepeatedRootCommitsOnce736=== PAUSE TestPush_RepeatedRootCommitsOnce737=== RUN TestPush_CompleteWaitsForCleanupOfThePush738=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush739=== RUN TestPush_RootsAreLockedInByteOrder740=== PAUSE TestPush_RootsAreLockedInByteOrder741=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit742=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit743=== RUN TestPush_RejectsBadRequests744=== PAUSE TestPush_RejectsBadRequests745=== RUN TestPush_SignsNarinfosOfItsPendingObjects746=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects747=== RUN TestRedundantMultipartUpload748=== PAUSE TestRedundantMultipartUpload749=== RUN TestCompleteMultipartUpload_ErrorButObjectExists750=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists751=== RUN TestCompletedNarNotReofferedAcrossClosures752=== PAUSE TestCompletedNarNotReofferedAcrossClosures753=== RUN TestPresignedUploadRegisteredBeforeCommit754=== PAUSE TestPresignedUploadRegisteredBeforeCommit755=== RUN TestService_Rustfstest756=== PAUSE TestService_Rustfstest757=== RUN TestParseSize758=== PAUSE TestParseSize759=== RUN TestSkippedUploadsHandler760=== PAUSE TestSkippedUploadsHandler761=== RUN TestSystemdListenerNotActivated762--- PASS: TestSystemdListenerNotActivated (0.00s)763=== RUN TestWatchdogBeatsWhenHealthy764--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)765=== RUN TestWatchdogSkipsWhenUnhealthy7662026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/27 08:54:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"776--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)777=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== RUN TestProxyWriteTimeout780=== PAUSE TestProxyWriteTimeout781=== RUN TestPendingClosureWriteTimeout782=== PAUSE TestPendingClosureWriteTimeout783=== RUN TestIsValidUploadKey784=== PAUSE TestIsValidUploadKey785=== RUN TestUploadHandlersRejectInvalidKeys786=== PAUSE TestUploadHandlersRejectInvalidKeys787=== RUN TestUploadHandlersRejectOversizedBody788=== PAUSE TestUploadHandlersRejectOversizedBody789=== RUN TestService_cleanupPendingClosuresHandler790=== PAUSE TestService_cleanupPendingClosuresHandler791=== RUN TestService_createPendingClosureHandler792=== PAUSE TestService_createPendingClosureHandler793=== RUN TestService_verifyS3Integrity794=== PAUSE TestService_verifyS3Integrity795=== RUN TestCompleteMultipartUnregistered796=== PAUSE TestCompleteMultipartUnregistered797=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT798=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestReadProxyRootRedirectsToIndexHTML800=== CONT TestIsValidCachePath801=== RUN TestIsValidCachePath/narinfo802=== PAUSE TestIsValidCachePath/narinfo803=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars804=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars805=== RUN TestIsValidCachePath/nar_zst806=== PAUSE TestIsValidCachePath/nar_zst807=== RUN TestIsValidCachePath/nar_xz808=== CONT TestCompletedNarNotReofferedAcrossClosures809=== CONT TestReadProxyConditionalGet810=== CONT TestReadProxyOutlastsServerWriteTimeout811=== CONT TestReadProxyHead812=== CONT TestReadProxyInvalidPath813=== CONT TestReadProxy404814=== CONT TestReadProxyNarStreaming815=== CONT TestReadProxyContentNegotiation816=== CONT TestReadProxyNarinfoAlreadyDecompressed817=== CONT TestReadProxyNarinfo818=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT819=== CONT TestCompleteMultipartUnregistered820=== CONT TestService_verifyS3Integrity821=== CONT TestService_createPendingClosureHandler822=== CONT TestService_cleanupPendingClosuresHandler823=== CONT TestUploadHandlersRejectOversizedBody824=== CONT TestUploadHandlersRejectInvalidKeys825=== CONT TestIsValidUploadKey826=== RUN TestIsValidUploadKey/narinfo827=== CONT TestPendingClosureWriteTimeout828=== CONT TestProxyWriteTimeout829=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle830=== RUN TestProxyWriteTimeout/narinfo831=== CONT TestService_AuthMiddleware832=== PAUSE TestProxyWriteTimeout/narinfo833=== RUN TestProxyWriteTimeout/1_GiB_nar834=== PAUSE TestProxyWriteTimeout/1_GiB_nar835=== RUN TestProxyWriteTimeout/10_GiB_nar836=== PAUSE TestProxyWriteTimeout/10_GiB_nar837=== RUN TestProxyWriteTimeout/unknown_size838=== PAUSE TestProxyWriteTimeout/unknown_size839=== PAUSE TestIsValidCachePath/nar_xz840=== CONT TestSkippedUploadsHandler841=== RUN TestIsValidCachePath/nar_bz2842=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info843=== PAUSE TestIsValidUploadKey/narinfo844=== RUN TestPendingClosureWriteTimeout/empty845=== PAUSE TestPendingClosureWriteTimeout/empty846=== RUN TestPendingClosureWriteTimeout/400_objects847=== PAUSE TestPendingClosureWriteTimeout/400_objects848=== RUN TestPendingClosureWriteTimeout/670k_objects849=== PAUSE TestPendingClosureWriteTimeout/670k_objects850=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline851=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline852=== RUN TestIsValidUploadKey/nar_zst8532026/10/27 08:54:56 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000854=== CONT TestParseSize855=== PAUSE TestIsValidUploadKey/nar_zst856=== RUN TestIsValidUploadKey/nar_xz857=== PAUSE TestIsValidUploadKey/nar_xz858=== RUN TestIsValidUploadKey/nar_plain859=== PAUSE TestIsValidUploadKey/nar_plain860=== RUN TestIsValidUploadKey/listing861=== PAUSE TestIsValidUploadKey/listing862=== RUN TestIsValidUploadKey/build_log863=== PAUSE TestIsValidUploadKey/build_log864=== RUN TestIsValidUploadKey/build_log_home-manager_file865=== PAUSE TestIsValidUploadKey/build_log_home-manager_file866=== RUN TestIsValidUploadKey/build_log_plus_in_name867=== PAUSE TestIsValidUploadKey/build_log_plus_in_name868=== RUN TestIsValidUploadKey/build_log_question_mark869=== PAUSE TestIsValidUploadKey/build_log_question_mark870=== RUN TestIsValidUploadKey/build_log_equals871=== PAUSE TestIsValidUploadKey/build_log_equals872=== RUN TestIsValidUploadKey/realisation873=== PAUSE TestIsValidUploadKey/realisation874=== RUN TestIsValidUploadKey/realisation_plus_in_output875=== PAUSE TestIsValidUploadKey/realisation_plus_in_output876=== RUN TestIsValidUploadKey/nix-cache-info877=== PAUSE TestIsValidUploadKey/nix-cache-info878=== RUN TestIsValidUploadKey/index.html879=== PAUSE TestIsValidUploadKey/index.html880=== RUN TestIsValidUploadKey/narinfo_key,_nar_type881=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type882=== RUN TestIsValidUploadKey/nar_key,_narinfo_type883=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type884=== RUN TestIsValidUploadKey/listing_key,_narinfo_type885=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type886=== RUN TestIsValidUploadKey/traversal887=== PAUSE TestIsValidUploadKey/traversal888=== RUN TestIsValidUploadKey/traversal_nar889=== PAUSE TestIsValidUploadKey/traversal_nar890=== RUN TestIsValidUploadKey/absolute891=== PAUSE TestIsValidUploadKey/absolute892=== RUN TestIsValidUploadKey/empty_key893=== PAUSE TestIsValidUploadKey/empty_key894=== RUN TestIsValidUploadKey/unknown_type895=== PAUSE TestIsValidUploadKey/unknown_type896=== PAUSE TestIsValidCachePath/nar_bz2897=== RUN TestIsValidCachePath/nar_uncompressed898=== PAUSE TestIsValidCachePath/nar_uncompressed899=== RUN TestIsValidCachePath/ls900=== PAUSE TestIsValidCachePath/ls901=== RUN TestIsValidCachePath/log902=== PAUSE TestIsValidCachePath/log903=== RUN TestIsValidCachePath/realisation904=== PAUSE TestIsValidCachePath/realisation905=== RUN TestIsValidCachePath/nix-cache-info906=== PAUSE TestIsValidCachePath/nix-cache-info907=== RUN TestIsValidCachePath/index.html908=== PAUSE TestIsValidCachePath/index.html909=== RUN TestIsValidCachePath/traversal_parent910=== PAUSE TestIsValidCachePath/traversal_parent911=== RUN TestIsValidCachePath/traversal_in_middle912=== PAUSE TestIsValidCachePath/traversal_in_middle913=== RUN TestIsValidCachePath/invalid_char_e914=== PAUSE TestIsValidCachePath/invalid_char_e915=== RUN TestIsValidCachePath/invalid_char_u916=== PAUSE TestIsValidCachePath/invalid_char_u917=== RUN TestIsValidCachePath/random_path918=== PAUSE TestIsValidCachePath/random_path919=== RUN TestIsValidCachePath/empty920=== PAUSE TestIsValidCachePath/empty921=== RUN TestIsValidCachePath/leading_slash922=== PAUSE TestIsValidCachePath/leading_slash923=== RUN TestIsValidCachePath/wrong_extension924=== PAUSE TestIsValidCachePath/wrong_extension925=== RUN TestIsValidCachePath/short_hash926=== PAUSE TestIsValidCachePath/short_hash927=== CONT TestPresignedUploadRegisteredBeforeCommit928=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info929=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal930=== CONT TestService_Rustfstest931=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal932=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key933=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key934=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key935=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key936=== CONT TestRegisterCompletedObjectNeedsPendingRow937--- PASS: TestParseSize (0.00s)938=== CONT TestParseSingleRange939=== RUN TestParseSingleRange/none940=== PAUSE TestParseSingleRange/none941=== RUN TestParseSingleRange/unknown_unit942=== PAUSE TestParseSingleRange/unknown_unit943=== RUN TestParseSingleRange/multi-range_ignored944=== PAUSE TestParseSingleRange/multi-range_ignored945=== RUN TestParseSingleRange/malformed_no_dash946=== PAUSE TestParseSingleRange/malformed_no_dash947=== RUN TestParseSingleRange/malformed_both_empty948=== PAUSE TestParseSingleRange/malformed_both_empty949=== RUN TestParseSingleRange/malformed_end_before_start950=== PAUSE TestParseSingleRange/malformed_end_before_start951=== RUN TestParseSingleRange/closed952=== PAUSE TestParseSingleRange/closed953=== RUN TestParseSingleRange/open-ended954=== PAUSE TestParseSingleRange/open-ended955=== RUN TestParseSingleRange/end_clamped_to_size956=== PAUSE TestParseSingleRange/end_clamped_to_size957=== RUN TestParseSingleRange/suffix958=== PAUSE TestParseSingleRange/suffix959=== RUN TestParseSingleRange/suffix_exceeds_size960=== PAUSE TestParseSingleRange/suffix_exceeds_size961=== RUN TestParseSingleRange/single_byte962=== PAUSE TestParseSingleRange/single_byte963=== RUN TestParseSingleRange/start_past_EOF964=== PAUSE TestParseSingleRange/start_past_EOF965=== RUN TestParseSingleRange/start_far_past_EOF966=== PAUSE TestParseSingleRange/start_far_past_EOF967--- PASS: TestSkippedUploadsHandler (0.05s)968=== CONT TestPresentRefreshesOnlyStaleClosures969=== CONT TestPresentNotReportedWhileGCDeletesClosure970=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale971=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale972=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh973=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh974=== CONT TestPresentReportsOnlyClosureRoots975=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts976=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts977=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure978=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure979=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart980=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart981=== CONT TestCreatePin_ReservedPins9822026/10/27 08:54:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49499/oidc9832026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures9842026/10/27 08:54:57 INFO Received uploads request method=POST path=/api/pending_closures985--- PASS: TestReadProxyConditionalGet (1.23s)986=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock987--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.52s)988=== CONT TestOrphanedObjectsGCStressTest989--- PASS: TestReadProxyHead (2.27s)990=== CONT TestOrphanedObjectsGC9912026/10/27 08:54:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/27 08:54:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLjkzYTE1MGUyLTljNzQtNDgyOS04MmU0LTE4NWE4MjBjMGQzOHgxNzkzMDkxMjk3NDM2NjI2MDAw parts=109932026/10/27 08:54:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9942026/10/27 08:54:59 INFO Completed upload id=1 objects=2 duration=27.196542ms9952026/10/27 08:54:59 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/27 08:54:59 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/27 08:54:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9982026/10/27 08:54:59 WARN Found objects in DB but missing from S3, will re-upload count=1999--- PASS: TestService_verifyS3Integrity (2.58s)1000=== CONT TestObjectStatsUpdatedOncePerCommit1001--- PASS: TestReadProxyInvalidPath (2.92s)1002=== CONT TestSweepSkipsRowsLockedByPush10032026/10/27 08:54:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/10/27 08:54:59 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLjM0MTExYjczLTM0ZWQtNGI2Zi05Y2Q0LTc3ZTYwYWJmZDBlNngxNzkzMDkxMjk3ODExMjY3MDAw parts=1210052026/10/27 08:54:59 INFO Received uploads request method=POST path=/api/pending_closures1006--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.07s)1007=== CONT TestFailedS3DeleteKeepsTombstone1008--- PASS: TestReadProxyNarStreaming (3.22s)1009=== CONT TestForceGCDuringPushOffersSweptObject1010=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1011=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1012=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1013=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1014=== CONT TestObjectStatsTrigger1015--- PASS: TestReadProxyContentNegotiation (3.51s)1016=== CONT TestPendingCleanupUsesOneCutoff10172026/10/27 08:55:00 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1018--- PASS: TestReadProxyNarinfo (3.67s)1019=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1020--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.82s)1021=== CONT TestMultipartCleanup10222026/10/27 08:55:01 INFO Received uploads request method=POST path=/api/pending_closures1023--- PASS: TestReadProxy404 (4.46s)1024=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10252026/10/27 08:55:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10262026/10/27 08:55:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1027--- PASS: TestCompleteMultipartUnregistered (4.55s)1028=== CONT TestGCSweepDeliversEachKeyOnce10292026/10/27 08:55:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10302026/10/27 08:55:01 INFO Received uploads request method=POST path=/api/pending_closures1031--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.78s)1032=== CONT TestTombstonedObjectOfferedWithoutWaiting10332026/10/27 08:55:01 INFO Received uploads request method=POST path=/api/pending_closures10342026/10/27 08:55:01 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/27 08:55:01 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/27 08:55:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1037--- PASS: TestService_AuthMiddleware (5.06s)1038=== CONT TestGCSweepSkipsPendingObjects1039--- PASS: TestPresentReportsOnlyClosureRoots (5.25s)1040=== CONT TestDeduplicatedObjectsRecordedAsPending1041--- PASS: TestPresentRefreshesOnlyStaleClosures (5.47s)1042=== CONT TestPushDedupSurvivesConcurrentGC1043--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.64s)1044=== CONT TestServerTLSConfig1045=== RUN TestServerTLSConfig/no_client_CA1046=== PAUSE TestServerTLSConfig/no_client_CA1047=== RUN TestServerTLSConfig/missing_CA_file1048=== PAUSE TestServerTLSConfig/missing_CA_file1049=== RUN TestServerTLSConfig/not_a_PEM_file1050=== PAUSE TestServerTLSConfig/not_a_PEM_file1051=== CONT TestService_NativeMTLS1052--- PASS: TestService_Rustfstest (5.83s)1053=== CONT TestMetricsCommit10542026/10/27 08:55:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/10/27 08:55:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLjNhY2IxMjk4LTk3YzctNDFjMS05ZDIxLWQyMzc2OGU5YzI5NHgxNzkzMDkxMzAxNzA5MTU1MDAw parts=1010562026/10/27 08:55:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10572026/10/27 08:55:02 INFO Completed upload id=1 objects=2 duration=10.922625ms10582026/10/27 08:55:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010592026/10/27 08:55:02 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/27 08:55:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures10612026/10/27 08:55:02 INFO Aborted multipart uploads count=0 kept=010622026/10/27 08:55:02 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=010632026/10/27 08:55:02 INFO Vacuumed table table=pending_closures10642026/10/27 08:55:02 INFO Received uploads request method=POST path=/api/pending_closures10652026/10/27 08:55:02 INFO Vacuumed table table=pending_objects10662026/10/27 08:55:02 INFO Vacuumed table table=multipart_uploads10672026/10/27 08:55:02 INFO Vacuumed table table=closures10682026/10/27 08:55:02 INFO Vacuumed table table=objects10692026/10/27 08:55:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010702026/10/27 08:55:02 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10712026/10/27 08:55:03 INFO Received uploads request method=POST path=/api/pending_closures1072--- PASS: TestService_createPendingClosureHandler (6.20s)1073=== CONT TestMetricsInventory1074--- PASS: TestPresignedUploadRegisteredBeforeCommit (6.15s)1075=== CONT TestGCMetrics10762026/10/27 08:55:03 INFO Received cleanup request method=DELETE path=/api/pending_closures10772026/10/27 08:55:03 INFO Aborted multipart uploads count=0 kept=010782026/10/27 08:55:03 INFO Received uploads request method=POST path=/api/pending_closures10792026/10/27 08:55:03 INFO Received cleanup request method=DELETE path=/api/pending_closures10802026/10/27 08:55:03 INFO Aborted multipart uploads count=1 kept=010812026/10/27 08:55:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10822026-10-27 08:55:03.332 UTC [89613] ERROR: Closure does not exist: id=110832026-10-27 08:55:03.332 UTC [89613] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10842026-10-27 08:55:03.332 UTC [89613] STATEMENT: -- name: CommitPendingClosure :one1085 SELECT commit_pending_closure($1::bigint)::bigint1086 1087--- PASS: TestService_cleanupPendingClosuresHandler (6.53s)1088=== CONT TestLeadElectsOneAndHandsOver10892026/10/27 08:55:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10902026/10/27 08:55:03 WARN Refused reserved pin name=worker-x86_64-linux10912026/10/27 08:55:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10922026/10/27 08:55:03 INFO Received create pin request method=POST path=/api/pins/my-app10932026/10/27 08:55:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1094--- PASS: TestCreatePin_ReservedPins (6.54s)1095=== CONT TestNARDeduplicationMetadataUploadBug1096--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.92s)1097=== CONT TestConnectWaitsForAPeerMigration1098--- PASS: TestObjectStatsUpdatedOncePerCommit (5.47s)1099=== CONT TestCreatePendingClosureRejectsOversizedNAR11002026/10/27 08:55:04 INFO Received uploads request method=POST path=/api/pending_closures1101--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1102=== CONT TestResolveDBConnectionString1103=== RUN TestResolveDBConnectionString/flag_wins1104=== PAUSE TestResolveDBConnectionString/flag_wins1105=== RUN TestResolveDBConnectionString/file_when_flag_empty1106=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1107=== RUN TestResolveDBConnectionString/missing_file_is_an_error1108=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1109=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1110=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1111=== RUN TestResolveDBConnectionString/nothing_configured1112=== PAUSE TestResolveDBConnectionString/nothing_configured1113=== CONT TestCacheConfigHandlerMaxNarSize1114--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1115=== CONT TestLeadIncumbentAnnouncesAtOnce11162026/10/27 08:55:05 INFO Aborted multipart uploads count=0 kept=011172026/10/27 08:55:05 WARN Force mode enabled - objects will be deleted immediately without grace period11182026/10/27 08:55: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=011192026/10/27 08:55:05 INFO Vacuumed table table=pending_closures11202026/10/27 08:55:05 INFO Vacuumed table table=pending_objects11212026/10/27 08:55:05 INFO Vacuumed table table=multipart_uploads1122--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.10s)11232026/10/27 08:55:05 INFO Vacuumed table table=closures1124=== CONT TestGCAdvisoryLockBlocksConcurrentRun11252026/10/27 08:55:05 INFO Vacuumed table table=objects11262026/10/27 08:55:05 INFO Aborted multipart uploads count=0 kept=011272026/10/27 08:55:05 WARN Force mode enabled - objects will be deleted immediately without grace period11282026/10/27 08:55:05 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/27 08:55:05 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=011302026/10/27 08:55:05 INFO Vacuumed table table=pending_closures11312026/10/27 08:55:05 INFO Vacuumed table table=pending_objects11322026/10/27 08:55:05 INFO Vacuumed table table=multipart_uploads11332026/10/27 08:55:05 INFO Vacuumed table table=closures11342026/10/27 08:55:05 INFO Vacuumed table table=objects1135--- PASS: TestSweepSkipsRowsLockedByPush (5.90s)1136=== CONT TestGenerateLandingPage1137--- PASS: TestGenerateLandingPage (0.00s)1138=== CONT TestLeadEndsOnShutdown11392026/10/27 08:55:05 INFO Aborted multipart uploads count=0 kept=011402026/10/27 08:55:05 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/27 08:55:05 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11422026/10/27 08:55:05 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1143--- PASS: TestFailedS3DeleteKeepsTombstone (5.83s)1144=== CONT TestGCBugBareHashReferences1145--- PASS: TestObjectStatsTrigger (5.88s)1146=== CONT TestService_AuthMiddleware_OIDC11472026/10/27 08:55:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49611/oidc11482026/10/27 08:55:06 INFO Received uploads request method=POST path=/api/pending_closures11492026/10/27 08:55:06 WARN Rate limiter enabled after throttle name=s3-test rate=511502026/10/27 08:55:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1151=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1152 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101153 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001154--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (9.55s)1155=== CONT TestService_readinessHandler11562026/10/27 08:55:06 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/27 08:55:06 INFO Received cleanup request method=DELETE path=/api/pending_closures1158=== NAME TestOrphanedObjectsGC1159 orphaned_objects_gc_test.go:287: GC Test Summary:1160 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1161 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1162 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1163 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1164 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1165--- PASS: TestOrphanedObjectsGC (7.58s)1166=== CONT TestService_healthCheckHandler11672026/10/27 08:55:06 INFO Received uploads request method=POST path=/api/pending_closures1168--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.41s)1169=== CONT TestGracefulShutdownDrainsInflight11702026/10/27 08:55:06 INFO Starting HTTP server address=127.0.0.1:4962511712026/10/27 08:55:06 INFO Shutdown signal received, draining in-flight requests timeout=10s1172--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1173=== CONT TestGCTaskStore_Fail1174--- PASS: TestGCTaskStore_Fail (0.00s)1175=== CONT TestClientCADerivations11762026/10/27 08:55:07 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/27 08:55:07 INFO Received cleanup request method=DELETE path=/api/pending_closures11782026/10/27 08:55:07 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11792026/10/27 08:55:07 INFO Aborted multipart uploads count=0 kept=111802026/10/27 08:55:07 INFO Received cleanup request method=DELETE path=/api/pending_closures11812026/10/27 08:55:07 INFO Aborted multipart uploads count=1 kept=01182--- PASS: TestMultipartCleanup (6.78s)1183=== CONT TestDeleteClosuresRacingPins11842026/10/27 08:55:07 INFO Received uploads request method=POST path=/api/pending_closures1185--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.47s)1186=== CONT TestGCTaskStore_PhaseUpdates1187--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1188=== CONT TestGCTaskStore_CompletedAllowsNewTask1189--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1190=== CONT TestCacheStatsHandler11912026/10/27 08:55:08 INFO Aborted multipart uploads count=0 kept=011922026/10/27 08:55:08 WARN Force mode enabled - objects will be deleted immediately without grace period11932026/10/27 08:55:08 INFO Received uploads request method=POST path=/api/pending_closures1194--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.66s)1195=== CONT TestCacheConfigHandler1196=== RUN TestCacheConfigHandler/full_config,_no_issuer1197=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1198=== RUN TestCacheConfigHandler/no_cache_url_configured1199=== PAUSE TestCacheConfigHandler/no_cache_url_configured1200=== RUN TestCacheConfigHandler/no_signing_keys1201=== PAUSE TestCacheConfigHandler/no_signing_keys1202=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1203=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1204=== CONT TestGCTaskStore_GetReturnsLatest1205--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1206=== CONT TestService_ReadScope_PublicByDefault12072026/10/27 08:55:08 INFO Received uploads request method=POST path=/api/pending_closures12082026/10/27 08:55:08 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=012092026/10/27 08:55:08 INFO Vacuumed table table=pending_closures12102026/10/27 08:55:08 INFO Vacuumed table table=pending_objects12112026/10/27 08:55:08 INFO Vacuumed table table=multipart_uploads12122026/10/27 08:55:08 INFO Vacuumed table table=closures12132026/10/27 08:55:08 INFO Vacuumed table table=objects1214--- PASS: TestGCSweepDeliversEachKeyOnce (7.40s)1215=== CONT TestGCTaskStore_GetEmpty1216--- PASS: TestGCTaskStore_GetEmpty (0.00s)1217=== CONT TestService_RequireScope_OIDC12182026/10/27 08:55:08 INFO Aborted multipart uploads count=0 kept=012192026/10/27 08:55:08 WARN Force mode enabled - objects will be deleted immediately without grace period12202026/10/27 08:55: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=012212026/10/27 08:55:08 INFO Vacuumed table table=pending_closures12222026/10/27 08:55:08 INFO Vacuumed table table=pending_objects12232026/10/27 08:55:08 INFO Vacuumed table table=multipart_uploads12242026/10/27 08:55:08 INFO Vacuumed table table=closures12252026/10/27 08:55:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49639/oidc12262026/10/27 08:55:08 INFO Vacuumed table table=objects1227--- PASS: TestGCSweepSkipsPendingObjects (7.06s)1228=== CONT TestClientFallsBackToClosures12292026/10/27 08:55:08 INFO Received uploads request method=POST path=/api/pending_closures1230--- PASS: TestDeduplicatedObjectsRecordedAsPending (6.87s)1231=== CONT TestClientPushesUseOnePush12322026/10/27 08:55:09 INFO Received uploads request method=POST path=/api/pending_closures12332026/10/27 08:55:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12342026/10/27 08:55:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1235--- PASS: TestService_NativeMTLS (7.03s)1236=== CONT TestCommitRacingPendingCleanupKeepsObjects12372026/10/27 08:55:09 INFO Aborted multipart uploads count=0 kept=012382026/10/27 08:55:09 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=012392026/10/27 08:55:09 INFO Vacuumed table table=pending_closures12402026/10/27 08:55:09 INFO Vacuumed table table=pending_objects12412026/10/27 08:55:09 INFO Vacuumed table table=multipart_uploads12422026/10/27 08:55:09 INFO Vacuumed table table=closures12432026/10/27 08:55:09 INFO Vacuumed table table=objects12442026/10/27 08:55:09 INFO Aborted multipart uploads count=0 kept=012452026/10/27 08:55:09 WARN Force mode enabled - objects will be deleted immediately without grace period12462026/10/27 08:55:09 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=012472026/10/27 08:55:09 INFO Vacuumed table table=pending_closures12482026/10/27 08:55:09 INFO Vacuumed table table=pending_objects12492026/10/27 08:55:09 INFO Vacuumed table table=multipart_uploads12502026/10/27 08:55:09 INFO Vacuumed table table=closures12512026/10/27 08:55:09 INFO Vacuumed table table=objects1252--- PASS: TestPushDedupSurvivesConcurrentGC (7.42s)1253=== CONT TestPinProtectsFromGC12542026/10/27 08:55:09 INFO Received push request method=POST path=/api/pushes12552026/10/27 08:55:09 INFO Received complete push request method=POST path=/api/pushes/1/complete12562026/10/27 08:55:09 INFO Completed push id=1 objects=4 duration=32.389666ms12572026/10/27 08:55:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12582026/10/27 08:55:09 INFO Completed upload id=2 objects=2 duration=1.406834ms1259--- PASS: TestMetricsCommit (7.25s)1260=== CONT TestGCTaskStore_DeduplicateSameParams1261--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1262=== CONT TestClientSharedPathCommittedMidPush12632026/10/27 08:55:10 INFO Aborted multipart uploads count=0 kept=012642026/10/27 08:55:10 WARN Force mode enabled - objects will be deleted immediately without grace period12652026/10/27 08:55: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=012662026/10/27 08:55:10 INFO Vacuumed table table=pending_closures12672026/10/27 08:55:10 INFO Vacuumed table table=pending_objects12682026/10/27 08:55:10 INFO Vacuumed table table=multipart_uploads12692026/10/27 08:55:10 INFO Vacuumed table table=closures12702026/10/27 08:55:10 INFO Vacuumed table table=objects1271--- PASS: TestGCMetrics (7.18s)1272=== CONT TestGCTaskStore_StartNew1273--- PASS: TestGCTaskStore_StartNew (0.00s)1274=== CONT TestGCTaskStore_ConflictDifferentParams1275--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1276=== CONT TestGCEndsOnShutdown1277=== RUN TestGCEndsOnShutdown/before_the_run1278=== PAUSE TestGCEndsOnShutdown/before_the_run1279=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1280=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1281=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1282=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1283=== CONT TestPushWaitsForSweepHoldingRow1284--- PASS: TestMetricsInventory (7.44s)1285=== CONT TestSweepRechecksPendingAfterLocking12862026/10/27 08:55:10 INFO lead: acquired remote=192.0.2.1:12341287=== NAME TestNARDeduplicationMetadataUploadBug1288 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestNARDeduplicationMetadataUploadBug3116086910/001/store/mqm5xg2jzwk250yvvr2p96ws42z5lwaw-file1.txt12892026/10/27 08:55:11 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1290--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (6.12s)1291=== CONT TestGetExistingObjectsLocksRows12922026/10/27 08:55:11 INFO Received push request method=POST path=/api/pushes12932026/10/27 08:55:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12942026/10/27 08:55:11 INFO Uploading mqm5xg2jzwk250yvvr2p96ws42z5lwaw-file1.txt (160B)12952026/10/27 08:55:11 WARN Failed to register uploaded object key=mqm5xg2jzwk250yvvr2p96ws42z5lwaw.ls error="server returned 404: 404 page not found\n"12962026/10/27 08:55:11 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12972026/10/27 08:55:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12982026/10/27 08:55:11 INFO Signed narinfos id=1 count=112992026/10/27 08:55:11 INFO Uploading 1 narinfos13002026/10/27 08:55:11 INFO Received complete push request method=POST path=/api/pushes/1/complete13012026/10/27 08:55:11 WARN Failed to register uploaded object key=mqm5xg2jzwk250yvvr2p96ws42z5lwaw.narinfo error="server returned 404: 404 page not found\n"13022026/10/27 08:55:11 INFO Completed push id=1 objects=3 duration=19.768291ms13032026/10/27 08:55:11 INFO Upload complete. (235ms)1304=== NAME TestNARDeduplicationMetadataUploadBug1305 metadata_upload_test.go:54: Retrieved narinfo from S3:1306 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestNARDeduplicationMetadataUploadBug3116086910/001/store/mqm5xg2jzwk250yvvr2p96ws42z5lwaw-file1.txt1307 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1308 Compression: zstd1309 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1310 NarSize: 1601311 References: 1312 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1313 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1314 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1315 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13162026/10/27 08:55:11 INFO lead: acquired remote=192.0.2.1:123413172026/10/27 08:55:11 INFO lead: released remote=192.0.2.1:12341318--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.64s)1319=== CONT TestClientWithDependencies1320=== NAME TestNARDeduplicationMetadataUploadBug1321 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestNARDeduplicationMetadataUploadBug3116086910/001/store/rw80via8rgfm2mc7b3h32qabwz9sc4s1-file2.txt13222026/10/27 08:55:11 INFO Received push request method=POST path=/api/pushes13232026/10/27 08:55:11 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13242026/10/27 08:55:11 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13252026/10/27 08:55:11 WARN Failed to register uploaded object key=rw80via8rgfm2mc7b3h32qabwz9sc4s1.ls error="server returned 404: 404 page not found\n"13262026/10/27 08:55:11 INFO Signed narinfos id=2 count=113272026/10/27 08:55:11 INFO Uploading 1 narinfos13282026/10/27 08:55:11 INFO Received complete push request method=POST path=/api/pushes/2/complete13292026/10/27 08:55:11 WARN Failed to register uploaded object key=rw80via8rgfm2mc7b3h32qabwz9sc4s1.narinfo error="server returned 404: 404 page not found\n"13302026/10/27 08:55:11 INFO Completed push id=2 objects=3 duration=610.375µs13312026/10/27 08:55:11 INFO Upload complete. (139ms)1332 metadata_upload_test.go:76: Retrieved narinfo from S3:1333 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestNARDeduplicationMetadataUploadBug3116086910/001/store/rw80via8rgfm2mc7b3h32qabwz9sc4s1-file2.txt1334 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1335 Compression: zstd1336 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1337 NarSize: 1601338 References: 1339 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1340 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1341 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1342 {"version":1,"root":{"type":"regular","size":44}}1343--- PASS: TestNARDeduplicationMetadataUploadBug (8.44s)1344=== CONT TestService_AuthMiddleware_MTLSProxyHeader13452026/10/27 08:55:11 INFO lead: released remote=192.0.2.1:123413462026/10/27 08:55:11 INFO lead: acquired remote=192.0.2.1:123413472026/10/27 08:55:11 INFO lead: acquired remote=192.0.2.1:12341348--- PASS: TestGCBugBareHashReferences (6.32s)1349=== CONT TestClientMultipleUploads1350=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1351=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1352=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1353=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1354=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1355=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1356=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1357=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1358=== CONT TestPush_RepeatedRootCommitsOnce13592026/10/27 08:55:12 WARN readiness check failed error="closed pool"1360--- PASS: TestService_readinessHandler (6.06s)1361=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1362--- PASS: TestConnectWaitsForAPeerMigration (8.75s)1363=== CONT TestClientIntegration13642026/10/27 08:55:12 INFO Aborted multipart uploads count=1 kept=013652026/10/27 08:55:12 INFO Received cleanup request method=DELETE path=/api/pending_closures13662026/10/27 08:55:12 INFO Aborted multipart uploads count=1 kept=01367--- PASS: TestPendingCleanupUsesOneCutoff (12.30s)1368=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1369--- PASS: TestService_healthCheckHandler (6.02s)1370=== CONT TestService_ReadAuthMiddleware13712026/10/27 08:55:13 INFO lead: released remote=192.0.2.1:12341372--- PASS: TestLeadElectsOneAndHandsOver (9.70s)13732026/10/27 08:55:13 INFO lead: released remote=192.0.2.1:12341374=== CONT TestClientErrorHandling1375=== RUN TestClientErrorHandling/InvalidStorePath1376--- PASS: TestLeadEndsOnShutdown (7.40s)1377=== PAUSE TestClientErrorHandling/InvalidStorePath1378=== RUN TestClientErrorHandling/InvalidAuthToken1379=== PAUSE TestClientErrorHandling/InvalidAuthToken1380=== RUN TestClientErrorHandling/ServerNotAvailable1381=== PAUSE TestClientErrorHandling/ServerNotAvailable1382=== CONT TestRedundantMultipartUpload1383=== CONT TestPush_RootsAreLockedInByteOrder1384=== NAME TestClientCADerivations1385 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientCADerivations166795894/001/store/8175a1l9qlg09js0b9xqh93nfqd64rq6-ca-test1386 client_ca_test.go:139: Found 1 dependencies (including self)1387--- PASS: TestCacheStatsHandler (5.81s)1388=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13892026/10/27 08:55:13 INFO Received push request method=POST path=/api/pushes13902026/10/27 08:55:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13912026/10/27 08:55:13 INFO Uploading 8175a1l9qlg09js0b9xqh93nfqd64rq6-ca-test (144B)13922026/10/27 08:55:13 WARN Failed to register uploaded object key=8175a1l9qlg09js0b9xqh93nfqd64rq6.ls error="server returned 404: 404 page not found\n"1393--- PASS: TestService_ReadScope_PublicByDefault (5.53s)1394=== CONT TestPush_CompleteWaitsForCleanupOfThePush13952026/10/27 08:55:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13962026/10/27 08:55:13 WARN Failed to register uploaded object key=log/rg8amhrdcldc8jgv8qbrq6szwrv7hqxf-ca-test.drv error="server returned 404: 404 page not found\n"13972026/10/27 08:55:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/10/27 08:55:13 INFO Signed narinfos id=1 count=113992026/10/27 08:55:13 INFO Uploading 1 narinfos14002026/10/27 08:55:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14012026/10/27 08:55:13 WARN Failed to register uploaded object key=8175a1l9qlg09js0b9xqh93nfqd64rq6.narinfo error="server returned 404: 404 page not found\n"14022026/10/27 08:55:13 INFO Completed push id=1 objects=4 duration=31.276417ms14032026/10/27 08:55:13 INFO Upload complete. (330ms)1404=== NAME TestClientCADerivations1405 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientCADerivations166795894/001/store/8175a1l9qlg09js0b9xqh93nfqd64rq6-ca-test1406 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1407 Compression: zstd1408 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1409 NarSize: 1441410 References: 1411 Deriver: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientCADerivations166795894/001/store/rg8amhrdcldc8jgv8qbrq6szwrv7hqxf-ca-test.drv1412 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1413 client_ca_test.go:185: Checking for realisation files in S3...1414 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1415 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1416 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket57?endpoint=http://localhost:49476®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientCADerivations166795894/001/store'1417 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11418--- PASS: TestClientCADerivations (7.08s)1419=== CONT TestPush_RejectsBadRequests1420=== RUN TestService_RequireScope_OIDC/builder_may_write1421=== PAUSE TestService_RequireScope_OIDC/builder_may_write1422=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1423=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1424=== RUN TestService_RequireScope_OIDC/ops_may_admin1425=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1426=== RUN TestService_RequireScope_OIDC/ops_may_not_write1427=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1428=== RUN TestService_RequireScope_OIDC/reader_may_not_write1429=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1430=== RUN TestService_RequireScope_OIDC/static_token_may_admin1431=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1432=== RUN TestService_RequireScope_OIDC/static_token_may_write1433=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1434=== RUN TestService_RequireScope_OIDC/reader_may_read1435=== PAUSE TestService_RequireScope_OIDC/reader_may_read1436=== RUN TestService_RequireScope_OIDC/writer_implies_read1437=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1438=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1439=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1440=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1441=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1442=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1443=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1444=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1445=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1446=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1447=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1448=== CONT TestPush_SignsNarinfosOfItsPendingObjects14492026/10/27 08:55:14 INFO Received uploads request method=POST path=/api/pending_closures14502026/10/27 08:55:14 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/27 08:55:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14522026/10/27 08:55:14 INFO Uploading y0j3qawkdv076wppf3d0238p87vds0am-shared-dep (136B)14532026/10/27 08:55:14 INFO Uploading vn2vpb97ppjxf5sx77w42y5qwwjncf4f-b (256B)14542026/10/27 08:55:14 WARN Failed to register uploaded object key=97f4gqcaajksglb0b5l4n13pl283ym3x.ls error="server returned 404: 404 page not found\n"14552026/10/27 08:55:14 WARN Failed to register uploaded object key=y0j3qawkdv076wppf3d0238p87vds0am.ls error="server returned 404: 404 page not found\n"14562026/10/27 08:55:14 WARN Failed to register uploaded object key=nar/1h3cx8zxq3mlxfjhchrb42ns90rbya3pczb02fk3n0vpkv30prz6.nar.zst error="server returned 404: 404 page not found\n"14572026/10/27 08:55:14 WARN Failed to register uploaded object key=vn2vpb97ppjxf5sx77w42y5qwwjncf4f.ls error="server returned 404: 404 page not found\n"14582026/10/27 08:55:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14592026/10/27 08:55:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14602026/10/27 08:55:15 INFO Signed narinfos id=1 count=214612026/10/27 08:55:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14622026/10/27 08:55:15 INFO Signed narinfos id=2 count=214632026/10/27 08:55:15 INFO Uploading 4 narinfos14642026/10/27 08:55:15 WARN Failed to register uploaded object key=97f4gqcaajksglb0b5l4n13pl283ym3x.narinfo error="server returned 404: 404 page not found\n"14652026/10/27 08:55:15 WARN Failed to register uploaded object key=y0j3qawkdv076wppf3d0238p87vds0am.narinfo error="server returned 404: 404 page not found\n"14662026/10/27 08:55:15 WARN Failed to register uploaded object key=vn2vpb97ppjxf5sx77w42y5qwwjncf4f.narinfo error="server returned 404: 404 page not found\n"14672026/10/27 08:55:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14682026/10/27 08:55:15 WARN Failed to register uploaded object key=y0j3qawkdv076wppf3d0238p87vds0am.narinfo error="server returned 404: 404 page not found\n"14692026/10/27 08:55:15 INFO Completed upload id=2 objects=6 duration=8.418541ms14702026/10/27 08:55:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14712026/10/27 08:55:15 INFO Completed upload id=1 objects=6 duration=285.458µs14722026/10/27 08:55:15 INFO Upload complete. (386ms)1473=== NAME TestClientFallsBackToClosures1474 client_pushes_test.go:112: Retrieved narinfo from S3:1475 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientFallsBackToClosures2912547805/001/store/y0j3qawkdv076wppf3d0238p87vds0am-shared-dep1476 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1477 Compression: zstd1478 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821479 NarSize: 1361480 References: 1481 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1482 client_pushes_test.go:112: Retrieved narinfo from S3:1483 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientFallsBackToClosures2912547805/001/store/97f4gqcaajksglb0b5l4n13pl283ym3x-a1484 URL: nar/1h3cx8zxq3mlxfjhchrb42ns90rbya3pczb02fk3n0vpkv30prz6.nar.zst1485 Compression: zstd1486 NarHash: sha256:1h3cx8zxq3mlxfjhchrb42ns90rbya3pczb02fk3n0vpkv30prz61487 NarSize: 2561488 References: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientFallsBackToClosures2912547805/001/store/y0j3qawkdv076wppf3d0238p87vds0am-shared-dep1489 CA: text:sha256:1vxkc33fz1wy0jdbfiinjd7186s8vmccb4a0x04w7xir8w5ar6c11490 client_pushes_test.go:112: Retrieved narinfo from S3:1491 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientFallsBackToClosures2912547805/001/store/vn2vpb97ppjxf5sx77w42y5qwwjncf4f-b1492 URL: nar/1h3cx8zxq3mlxfjhchrb42ns90rbya3pczb02fk3n0vpkv30prz6.nar.zst1493 Compression: zstd1494 NarHash: sha256:1h3cx8zxq3mlxfjhchrb42ns90rbya3pczb02fk3n0vpkv30prz61495 NarSize: 2561496 References: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientFallsBackToClosures2912547805/001/store/y0j3qawkdv076wppf3d0238p87vds0am-shared-dep1497 CA: text:sha256:1vxkc33fz1wy0jdbfiinjd7186s8vmccb4a0x04w7xir8w5ar6c114982026/10/27 08:55:15 INFO Aborted multipart uploads count=0 kept=014992026/10/27 08:55:15 WARN Force mode enabled - objects will be deleted immediately without grace period15002026/10/27 08:55:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015012026/10/27 08:55:15 INFO Vacuumed table table=pending_closures1502--- PASS: TestClientFallsBackToClosures (6.35s)1503=== CONT TestReadProxyRangeRequest15042026/10/27 08:55:15 INFO Vacuumed table table=pending_objects15052026/10/27 08:55:15 INFO Received push request method=POST path=/api/pushes15062026/10/27 08:55:15 INFO Vacuumed table table=multipart_uploads15072026/10/27 08:55:15 INFO Vacuumed table table=closures15082026/10/27 08:55:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15092026/10/27 08:55:15 INFO Uploading vib2adlyzpg0d5caysg2958zmz6xkg2k-shared-dep (136B)15102026/10/27 08:55:15 INFO Uploading q60rk1w5d7174xawl3mi53r0d8gmql0v-b (256B)15112026/10/27 08:55:15 INFO Vacuumed table table=objects1512--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.86s)1513=== CONT TestReadRedirectNar15142026/10/27 08:55:15 WARN Failed to register uploaded object key=nfy7h4rv14cisf5h53k7jhw0r3dckzl9.ls error="server returned 404: 404 page not found\n"15152026/10/27 08:55:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15162026/10/27 08:55:15 WARN Failed to register uploaded object key=nar/05h6269683ilvdwsrlkkl937svkfbyigcy626x4sk6wn1aqh5qzd.nar.zst error="server returned 404: 404 page not found\n"15172026/10/27 08:55:15 WARN Failed to register uploaded object key=q60rk1w5d7174xawl3mi53r0d8gmql0v.ls error="server returned 404: 404 page not found\n"15182026/10/27 08:55:15 WARN Failed to register uploaded object key=vib2adlyzpg0d5caysg2958zmz6xkg2k.ls error="server returned 404: 404 page not found\n"15192026/10/27 08:55:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15202026/10/27 08:55:15 INFO Signed narinfos id=1 count=315212026/10/27 08:55:15 INFO Uploading 3 narinfos15222026/10/27 08:55:15 WARN Failed to register uploaded object key=nfy7h4rv14cisf5h53k7jhw0r3dckzl9.narinfo error="server returned 404: 404 page not found\n"15232026/10/27 08:55:15 WARN Failed to register uploaded object key=vib2adlyzpg0d5caysg2958zmz6xkg2k.narinfo error="server returned 404: 404 page not found\n"15242026/10/27 08:55:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15252026/10/27 08:55:15 WARN Failed to register uploaded object key=q60rk1w5d7174xawl3mi53r0d8gmql0v.narinfo error="server returned 404: 404 page not found\n"15262026/10/27 08:55:15 INFO Completed push id=1 objects=8 duration=19.924292ms15272026/10/27 08:55:15 INFO Upload complete. (313ms)1528=== NAME TestClientPushesUseOnePush1529 client_pushes_test.go:97: Retrieved narinfo from S3:1530 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientPushesUseOnePush653797794/001/store/vib2adlyzpg0d5caysg2958zmz6xkg2k-shared-dep1531 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1532 Compression: zstd1533 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821534 NarSize: 1361535 References: 1536 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1537 client_pushes_test.go:97: Retrieved narinfo from S3:1538 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientPushesUseOnePush653797794/001/store/nfy7h4rv14cisf5h53k7jhw0r3dckzl9-a1539 URL: nar/05h6269683ilvdwsrlkkl937svkfbyigcy626x4sk6wn1aqh5qzd.nar.zst1540 Compression: zstd1541 NarHash: sha256:05h6269683ilvdwsrlkkl937svkfbyigcy626x4sk6wn1aqh5qzd1542 NarSize: 2561543 References: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientPushesUseOnePush653797794/001/store/vib2adlyzpg0d5caysg2958zmz6xkg2k-shared-dep1544 CA: text:sha256:1bxd5g1drgg8n3wvq8ma3qhx0w6hgixr4xd0wbscmads7z99hxv41545 client_pushes_test.go:97: Retrieved narinfo from S3:1546 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientPushesUseOnePush653797794/001/store/q60rk1w5d7174xawl3mi53r0d8gmql0v-b1547 URL: nar/05h6269683ilvdwsrlkkl937svkfbyigcy626x4sk6wn1aqh5qzd.nar.zst1548 Compression: zstd1549 NarHash: sha256:05h6269683ilvdwsrlkkl937svkfbyigcy626x4sk6wn1aqh5qzd1550 NarSize: 2561551 References: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientPushesUseOnePush653797794/001/store/vib2adlyzpg0d5caysg2958zmz6xkg2k-shared-dep1552 CA: text:sha256:1bxd5g1drgg8n3wvq8ma3qhx0w6hgixr4xd0wbscmads7z99hxv41553--- PASS: TestClientPushesUseOnePush (6.63s)1554=== CONT TestReadRedirectKeepsNarinfoProxied1555=== NAME TestPinProtectsFromGC1556 client_integration_test.go:778: Pinned store path: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestPinProtectsFromGC1733047128/001/store/rgm25736bhamcbmv3npdrl4iwpcnds9b-pinned-file.txt1557 client_integration_test.go:779: Unpinned store path: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestPinProtectsFromGC1733047128/001/store/p95vfbk02kj7zsfqqm422ifrr8knx7nj-unpinned-file.txt1558=== NAME TestOrphanedObjectsGCStressTest15592026/10/27 08:55:15 INFO Received push request method=POST path=/api/pushes1560 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15612026/10/27 08:55:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15622026/10/27 08:55:15 INFO Uploading rgm25736bhamcbmv3npdrl4iwpcnds9b-pinned-file.txt (128B)1563 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion15642026/10/27 08:55:15 WARN Failed to register uploaded object key=rgm25736bhamcbmv3npdrl4iwpcnds9b.ls error="server returned 404: 404 page not found\n"15652026/10/27 08:55:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15662026/10/27 08:55:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15672026/10/27 08:55:15 INFO Signed narinfos id=1 count=115682026/10/27 08:55:15 INFO Uploading 1 narinfos15692026/10/27 08:55:15 INFO Received uploads request method=POST path=/api/pending_closures15702026/10/27 08:55:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15712026/10/27 08:55:15 WARN Failed to register uploaded object key=rgm25736bhamcbmv3npdrl4iwpcnds9b.narinfo error="server returned 404: 404 page not found\n"15722026/10/27 08:55:16 INFO Completed push id=1 objects=3 duration=24.679583ms15732026/10/27 08:55:16 INFO Upload complete. (277ms)15742026/10/27 08:55:16 INFO Received push request method=POST path=/api/pushes15752026/10/27 08:55:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15762026/10/27 08:55:16 INFO Uploading p95vfbk02kj7zsfqqm422ifrr8knx7nj-unpinned-file.txt (128B)15772026/10/27 08:55:16 INFO Received push request method=POST path=/api/pushes15782026/10/27 08:55:16 WARN Failed to register uploaded object key=p95vfbk02kj7zsfqqm422ifrr8knx7nj.ls error="server returned 404: 404 page not found\n"15792026/10/27 08:55:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15802026/10/27 08:55:16 INFO Uploading a96xzwg8bgfsi99nmsm71np6nsd7gzhz-top (264B)15812026/10/27 08:55:16 INFO Uploading 20g1wbh6284m2na8amq4bbks8lp18rs3-shared-dep (136B)15822026/10/27 08:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15832026/10/27 08:55:16 INFO Signed narinfos id=2 count=115842026/10/27 08:55:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15852026/10/27 08:55:16 INFO Uploading 1 narinfos15862026/10/27 08:55:16 INFO Received complete push request method=POST path=/api/pushes/2/complete15872026/10/27 08:55:16 WARN Failed to register uploaded object key=nar/0zivz49rl2ja2xsrwa2pll5q4pq73d65xpbihpl8p9m95fv2v6pv.nar.zst error="server returned 404: 404 page not found\n"15882026/10/27 08:55:16 WARN Failed to register uploaded object key=p95vfbk02kj7zsfqqm422ifrr8knx7nj.narinfo error="server returned 404: 404 page not found\n"15892026/10/27 08:55:16 WARN Failed to register uploaded object key=a96xzwg8bgfsi99nmsm71np6nsd7gzhz.ls error="server returned 404: 404 page not found\n"15902026/10/27 08:55:16 WARN Failed to register uploaded object key=20g1wbh6284m2na8amq4bbks8lp18rs3.ls error="server returned 404: 404 page not found\n"15912026/10/27 08:55:16 INFO Completed push id=2 objects=3 duration=1.351458ms15922026/10/27 08:55:16 INFO Upload complete. (192ms)15932026/10/27 08:55:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15942026/10/27 08:55:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15952026/10/27 08:55:16 INFO Signed narinfos id=1 count=215962026/10/27 08:55:16 INFO Uploading 2 narinfos15972026/10/27 08:55:16 WARN Failed to register uploaded object key=a96xzwg8bgfsi99nmsm71np6nsd7gzhz.narinfo error="server returned 404: 404 page not found\n"15982026/10/27 08:55:16 INFO Received complete push request method=POST path=/api/pushes/1/complete15992026/10/27 08:55:16 WARN Failed to register uploaded object key=20g1wbh6284m2na8amq4bbks8lp18rs3.narinfo error="server returned 404: 404 page not found\n"16002026/10/27 08:55:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures16012026/10/27 08:55:16 INFO Garbage collection started16022026/10/27 08:55:16 INFO Completed push id=1 objects=6 duration=29.670166ms16032026/10/27 08:55:16 INFO Upload complete. (252ms)16042026/10/27 08:55:16 INFO Aborted multipart uploads count=0 kept=01605=== NAME TestClientSharedPathCommittedMidPush1606 client_integration_test.go:727: Retrieved narinfo from S3:1607 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientSharedPathCommittedMidPush2285321869/001/store/20g1wbh6284m2na8amq4bbks8lp18rs3-shared-dep1608 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1609 Compression: zstd1610 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821611 NarSize: 1361612 References: 1613 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1614 client_integration_test.go:727: Retrieved narinfo from S3:1615 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientSharedPathCommittedMidPush2285321869/001/store/a96xzwg8bgfsi99nmsm71np6nsd7gzhz-top1616 URL: nar/0zivz49rl2ja2xsrwa2pll5q4pq73d65xpbihpl8p9m95fv2v6pv.nar.zst1617 Compression: zstd1618 NarHash: sha256:0zivz49rl2ja2xsrwa2pll5q4pq73d65xpbihpl8p9m95fv2v6pv1619 NarSize: 2641620 References: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientSharedPathCommittedMidPush2285321869/001/store/20g1wbh6284m2na8amq4bbks8lp18rs3-shared-dep1621 CA: text:sha256:0j84nphbifw1j18ysbjd01ngxcbb0z3rgamhi38chf47i56b7imz16222026/10/27 08:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period16232026/10/27 08:55:16 INFO Aborted multipart uploads count=0 kept=016242026/10/27 08:55:16 WARN Force mode enabled - objects will be deleted immediately without grace period16252026/10/27 08:55:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01626--- PASS: TestClientSharedPathCommittedMidPush (6.49s)1627=== CONT TestPush_CompleteCommitsEveryRoot16282026/10/27 08:55:16 INFO Vacuumed table table=pending_closures16292026/10/27 08:55:16 INFO Vacuumed table table=pending_objects1630--- PASS: TestPushWaitsForSweepHoldingRow (6.29s)1631=== CONT TestPush_OverlappingRootsStoreOneRowPerKey16322026/10/27 08:55:16 INFO Vacuumed table table=multipart_uploads16332026/10/27 08:55:16 INFO Vacuumed table table=closures16342026/10/27 08:55:16 INFO Vacuumed table table=objects1635--- PASS: TestSweepRechecksPendingAfterLocking (6.07s)1636=== CONT TestReadRedirectUsesPublicS3URL1637--- PASS: TestGetExistingObjectsLocksRows (5.31s)1638=== CONT TestReadProxyDisabled16392026/10/27 08:55:16 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=016402026/10/27 08:55:16 INFO Vacuumed table table=pending_closures16412026/10/27 08:55:16 INFO Vacuumed table table=pending_objects16422026/10/27 08:55:16 INFO Vacuumed table table=multipart_uploads16432026/10/27 08:55:16 INFO Vacuumed table table=closures16442026/10/27 08:55:16 INFO Vacuumed table table=objects1645--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (5.27s)1646=== CONT TestProxyWriteTimeout/narinfo1647=== CONT TestProxyWriteTimeout/10_GiB_nar1648=== CONT TestProxyWriteTimeout/unknown_size1649=== CONT TestProxyWriteTimeout/1_GiB_nar1650--- PASS: TestProxyWriteTimeout (0.00s)1651 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1652 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1653 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1654 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1655=== CONT TestPendingClosureWriteTimeout/empty1656=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1657=== NAME TestClientWithDependencies1658 client_integration_test.go:660: Built derivation: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientWithDependencies3213291255/001/store/j4zy54hvlm0zpydycfcbd4c69ma1mvrq-test-script1659 client_integration_test.go:662: Found 1 dependencies (including self)16602026/10/27 08:55:17 INFO Received push request method=POST path=/api/pushes16612026/10/27 08:55:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16622026/10/27 08:55:17 INFO Uploading j4zy54hvlm0zpydycfcbd4c69ma1mvrq-test-script (136B)16632026/10/27 08:55:17 WARN Failed to register uploaded object key=j4zy54hvlm0zpydycfcbd4c69ma1mvrq.ls error="server returned 404: 404 page not found\n"16642026/10/27 08:55:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16652026/10/27 08:55:17 WARN Failed to register uploaded object key=log/0bv6i6dndmv371dbjxrm139cah8zy666-test-script.drv error="server returned 404: 404 page not found\n"16662026/10/27 08:55:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16672026/10/27 08:55:17 INFO Signed narinfos id=1 count=116682026/10/27 08:55:17 INFO Uploading 1 narinfos1669=== NAME TestClientMultipleUploads1670 client_integration_test.go:405: Created store path 0: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientMultipleUploads1806492248/001/store/l6nsrkxijprnl38y75i6qxj42hflzp8r-test-file-0.txt16712026/10/27 08:55:17 INFO Received push request method=POST path=/api/pushes16722026/10/27 08:55:17 INFO Received complete push request method=POST path=/api/pushes/1/complete16732026/10/27 08:55:17 WARN Failed to register uploaded object key=j4zy54hvlm0zpydycfcbd4c69ma1mvrq.narinfo error="server returned 404: 404 page not found\n"1674--- PASS: TestDeleteClosuresRacingPins (10.33s)1675=== CONT TestPendingClosureWriteTimeout/670k_objects1676=== CONT TestPendingClosureWriteTimeout/400_objects1677=== CONT TestIsValidUploadKey/narinfo16782026/10/27 08:55:17 INFO Completed push id=1 objects=4 duration=23.718375ms1679=== CONT TestIsValidCachePath/narinfo1680=== CONT TestIsValidUploadKey/nar_zst1681=== CONT TestIsValidUploadKey/unknown_type1682=== CONT TestIsValidUploadKey/empty_key1683=== CONT TestIsValidUploadKey/absolute1684=== CONT TestIsValidUploadKey/traversal_nar16852026/10/27 08:55:17 INFO Upload complete. (267ms)1686=== CONT TestIsValidUploadKey/traversal1687=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1688=== NAME TestClientWithDependencies1689 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientWithDependencies3213291255/001/store) requires matching store prefix1690=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1691=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1692=== CONT TestIsValidUploadKey/index.html1693=== CONT TestIsValidUploadKey/nix-cache-info16942026/10/27 08:55:17 INFO Received complete push request method=POST path=/api/pushes/1/complete1695=== NAME TestClientMultipleUploads1696 client_integration_test.go:405: Created store path 1: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientMultipleUploads1806492248/001/store/ddsz55vlpvpqwq37lclq77r3s3yn15fc-test-file-1.txt1697=== CONT TestIsValidUploadKey/realisation_plus_in_output1698=== CONT TestIsValidUploadKey/realisation1699=== CONT TestIsValidUploadKey/build_log_equals1700=== CONT TestIsValidUploadKey/build_log_question_mark1701=== CONT TestIsValidUploadKey/build_log_plus_in_name1702=== CONT TestIsValidUploadKey/build_log_home-manager_file1703=== CONT TestIsValidUploadKey/build_log1704=== CONT TestIsValidUploadKey/listing1705=== CONT TestIsValidUploadKey/nar_plain1706=== CONT TestIsValidUploadKey/nar_xz1707=== CONT TestIsValidCachePath/traversal_parent1708--- PASS: TestIsValidUploadKey (0.05s)1709 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1710 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1711 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1712 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1713 --- PASS: TestIsValidUploadKey/absolute (0.00s)1714 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1715 --- PASS: TestIsValidUploadKey/traversal (0.00s)1716 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1717 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1718 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1719 --- PASS: TestIsValidUploadKey/index.html (0.00s)1720 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1721 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1722 --- PASS: TestIsValidUploadKey/realisation (0.00s)1723 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1724 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1725 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1726 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1727 --- PASS: TestIsValidUploadKey/build_log (0.00s)1728 --- PASS: TestIsValidUploadKey/listing (0.00s)1729 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1730 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1731=== CONT TestIsValidCachePath/empty1732=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17332026/10/27 08:55:17 INFO Completed push id=1 objects=4 duration=23.391208ms17342026/10/27 08:55:17 INFO Received uploads request method=POST path=/1735--- PASS: TestPush_RepeatedRootCommitsOnce (5.65s)1736=== CONT TestIsValidCachePath/random_path1737=== CONT TestIsValidCachePath/invalid_char_e1738=== CONT TestIsValidCachePath/traversal_in_middle1739=== CONT TestIsValidCachePath/invalid_char_u1740=== CONT TestIsValidCachePath/wrong_extension1741=== CONT TestIsValidCachePath/leading_slash1742=== CONT TestIsValidCachePath/ls1743=== CONT TestIsValidCachePath/index.html1744=== CONT TestIsValidCachePath/nix-cache-info1745=== CONT TestIsValidCachePath/realisation1746=== CONT TestIsValidCachePath/short_hash1747=== CONT TestIsValidCachePath/log1748=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1749=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17502026/10/27 08:55:17 INFO Received uploads request method=POST path=/17512026/10/27 08:55:17 INFO Received complete multipart upload request method=POST path=/1752=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17532026/10/27 08:55:17 INFO Received request for more parts method=POST path=/1754--- PASS: TestUploadHandlersRejectInvalidKeys (0.05s)1755 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)1756 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1759=== CONT TestIsValidCachePath/nar_xz1760=== CONT TestIsValidCachePath/nar_bz21761=== CONT TestIsValidCachePath/nar_zst1762=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1763=== CONT TestIsValidCachePath/nar_uncompressed1764--- PASS: TestIsValidCachePath (0.05s)1765 --- PASS: TestIsValidCachePath/narinfo (0.00s)1766 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1767 --- PASS: TestIsValidCachePath/empty (0.00s)1768 --- PASS: TestIsValidCachePath/random_path (0.00s)1769 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1770 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1771 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1772 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1773 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1774 --- PASS: TestIsValidCachePath/ls (0.00s)1775 --- PASS: TestIsValidCachePath/index.html (0.00s)1776 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1777 --- PASS: TestIsValidCachePath/realisation (0.00s)1778 --- PASS: TestIsValidCachePath/short_hash (0.00s)1779 --- PASS: TestIsValidCachePath/log (0.00s)1780 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1781 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1782 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1783 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1784 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1785=== CONT TestParseSingleRange/none1786=== CONT TestParseSingleRange/open-ended1787=== CONT TestParseSingleRange/start_far_past_EOF1788=== CONT TestParseSingleRange/start_past_EOF1789=== CONT TestParseSingleRange/single_byte1790=== CONT TestParseSingleRange/suffix_exceeds_size1791=== CONT TestParseSingleRange/suffix1792=== CONT TestParseSingleRange/end_clamped_to_size1793=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1794=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1795=== NAME TestClientMultipleUploads1796 client_integration_test.go:405: Created store path 2: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientMultipleUploads1806492248/001/store/lzdckb7jz4rg8dymqy36mfml83rdp1l5-test-file-2.txt1797--- PASS: TestClientWithDependencies (6.41s)1798=== CONT TestParseSingleRange/malformed_no_dash1799=== CONT TestParseSingleRange/closed1800=== CONT TestParseSingleRange/malformed_end_before_start1801=== CONT TestParseSingleRange/malformed_both_empty1802=== CONT TestParseSingleRange/unknown_unit1803=== CONT TestParseSingleRange/multi-range_ignored1804--- PASS: TestParseSingleRange (0.00s)1805 --- PASS: TestParseSingleRange/none (0.00s)1806 --- PASS: TestParseSingleRange/open-ended (0.00s)1807 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1808 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1809 --- PASS: TestParseSingleRange/single_byte (0.00s)1810 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1811 --- PASS: TestParseSingleRange/suffix (0.00s)1812 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1813 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1814 --- PASS: TestParseSingleRange/closed (0.00s)1815 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1816 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1817 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1818 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1819=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18202026/10/27 08:55:17 INFO Received request for more parts method=POST path=/1821=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18222026/10/27 08:55:17 INFO Received complete multipart upload request method=POST path=/1823=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18242026/10/27 08:55:18 INFO Received uploads request method=POST path=/18252026/10/27 08:55:18 INFO Received push request method=POST path=/api/pushes18262026/10/27 08:55:18 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18272026/10/27 08:55:18 INFO Uploading lzdckb7jz4rg8dymqy36mfml83rdp1l5-test-file-2.txt (160B)18282026/10/27 08:55:18 INFO Uploading ddsz55vlpvpqwq37lclq77r3s3yn15fc-test-file-1.txt (160B)18292026/10/27 08:55:18 INFO Uploading l6nsrkxijprnl38y75i6qxj42hflzp8r-test-file-0.txt (160B)18302026/10/27 08:55:18 WARN Failed to register uploaded object key=lzdckb7jz4rg8dymqy36mfml83rdp1l5.ls error="server returned 404: 404 page not found\n"18312026/10/27 08:55:18 WARN Failed to register uploaded object key=ddsz55vlpvpqwq37lclq77r3s3yn15fc.ls error="server returned 404: 404 page not found\n"18322026/10/27 08:55:18 WARN Failed to register uploaded object key=l6nsrkxijprnl38y75i6qxj42hflzp8r.ls error="server returned 404: 404 page not found\n"18332026/10/27 08:55:18 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18342026/10/27 08:55:18 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18352026/10/27 08:55:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18362026/10/27 08:55:18 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18372026/10/27 08:55:18 INFO Signed narinfos id=1 count=318382026/10/27 08:55:18 INFO Uploading 3 narinfos18392026/10/27 08:55:18 WARN Failed to register uploaded object key=ddsz55vlpvpqwq37lclq77r3s3yn15fc.narinfo error="server returned 404: 404 page not found\n"18402026/10/27 08:55:18 WARN Failed to register uploaded object key=l6nsrkxijprnl38y75i6qxj42hflzp8r.narinfo error="server returned 404: 404 page not found\n"18412026/10/27 08:55:18 INFO Received complete push request method=POST path=/api/pushes/1/complete18422026/10/27 08:55:18 WARN Failed to register uploaded object key=lzdckb7jz4rg8dymqy36mfml83rdp1l5.narinfo error="server returned 404: 404 page not found\n"18432026/10/27 08:55:18 INFO Completed push id=1 objects=9 duration=36.600125ms18442026/10/27 08:55:18 INFO Upload complete. (321ms)1845=== NAME TestClientMultipleUploads1846 client_integration_test.go:416: Uploaded 3 paths in 355.743583ms1847=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1848--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)1849 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1850 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1851 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.27s)18522026/10/27 08:55:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018532026/10/27 08:55:18 INFO Received create pin request method=POST path=/api/pins/myapp18542026/10/27 08:55:18 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestPinProtectsFromGC1733047128/001/store/rgm25736bhamcbmv3npdrl4iwpcnds9b-pinned-file.txt narinfo_key=rgm25736bhamcbmv3npdrl4iwpcnds9b.narinfo18552026/10/27 08:55:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures18562026/10/27 08:55:18 INFO Garbage collection started18572026/10/27 08:55:18 INFO Aborted multipart uploads count=0 kept=01858--- PASS: TestClientMultipleUploads (6.36s)18592026/10/27 08:55:18 WARN Force mode enabled - objects will be deleted immediately without grace period1860=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18612026/10/27 08:55:18 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=018622026/10/27 08:55:18 INFO Vacuumed table table=pending_closures18632026/10/27 08:55:18 INFO Vacuumed table table=pending_objects18642026/10/27 08:55:18 INFO Vacuumed table table=multipart_uploads18652026/10/27 08:55:18 INFO Vacuumed table table=closures18662026/10/27 08:55:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18672026/10/27 08:55:18 WARN mTLS auth: bound subjects configured but subject DN unavailable18682026/10/27 08:55:18 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1869--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.00s)1870=== CONT TestServerTLSConfig/no_client_CA18712026/10/27 08:55:18 INFO Vacuumed table table=objects1872=== CONT TestServerTLSConfig/not_a_PEM_file1873=== NAME TestClientIntegration1874 client_integration_test.go:291: Created store path: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientIntegration307808822/002/store/byws99zvwqj6qil6cqf3p24gj21w3s3h-test-file.txt1875=== CONT TestServerTLSConfig/missing_CA_file1876--- PASS: TestServerTLSConfig (0.00s)1877 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1878 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1879 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1880=== CONT TestResolveDBConnectionString/flag_wins1881=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1882=== CONT TestResolveDBConnectionString/nothing_configured1883=== CONT TestResolveDBConnectionString/missing_file_is_an_error1884=== CONT TestResolveDBConnectionString/file_when_flag_empty1885=== CONT TestCacheConfigHandler/full_config,_no_issuer1886--- PASS: TestResolveDBConnectionString (0.01s)1887 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1888 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1889 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1890 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1891 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1892=== CONT TestCacheConfigHandler/no_signing_keys1893=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1894=== CONT TestCacheConfigHandler/no_cache_url_configured1895--- PASS: TestCacheConfigHandler (0.00s)1896 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1897 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1898 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1899 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1900=== CONT TestGCEndsOnShutdown/before_the_run19012026/10/27 08:55:18 INFO Received push request method=POST path=/api/pushes19022026/10/27 08:55:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19032026/10/27 08:55:18 INFO Uploading byws99zvwqj6qil6cqf3p24gj21w3s3h-test-file.txt (152B)19042026/10/27 08:55:18 WARN Failed to register uploaded object key=byws99zvwqj6qil6cqf3p24gj21w3s3h.ls error="server returned 404: 404 page not found\n"19052026/10/27 08:55:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19062026/10/27 08:55:18 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19072026/10/27 08:55:18 INFO Signed narinfos id=1 count=119082026/10/27 08:55:18 INFO Uploading 1 narinfos19092026/10/27 08:55:18 INFO Received complete push request method=POST path=/api/pushes/1/complete19102026/10/27 08:55:18 WARN Failed to register uploaded object key=byws99zvwqj6qil6cqf3p24gj21w3s3h.narinfo error="server returned 404: 404 page not found\n"19112026/10/27 08:55:18 INFO Completed push id=1 objects=3 duration=27.121417ms19122026/10/27 08:55:18 INFO Upload complete. (281ms)19132026/10/27 08:55:18 INFO Received uploads request method=POST path=/api/pending_closures19142026/10/27 08:55:18 INFO All 1 paths already cached1915=== NAME TestClientIntegration1916 client_integration_test.go:317: Retrieved narinfo from S3:1917 StorePath: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestClientIntegration307808822/002/store/byws99zvwqj6qil6cqf3p24gj21w3s3h-test-file.txt1918 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1919 Compression: zstd1920 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11921 NarSize: 1521922 References: 1923 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11924 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1925 client_integration_test.go:318: Decompressed .ls content (64 bytes):1926 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19272026/10/27 08:55:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19282026/10/27 08:55:19 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLmRhYmZmZTAxLTQ5ZTktNDY4Yi05NDMzLTZlMzIxN2RjN2ExMHgxNzkzMDkxMzE4Nzg2ODM5MDAw1929--- PASS: TestService_ReadAuthMiddleware (6.42s)1930=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19312026/10/27 08:55:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLmRhYmZmZTAxLTQ5ZTktNDY4Yi05NDMzLTZlMzIxN2RjN2ExMHgxNzkzMDkxMzE4Nzg2ODM5MDAw parts=11932--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.52s)1933=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19342026/10/27 08:55:19 INFO Received push request method=POST path=/api/pushes19352026/10/27 08:55:19 INFO Object in database but missing from S3 key=byws99zvwqj6qil6cqf3p24gj21w3s3h.ls19362026/10/27 08:55:19 WARN Found objects in DB but missing from S3, will re-upload count=119372026/10/27 08:55:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19382026/10/27 08:55:19 INFO Received complete push request method=POST path=/api/pushes/2/complete19392026/10/27 08:55:19 WARN Failed to register uploaded object key=byws99zvwqj6qil6cqf3p24gj21w3s3h.ls error="server returned 404: 404 page not found\n"19402026/10/27 08:55:19 INFO Completed push id=2 objects=3 duration=848.25µs19412026/10/27 08:55:19 INFO Upload complete. (174ms)1942=== NAME TestClientIntegration1943 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1944 client_integration_test.go:335: Decompressed .ls content (49 bytes):1945 {"version":1,"root":{"type":"regular","size":39}}19462026/10/27 08:55:19 INFO Received uploads request method=POST path=/api/pending_closures19472026/10/27 08:55:19 INFO Received uploads request method=POST path=/api/pending_closures19482026/10/27 08:55:19 INFO Received push request method=POST path=/api/pushes19492026/10/27 08:55:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19502026/10/27 08:55:19 INFO Received complete push request method=POST path=/api/pushes/3/complete19512026/10/27 08:55:19 WARN Failed to register uploaded object key=byws99zvwqj6qil6cqf3p24gj21w3s3h.ls error="server returned 404: 404 page not found\n"19522026/10/27 08:55:19 INFO Completed push id=3 objects=3 duration=771.875µs19532026/10/27 08:55:19 INFO Upload complete. (162ms)1954 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1955 client_integration_test.go:352: Decompressed .ls content (49 bytes):1956 {"version":1,"root":{"type":"regular","size":39}}1957 client_integration_test.go:363: Testing garbage collection...19582026/10/27 08:55:19 INFO Received push request method=POST path=/api/pushes19592026/10/27 08:55:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures19602026/10/27 08:55:19 INFO Garbage collection started19612026/10/27 08:55:19 INFO Aborted multipart uploads count=0 kept=019622026/10/27 08:55:19 WARN Force mode enabled - objects will be deleted immediately without grace period19632026-10-27 08:55:20.169 UTC [89823] ERROR: could not obtain lock on row in relation "closures"19642026-10-27 08:55:20.169 UTC [89823] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT19652026-10-27 08:55:20.172 UTC [89823] ERROR: could not obtain lock on row in relation "closures"19662026-10-27 08:55:20.172 UTC [89823] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT19672026-10-27 08:55:20.181 UTC [89823] ERROR: could not obtain lock on row in relation "closures"19682026-10-27 08:55:20.181 UTC [89823] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT19692026-10-27 08:55:20.190 UTC [89823] ERROR: could not obtain lock on row in relation "closures"19702026-10-27 08:55:20.190 UTC [89823] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT19712026-10-27 08:55:20.194 UTC [89823] ERROR: could not obtain lock on row in relation "closures"19722026-10-27 08:55:20.194 UTC [89823] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1973--- PASS: TestPush_RootsAreLockedInByteOrder (7.17s)1974=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1975=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19762026/10/27 08:55:20 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]1977=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1978=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19792026/10/27 08:55:20 WARN Authentication failed token_preview=eyJhbGciOi...CcaGNPwVwg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1980=== CONT TestClientErrorHandling/InvalidStorePath1981--- PASS: TestService_AuthMiddleware_OIDC (6.29s)1982 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1983 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1984 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1985 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1986=== NAME TestPinProtectsFromGC1987 client_integration_test.go:887: Pin successfully protected closure from garbage collection19882026/10/27 08:55:20 INFO Received push request method=POST path=/api/pushes19892026/10/27 08:55:20 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=019902026/10/27 08:55:20 INFO Received complete push request method=POST path=/api/pushes/1/complete1991--- PASS: TestPinProtectsFromGC (10.86s)1992=== CONT TestClientErrorHandling/ServerNotAvailable19932026/10/27 08:55:20 INFO Completed push id=1 objects=4 duration=45.26325ms19942026/10/27 08:55:20 INFO Received push request method=POST path=/api/pushes19952026/10/27 08:55:20 INFO Vacuumed table table=pending_closures19962026/10/27 08:55:20 INFO Vacuumed table table=pending_objects19972026/10/27 08:55:20 INFO Vacuumed table table=multipart_uploads19982026/10/27 08:55:20 INFO Aborted multipart uploads count=0 kept=019992026/10/27 08:55:20 WARN Force mode enabled - objects will be deleted immediately without grace period20002026/10/27 08:55:20 INFO Vacuumed table table=closures20012026/10/27 08:55:20 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=020022026/10/27 08:55:20 INFO Vacuumed table table=objects20032026/10/27 08:55:20 INFO Vacuumed table table=pending_closures20042026/10/27 08:55:20 INFO Received push request method=POST path=/api/pushes20052026/10/27 08:55:20 INFO Vacuumed table table=pending_objects20062026/10/27 08:55:21 INFO Vacuumed table table=multipart_uploads20072026/10/27 08:55:21 INFO Vacuumed table table=closures20082026/10/27 08:55:21 INFO Vacuumed table table=objects20092026/10/27 08:55:21 INFO Received complete push request method=POST path=/api/pushes/2/complete20102026/10/27 08:55:21 INFO Completed push id=2 objects=4 duration=8.552042ms2011--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.61s)2012=== CONT TestClientErrorHandling/InvalidAuthToken20132026/10/27 08:55:21 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/present2014=== RUN TestPush_RejectsBadRequests/no_roots2015=== PAUSE TestPush_RejectsBadRequests/no_roots2016=== RUN TestPush_RejectsBadRequests/no_objects2017=== PAUSE TestPush_RejectsBadRequests/no_objects2018=== RUN TestPush_RejectsBadRequests/bad_root2019=== PAUSE TestPush_RejectsBadRequests/bad_root2020=== RUN TestPush_RejectsBadRequests/root_not_in_objects2021=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2022=== CONT TestService_RequireScope_OIDC/builder_may_write2023=== CONT TestService_RequireScope_OIDC/reader_may_read20242026-10-27 08:55:21.363 UTC [89919] ERROR: Push does not exist: id=120252026-10-27 08:55:21.363 UTC [89919] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE20262026-10-27 08:55:21.363 UTC [89919] STATEMENT: SELECT commit_push($1)2027=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2028=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2029--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (7.59s)20302026/10/27 08:55:21 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]2031=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2032=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2033=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2034=== CONT TestService_RequireScope_OIDC/writer_implies_read2035=== CONT TestService_RequireScope_OIDC/reader_may_not_write2036=== CONT TestService_RequireScope_OIDC/static_token_may_write2037=== CONT TestService_RequireScope_OIDC/static_token_may_admin2038=== CONT TestService_RequireScope_OIDC/ops_may_not_write2039=== CONT TestService_RequireScope_OIDC/ops_may_admin2040=== CONT TestPush_RejectsBadRequests/no_roots2041=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20422026/10/27 08:55:21 INFO Received push request method=POST path=/api/pushes2043=== CONT TestPush_RejectsBadRequests/bad_root20442026/10/27 08:55:21 WARN Request failed, retrying attempt=2 backoff=207.363421ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20452026/10/27 08:55:21 INFO Received push request method=POST path=/api/pushes2046--- PASS: TestService_RequireScope_OIDC (5.35s)2047 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2061=== CONT TestPush_RejectsBadRequests/root_not_in_objects2062=== CONT TestPush_RejectsBadRequests/no_objects20632026/10/27 08:55:21 INFO Received push request method=POST path=/api/pushes20642026/10/27 08:55:21 INFO Received push request method=POST path=/api/pushes2065--- PASS: TestPush_RejectsBadRequests (7.30s)2066 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)2067 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2068 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2069 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)20702026/10/27 08:55:21 WARN Request failed, retrying attempt=3 backoff=419.280206ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20712026/10/27 08:55:21 INFO Received push request method=POST path=/api/pushes20722026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20732026/10/27 08:55:21 INFO Signed narinfos id=1 count=120742026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20752026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20762026/10/27 08:55:21 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"20772026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20782026/10/27 08:55:21 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"20792026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20802026/10/27 08:55:21 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=120812026/10/27 08:55:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20822026/10/27 08:55:21 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo2083--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.81s)20842026/10/27 08:55:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02085=== NAME TestClientIntegration2086 client_integration_test.go:370: Objects in database after GC:2087 client_integration_test.go:370: Successfully deleted all objects with GC --force20882026/10/27 08:55:22 WARN Request failed, retrying attempt=4 backoff=842.958384ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2089--- PASS: TestClientIntegration (9.60s)20902026/10/27 08:55:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2091--- PASS: TestReadProxyRangeRequest (6.95s)20922026/10/27 08:55:22 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLjZmMWVlYzAyLTAxMTgtNGQ0Yy1hODEyLTQ3ZjUzZjM5MmU0ZXgxNzkzMDkxMzE5NTM2NzY2MDAw parts=1220932026/10/27 08:55:22 INFO Received uploads request method=POST path=/api/pending_closures20942026/10/27 08:55:22 INFO Received uploads request method=POST path=/api/pending_closures2095--- PASS: TestReadRedirectNar (7.29s)20962026/10/27 08:55:22 WARN Request failed, retrying attempt=5 backoff=1.633098166s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2097--- PASS: TestReadRedirectKeepsNarinfoProxied (7.46s)20982026/10/27 08:55:23 INFO Received push request method=POST path=/api/pushes20992026/10/27 08:55:23 INFO Received complete push request method=POST path=/api/pushes/1/complete21002026/10/27 08:55:23 INFO Completed push id=1 objects=6 duration=34.217333ms2101--- PASS: TestPush_CompleteCommitsEveryRoot (7.06s)21022026/10/27 08:55:23 INFO Received push request method=POST path=/api/pushes2103--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (7.32s)2104--- PASS: TestReadProxyDisabled (7.44s)21052026/10/27 08:55:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2106--- PASS: TestReadRedirectUsesPublicS3URL (7.83s)21072026/10/27 08:55:24 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLmExMDgwYmVmLWNiMGMtNDM4Yy1iNjM5LWJlNTE5YTQ0MjRjMngxNzkzMDkxMzIyMzg0MTkzMDAw error="Get \"http://127.0.0.1:1/bucket78/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21082026/10/27 08:55:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZWJmYWVjMWYtNTlkYy00Mzc1LTg5MjctZWYzNTU1ZmZhODhmLmZkYjRiOGYwLThhMGEtNGM0OS04NWYyLTUzNTI1YTIyOTQ3NHgxNzkzMDkxMzIyMzIwNTQ2MDAw parts=1221092026/10/27 08:55:24 INFO Received cleanup request method=DELETE path=/api/pending_closures21102026/10/27 08:55:24 INFO Aborted multipart uploads count=1 kept=02111--- PASS: TestRedundantMultipartUpload (11.40s)21122026/10/27 08:55:24 INFO Received uploads request method=POST path=/api/pending_closures21132026/10/27 08:55:24 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21142026/10/27 08:55:24 WARN Request failed, retrying attempt=2 backoff=198.268517ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21152026/10/27 08:55:24 WARN Request failed, retrying attempt=3 backoff=418.123389ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/27 08:55:25 INFO Received uploads request method=POST path=/api/pending_closures21172026/10/27 08:55:25 INFO Aborted multipart uploads count=0 kept=021182026/10/27 08:55:25 WARN Force mode enabled - objects will be deleted immediately without grace period21192026/10/27 08:55:25 WARN Request failed, retrying attempt=4 backoff=762.697578ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21202026/10/27 08:55:25 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=021212026/10/27 08:55:25 INFO Vacuumed table table=pending_closures21222026/10/27 08:55:25 INFO Vacuumed table table=pending_objects21232026/10/27 08:55:25 INFO Vacuumed table table=multipart_uploads21242026/10/27 08:55:25 INFO Vacuumed table table=closures2125--- PASS: TestPendingClosureWriteTimeout (0.00s)2126 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2127 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2128 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2129 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (8.24s)21302026/10/27 08:55:25 INFO Vacuumed table table=objects21312026/10/27 08:55:25 INFO Received uploads request method=POST path=/api/pending_closures21322026/10/27 08:55:25 INFO Aborted multipart uploads count=0 kept=021332026/10/27 08:55:25 WARN Force mode enabled - objects will be deleted immediately without grace period21342026/10/27 08:55:25 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=02135--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2136 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (7.36s)2137 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (7.56s)21382026/10/27 08:55:25 INFO Vacuumed table table=pending_closures21392026/10/27 08:55:25 INFO Vacuumed table table=pending_objects21402026/10/27 08:55:25 INFO Vacuumed table table=multipart_uploads21412026/10/27 08:55:25 INFO Vacuumed table table=closures21422026/10/27 08:55:25 INFO Vacuumed table table=objects2143--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2144 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (7.27s)2145 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (7.19s)21462026/10/27 08:55:25 INFO Aborted multipart uploads count=0 kept=021472026/10/27 08:55:25 WARN Force mode enabled - objects will be deleted immediately without grace period21482026/10/27 08:55:25 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:49476/bucket97/?delete=\": context canceled"21492026/10/27 08:55:26 INFO Aborted multipart uploads count=0 kept=021502026/10/27 08:55:26 WARN Force mode enabled - objects will be deleted immediately without grace period21512026-10-27 08:55:26.088 UTC [89947] ERROR: canceling statement due to user request21522026-10-27 08:55:26.088 UTC [89947] STATEMENT: -- name: MarkStaleObjects :execrows2153 WITH RECURSIVE ct AS (2154 SELECT timezone('UTC', now()) AS now2155 ),2156 closure_reach AS (2157 -- Start with all closure keys2158 SELECT o.key, o.refs2159 FROM objects o2160 INNER JOIN closures c ON o.key = c.key2161 UNION2162 -- Recursively add all referenced objects2163 SELECT o.key, o.refs2164 FROM objects o2165 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2166 ),2167 reachable_objects AS (2168 SELECT DISTINCT key FROM closure_reach2169 ),2170 stale_objects AS (2171 SELECT o.key2172 FROM objects AS o, ct2173 WHERE2174 NOT EXISTS (2175 SELECT 12176 FROM reachable_objects ro2177 WHERE ro.key = o.key2178 )2179 AND NOT EXISTS (2180 SELECT 12181 FROM pending_objects AS po2182 WHERE po.key = o.key2183 )2184 AND o.deleted_at IS NULL -- Only mark fresh objects2185 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2186 FOR UPDATE2187 )2188 UPDATE objects2189 SET2190 deleted_at = ct.now,2191 first_deleted_at = COALESCE(first_deleted_at, ct.now)2192 FROM stale_objects, ct2193 WHERE objects.key = stale_objects.key2194 2195--- PASS: TestGCEndsOnShutdown (0.00s)2196 --- PASS: TestGCEndsOnShutdown/before_the_run (7.21s)2197 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.74s)2198 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (6.97s)21992026/10/27 08:55:26 WARN Request failed, retrying attempt=5 backoff=1.738943047s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22002026/10/27 08:55:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22012026/10/27 08:55:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22022026/10/27 08:55:27 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"22032026/10/27 08:55:27 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-config22042026/10/27 08:55:27 WARN Request failed, retrying attempt=2 backoff=196.611304ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22052026/10/27 08:55:28 WARN Request failed, retrying attempt=3 backoff=412.726566ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22062026/10/27 08:55:28 WARN Request failed, retrying attempt=4 backoff=768.66094ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/10/27 08:55:29 WARN Request failed, retrying attempt=5 backoff=1.534944567s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/10/27 08:55:30 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_closures22092026/10/27 08:55:31 WARN Request failed, retrying attempt=2 backoff=185.371782ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22102026/10/27 08:55:31 WARN Request failed, retrying attempt=3 backoff=372.865018ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2211=== NAME TestOrphanedObjectsGCStressTest2212 orphaned_objects_gc_test.go:503: Stress test completed successfully:2213 orphaned_objects_gc_test.go:504: - Active objects preserved: 202214 orphaned_objects_gc_test.go:505: - Objects deleted: 2102215 orphaned_objects_gc_test.go:506: - Total GC'd: 2102216--- PASS: TestOrphanedObjectsGCStressTest (33.25s)22172026/10/27 08:55:31 WARN Request failed, retrying attempt=4 backoff=856.863436ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22182026/10/27 08:55:32 WARN Request failed, retrying attempt=5 backoff=1.481609611s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2219--- PASS: TestClientErrorHandling (0.01s)2220 --- PASS: TestClientErrorHandling/InvalidStorePath (6.01s)2221 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.47s)2222 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.33s)2223PASS2224{"timestamp":"2026-10-27T08:55:33.972772Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49530","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}2225{"timestamp":"2026-10-27T08:55:33.973225Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49827","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}22262026-10-27 08:55:34.103 UTC [89485] LOG: received smart shutdown request22272026-10-27 08:55:34.104 UTC [89485] LOG: background worker "logical replication launcher" (PID 89495) exited with exit code 122282026-10-27 08:55:34.111 UTC [89490] LOG: shutting down22292026-10-27 08:55:34.112 UTC [89490] LOG: checkpoint starting: shutdown immediate22302026-10-27 08:55:35.418 UTC [89490] LOG: checkpoint complete: wrote 12189 buffers (74.4%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=0.613 s, sync=0.653 s, total=1.307 s; sync files=34044, longest=0.001 s, average=0.001 s; distance=501964 kB, estimate=501964 kB; lsn=0/201C0320, redo lsn=0/201C032022312026-10-27 08:55:35.425 UTC [89485] LOG: database system is shut down2232Running OIDC tests...2233=== RUN TestAudienceForIssuer2234=== PAUSE TestAudienceForIssuer2235=== RUN TestGlobMatch2236=== PAUSE TestGlobMatch2237=== RUN TestValidateToken_ValidToken2238=== PAUSE TestValidateToken_ValidToken2239=== RUN TestValidateToken_WrongAudience2240=== PAUSE TestValidateToken_WrongAudience2241=== RUN TestValidateToken_Expired2242=== PAUSE TestValidateToken_Expired2243=== RUN TestValidateToken_BoundClaimsMismatch2244=== PAUSE TestValidateToken_BoundClaimsMismatch2245=== RUN TestValidateToken_BoundSubjectMismatch2246=== PAUSE TestValidateToken_BoundSubjectMismatch2247=== RUN TestValidateToken_MultipleProviders2248=== PAUSE TestValidateToken_MultipleProviders2249=== RUN TestValidateToken_NoMatchingProvider2250=== PAUSE TestValidateToken_NoMatchingProvider2251=== RUN TestValidateToken_KubernetesServiceAccount2252=== PAUSE TestValidateToken_KubernetesServiceAccount2253=== RUN TestNewValidator_KubernetesRequiresCA2254=== PAUSE TestNewValidator_KubernetesRequiresCA2255=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2256=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2257=== RUN TestPins_ReservedForMatchingRule2258=== PAUSE TestPins_ReservedForMatchingRule2259=== RUN TestPins_TopLevelShorthand2260=== PAUSE TestPins_TopLevelShorthand2261=== RUN TestPins_ConfigValidation2262=== PAUSE TestPins_ConfigValidation2263=== RUN TestScopes_LegacyProviderDefaultsToWrite2264=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2265=== RUN TestScopes_Rules2266=== PAUSE TestScopes_Rules2267=== RUN TestScopes_ConfigValidation2268=== PAUSE TestScopes_ConfigValidation2269=== CONT TestAudienceForIssuer2270--- PASS: TestAudienceForIssuer (0.00s)2271=== CONT TestValidateToken_NoMatchingProvider2272=== CONT TestPins_ConfigValidation2273=== CONT TestValidateToken_Expired2274=== CONT TestValidateToken_WrongAudience2275=== CONT TestValidateToken_ValidToken2276=== CONT TestGlobMatch2277=== RUN TestGlobMatch/foo_foo2278=== PAUSE TestGlobMatch/foo_foo2279=== RUN TestGlobMatch/foo_bar2280=== PAUSE TestGlobMatch/foo_bar2281=== RUN TestGlobMatch/*_2282=== PAUSE TestGlobMatch/*_2283=== RUN TestGlobMatch/*_anything2284=== PAUSE TestGlobMatch/*_anything2285=== RUN TestGlobMatch/foo*_foo2286=== PAUSE TestGlobMatch/foo*_foo2287=== RUN TestGlobMatch/foo*_foobar2288=== PAUSE TestGlobMatch/foo*_foobar2289=== RUN TestGlobMatch/foo*_bar2290=== PAUSE TestGlobMatch/foo*_bar2291=== RUN TestGlobMatch/*bar_bar2292=== PAUSE TestGlobMatch/*bar_bar2293=== RUN TestGlobMatch/*bar_foobar2294=== PAUSE TestGlobMatch/*bar_foobar2295=== RUN TestGlobMatch/*bar_foo2296=== PAUSE TestGlobMatch/*bar_foo2297=== RUN TestGlobMatch/foo*bar_foobar2298=== PAUSE TestGlobMatch/foo*bar_foobar2299=== RUN TestGlobMatch/foo*bar_foo123bar2300=== PAUSE TestGlobMatch/foo*bar_foo123bar2301=== RUN TestGlobMatch/foo*bar_foobarbaz2302=== PAUSE TestGlobMatch/foo*bar_foobarbaz2303=== RUN TestGlobMatch/*/*_foo/bar2304=== PAUSE TestGlobMatch/*/*_foo/bar2305=== RUN TestGlobMatch/*/*_foo2306=== PAUSE TestGlobMatch/*/*_foo2307=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2308=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2309=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02310=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02311=== RUN TestGlobMatch/refs/*/main_refs/heads/main2312=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2313=== RUN TestGlobMatch/fo?_foo2314=== PAUSE TestGlobMatch/fo?_foo2315=== RUN TestGlobMatch/fo?_fo2316=== PAUSE TestGlobMatch/fo?_fo2317=== RUN TestGlobMatch/fo?_fooo2318=== PAUSE TestGlobMatch/fo?_fooo2319=== RUN TestGlobMatch/?oo_foo2320=== PAUSE TestGlobMatch/?oo_foo2321=== RUN TestGlobMatch/?oo_boo2322=== PAUSE TestGlobMatch/?oo_boo2323=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2324=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2325=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2326=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2327=== CONT TestGlobMatch/foo_foo2328=== CONT TestValidateToken_BoundClaimsMismatch2329--- PASS: TestPins_ConfigValidation (0.00s)2330=== CONT TestGlobMatch/*/*_foo/bar2331=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2332=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2333=== CONT TestGlobMatch/?oo_boo2334=== CONT TestGlobMatch/?oo_foo2335=== CONT TestGlobMatch/fo?_fooo2336=== CONT TestGlobMatch/fo?_fo2337=== CONT TestGlobMatch/fo?_foo2338=== CONT TestGlobMatch/refs/*/main_refs/heads/main2339=== CONT TestGlobMatch/*bar_bar2340=== CONT TestGlobMatch/foo*bar_foo123bar2341=== CONT TestGlobMatch/*_2342=== CONT TestGlobMatch/*_anything2343=== CONT TestGlobMatch/*bar_foo2344=== CONT TestGlobMatch/*bar_foobar2345=== CONT TestGlobMatch/foo_bar2346=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02347=== CONT TestPins_ReservedForMatchingRule2348=== CONT TestValidateToken_MultipleProviders2349=== CONT TestPins_TopLevelShorthand2350=== CONT TestValidateToken_BoundSubjectMismatch2351=== CONT TestNewValidator_KubernetesRequiresCA2352=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2353=== CONT TestScopes_ConfigValidation2354=== CONT TestScopes_LegacyProviderDefaultsToWrite2355--- PASS: TestScopes_ConfigValidation (0.00s)2356=== CONT TestValidateToken_KubernetesServiceAccount2357=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2358=== CONT TestGlobMatch/*/*_foo2359=== CONT TestGlobMatch/foo*_foo2360=== CONT TestGlobMatch/foo*_bar2361=== CONT TestGlobMatch/foo*_foobar2362=== CONT TestGlobMatch/foo*bar_foobar2363=== CONT TestGlobMatch/foo*bar_foobarbaz2364--- PASS: TestGlobMatch (0.00s)2365 --- PASS: TestGlobMatch/foo_foo (0.00s)2366 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2367 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2368 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2369 --- PASS: TestGlobMatch/?oo_boo (0.00s)2370 --- PASS: TestGlobMatch/?oo_foo (0.00s)2371 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2372 --- PASS: TestGlobMatch/fo?_fo (0.00s)2373 --- PASS: TestGlobMatch/fo?_foo (0.00s)2374 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2375 --- PASS: TestGlobMatch/*bar_bar (0.00s)2376 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2377 --- PASS: TestGlobMatch/*_ (0.00s)2378 --- PASS: TestGlobMatch/*_anything (0.00s)2379 --- PASS: TestGlobMatch/*bar_foo (0.00s)2380 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2381 --- PASS: TestGlobMatch/foo_bar (0.00s)2382 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2383 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2384 --- PASS: TestGlobMatch/*/*_foo (0.00s)2385 --- PASS: TestGlobMatch/foo*_foo (0.00s)2386 --- PASS: TestGlobMatch/foo*_bar (0.00s)2387 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2388 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2389 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2390=== CONT TestScopes_Rules23912026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49989/oidc23922026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49988/oidc2393--- PASS: TestValidateToken_BoundSubjectMismatch (0.04s)23942026/10/27 08:55:37 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232395--- PASS: TestValidateToken_Expired (0.07s)23962026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49986/oidc23972026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49992/oidc23982026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49994/oidc2399--- PASS: TestValidateToken_WrongAudience (0.07s)2400--- PASS: TestValidateToken_ValidToken (0.07s)2401--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2402--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)24032026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49999/oidc2404--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)24052026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50004/oidc24062026/10/27 08:55:37 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:500002407--- PASS: TestPins_TopLevelShorthand (0.08s)2408--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)24092026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50006/oidc2410--- PASS: TestPins_ReservedForMatchingRule (0.09s)24112026/10/27 08:55:37 http: TLS handshake error from 127.0.0.1:50009: read tcp 127.0.0.1:50008->127.0.0.1:50009: use of closed network connection2412--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)24132026/10/27 08:55:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:50003/oidc24142026/10/27 08:55:37 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:50010/oidc2415--- PASS: TestValidateToken_MultipleProviders (0.10s)24162026/10/27 08:55:37 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49998/oidc2417--- PASS: TestValidateToken_NoMatchingProvider (0.13s)24182026/10/27 08:55:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:50015/oidc2419--- PASS: TestScopes_Rules (0.12s)2420PASS2421Running hook tests...2422=== RUN TestSendPathsEmpty2423=== PAUSE TestSendPathsEmpty2424=== RUN TestQueueEnqueueAndFetch2425=== PAUSE TestQueueEnqueueAndFetch2426=== RUN TestQueueDeduplication2427=== PAUSE TestQueueDeduplication2428=== RUN TestQueueRemove2429=== PAUSE TestQueueRemove2430=== RUN TestQueueFetchBatchLimit2431=== PAUSE TestQueueFetchBatchLimit2432=== RUN TestQueueRetryMovesToBack2433=== PAUSE TestQueueRetryMovesToBack2434=== RUN TestQueueFetchRemoveLifecycle2435=== PAUSE TestQueueFetchRemoveLifecycle2436=== RUN TestQueueConcurrentWriters2437=== PAUSE TestQueueConcurrentWriters2438=== RUN TestQueueRemoveLargeClosure2439=== PAUSE TestQueueRemoveLargeClosure2440=== RUN TestServerClientIntegration2441--- PASS: TestServerClientIntegration (0.00s)2442=== RUN TestServerQueueError24432026/10/27 08:55:37 ERROR Failed to queue paths error="permission denied" count=12444--- PASS: TestServerQueueError (0.00s)2445=== RUN TestGetListenerSocketActivation2446 server_test.go:145: systemd socket activation does not exist on darwin2447--- SKIP: TestGetListenerSocketActivation (0.00s)2448=== RUN TestServerStalledClientDoesNotBlockShutdown2449=== PAUSE TestServerStalledClientDoesNotBlockShutdown2450=== RUN TestServerBacksOffOnAcceptErrors2451=== PAUSE TestServerBacksOffOnAcceptErrors2452=== RUN TestDrainIsolatesPoisonPath2453=== PAUSE TestDrainIsolatesPoisonPath2454=== RUN TestRunNotBlockedByPoisonHead2455=== PAUSE TestRunNotBlockedByPoisonHead2456=== RUN TestDrainGivesUpWhenServerDown2457=== PAUSE TestDrainGivesUpWhenServerDown2458=== RUN TestFailedPathPrunedByLaterClosure2459=== PAUSE TestFailedPathPrunedByLaterClosure2460=== RUN TestWorkerUploadsAndRemoves2461=== PAUSE TestWorkerUploadsAndRemoves2462=== RUN TestWorkerSkipsGCdPaths2463=== PAUSE TestWorkerSkipsGCdPaths2464=== RUN TestWorkerPrunesClosureDeps2465=== PAUSE TestWorkerPrunesClosureDeps2466=== RUN TestDrainTimeout2467=== PAUSE TestDrainTimeout2468=== RUN TestWorkerRemoveFailureIsNotProgress2469=== PAUSE TestWorkerRemoveFailureIsNotProgress2470=== RUN TestWorkerKeepsPathItCannotStat2471=== PAUSE TestWorkerKeepsPathItCannotStat2472=== CONT TestSendPathsEmpty2473=== CONT TestDrainIsolatesPoisonPath2474--- PASS: TestSendPathsEmpty (0.00s)2475=== CONT TestServerBacksOffOnAcceptErrors24762026/10/27 08:55:37 ERROR Accept failed error="too many open files"2477=== CONT TestServerStalledClientDoesNotBlockShutdown2478=== CONT TestQueueRemoveLargeClosure2479=== CONT TestQueueConcurrentWriters2480=== CONT TestQueueFetchRemoveLifecycle2481=== CONT TestQueueRetryMovesToBack2482=== CONT TestQueueFetchBatchLimit2483=== CONT TestQueueRemove2484=== CONT TestWorkerSkipsGCdPaths2485=== CONT TestWorkerKeepsPathItCannotStat2486=== CONT TestWorkerRemoveFailureIsNotProgress2487=== CONT TestQueueDeduplication2488=== CONT TestDrainTimeout2489=== CONT TestWorkerPrunesClosureDeps2490=== CONT TestQueueEnqueueAndFetch2491=== CONT TestFailedPathPrunedByLaterClosure2492=== CONT TestWorkerUploadsAndRemoves2493=== CONT TestDrainGivesUpWhenServerDown2494=== CONT TestRunNotBlockedByPoisonHead24952026/10/27 08:55:37 ERROR Accept failed error="too many open files"24962026/10/27 08:55:37 INFO Uploading batch count=22497--- PASS: TestQueueRetryMovesToBack (0.01s)2498--- PASS: TestQueueRemove (0.01s)24992026/10/27 08:55:37 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa error="stat /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa: permission denied"25002026/10/27 08:55:37 INFO Upload queue status pending=225012026/10/27 08:55:37 INFO Uploading batch count=225022026/10/27 08:55:37 INFO Upload queue status pending=225032026/10/27 08:55:37 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa error="stat /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa: permission denied"25042026/10/27 08:55:37 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa error="stat /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerKeepsPathItCannotStat2035953351/002/locked/aaa: permission denied"25052026/10/27 08:55:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerSkipsGCdPaths809876069/002/nonexistent25062026/10/27 08:55:37 ERROR Accept failed error="too many open files"25072026/10/27 08:55:37 INFO Uploading batch count=125082026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=12509--- PASS: TestQueueEnqueueAndFetch (0.01s)25102026/10/27 08:55:37 INFO Uploading batch count=125112026/10/27 08:55:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerRemoveFailureIsNotProgress4169463473/002/nonexistent25122026/10/27 08:55:37 ERROR Drain finished with paths left in queue remaining=125132026/10/27 08:55:37 INFO Upload queue status pending=225142026/10/27 08:55:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125152026/10/27 08:55:37 INFO Uploading batch count=12516--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2517--- PASS: TestQueueFetchBatchLimit (0.02s)25182026/10/27 08:55:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerRemoveFailureIsNotProgress4169463473/002/nonexistent25192026/10/27 08:55:37 INFO Uploading batch count=225202026/10/27 08:55:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125212026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=225222026/10/27 08:55:37 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestWorkerRemoveFailureIsNotProgress4169463473/002/nonexistent25232026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/a25242026/10/27 08:55:37 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125252026/10/27 08:55:37 ERROR Drain finished with paths left in queue remaining=125262026/10/27 08:55:37 INFO Uploading batch count=425272026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=425282026/10/27 08:55:37 INFO Upload queue status pending=325292026/10/27 08:55:37 INFO Uploading batch count=125302026/10/27 08:55:37 INFO Uploading batch count=125312026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=125322026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/b25332026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainIsolatesPoisonPath3916240870/002/bbb25342026/10/27 08:55:37 INFO Uploading batch count=125352026/10/27 08:55:37 INFO Uploading batch count=225362026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=225372026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/c2538--- PASS: TestQueueDeduplication (0.02s)25392026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/d2540--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2541--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25422026/10/27 08:55:37 INFO Uploading batch count=225432026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=225442026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/e25452026/10/27 08:55:37 INFO Uploading batch count=125462026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=125472026/10/27 08:55:37 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestDrainGivesUpWhenServerDown3464257264/002/f25482026/10/27 08:55:37 INFO Uploading batch count=125492026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=125502026/10/27 08:55:37 ERROR Drain finished with paths left in queue remaining=1025512026/10/27 08:55:37 INFO Uploading batch count=125522026/10/27 08:55:37 ERROR Upload failed error="upload failed" count=125532026/10/27 08:55:37 ERROR Drain finished with paths left in queue remaining=12554--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2555--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2556--- PASS: TestDrainIsolatesPoisonPath (0.02s)2557--- PASS: TestWorkerUploadsAndRemoves (0.03s)2558--- PASS: TestWorkerSkipsGCdPaths (0.03s)25592026/10/27 08:55:37 ERROR Accept failed error="too many open files"2560--- PASS: TestWorkerPrunesClosureDeps (0.04s)2561--- PASS: TestQueueRemoveLargeClosure (0.06s)2562--- PASS: TestQueueConcurrentWriters (0.06s)25632026/10/27 08:55:37 ERROR Accept failed error="too many open files"25642026/10/27 08:55:37 ERROR Accept failed error="too many open files"25652026/10/27 08:55:37 ERROR Failed to decode request error="read unix /private/var/tb/8/scratch/651f346cfe2ac1bb/build/hook891888428/test.sock->: i/o timeout"25662026/10/27 08:55:37 ERROR Failed to write response error="write unix /private/var/tb/8/scratch/651f346cfe2ac1bb/build/hook891888428/test.sock->: i/o timeout"2567--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25682026/10/27 08:55:37 ERROR Upload failed error="context deadline exceeded" count=225692026/10/27 08:55:37 ERROR Drain finished with paths left in queue remaining=42570--- PASS: TestDrainTimeout (0.21s)25712026/10/27 08:55:37 ERROR Accept failed error="too many open files"25722026/10/27 08:55:38 ERROR Accept failed error="too many open files"2573--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25742026/10/27 08:55:38 INFO Uploading batch count=125752026/10/27 08:55:38 INFO Uploading batch count=125762026/10/27 08:55:38 INFO Uploading batch count=125772026/10/27 08:55:38 ERROR Upload failed error="upload failed" count=125782026/10/27 08:55:38 INFO Uploading batch count=125792026/10/27 08:55:38 ERROR Upload failed error="upload failed" count=125802026/10/27 08:55:38 INFO Uploading batch count=125812026/10/27 08:55:38 ERROR Upload failed error="upload failed" count=125822026/10/27 08:55:38 INFO Uploading batch count=125832026/10/27 08:55:38 ERROR Upload failed error="upload failed" count=125842026/10/27 08:55:38 ERROR Drain finished with paths left in queue remaining=12585--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2586PASS2587Running signing tests...2588=== RUN TestExternalSigner2589=== PAUSE TestExternalSigner2590=== RUN TestExternalSignerWrongPublicKey2591=== PAUSE TestExternalSignerWrongPublicKey2592=== RUN TestExternalSignerErrors2593=== PAUSE TestExternalSignerErrors2594=== RUN TestExternalSignerRestartsAfterCrash2595=== PAUSE TestExternalSignerRestartsAfterCrash2596=== RUN TestExternalSignerProgramErrorKeepsProcess2597=== PAUSE TestExternalSignerProgramErrorKeepsProcess2598=== RUN TestExternalSignerClose2599=== PAUSE TestExternalSignerClose2600=== RUN TestExternalSignerRejectsInvalidPublicKey2601=== PAUSE TestExternalSignerRejectsInvalidPublicKey2602=== RUN TestExternalSignerCancellation2603=== PAUSE TestExternalSignerCancellation2604=== RUN TestGenerateFingerprint2605=== PAUSE TestGenerateFingerprint2606=== RUN TestParseSigningKey2607=== PAUSE TestParseSigningKey2608=== RUN TestSign2609=== PAUSE TestSign2610=== RUN TestSignBatch2611=== PAUSE TestSignBatch2612=== RUN TestNilKeyPublicKey2613=== PAUSE TestNilKeyPublicKey2614=== RUN TestSignErrors2615=== PAUSE TestSignErrors2616=== CONT TestExternalSigner2617=== CONT TestExternalSignerCancellation2618=== CONT TestSignBatch2619=== CONT TestSignErrors2620=== CONT TestParseSigningKey2621=== RUN TestParseSigningKey/valid_32-byte_key2622=== PAUSE TestParseSigningKey/valid_32-byte_key2623=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2624=== CONT TestNilKeyPublicKey2625--- PASS: TestNilKeyPublicKey (0.00s)2626=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2627=== CONT TestSign2628=== CONT TestExternalSignerProgramErrorKeepsProcess2629=== CONT TestExternalSignerRejectsInvalidPublicKey2630=== RUN TestExternalSignerRejectsInvalidPublicKey/#002631=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002632=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2633=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2634=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2635=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2636=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2637=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2638=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2639=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2640=== CONT TestExternalSignerRejectsInvalidPublicKey/#002641=== CONT TestExternalSignerClose2642=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2643=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2644=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2645=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2646--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2647 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2648 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2649 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2650 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2651 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2652=== CONT TestGenerateFingerprint2653=== RUN TestGenerateFingerprint/basic_with_references2654=== PAUSE TestGenerateFingerprint/basic_with_references2655=== RUN TestGenerateFingerprint/no_references2656=== PAUSE TestGenerateFingerprint/no_references2657=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2658=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2659=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2660=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2661=== RUN TestGenerateFingerprint/invalid_nar_hash_length2662=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2663=== RUN TestGenerateFingerprint/invalid_store_path_prefix2664=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2665=== RUN TestGenerateFingerprint/invalid_reference_prefix2666=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2667=== CONT TestGenerateFingerprint/basic_with_references2668=== CONT TestExternalSignerErrors2669=== RUN TestExternalSignerErrors/missing_signature_name2670=== PAUSE TestExternalSignerErrors/missing_signature_name2671=== CONT TestGenerateFingerprint/no_references2672=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2673=== RUN TestExternalSignerErrors/wrong_signature_length2674=== CONT TestExternalSignerWrongPublicKey2675=== RUN TestParseSigningKey/no_colon2676=== CONT TestGenerateFingerprint/invalid_reference_prefix2677=== CONT TestGenerateFingerprint/invalid_store_path_prefix2678=== CONT TestGenerateFingerprint/invalid_nar_hash_length2679=== CONT TestExternalSignerRestartsAfterCrash2680=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2681--- PASS: TestGenerateFingerprint (0.00s)2682 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2683 --- PASS: TestGenerateFingerprint/no_references (0.00s)2684 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2685 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2686 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2687 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2688 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2689=== PAUSE TestExternalSignerErrors/wrong_signature_length2690=== PAUSE TestParseSigningKey/no_colon2691=== RUN TestParseSigningKey/empty_name2692=== PAUSE TestParseSigningKey/empty_name2693=== RUN TestParseSigningKey/invalid_base642694=== PAUSE TestParseSigningKey/invalid_base642695=== RUN TestParseSigningKey/wrong_length2696=== PAUSE TestParseSigningKey/wrong_length2697=== CONT TestParseSigningKey/valid_32-byte_key2698=== CONT TestParseSigningKey/wrong_length2699=== RUN TestExternalSignerErrors/program_error2700=== PAUSE TestExternalSignerErrors/program_error2701=== RUN TestExternalSignerErrors/wrong_id2702=== PAUSE TestExternalSignerErrors/wrong_id2703=== RUN TestExternalSignerErrors/wrong_signatures_shape2704=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2705=== RUN TestExternalSignerErrors/unrequested_key2706=== PAUSE TestExternalSignerErrors/unrequested_key2707=== RUN TestExternalSignerErrors/wrong_signature_name2708=== PAUSE TestExternalSignerErrors/wrong_signature_name2709=== RUN TestExternalSignerErrors/invalid_signature_base642710=== PAUSE TestExternalSignerErrors/invalid_signature_base642711=== RUN TestExternalSignerErrors/exit_at_startup2712=== PAUSE TestExternalSignerErrors/exit_at_startup2713=== RUN TestExternalSignerErrors/exit_on_request2714=== PAUSE TestExternalSignerErrors/exit_on_request2715=== RUN TestExternalSignerErrors/wrong_shape2716=== PAUSE TestExternalSignerErrors/wrong_shape2717=== CONT TestParseSigningKey/invalid_base642718=== CONT TestParseSigningKey/empty_name2719=== CONT TestParseSigningKey/no_colon2720=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2721=== RUN TestExternalSignerErrors/null_signatures2722=== PAUSE TestExternalSignerErrors/null_signatures2723=== RUN TestExternalSignerErrors/invalid_JSON2724=== PAUSE TestExternalSignerErrors/invalid_JSON2725=== RUN TestExternalSignerErrors/null2726=== PAUSE TestExternalSignerErrors/null2727=== RUN TestExternalSignerErrors/missing_signatures2728=== PAUSE TestExternalSignerErrors/missing_signatures2729=== RUN TestExternalSignerErrors/too_few_signatures2730=== PAUSE TestExternalSignerErrors/too_few_signatures2731=== CONT TestExternalSignerErrors/missing_signature_name2732=== RUN TestSignErrors/nil_key2733=== CONT TestExternalSignerErrors/exit_at_startup2734=== PAUSE TestSignErrors/nil_key2735=== RUN TestSignErrors/nil_narinfo2736=== PAUSE TestSignErrors/nil_narinfo2737=== RUN TestSignErrors/invalid_narinfo2738=== PAUSE TestSignErrors/invalid_narinfo2739=== RUN TestSignErrors/canceled2740=== PAUSE TestSignErrors/canceled2741=== CONT TestSignErrors/nil_key2742=== CONT TestExternalSignerErrors/too_few_signatures2743=== CONT TestSignErrors/invalid_narinfo2744=== CONT TestSignErrors/canceled2745--- PASS: TestSign (0.00s)2746=== CONT TestSignErrors/nil_narinfo2747--- PASS: TestSignErrors (0.00s)2748 --- PASS: TestSignErrors/nil_key (0.00s)2749 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2750 --- PASS: TestSignErrors/canceled (0.00s)2751 --- PASS: TestSignErrors/nil_narinfo (0.00s)2752=== CONT TestExternalSignerErrors/wrong_signatures_shape2753--- PASS: TestParseSigningKey (0.00s)2754 --- PASS: TestParseSigningKey/wrong_length (0.00s)2755 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2756 --- PASS: TestParseSigningKey/empty_name (0.00s)2757 --- PASS: TestParseSigningKey/no_colon (0.00s)2758 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2759 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2760=== CONT TestExternalSignerErrors/wrong_signature_name2761=== CONT TestExternalSignerErrors/wrong_shape2762=== CONT TestExternalSignerErrors/invalid_JSON2763=== CONT TestExternalSignerErrors/unrequested_key2764=== CONT TestExternalSignerErrors/exit_on_request2765=== CONT TestExternalSignerErrors/invalid_signature_base642766--- PASS: TestSignBatch (0.00s)2767=== CONT TestExternalSignerErrors/program_error2768=== CONT TestExternalSignerErrors/null2769=== CONT TestExternalSignerErrors/wrong_id2770=== CONT TestExternalSignerErrors/wrong_signature_length2771=== CONT TestExternalSignerErrors/null_signatures2772=== CONT TestExternalSignerErrors/missing_signatures2773--- PASS: TestExternalSigner (0.10s)2774--- PASS: TestExternalSignerClose (0.17s)2775--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.24s)2776--- PASS: TestExternalSignerCancellation (0.33s)2777--- PASS: TestExternalSignerRestartsAfterCrash (0.48s)2778/private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestExternalSignerRestartsAfterCrash2197394787/001/sign program: line 7: /private/var/tb/8/scratch/651f346cfe2ac1bb/build/TestExternalSignerRestartsAfterCrash2197394787/001/sign program.starts: No such file or directory2779--- PASS: TestExternalSignerWrongPublicKey (0.69s)2780--- PASS: TestExternalSignerErrors (0.00s)2781 --- PASS: TestExternalSignerErrors/missing_signature_name (0.39s)2782 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.54s)2783 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.61s)2784 --- PASS: TestExternalSignerErrors/null (0.76s)2785 --- PASS: TestExternalSignerErrors/null_signatures (0.84s)2786 --- PASS: TestExternalSignerErrors/exit_on_request (0.91s)2787 --- PASS: TestExternalSignerErrors/wrong_shape (0.99s)2788 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.06s)2789 --- PASS: TestExternalSignerErrors/program_error (1.14s)2790 --- PASS: TestExternalSignerErrors/invalid_JSON (1.21s)2791 --- PASS: TestExternalSignerErrors/missing_signatures (1.29s)2792 --- PASS: TestExternalSignerErrors/wrong_id (1.37s)2793 --- PASS: TestExternalSignerErrors/unrequested_key (1.44s)2794 --- PASS: TestExternalSignerErrors/too_few_signatures (1.52s)2795 --- PASS: TestExternalSignerErrors/exit_at_startup (1.60s)2796 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.68s)2797PASS2798Running OpenBao signer tests...2799=== RUN TestSign2800=== PAUSE TestSign2801=== RUN TestSignErrors2802=== PAUSE TestSignErrors2803=== RUN TestServe2804=== PAUSE TestServe2805=== RUN TestServeRejectsGarbage2806=== PAUSE TestServeRejectsGarbage2807=== CONT TestSign2808=== CONT TestServe2809=== CONT TestSignErrors2810=== RUN TestSignErrors/invalid_base642811=== CONT TestServeRejectsGarbage2812=== PAUSE TestSignErrors/invalid_base642813=== RUN TestSignErrors/http_error2814=== PAUSE TestSignErrors/http_error2815--- PASS: TestServeRejectsGarbage (0.00s)2816=== RUN TestSignErrors/invalid_json2817=== PAUSE TestSignErrors/invalid_json2818=== RUN TestSignErrors/no_prefix2819=== PAUSE TestSignErrors/no_prefix2820=== CONT TestSignErrors/invalid_base642821=== CONT TestSignErrors/http_error2822=== CONT TestSignErrors/no_prefix2823=== CONT TestSignErrors/invalid_json2824--- PASS: TestServe (0.00s)2825--- PASS: TestSign (0.00s)2826--- PASS: TestSignErrors (0.00s)2827 --- PASS: TestSignErrors/no_prefix (0.00s)2828 --- PASS: TestSignErrors/invalid_base64 (0.00s)2829 --- PASS: TestSignErrors/http_error (0.00s)2830 --- PASS: TestSignErrors/invalid_json (0.00s)2831PASS