niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #424
· 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 TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestDumpPathWriterError118=== CONT TestResolveStorePath119=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer120=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess121=== CONT TestRateLimiterFeedback122=== CONT TestPathInfoCACompatibility123=== CONT TestParsePathInfoJSONMultiplePaths124=== CONT TestParsePathInfoJSON125=== CONT TestPathInfoHashCompatibility126=== CONT TestGetStorePathHash127=== CONT TestConvertHashToNix32128=== CONT TestEncodeNixBase32WithRealHash129=== CONT TestEncodeNixBase32130=== CONT TestScriptTokenNoExpiryRerunsEveryCall131=== CONT TestScriptTokenEmptyCommand132=== CONT TestScriptTokenScriptFails133=== CONT TestSetClientTLS134=== CONT TestScriptTokenBadJSON135=== CONT TestScriptTokenEmptyToken136=== CONT TestFileTokenEmpty137=== CONT TestFileTokenMissing138=== CONT TestScriptTokenCachesUntilRefresh139=== RUN TestEncodeNixBase32/test_string_hash140=== RUN TestPathInfoCACompatibility/null_ca_field141=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1422026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=server-test rate=5143=== PAUSE TestPathInfoCACompatibility/null_ca_field144=== RUN TestPathInfoCACompatibility/old_string_format_-_text145=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text146=== PAUSE TestEncodeNixBase32/test_string_hash147=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== CONT TestFileTokenReadsAndCaches149--- PASS: TestEncodeNixBase32WithRealHash (0.00s)150--- PASS: TestScriptTokenEmptyCommand (0.00s)151=== RUN TestParsePathInfoJSON/Nix_format152=== PAUSE TestParsePathInfoJSON/Nix_format153=== RUN TestParsePathInfoJSON/Lix_format154=== PAUSE TestParsePathInfoJSON/Lix_format155=== RUN TestParsePathInfoJSON/empty_input156=== PAUSE TestParsePathInfoJSON/empty_input157=== RUN TestParsePathInfoJSON/whitespace_only158=== PAUSE TestParsePathInfoJSON/whitespace_only159=== RUN TestParsePathInfoJSON/invalid_JSON160=== PAUSE TestParsePathInfoJSON/invalid_JSON161=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon165=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI166=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI167=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512168=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512169=== CONT TestSetClientTLSDoesNotMutateDefaultTransport170=== RUN TestGetStorePathHash/valid_store_path171=== PAUSE TestGetStorePathHash/valid_store_path172=== RUN TestGetStorePathHash/basename_without_hyphen_should_error173=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error174=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error175=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error176=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error177=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error178=== CONT TestStaticToken179--- PASS: TestStaticToken (0.00s)180=== CONT TestFilterOversizedClosures181=== RUN TestFilterOversizedClosures/no_limit_keeps_everything182=== RUN TestConvertHashToNix32/SRI_format_to_Nix32183=== CONT TestSetClientTLSErrors184=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive185=== RUN TestEncodeNixBase32/empty_input186=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths187=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32188=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun189=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything190--- PASS: TestResolveStorePath (0.00s)191=== CONT TestCaseHackSuffix192=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths193=== PAUSE TestEncodeNixBase32/empty_input194--- PASS: TestScriptTokenScriptFails (0.00s)195=== CONT TestDumpPathSingleFile196=== RUN TestRateLimiterFeedback/429_enables_limiter197=== PAUSE TestRateLimiterFeedback/429_enables_limiter198=== RUN TestRateLimiterFeedback/503_enables_limiter199=== PAUSE TestRateLimiterFeedback/503_enables_limiter200=== RUN TestConvertHashToNix32/already_Nix32_format201=== PAUSE TestConvertHashToNix32/already_Nix32_format202=== RUN TestConvertHashToNix32/invalid_format203=== PAUSE TestConvertHashToNix32/invalid_format204=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped205=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== RUN TestFilterOversizedClosures/all_closures_skipped207=== PAUSE TestFilterOversizedClosures/all_closures_skipped208=== CONT TestDumpPathMatchesNix209=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter210=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter211=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter212=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter213=== CONT TestPartSizeForNAR214=== RUN TestPartSizeForNAR/zero_stays_at_minimum215=== CONT TestRegisterUploadedObjectReusesConnections216=== RUN TestSetClientTLSErrors/missing_cert_file217=== PAUSE TestSetClientTLSErrors/missing_cert_file218=== CONT TestUploadMultipart_SupersededByPeer219=== RUN TestUploadMultipart_SupersededByPeer/exists220=== PAUSE TestUploadMultipart_SupersededByPeer/exists221--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)222--- PASS: TestFileTokenMissing (0.00s)223=== CONT TestUploadMultipart_FailedPartBufferNotReused224=== RUN TestUploadMultipart_SupersededByPeer/missing225=== CONT TestStreamPushIsolatesFailures226=== CONT TestSupersededNARStillUploadsListing227=== CONT TestUploadMultipart_PartsInParallel228=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum229=== RUN TestSetClientTLS/rejects_connection_without_client_cert230=== RUN TestPartSizeForNAR/small_stays_at_minimum231=== RUN TestSetClientTLSErrors/missing_key_file232=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive233=== CONT TestStreamPushStopsWhenCanceled234--- PASS: TestFileTokenReadsAndCaches (0.01s)235=== PAUSE TestUploadMultipart_SupersededByPeer/missing236--- PASS: TestDoServerRequestAttachesToken (0.01s)237=== RUN TestSupersededNARStillUploadsListing/small_NAR238=== RUN TestPathInfoCACompatibility/new_structured_format_-_text239=== PAUSE TestSetClientTLSErrors/missing_key_file240=== RUN TestSetClientTLSErrors/missing_ca_file2412026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=server-test rate=52422026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58554243=== PAUSE TestPartSizeForNAR/small_stays_at_minimum244=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert245--- PASS: TestFileTokenEmpty (0.01s)246--- PASS: TestScriptTokenEmptyToken (0.01s)247=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica248=== PAUSE TestSetClientTLSErrors/missing_ca_file249=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text250=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum251=== CONT TestClientSignaturesByStorePath252=== CONT TestStreamPushReportsSkippedPaths253=== PAUSE TestSupersededNARStillUploadsListing/small_NAR254=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum255--- PASS: TestClientSignaturesByStorePath (0.00s)256=== CONT TestShellSplitErrors257--- PASS: TestShellSplitErrors (0.00s)258=== CONT TestStreamPushReportsSignatures259=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA260=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA261--- PASS: TestStreamPushReportsSkippedPaths (0.00s)262=== RUN TestSetClientTLS/preserves_debug_logging_transport263=== PAUSE TestSetClientTLS/preserves_debug_logging_transport264=== CONT TestStreamPushRequestLine265=== CONT TestStreamPushBatchesUnderLoad266=== RUN TestSetClientTLSErrors/invalid_ca_file267=== PAUSE TestSetClientTLSErrors/invalid_ca_file268=== CONT TestStreamPushReportsEveryPath269=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method271--- PASS: TestStreamPushReportsEveryPath (0.00s)272=== CONT TestDoWithRetry_FinalResponseBodyReadable273=== RUN TestSupersededNARStillUploadsListing/dump_cut_short274=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short275=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails276=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails277=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry278--- PASS: TestScriptTokenBadJSON (0.02s)279=== CONT TestRetryTimeoutOutlastsMaxRetries280=== CONT TestShellSplit281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestPartSizeForNAR/5_TiB_S3_max_object286=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object287=== RUN TestPartSizeForNAR/capped_at_5_GiB288=== PAUSE TestPartSizeForNAR/capped_at_5_GiB289--- PASS: TestShellSplit (0.00s)290=== CONT TestStreamPushGivesUpOnDeadServer2912026/10/25 13:48:58 WARN Rate limiter backed off name=server-test rate=52922026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:585542932026/10/25 13:48:58 ERROR Upload failed error="connection refused" count=202942026/10/25 13:48:58 ERROR Server seems unavailable, giving up on batch untried=172952026/10/25 13:48:58 ERROR Upload failed error=boom count=12962026/10/25 13:48:58 ERROR Upload failed error=boom count=12972026/10/25 13:48:58 INFO Garbage collection started2982026/10/25 13:48:58 INFO Garbage collection started299=== CONT TestParsePathInfoJSON/Nix_format300--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)301--- PASS: TestStreamPushReportsSignatures (0.00s)302=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)303=== CONT TestParsePathInfoJSON/invalid_JSON304=== CONT TestParsePathInfoJSON/Lix_format305=== CONT TestParsePathInfoJSON/whitespace_only306=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512307=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon308=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI309--- PASS: TestPathInfoHashCompatibility (0.00s)310 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)311 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)312 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)313 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)314=== CONT TestParsePathInfoJSON/empty_input315--- PASS: TestParsePathInfoJSON (0.00s)316 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)317 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)318 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)319 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)320 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)321=== CONT TestGetStorePathHash/valid_store_path322=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error323=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths324=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error325=== CONT TestEncodeNixBase32/test_string_hash326=== CONT TestGetStorePathHash/basename_without_hyphen_should_error327--- PASS: TestGetStorePathHash (0.00s)328 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)329 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)330 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)331 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)332=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths333--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)335 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)336=== CONT TestEncodeNixBase32/empty_input337--- PASS: TestEncodeNixBase32 (0.00s)338 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)339 --- PASS: TestEncodeNixBase32/empty_input (0.00s)340=== CONT TestConvertHashToNix32/SRI_format_to_Nix32341=== CONT TestConvertHashToNix32/invalid_format342=== CONT TestRateLimiterFeedback/429_enables_limiter343=== CONT TestConvertHashToNix32/already_Nix32_format344--- PASS: TestConvertHashToNix32 (0.00s)345 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)346 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)347 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)348=== CONT TestFilterOversizedClosures/no_limit_keeps_everything349=== CONT TestRateLimiterFeedback/503_enables_limiter350=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter351--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)352=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3532026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=server-test rate=53542026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:586343552026/10/25 13:48:58 ERROR Upload failed error="bad path" count=3356--- PASS: TestStreamPushIsolatesFailures (0.01s)357=== CONT TestFilterOversizedClosures/all_closures_skipped3582026/10/25 13:48:58 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=50359=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3602026/10/25 13:48:58 WARN Rate limiter backed off name=server-test rate=53612026/10/25 13:48:58 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=2000362--- PASS: TestFilterOversizedClosures (0.00s)363 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)364 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)365 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)366=== CONT TestUploadMultipart_SupersededByPeer/missing367--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)368=== CONT TestUploadMultipart_SupersededByPeer/exists369--- PASS: TestStreamPushStopsWhenCanceled (0.01s)370=== CONT TestSetClientTLS/rejects_connection_without_client_cert3712026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:58636372--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)373=== CONT TestSetClientTLS/preserves_debug_logging_transport3742026/10/25 13:48:58 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=03752026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=s3-test rate=53762026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:586413772026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=server-test rate=53782026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:586443792026/10/25 13:48:58 WARN Rate limiter backed off name=server-test rate=5380=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3812026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=server-test rate=53822026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58640383=== CONT TestSetClientTLSErrors/missing_cert_file384=== CONT TestSetClientTLSErrors/invalid_ca_file3852026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:58636386=== CONT TestSetClientTLSErrors/missing_key_file387=== CONT TestSetClientTLSErrors/missing_ca_file388=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method389=== CONT TestPathInfoCACompatibility/new_structured_format_-_text3902026/10/25 13:48:58 WARN Rate limiter backed off name=server-test rate=53912026/10/25 13:48:58 WARN Garbage collection finished on another replica. Its statistics are not available here3922026/10/25 13:48:58 WARN Rate limiter enabled after throttle name=s3-test rate=5393=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive394=== CONT TestPartSizeForNAR/1_TiB395=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts396=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum397=== CONT TestPartSizeForNAR/small_stays_at_minimum398=== CONT TestPathInfoCACompatibility/null_ca_field399--- PASS: TestRateLimiterFeedback (0.00s)400 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)401 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)402 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)403 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)404--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)405--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)406=== CONT TestSupersededNARStillUploadsListing/small_NAR407--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)408 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)409 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)410--- PASS: TestSetClientTLSErrors (0.02s)411 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)412 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)413 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)414 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)415=== CONT TestPathInfoCACompatibility/old_string_format_-_text416=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails417=== CONT TestSupersededNARStillUploadsListing/dump_cut_short418=== CONT TestPartSizeForNAR/zero_stays_at_minimum419=== CONT TestPartSizeForNAR/capped_at_5_GiB420=== CONT TestPartSizeForNAR/5_TiB_S3_max_object421--- PASS: TestStreamPushRequestLine (0.02s)422--- PASS: TestPartSizeForNAR (0.01s)423 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)424 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)425 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)426 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)427 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)428 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)429 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)430--- PASS: TestPathInfoCACompatibility (0.02s)431 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)432 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)433 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)434 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)435 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)4362026/10/25 13:48:58 INFO Uploading abc-hello (1.0GB)4372026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:586364382026/10/25 13:48:58 INFO Uploading abc-hello (1.0GB)4392026/10/25 13:48:58 http: TLS handshake error from 127.0.0.1:58638: read tcp 127.0.0.1:58564->127.0.0.1:58638: use of closed network connection440--- PASS: TestSetClientTLS (0.02s)441 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)442 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)443 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4442026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:586364452026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:586364462026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:586364472026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:586364482026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:58636449--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4502026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:586364512026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:58636452--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)4532026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:586364542026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:586364552026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:586364562026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:586364572026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:586364582026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:586364592026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:58636460--- PASS: TestDumpPathSingleFile (0.06s)4612026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:586364622026/10/25 13:48:58 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:58636463--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)464--- PASS: TestCaseHackSuffix (0.07s)465--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.05s)466--- PASS: TestDumpPathWriterError (0.07s)4672026/10/25 13:48:58 INFO Uploading abc-hello (1.0GB)4682026/10/25 13:48:58 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:58664/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:58664/part/24692026/10/25 13:48:58 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"470--- PASS: TestDumpPathMatchesNix (0.10s)471--- PASS: TestStreamPushBatchesUnderLoad (0.10s)472--- PASS: TestSupersededNARStillUploadsListing (0.01s)473 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.00s)474 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)475 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.55s)476--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.58s)477--- PASS: TestUploadMultipart_PartsInParallel (0.63s)4782026/10/25 13:48:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58553/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58553/api/uploads/complete4792026/10/25 13:48:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4802026/10/25 13:48:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58553/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58553/api/uploads/complete481--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4822026/10/25 13:48:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4832026/10/25 13:48:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58553/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58553/api/uploads/complete4842026/10/25 13:48:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)486PASS487Running server tests...488The files belonging to this database system will be owned by user "_tribuchetbld3".489This user must also own the server process.490491The database cluster will be initialized with locale "C".492The default database encoding has accordingly been set to "SQL_ASCII".493The default text search configuration will be set to "english".494495Data page checksums are enabled.496497creating directory /private/var/tb/3/scratch/8dda0facea84ca9b/build/postgres3784301618/data ... ok498creating subdirectories ... ok499selecting dynamic shared memory implementation ... posix500selecting default "max_connections" ... 100501selecting default "shared_buffers" ... 128MB502selecting default time zone ... UTC503creating configuration files ... ok504running bootstrap script ... ok505performing post-bootstrap initialization ... ok506syncing data to disk ... ok507508initdb: warning: enabling "trust" authentication for local connections509initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.510511Success. You can now start the database server using:512513 pg_ctl -D /private/var/tb/3/scratch/8dda0facea84ca9b/build/postgres3784301618/data -l logfile start514515/private/var/tb/3/scratch/8dda0facea84ca9b/build/postgres3784301618:5432 - no response5162026-10-25 13:49:00.279 UTC [40838] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5172026-10-25 13:49:00.279 UTC [40838] LOG: listening on Unix socket "/private/var/tb/3/scratch/8dda0facea84ca9b/build/postgres3784301618/.s.PGSQL.5432"5182026-10-25 13:49:00.281 UTC [40845] LOG: database system was shut down at 2026-10-25 13:49:00 UTC5192026-10-25 13:49:00.282 UTC [40838] LOG: database system is ready to accept connections520/private/var/tb/3/scratch/8dda0facea84ca9b/build/postgres3784301618:5432 - accepting connections521{"timestamp":"2026-10-25T13:49:00.498833Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2fed10f0-b5a3-47e1-8af3-15a4b2a4464d","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}522=== RUN TestService_AuthMiddleware523=== PAUSE TestService_AuthMiddleware524=== RUN TestService_AuthMiddleware_MTLSProxyHeader525=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader526=== RUN TestService_AuthMiddleware_MTLSBoundSubjects527=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects528=== RUN TestService_ReadAuthMiddleware529=== PAUSE TestService_ReadAuthMiddleware530=== RUN TestService_AuthMiddleware_OIDC531=== PAUSE TestService_AuthMiddleware_OIDC532=== RUN TestService_RequireScope_OIDC533=== PAUSE TestService_RequireScope_OIDC534=== RUN TestService_ReadScope_PublicByDefault535=== PAUSE TestService_ReadScope_PublicByDefault536=== RUN TestCacheConfigHandler537=== PAUSE TestCacheConfigHandler538=== RUN TestCacheStatsHandler539=== PAUSE TestCacheStatsHandler540=== RUN TestClientCADerivations541=== PAUSE TestClientCADerivations542=== RUN TestClientErrorHandling543=== PAUSE TestClientErrorHandling544=== RUN TestClientIntegration545=== PAUSE TestClientIntegration546=== RUN TestClientMultipleUploads547=== PAUSE TestClientMultipleUploads548=== RUN TestClientWithDependencies549=== PAUSE TestClientWithDependencies550=== RUN TestClientSharedPathCommittedMidPush551=== PAUSE TestClientSharedPathCommittedMidPush552=== RUN TestPinProtectsFromGC553=== PAUSE TestPinProtectsFromGC554=== RUN TestClientPushesUseOnePush555=== PAUSE TestClientPushesUseOnePush556=== RUN TestClientFallsBackToClosures557=== PAUSE TestClientFallsBackToClosures558=== RUN TestDeleteClosuresRacingPins559=== PAUSE TestDeleteClosuresRacingPins560=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock562=== RUN TestResolveDBConnectionString563=== PAUSE TestResolveDBConnectionString564=== RUN TestConnectWaitsForAPeerMigration565=== PAUSE TestConnectWaitsForAPeerMigration566=== RUN TestLeadElectsOneAndHandsOver567=== PAUSE TestLeadElectsOneAndHandsOver568=== RUN TestLeadIncumbentWinsAfterRestart5692026/10/25 13:49:00 INFO lead: acquired remote=192.0.2.1:12345702026/10/25 13:49:01 INFO lead: released remote=192.0.2.1:12345712026/10/25 13:49:01 INFO lead: acquired remote=192.0.2.1:12345722026/10/25 13:49:02 INFO lead: released remote=192.0.2.1:1234573--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)574=== RUN TestLeadIncumbentAnnouncesAtOnce575=== PAUSE TestLeadIncumbentAnnouncesAtOnce576=== RUN TestLeadEndsOnShutdown577=== PAUSE TestLeadEndsOnShutdown578=== RUN TestLeadEndsWhenItsConnectionHangs5792026/10/25 13:49:02 INFO lead: acquired remote=192.0.2.1:12345802026-10-25 13:49:03.898 UTC [40880] FATAL: terminating connection due to administrator command5812026/10/25 13:49:04 INFO lead: acquired remote=192.0.2.1:12345822026/10/25 13:49:05 WARN lead: lock connection lost error="timeout: context deadline exceeded"5832026/10/25 13:49:05 INFO lead: released remote=192.0.2.1:12345842026/10/25 13:49:05 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)586=== RUN TestGCAdvisoryLockBlocksConcurrentRun587=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun588=== RUN TestGCBugBareHashReferences589=== PAUSE TestGCBugBareHashReferences590=== RUN TestGCMetrics591=== PAUSE TestGCMetrics592=== RUN TestPushDedupSurvivesConcurrentGC593=== PAUSE TestPushDedupSurvivesConcurrentGC594=== RUN TestDeduplicatedObjectsRecordedAsPending595=== PAUSE TestDeduplicatedObjectsRecordedAsPending596=== RUN TestGCSweepSkipsPendingObjects597=== PAUSE TestGCSweepSkipsPendingObjects598=== RUN TestTombstonedObjectOfferedWithoutWaiting599=== PAUSE TestTombstonedObjectOfferedWithoutWaiting600=== RUN TestGCSweepDeliversEachKeyOnce601=== PAUSE TestGCSweepDeliversEachKeyOnce602=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection604=== RUN TestForceGCDuringPushOffersSweptObject605=== PAUSE TestForceGCDuringPushOffersSweptObject606=== RUN TestFailedS3DeleteKeepsTombstone607=== PAUSE TestFailedS3DeleteKeepsTombstone608=== RUN TestSweepSkipsRowsLockedByPush609=== PAUSE TestSweepSkipsRowsLockedByPush610=== RUN TestRegisterCompletedObjectNeedsPendingRow611=== PAUSE TestRegisterCompletedObjectNeedsPendingRow612=== RUN TestGetExistingObjectsLocksRows613=== PAUSE TestGetExistingObjectsLocksRows614=== RUN TestSweepRechecksPendingAfterLocking615=== PAUSE TestSweepRechecksPendingAfterLocking616=== RUN TestPushWaitsForSweepHoldingRow617=== PAUSE TestPushWaitsForSweepHoldingRow618=== RUN TestCommitRacingPendingCleanupKeepsObjects619=== PAUSE TestCommitRacingPendingCleanupKeepsObjects620=== RUN TestGCEndsOnShutdown621=== PAUSE TestGCEndsOnShutdown622=== RUN TestGCTaskStore_StartNew623=== PAUSE TestGCTaskStore_StartNew624=== RUN TestGCTaskStore_DeduplicateSameParams625=== PAUSE TestGCTaskStore_DeduplicateSameParams626=== RUN TestGCTaskStore_ConflictDifferentParams627=== PAUSE TestGCTaskStore_ConflictDifferentParams628=== RUN TestGCTaskStore_GetEmpty629=== PAUSE TestGCTaskStore_GetEmpty630=== RUN TestGCTaskStore_GetReturnsLatest631=== PAUSE TestGCTaskStore_GetReturnsLatest632=== RUN TestGCTaskStore_CompletedAllowsNewTask633=== PAUSE TestGCTaskStore_CompletedAllowsNewTask634=== RUN TestGCTaskStore_PhaseUpdates635=== PAUSE TestGCTaskStore_PhaseUpdates636=== RUN TestGCTaskStore_Fail637=== PAUSE TestGCTaskStore_Fail638=== RUN TestGracefulShutdownDrainsInflight639=== PAUSE TestGracefulShutdownDrainsInflight640=== RUN TestService_healthCheckHandler641=== PAUSE TestService_healthCheckHandler642=== RUN TestService_readinessHandler643=== PAUSE TestService_readinessHandler644=== RUN TestGenerateLandingPage645=== PAUSE TestGenerateLandingPage646=== RUN TestCacheConfigHandlerMaxNarSize647=== PAUSE TestCacheConfigHandlerMaxNarSize648=== RUN TestCreatePendingClosureRejectsOversizedNAR649=== PAUSE TestCreatePendingClosureRejectsOversizedNAR650=== RUN TestNARDeduplicationMetadataUploadBug651=== PAUSE TestNARDeduplicationMetadataUploadBug652=== RUN TestMetricsInventory653=== PAUSE TestMetricsInventory654=== RUN TestMetricsCommit655=== PAUSE TestMetricsCommit656=== RUN TestService_NativeMTLS657=== PAUSE TestService_NativeMTLS658=== RUN TestServerTLSConfig659=== PAUSE TestServerTLSConfig660=== RUN TestMultipartCleanup661=== PAUSE TestMultipartCleanup662=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded664=== RUN TestPendingCleanupUsesOneCutoff665=== PAUSE TestPendingCleanupUsesOneCutoff666=== RUN TestObjectStatsTrigger667=== PAUSE TestObjectStatsTrigger668=== RUN TestObjectStatsUpdatedOncePerCommit669=== PAUSE TestObjectStatsUpdatedOncePerCommit670=== RUN TestOrphanedObjectsGC671=== PAUSE TestOrphanedObjectsGC672=== RUN TestOrphanedObjectsGCStressTest673=== PAUSE TestOrphanedObjectsGCStressTest674=== RUN TestCreatePin_ReservedPins675=== PAUSE TestCreatePin_ReservedPins676=== RUN TestPresentReportsOnlyClosureRoots677=== PAUSE TestPresentReportsOnlyClosureRoots678=== RUN TestPresentRefreshesOnlyStaleClosures679=== PAUSE TestPresentRefreshesOnlyStaleClosures680=== RUN TestPresentNotReportedWhileGCDeletesClosure681=== PAUSE TestPresentNotReportedWhileGCDeletesClosure682=== RUN TestParseSingleRange683=== PAUSE TestParseSingleRange684=== RUN TestProxyHeadersOnlyTrustedOnSocket6852026/10/25 13:49:05 INFO Starting HTTP server address=proxy.sock6862026/10/25 13:49:05 INFO Starting HTTP server address=127.0.0.1:586956872026/10/25 13:49:05 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6882026/10/25 13:49:05 INFO Shutdown signal received, draining in-flight requests timeout=10s689--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.18s)690=== RUN TestIsValidCachePath691=== PAUSE TestIsValidCachePath692=== RUN TestReadProxyNarinfo693=== PAUSE TestReadProxyNarinfo694=== RUN TestReadProxyNarinfoAlreadyDecompressed695=== PAUSE TestReadProxyNarinfoAlreadyDecompressed696=== RUN TestReadProxyContentNegotiation697=== PAUSE TestReadProxyContentNegotiation698=== RUN TestReadProxyNarStreaming699=== PAUSE TestReadProxyNarStreaming700=== RUN TestReadProxy404701=== PAUSE TestReadProxy404702=== RUN TestReadProxyInvalidPath703=== PAUSE TestReadProxyInvalidPath704=== RUN TestReadProxyHead705=== PAUSE TestReadProxyHead706=== RUN TestReadProxyOutlastsServerWriteTimeout707=== PAUSE TestReadProxyOutlastsServerWriteTimeout708=== RUN TestReadProxyConditionalGet709=== PAUSE TestReadProxyConditionalGet710=== RUN TestReadProxyRootRedirectsToIndexHTML711=== PAUSE TestReadProxyRootRedirectsToIndexHTML712=== RUN TestReadProxyDisabled713=== PAUSE TestReadProxyDisabled714=== RUN TestReadRedirectNar715=== PAUSE TestReadRedirectNar716=== RUN TestReadRedirectKeepsNarinfoProxied717=== PAUSE TestReadRedirectKeepsNarinfoProxied718=== RUN TestReadProxyRangeRequest719=== PAUSE TestReadProxyRangeRequest720=== RUN TestReadRedirectUsesPublicS3URL721=== PAUSE TestReadRedirectUsesPublicS3URL722=== RUN TestPush_OverlappingRootsStoreOneRowPerKey723=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey724=== RUN TestPush_CompleteCommitsEveryRoot725=== PAUSE TestPush_CompleteCommitsEveryRoot726=== RUN TestPush_RepeatedRootCommitsOnce727=== PAUSE TestPush_RepeatedRootCommitsOnce728=== RUN TestPush_CompleteWaitsForCleanupOfThePush729=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush730=== RUN TestPush_RootsAreLockedInByteOrder731=== PAUSE TestPush_RootsAreLockedInByteOrder732=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit733=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit734=== RUN TestPush_RejectsBadRequests735=== PAUSE TestPush_RejectsBadRequests736=== RUN TestPush_SignsNarinfosOfItsPendingObjects737=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects738=== RUN TestRedundantMultipartUpload739=== PAUSE TestRedundantMultipartUpload740=== RUN TestCompleteMultipartUpload_ErrorButObjectExists741=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists742=== RUN TestCompletedNarNotReofferedAcrossClosures743=== PAUSE TestCompletedNarNotReofferedAcrossClosures744=== RUN TestPresignedUploadRegisteredBeforeCommit745=== PAUSE TestPresignedUploadRegisteredBeforeCommit746=== RUN TestService_Rustfstest747=== PAUSE TestService_Rustfstest748=== RUN TestParseSize749=== PAUSE TestParseSize750=== RUN TestSkippedUploadsHandler751=== PAUSE TestSkippedUploadsHandler752=== RUN TestSystemdListenerNotActivated753--- PASS: TestSystemdListenerNotActivated (0.00s)754=== RUN TestWatchdogBeatsWhenHealthy755--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)756=== RUN TestWatchdogSkipsWhenUnhealthy7572026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 13:49:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"767--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)768=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle770=== RUN TestProxyWriteTimeout771=== PAUSE TestProxyWriteTimeout772=== RUN TestPendingClosureWriteTimeout773=== PAUSE TestPendingClosureWriteTimeout774=== RUN TestIsValidUploadKey775=== PAUSE TestIsValidUploadKey776=== RUN TestUploadHandlersRejectInvalidKeys777=== PAUSE TestUploadHandlersRejectInvalidKeys778=== RUN TestUploadHandlersRejectOversizedBody779=== PAUSE TestUploadHandlersRejectOversizedBody780=== RUN TestService_cleanupPendingClosuresHandler781=== PAUSE TestService_cleanupPendingClosuresHandler782=== RUN TestService_createPendingClosureHandler783=== PAUSE TestService_createPendingClosureHandler784=== RUN TestService_verifyS3Integrity785=== PAUSE TestService_verifyS3Integrity786=== RUN TestCompleteMultipartUnregistered787=== PAUSE TestCompleteMultipartUnregistered788=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT789=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT790=== CONT TestReadProxyHead791=== CONT TestService_AuthMiddleware792=== CONT TestReadProxyInvalidPath793=== CONT TestReadProxy404794=== CONT TestReadProxyNarStreaming795=== CONT TestReadProxyContentNegotiation796=== CONT TestReadProxyNarinfoAlreadyDecompressed797=== CONT TestCompleteMultipartUpload_ErrorButObjectExists798=== CONT TestReadProxyNarinfo799=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestIsValidCachePath801=== CONT TestCompleteMultipartUnregistered802=== CONT TestParseSingleRange803=== CONT TestService_verifyS3Integrity804=== CONT TestService_createPendingClosureHandler805=== CONT TestPresentNotReportedWhileGCDeletesClosure806=== CONT TestService_cleanupPendingClosuresHandler807=== CONT TestUploadHandlersRejectOversizedBody808=== CONT TestPresentRefreshesOnlyStaleClosures809=== CONT TestUploadHandlersRejectInvalidKeys810=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info811=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info812=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal813=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal814=== CONT TestIsValidUploadKey815=== CONT TestParseSize816=== CONT TestPresentReportsOnlyClosureRoots817=== CONT TestService_Rustfstest818=== RUN TestIsValidUploadKey/narinfo819--- PASS: TestParseSize (0.00s)820=== CONT TestCreatePin_ReservedPins821=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key822=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key823=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key824=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key825=== RUN TestParseSingleRange/none826=== PAUSE TestParseSingleRange/none827=== RUN TestParseSingleRange/unknown_unit828=== PAUSE TestParseSingleRange/unknown_unit829=== RUN TestIsValidCachePath/narinfo830=== RUN TestParseSingleRange/multi-range_ignored831=== PAUSE TestIsValidCachePath/narinfo832=== CONT TestPresignedUploadRegisteredBeforeCommit833=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh834=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh835=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale836=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale837=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars838=== PAUSE TestIsValidUploadKey/narinfo839=== CONT TestOrphanedObjectsGCStressTest840=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars841=== RUN TestIsValidCachePath/nar_zst842=== RUN TestIsValidUploadKey/nar_zst843=== PAUSE TestParseSingleRange/multi-range_ignored844=== RUN TestParseSingleRange/malformed_no_dash845=== PAUSE TestIsValidCachePath/nar_zst846=== PAUSE TestParseSingleRange/malformed_no_dash847=== PAUSE TestIsValidUploadKey/nar_zst848=== RUN TestParseSingleRange/malformed_both_empty849=== RUN TestIsValidCachePath/nar_xz850=== PAUSE TestIsValidCachePath/nar_xz851=== RUN TestIsValidCachePath/nar_bz2852=== PAUSE TestIsValidCachePath/nar_bz2853=== RUN TestIsValidCachePath/nar_uncompressed854=== PAUSE TestIsValidCachePath/nar_uncompressed855=== RUN TestIsValidCachePath/ls856=== RUN TestIsValidUploadKey/nar_xz857=== PAUSE TestParseSingleRange/malformed_both_empty858=== RUN TestParseSingleRange/malformed_end_before_start859=== PAUSE TestIsValidCachePath/ls860=== PAUSE TestIsValidUploadKey/nar_xz861=== RUN TestIsValidCachePath/log862=== PAUSE TestIsValidCachePath/log863=== RUN TestIsValidCachePath/realisation864=== RUN TestIsValidUploadKey/nar_plain865=== PAUSE TestParseSingleRange/malformed_end_before_start866=== RUN TestParseSingleRange/closed867=== PAUSE TestParseSingleRange/closed868=== RUN TestParseSingleRange/open-ended869=== PAUSE TestIsValidUploadKey/nar_plain870=== RUN TestIsValidUploadKey/listing871=== PAUSE TestIsValidUploadKey/listing872=== RUN TestIsValidUploadKey/build_log873=== PAUSE TestIsValidUploadKey/build_log874=== RUN TestIsValidUploadKey/build_log_home-manager_file875=== PAUSE TestIsValidUploadKey/build_log_home-manager_file876=== RUN TestIsValidUploadKey/build_log_plus_in_name877=== PAUSE TestIsValidUploadKey/build_log_plus_in_name878=== RUN TestIsValidUploadKey/build_log_question_mark879=== PAUSE TestIsValidUploadKey/build_log_question_mark880=== RUN TestIsValidUploadKey/build_log_equals881=== PAUSE TestIsValidUploadKey/build_log_equals882=== RUN TestIsValidUploadKey/realisation883=== PAUSE TestIsValidUploadKey/realisation884=== RUN TestIsValidUploadKey/realisation_plus_in_output885=== PAUSE TestIsValidUploadKey/realisation_plus_in_output886=== RUN TestIsValidUploadKey/nix-cache-info887=== PAUSE TestIsValidUploadKey/nix-cache-info888=== RUN TestIsValidUploadKey/index.html889=== PAUSE TestIsValidUploadKey/index.html890=== RUN TestIsValidUploadKey/narinfo_key,_nar_type891=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type892=== RUN TestIsValidUploadKey/nar_key,_narinfo_type893=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type894=== RUN TestIsValidUploadKey/listing_key,_narinfo_type895=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type896=== RUN TestIsValidUploadKey/traversal897=== PAUSE TestIsValidUploadKey/traversal898=== RUN TestIsValidUploadKey/traversal_nar899=== PAUSE TestIsValidUploadKey/traversal_nar900=== RUN TestIsValidUploadKey/absolute901=== PAUSE TestIsValidUploadKey/absolute902=== RUN TestIsValidUploadKey/empty_key903=== PAUSE TestIsValidUploadKey/empty_key904=== RUN TestIsValidUploadKey/unknown_type905=== PAUSE TestIsValidUploadKey/unknown_type906=== PAUSE TestParseSingleRange/open-ended907=== RUN TestParseSingleRange/end_clamped_to_size908=== PAUSE TestParseSingleRange/end_clamped_to_size909=== RUN TestParseSingleRange/suffix910=== PAUSE TestParseSingleRange/suffix911=== RUN TestParseSingleRange/suffix_exceeds_size912=== PAUSE TestParseSingleRange/suffix_exceeds_size913=== RUN TestParseSingleRange/single_byte914=== PAUSE TestParseSingleRange/single_byte915=== RUN TestParseSingleRange/start_past_EOF916=== PAUSE TestParseSingleRange/start_past_EOF917=== RUN TestParseSingleRange/start_far_past_EOF918=== PAUSE TestParseSingleRange/start_far_past_EOF919=== CONT TestCompletedNarNotReofferedAcrossClosures920=== PAUSE TestIsValidCachePath/realisation921=== RUN TestIsValidCachePath/nix-cache-info922=== PAUSE TestIsValidCachePath/nix-cache-info923=== RUN TestIsValidCachePath/index.html924=== PAUSE TestIsValidCachePath/index.html925=== RUN TestIsValidCachePath/traversal_parent926=== PAUSE TestIsValidCachePath/traversal_parent927=== RUN TestIsValidCachePath/traversal_in_middle928=== PAUSE TestIsValidCachePath/traversal_in_middle929=== RUN TestIsValidCachePath/invalid_char_e930=== PAUSE TestIsValidCachePath/invalid_char_e931=== RUN TestIsValidCachePath/invalid_char_u932=== PAUSE TestIsValidCachePath/invalid_char_u933=== RUN TestIsValidCachePath/random_path934=== PAUSE TestIsValidCachePath/random_path935=== RUN TestIsValidCachePath/empty936=== PAUSE TestIsValidCachePath/empty937=== RUN TestIsValidCachePath/leading_slash938=== PAUSE TestIsValidCachePath/leading_slash939=== RUN TestIsValidCachePath/wrong_extension940=== PAUSE TestIsValidCachePath/wrong_extension941=== RUN TestIsValidCachePath/short_hash942=== PAUSE TestIsValidCachePath/short_hash943=== CONT TestOrphanedObjectsGC944=== CONT TestObjectStatsUpdatedOncePerCommit945=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure946=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure947=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart948=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart949=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts950=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts951=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9522026/10/25 13:49:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58697/oidc9532026/10/25 13:49:06 INFO Received uploads request method=POST path=/api/pending_closures9542026/10/25 13:49:06 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"955--- PASS: TestService_AuthMiddleware (1.02s)956=== CONT TestRedundantMultipartUpload9572026/10/25 13:49:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9582026/10/25 13:49:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst959--- PASS: TestCompleteMultipartUnregistered (1.40s)960=== CONT TestPush_SignsNarinfosOfItsPendingObjects9612026/10/25 13:49:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9622026/10/25 13:49:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LjY1ODUyYTBjLWM0NzQtNDMxMC05NjYyLTBmOTMxYjgxY2NjN3gxNzkyOTM2MTQ2Mzc5MTk3MDAw parts=109632026/10/25 13:49:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9642026/10/25 13:49:08 INFO Completed upload id=1 objects=2 duration=26.07975ms9652026/10/25 13:49:08 INFO Received uploads request method=POST path=/api/pending_closures9662026/10/25 13:49:08 INFO Received uploads request method=POST path=/api/pending_closures9672026/10/25 13:49:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9682026/10/25 13:49:08 WARN Found objects in DB but missing from S3, will re-upload count=1969--- PASS: TestService_verifyS3Integrity (2.42s)970=== CONT TestPush_RejectsBadRequests971--- PASS: TestReadProxy404 (2.45s)972=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit973--- PASS: TestReadProxyInvalidPath (2.58s)974=== CONT TestSkippedUploadsHandler9752026/10/25 13:49:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000976--- PASS: TestSkippedUploadsHandler (0.00s)977=== CONT TestPush_RootsAreLockedInByteOrder978--- PASS: TestReadProxyNarStreaming (2.85s)979=== CONT TestPendingClosureWriteTimeout980=== RUN TestPendingClosureWriteTimeout/empty981=== PAUSE TestPendingClosureWriteTimeout/empty982=== RUN TestPendingClosureWriteTimeout/400_objects983=== PAUSE TestPendingClosureWriteTimeout/400_objects984=== RUN TestPendingClosureWriteTimeout/670k_objects985=== PAUSE TestPendingClosureWriteTimeout/670k_objects986=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline987=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline988=== CONT TestPush_CompleteWaitsForCleanupOfThePush989--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.08s)990=== CONT TestProxyWriteTimeout991=== RUN TestProxyWriteTimeout/narinfo992=== PAUSE TestProxyWriteTimeout/narinfo993=== RUN TestProxyWriteTimeout/1_GiB_nar994=== PAUSE TestProxyWriteTimeout/1_GiB_nar995=== RUN TestProxyWriteTimeout/10_GiB_nar996=== PAUSE TestProxyWriteTimeout/10_GiB_nar997=== RUN TestProxyWriteTimeout/unknown_size998=== PAUSE TestProxyWriteTimeout/unknown_size999=== CONT TestPush_RepeatedRootCommitsOnce10002026/10/25 13:49:08 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/25 13:49:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10022026/10/25 13:49:09 INFO Received uploads request method=POST path=/api/pending_closures1003--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.40s)1004=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1005--- PASS: TestReadProxyHead (3.57s)1006=== CONT TestPush_CompleteCommitsEveryRoot1007--- PASS: TestPresentReportsOnlyClosureRoots (3.85s)1008=== CONT TestReadRedirectNar10092026/10/25 13:49:09 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1010--- PASS: TestReadProxyNarinfo (4.11s)1011=== CONT TestReadRedirectUsesPublicS3URL10122026/10/25 13:49:09 INFO Received uploads request method=POST path=/api/pending_closures10132026/10/25 13:49:09 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/25 13:49:09 INFO Received uploads request method=POST path=/api/pending_closures1015--- PASS: TestReadProxyContentNegotiation (4.62s)1016=== CONT TestReadProxyRangeRequest10172026/10/25 13:49:10 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/25 13:49:10 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/25 13:49:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10202026/10/25 13:49:10 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LmYxNWJlYjc0LWNmODgtNGRlMi1iZWJkLTU1OTFiMmJkNmRmM3gxNzkyOTM2MTUwNDk3MDA3MDAw1021--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (5.12s)1022=== CONT TestReadRedirectKeepsNarinfoProxied10232026/10/25 13:49:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LmYxNWJlYjc0LWNmODgtNGRlMi1iZWJkLTU1OTFiMmJkNmRmM3gxNzkyOTM2MTUwNDk3MDA3MDAw parts=11024--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.14s)1025=== CONT TestReadProxyRootRedirectsToIndexHTML10262026/10/25 13:49:11 INFO Received push request method=POST path=/api/pushes1027--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.40s)1028=== CONT TestReadProxyDisabled10292026/10/25 13:49:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1030--- PASS: TestPresentRefreshesOnlyStaleClosures (5.74s)1031=== CONT TestObjectStatsTrigger10322026/10/25 13:49:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LjQwNThkZDYwLWM2ZDMtNDg2Ni1hZDg3LWE1MzE3ZmZkN2Q5NngxNzkyOTM2MTUwMDAwMDMwMDAw parts=1010332026/10/25 13:49:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026/10/25 13:49:11 INFO Completed upload id=1 objects=2 duration=7.616792ms10352026/10/25 13:49:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010362026/10/25 13:49:11 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/25 13:49:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures10382026/10/25 13:49:11 INFO Aborted multipart uploads count=0 kept=010392026/10/25 13:49:11 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=010402026/10/25 13:49:11 INFO Vacuumed table table=pending_closures10412026/10/25 13:49:11 INFO Vacuumed table table=pending_objects10422026/10/25 13:49:11 INFO Vacuumed table table=multipart_uploads10432026/10/25 13:49:11 INFO Vacuumed table table=closures10442026/10/25 13:49:11 INFO Vacuumed table table=objects10452026/10/25 13:49:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001046--- PASS: TestService_createPendingClosureHandler (5.95s)1047=== CONT TestGCSweepDeliversEachKeyOnce1048--- PASS: TestObjectStatsUpdatedOncePerCommit (6.04s)1049=== CONT TestTombstonedObjectOfferedWithoutWaiting1050--- PASS: TestService_Rustfstest (6.13s)1051=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10522026/10/25 13:49:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10532026/10/25 13:49:12 INFO Aborted multipart uploads count=0 kept=010542026/10/25 13:49:12 INFO Received uploads request method=POST path=/api/pending_closures10552026/10/25 13:49:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10562026/10/25 13:49:12 INFO Aborted multipart uploads count=1 kept=010572026/10/25 13:49:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10582026-10-25 13:49:12.624 UTC [40966] ERROR: Closure does not exist: id=110592026-10-25 13:49:12.624 UTC [40966] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10602026-10-25 13:49:12.624 UTC [40966] STATEMENT: -- name: CommitPendingClosure :one1061 SELECT commit_pending_closure($1::bigint)::bigint1062 1063--- PASS: TestService_cleanupPendingClosuresHandler (6.91s)1064=== CONT TestNARDeduplicationMetadataUploadBug10652026/10/25 13:49:13 INFO Received uploads request method=POST path=/api/pending_closures10662026/10/25 13:49:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10672026/10/25 13:49:13 WARN Refused reserved pin name=worker-x86_64-linux10682026/10/25 13:49:13 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10692026/10/25 13:49:13 INFO Received create pin request method=POST path=/api/pins/my-app10702026/10/25 13:49:14 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1071--- PASS: TestCreatePin_ReservedPins (8.31s)1072=== CONT TestGCSweepSkipsPendingObjects10732026/10/25 13:49:14 INFO Received push request method=POST path=/api/pushes1074=== NAME TestOrphanedObjectsGC1075 orphaned_objects_gc_test.go:287: GC Test Summary:10762026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1077 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1078 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1079 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1080 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1081 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1082--- PASS: TestOrphanedObjectsGC (8.90s)1083=== CONT TestGCTaskStore_CompletedAllowsNewTask1084--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1085=== CONT TestGCTaskStore_GetReturnsLatest1086--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1087=== CONT TestDeduplicatedObjectsRecordedAsPending10882026/10/25 13:49:14 INFO Signed narinfos id=1 count=110892026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10902026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10912026/10/25 13:49:14 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10922026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10932026/10/25 13:49:14 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10942026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10952026/10/25 13:49:14 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110962026/10/25 13:49:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10972026/10/25 13:49:14 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1098--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.58s)1099=== CONT TestPendingCleanupUsesOneCutoff11002026/10/25 13:49:15 INFO Received uploads request method=POST path=/api/pending_closures11012026/10/25 13:49:15 INFO Received uploads request method=POST path=/api/pending_closures11022026/10/25 13:49:15 INFO Received push request method=POST path=/api/pushes11032026/10/25 13:49:15 INFO Received complete push request method=POST path=/api/pushes/1/complete11042026/10/25 13:49:16 INFO Completed push id=1 objects=4 duration=71.705333ms11052026/10/25 13:49:16 INFO Received push request method=POST path=/api/pushes11062026/10/25 13:49:16 INFO Aborted multipart uploads count=0 kept=011072026/10/25 13:49:16 WARN Force mode enabled - objects will be deleted immediately without grace period11082026/10/25 13:49:16 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=01109=== RUN TestPush_RejectsBadRequests/no_objects1110=== PAUSE TestPush_RejectsBadRequests/no_objects1111=== RUN TestPush_RejectsBadRequests/bad_root1112=== PAUSE TestPush_RejectsBadRequests/bad_root1113=== RUN TestPush_RejectsBadRequests/root_not_in_objects1114=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1115=== RUN TestPush_RejectsBadRequests/no_roots1116=== PAUSE TestPush_RejectsBadRequests/no_roots1117=== CONT TestPushDedupSurvivesConcurrentGC11182026/10/25 13:49:16 INFO Vacuumed table table=pending_closures11192026/10/25 13:49:16 INFO Vacuumed table table=pending_objects11202026/10/25 13:49:16 INFO Vacuumed table table=multipart_uploads11212026/10/25 13:49:16 INFO Vacuumed table table=closures11222026/10/25 13:49:16 INFO Vacuumed table table=objects11232026/10/25 13:49:16 INFO Received complete push request method=POST path=/api/pushes/2/complete11242026/10/25 13:49:16 INFO Completed push id=2 objects=4 duration=8.225542ms1125--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (8.22s)1126=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11272026/10/25 13:49:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11282026/10/25 13:49:16 INFO Received push request method=POST path=/api/pushes11292026/10/25 13:49:16 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LjdiMmI0NTdiLTdmMjktNDNmOS04ODlhLWJjMTVmOGM3OTU4ZXgxNzkyOTM2MTUzNTI5MzYzMDAw parts=1211302026/10/25 13:49:16 INFO Received uploads request method=POST path=/api/pending_closures1131--- PASS: TestCompletedNarNotReofferedAcrossClosures (10.92s)1132=== CONT TestGCMetrics11332026-10-25 13:49:16.857 UTC [40983] ERROR: could not obtain lock on row in relation "closures"11342026-10-25 13:49:16.857 UTC [40983] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11352026-10-25 13:49:16.868 UTC [40983] ERROR: could not obtain lock on row in relation "closures"11362026-10-25 13:49:16.868 UTC [40983] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11372026-10-25 13:49:16.873 UTC [40983] ERROR: could not obtain lock on row in relation "closures"11382026-10-25 13:49:16.873 UTC [40983] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11392026-10-25 13:49:16.882 UTC [40983] ERROR: could not obtain lock on row in relation "closures"11402026-10-25 13:49:16.882 UTC [40983] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11412026-10-25 13:49:16.888 UTC [40983] ERROR: could not obtain lock on row in relation "closures"11422026-10-25 13:49:16.888 UTC [40983] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1143--- PASS: TestPush_RootsAreLockedInByteOrder (8.62s)1144=== CONT TestMultipartCleanup11452026/10/25 13:49:17 INFO Received push request method=POST path=/api/pushes11462026/10/25 13:49:17 INFO Received push request method=POST path=/api/pushes11472026-10-25 13:49:17.468 UTC [41039] ERROR: Push does not exist: id=111482026-10-25 13:49:17.468 UTC [41039] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11492026-10-25 13:49:17.468 UTC [41039] STATEMENT: SELECT commit_push($1)1150--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (8.94s)1151=== CONT TestGCBugBareHashReferences11522026/10/25 13:49:17 INFO Received complete push request method=POST path=/api/pushes/1/complete11532026/10/25 13:49:17 INFO Completed push id=1 objects=4 duration=45.911041ms1154--- PASS: TestPush_RepeatedRootCommitsOnce (8.94s)1155=== CONT TestServerTLSConfig1156=== RUN TestServerTLSConfig/no_client_CA1157=== PAUSE TestServerTLSConfig/no_client_CA1158=== RUN TestServerTLSConfig/missing_CA_file1159=== PAUSE TestServerTLSConfig/missing_CA_file1160=== RUN TestServerTLSConfig/not_a_PEM_file1161=== PAUSE TestServerTLSConfig/not_a_PEM_file1162=== CONT TestGCAdvisoryLockBlocksConcurrentRun11632026/10/25 13:49:17 INFO Received uploads request method=POST path=/api/pending_closures11642026/10/25 13:49:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11652026/10/25 13:49:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LmU1YmJmNmNkLTI3OGQtNGFiNy1hMmZjLTQwMDY4ZWVlYWE3MXgxNzkyOTM2MTU1MTAyMjg2MDAw parts=1211662026/10/25 13:49:18 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/25 13:49:18 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/25 13:49:18 INFO Received push request method=POST path=/api/pushes11692026/10/25 13:49:18 INFO Received complete push request method=POST path=/api/pushes/1/complete11702026/10/25 13:49:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11712026/10/25 13:49:18 INFO Completed push id=1 objects=6 duration=75.486334ms1172--- PASS: TestPush_CompleteCommitsEveryRoot (9.41s)1173=== CONT TestGCTaskStore_PhaseUpdates1174--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1175=== CONT TestService_NativeMTLS1176--- PASS: TestReadRedirectNar (9.47s)1177=== CONT TestGCTaskStore_GetEmpty1178--- PASS: TestGCTaskStore_GetEmpty (0.00s)1179=== CONT TestMetricsCommit1180--- PASS: TestReadRedirectUsesPublicS3URL (9.68s)1181=== CONT TestCreatePendingClosureRejectsOversizedNAR11822026/10/25 13:49:19 INFO Received uploads request method=POST path=/api/pending_closures1183--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1184=== CONT TestMetricsInventory1185--- PASS: TestReadProxyRangeRequest (9.62s)1186=== CONT TestCacheConfigHandlerMaxNarSize1187--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1188=== CONT TestGenerateLandingPage1189--- PASS: TestGenerateLandingPage (0.00s)1190=== CONT TestLeadEndsOnShutdown1191--- PASS: TestReadRedirectKeepsNarinfoProxied (9.58s)1192=== CONT TestService_readinessHandler1193--- PASS: TestReadProxyRootRedirectsToIndexHTML (10.05s)1194=== CONT TestService_healthCheckHandler11952026/10/25 13:49:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11962026/10/25 13:49:21 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LmI1NDMxMWQxLTIzYTYtNDdjOS04NzI2LWRiZTVhMDQyNTZmYXgxNzkyOTM2MTU4MjAwNjI4MDAw error="Get \"http://127.0.0.1:1/bucket29/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11972026/10/25 13:49:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=N2UyMjU5YTMtZWE2NS00NDYwLWI5NzItM2JkNGMwNTc4Mjk4LjBlZWFhMzA1LTg5MGUtNDg5OS04MTM3LTczOWE2ZTM2NGRhNngxNzkyOTM2MTU4MTA5NTI1MDAw parts=1211982026/10/25 13:49:21 INFO Received cleanup request method=DELETE path=/api/pending_closures11992026/10/25 13:49:21 INFO Aborted multipart uploads count=1 kept=01200--- PASS: TestRedundantMultipartUpload (14.40s)1201=== CONT TestGCTaskStore_ConflictDifferentParams1202--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1203=== CONT TestGracefulShutdownDrainsInflight12042026/10/25 13:49:21 INFO Starting HTTP server address=127.0.0.1:5884812052026/10/25 13:49:21 INFO Shutdown signal received, draining in-flight requests timeout=10s1206--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1207=== CONT TestGCTaskStore_DeduplicateSameParams1208--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1209=== CONT TestGCTaskStore_Fail1210--- PASS: TestGCTaskStore_Fail (0.00s)1211=== CONT TestGCTaskStore_StartNew1212--- PASS: TestGCTaskStore_StartNew (0.00s)1213=== CONT TestGetExistingObjectsLocksRows1214--- PASS: TestReadProxyDisabled (10.09s)1215=== CONT TestRegisterCompletedObjectNeedsPendingRow1216--- PASS: TestObjectStatsTrigger (10.42s)1217=== CONT TestGCEndsOnShutdown1218=== RUN TestGCEndsOnShutdown/before_the_run1219=== PAUSE TestGCEndsOnShutdown/before_the_run1220=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1221=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1222=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1223=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1224=== CONT TestSweepSkipsRowsLockedByPush12252026/10/25 13:49:22 WARN Rate limiter enabled after throttle name=s3-test rate=512262026/10/25 13:49:22 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1227=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1228 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101229 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001230--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.28s)1231=== CONT TestFailedS3DeleteKeepsTombstone12322026/10/25 13:49:22 INFO Aborted multipart uploads count=0 kept=012332026/10/25 13:49:22 WARN Force mode enabled - objects will be deleted immediately without grace period12342026/10/25 13:49:22 INFO Received uploads request method=POST path=/api/pending_closures1235--- PASS: TestTombstonedObjectOfferedWithoutWaiting (10.92s)1236=== CONT TestCommitRacingPendingCleanupKeepsObjects12372026/10/25 13:49:22 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=012382026/10/25 13:49:22 INFO Vacuumed table table=pending_closures12392026/10/25 13:49:22 INFO Vacuumed table table=pending_objects12402026/10/25 13:49:22 INFO Vacuumed table table=multipart_uploads12412026/10/25 13:49:22 INFO Vacuumed table table=closures12422026/10/25 13:49:22 INFO Vacuumed table table=objects1243--- PASS: TestGCSweepDeliversEachKeyOnce (11.19s)1244=== CONT TestForceGCDuringPushOffersSweptObject1245=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1246=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1247=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1248=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1249=== CONT TestPushWaitsForSweepHoldingRow12502026/10/25 13:49:23 INFO Received uploads request method=POST path=/api/pending_closures1251--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (11.52s)1252=== CONT TestSweepRechecksPendingAfterLocking1253=== NAME TestNARDeduplicationMetadataUploadBug1254 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestNARDeduplicationMetadataUploadBug1287691631/001/store/jx6qqzv23cghwbqj4m4a369prz5aqrbq-file1.txt12552026/10/25 13:49:23 INFO Received uploads request method=POST path=/api/pending_closures12562026/10/25 13:49:24 INFO Aborted multipart uploads count=0 kept=012572026/10/25 13:49:24 INFO Received push request method=POST path=/api/pushes12582026/10/25 13:49:24 WARN Force mode enabled - objects will be deleted immediately without grace period12592026/10/25 13:49:24 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=012602026/10/25 13:49:24 INFO Vacuumed table table=pending_closures12612026/10/25 13:49:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12622026/10/25 13:49:24 INFO Uploading jx6qqzv23cghwbqj4m4a369prz5aqrbq-file1.txt (160B)12632026/10/25 13:49:24 INFO Vacuumed table table=pending_objects12642026/10/25 13:49:24 INFO Vacuumed table table=multipart_uploads12652026/10/25 13:49:24 INFO Vacuumed table table=closures12662026/10/25 13:49:24 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12672026/10/25 13:49:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12682026/10/25 13:49:24 WARN Failed to register uploaded object key=jx6qqzv23cghwbqj4m4a369prz5aqrbq.ls error="server returned 404: 404 page not found\n"12692026/10/25 13:49:24 INFO Signed narinfos id=1 count=112702026/10/25 13:49:24 INFO Uploading 1 narinfos12712026/10/25 13:49:24 INFO Vacuumed table table=objects12722026/10/25 13:49:24 INFO Received complete push request method=POST path=/api/pushes/1/complete12732026/10/25 13:49:24 WARN Failed to register uploaded object key=jx6qqzv23cghwbqj4m4a369prz5aqrbq.narinfo error="server returned 404: 404 page not found\n"1274--- PASS: TestGCSweepSkipsPendingObjects (10.40s)1275=== CONT TestReadProxyConditionalGet12762026/10/25 13:49:24 INFO Completed push id=1 objects=3 duration=71.874292ms12772026/10/25 13:49:24 INFO Received uploads request method=POST path=/api/pending_closures12782026/10/25 13:49:24 INFO Upload complete. (459ms)1279=== NAME TestNARDeduplicationMetadataUploadBug1280 metadata_upload_test.go:54: Retrieved narinfo from S3:1281 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestNARDeduplicationMetadataUploadBug1287691631/001/store/jx6qqzv23cghwbqj4m4a369prz5aqrbq-file1.txt1282 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1283 Compression: zstd1284 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1285 NarSize: 1601286 References: 1287 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1288 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1289 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1290 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1291--- PASS: TestDeduplicatedObjectsRecordedAsPending (9.87s)1292=== CONT TestService_ReadAuthMiddleware1293=== NAME TestNARDeduplicationMetadataUploadBug1294 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestNARDeduplicationMetadataUploadBug1287691631/001/store/450p42cvsnyv6p9d13jdfkhc5yqxziz9-file2.txt12952026/10/25 13:49:24 INFO Received uploads request method=POST path=/api/pending_closures12962026/10/25 13:49:24 INFO Received push request method=POST path=/api/pushes12972026/10/25 13:49:24 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12982026/10/25 13:49:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12992026/10/25 13:49:25 WARN Failed to register uploaded object key=450p42cvsnyv6p9d13jdfkhc5yqxziz9.ls error="server returned 404: 404 page not found\n"13002026/10/25 13:49:25 INFO Signed narinfos id=2 count=113012026/10/25 13:49:25 INFO Uploading 1 narinfos13022026/10/25 13:49:25 INFO Received uploads request method=POST path=/api/pending_closures13032026/10/25 13:49:25 INFO Received complete push request method=POST path=/api/pushes/2/complete13042026/10/25 13:49:25 WARN Failed to register uploaded object key=450p42cvsnyv6p9d13jdfkhc5yqxziz9.narinfo error="server returned 404: 404 page not found\n"13052026/10/25 13:49:25 INFO Completed push id=2 objects=3 duration=1.163333ms13062026/10/25 13:49:25 INFO Upload complete. (294ms)13072026/10/25 13:49:25 INFO Received cleanup request method=DELETE path=/api/pending_closures1308 metadata_upload_test.go:76: Retrieved narinfo from S3:1309 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestNARDeduplicationMetadataUploadBug1287691631/001/store/450p42cvsnyv6p9d13jdfkhc5yqxziz9-file2.txt1310 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1311 Compression: zstd1312 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1313 NarSize: 1601314 References: 1315 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1316 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1317 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1318 {"version":1,"root":{"type":"regular","size":44}}1319--- PASS: TestNARDeduplicationMetadataUploadBug (12.72s)1320=== CONT TestService_ReadScope_PublicByDefault13212026/10/25 13:49:25 INFO Received uploads request method=POST path=/api/pending_closures13222026/10/25 13:49:25 INFO Received uploads request method=POST path=/api/pending_closures13232026/10/25 13:49:25 INFO Aborted multipart uploads count=0 kept=01324--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (9.68s)1325=== CONT TestService_RequireScope_OIDC13262026/10/25 13:49:26 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=013272026/10/25 13:49:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58894/oidc13282026/10/25 13:49:26 INFO Vacuumed table table=pending_closures13292026/10/25 13:49:26 INFO Vacuumed table table=pending_objects13302026/10/25 13:49:26 INFO Vacuumed table table=multipart_uploads13312026/10/25 13:49:26 INFO Vacuumed table table=closures13322026/10/25 13:49:26 INFO Vacuumed table table=objects13332026/10/25 13:49:26 INFO Aborted multipart uploads count=0 kept=013342026/10/25 13:49:26 WARN Force mode enabled - objects will be deleted immediately without grace period13352026/10/25 13:49:26 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=013362026/10/25 13:49:26 INFO Vacuumed table table=pending_closures13372026/10/25 13:49:26 INFO Vacuumed table table=pending_objects13382026/10/25 13:49:26 INFO Vacuumed table table=multipart_uploads13392026/10/25 13:49:26 INFO Aborted multipart uploads count=0 kept=013402026/10/25 13:49:26 INFO Vacuumed table table=closures13412026/10/25 13:49:26 INFO Vacuumed table table=objects1342--- PASS: TestPushDedupSurvivesConcurrentGC (10.34s)1343=== CONT TestClientErrorHandling1344=== RUN TestClientErrorHandling/InvalidStorePath1345=== PAUSE TestClientErrorHandling/InvalidStorePath13462026/10/25 13:49:26 WARN Force mode enabled - objects will be deleted immediately without grace period1347=== RUN TestClientErrorHandling/InvalidAuthToken1348=== PAUSE TestClientErrorHandling/InvalidAuthToken1349=== RUN TestClientErrorHandling/ServerNotAvailable1350=== PAUSE TestClientErrorHandling/ServerNotAvailable1351=== CONT TestClientCADerivations13522026/10/25 13:49:26 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=013532026/10/25 13:49:26 INFO Vacuumed table table=pending_closures13542026/10/25 13:49:26 INFO Vacuumed table table=pending_objects13552026/10/25 13:49:26 INFO Vacuumed table table=multipart_uploads13562026/10/25 13:49:26 INFO Vacuumed table table=closures13572026/10/25 13:49:26 INFO Vacuumed table table=objects1358--- PASS: TestGCMetrics (9.96s)1359=== CONT TestService_AuthMiddleware_OIDC13602026/10/25 13:49:26 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58898/oidc13612026/10/25 13:49:26 INFO Received uploads request method=POST path=/api/pending_closures13622026/10/25 13:49:27 INFO Received cleanup request method=DELETE path=/api/pending_closures13632026/10/25 13:49:27 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13642026/10/25 13:49:27 INFO Aborted multipart uploads count=0 kept=113652026/10/25 13:49:27 INFO Received cleanup request method=DELETE path=/api/pending_closures13662026/10/25 13:49:27 INFO Aborted multipart uploads count=1 kept=01367--- PASS: TestMultipartCleanup (10.35s)1368=== CONT TestCacheConfigHandler1369=== RUN TestCacheConfigHandler/full_config,_no_issuer1370=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1371=== RUN TestCacheConfigHandler/no_cache_url_configured1372=== PAUSE TestCacheConfigHandler/no_cache_url_configured1373=== RUN TestCacheConfigHandler/no_signing_keys1374=== PAUSE TestCacheConfigHandler/no_signing_keys1375=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1376=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1377=== CONT TestClientIntegration1378--- PASS: TestGCBugBareHashReferences (10.32s)1379=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13802026/10/25 13:49:27 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1381--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (10.23s)1382=== CONT TestReadProxyOutlastsServerWriteTimeout13832026/10/25 13:49:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13842026/10/25 13:49:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1385--- PASS: TestService_NativeMTLS (9.65s)1386=== CONT TestService_AuthMiddleware_MTLSProxyHeader13872026/10/25 13:49:28 INFO Received push request method=POST path=/api/pushes13882026/10/25 13:49:28 INFO Received complete push request method=POST path=/api/pushes/1/complete13892026/10/25 13:49:29 INFO Completed push id=1 objects=4 duration=50.05225ms13902026/10/25 13:49:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13912026/10/25 13:49:29 INFO Completed upload id=2 objects=2 duration=1.856708ms1392--- PASS: TestMetricsCommit (10.02s)1393=== CONT TestDeleteClosuresRacingPins1394=== NAME TestOrphanedObjectsGCStressTest1395 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1396--- PASS: TestMetricsInventory (9.83s)1397=== CONT TestLeadIncumbentAnnouncesAtOnce1398=== NAME TestOrphanedObjectsGCStressTest1399 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion14002026/10/25 13:49:29 INFO lead: acquired remote=192.0.2.1:123414012026/10/25 13:49:30 WARN readiness check failed error="closed pool"1402--- PASS: TestService_readinessHandler (9.65s)1403=== CONT TestClientFallsBackToClosures1404--- PASS: TestService_healthCheckHandler (9.50s)1405=== CONT TestCacheStatsHandler14062026/10/25 13:49:30 INFO lead: released remote=192.0.2.1:12341407--- PASS: TestLeadEndsOnShutdown (10.72s)1408=== CONT TestLeadElectsOneAndHandsOver1409--- PASS: TestGetExistingObjectsLocksRows (9.66s)1410=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14112026/10/25 13:49:31 INFO Aborted multipart uploads count=1 kept=014122026/10/25 13:49:31 INFO Received cleanup request method=DELETE path=/api/pending_closures1413--- PASS: TestRegisterCompletedObjectNeedsPendingRow (9.95s)14142026/10/25 13:49:31 INFO Aborted multipart uploads count=1 kept=01415=== CONT TestClientPushesUseOnePush1416=== CONT TestClientWithDependencies1417--- PASS: TestPendingCleanupUsesOneCutoff (16.55s)14182026/10/25 13:49:31 INFO Aborted multipart uploads count=0 kept=014192026/10/25 13:49:31 WARN Force mode enabled - objects will be deleted immediately without grace period14202026/10/25 13:49:31 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=014212026/10/25 13:49:31 INFO Vacuumed table table=pending_closures14222026/10/25 13:49:31 INFO Vacuumed table table=pending_objects14232026/10/25 13:49:31 INFO Vacuumed table table=multipart_uploads14242026/10/25 13:49:31 INFO Vacuumed table table=closures14252026/10/25 13:49:31 INFO Vacuumed table table=objects14262026/10/25 13:49:31 INFO Aborted multipart uploads count=0 kept=014272026/10/25 13:49:31 WARN Force mode enabled - objects will be deleted immediately without grace period14282026/10/25 13:49:31 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=014292026/10/25 13:49:32 INFO Vacuumed table table=pending_closures14302026/10/25 13:49:32 INFO Vacuumed table table=pending_objects14312026/10/25 13:49:32 INFO Vacuumed table table=multipart_uploads14322026/10/25 13:49:32 INFO Vacuumed table table=closures14332026/10/25 13:49:32 INFO Vacuumed table table=objects1434--- PASS: TestSweepSkipsRowsLockedByPush (10.20s)1435=== CONT TestPinProtectsFromGC14362026/10/25 13:49:32 INFO Received uploads request method=POST path=/api/pending_closures14372026/10/25 13:49:32 INFO Aborted multipart uploads count=0 kept=014382026/10/25 13:49:32 WARN Force mode enabled - objects will be deleted immediately without grace period14392026/10/25 13:49:32 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14402026/10/25 13:49:32 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1441--- PASS: TestFailedS3DeleteKeepsTombstone (10.05s)1442=== CONT TestResolveDBConnectionString1443=== RUN TestResolveDBConnectionString/flag_wins1444=== PAUSE TestResolveDBConnectionString/flag_wins1445=== RUN TestResolveDBConnectionString/file_when_flag_empty1446=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1447=== RUN TestResolveDBConnectionString/missing_file_is_an_error1448=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1449=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1450=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1451=== RUN TestResolveDBConnectionString/nothing_configured1452=== PAUSE TestResolveDBConnectionString/nothing_configured1453=== CONT TestClientSharedPathCommittedMidPush14542026/10/25 13:49:32 INFO Aborted multipart uploads count=0 kept=014552026/10/25 13:49:32 WARN Force mode enabled - objects will be deleted immediately without grace period14562026/10/25 13:49:32 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=014572026/10/25 13:49:33 INFO Vacuumed table table=pending_closures14582026/10/25 13:49:33 INFO Received uploads request method=POST path=/api/pending_closures14592026/10/25 13:49:33 INFO Vacuumed table table=pending_objects14602026/10/25 13:49:33 INFO Vacuumed table table=multipart_uploads14612026/10/25 13:49:33 INFO Vacuumed table table=closures14622026/10/25 13:49:33 INFO Vacuumed table table=objects1463--- PASS: TestCommitRacingPendingCleanupKeepsObjects (10.43s)1464=== CONT TestConnectWaitsForAPeerMigration14652026/10/25 13:49:33 INFO Aborted multipart uploads count=0 kept=01466--- PASS: TestPushWaitsForSweepHoldingRow (10.69s)14672026/10/25 13:49:33 WARN Force mode enabled - objects will be deleted immediately without grace period1468=== CONT TestClientMultipleUploads14692026/10/25 13:49:33 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=014702026/10/25 13:49:33 INFO Vacuumed table table=pending_closures14712026/10/25 13:49:33 INFO Vacuumed table table=pending_objects14722026/10/25 13:49:33 INFO Vacuumed table table=multipart_uploads14732026/10/25 13:49:33 INFO Vacuumed table table=closures14742026/10/25 13:49:33 INFO Vacuumed table table=objects1475--- PASS: TestSweepRechecksPendingAfterLocking (10.47s)1476=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14772026/10/25 13:49:33 INFO Received uploads request method=POST path=/1478=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14792026/10/25 13:49:33 INFO Received request for more parts method=POST path=/1480=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14812026/10/25 13:49:33 INFO Received complete multipart upload request method=POST path=/1482=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14832026/10/25 13:49:33 INFO Received uploads request method=POST path=/1484--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1485 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)1486 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1487 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1488 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1489=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1490--- PASS: TestReadProxyConditionalGet (9.47s)1491=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1492--- PASS: TestService_ReadAuthMiddleware (9.65s)1493=== CONT TestIsValidUploadKey/narinfo1494=== CONT TestParseSingleRange/none1495=== CONT TestIsValidUploadKey/listing1496=== CONT TestIsValidUploadKey/unknown_type1497=== CONT TestIsValidUploadKey/empty_key1498=== CONT TestIsValidUploadKey/absolute1499=== CONT TestIsValidUploadKey/traversal_nar1500=== CONT TestIsValidUploadKey/traversal1501=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1502=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1503=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1504=== CONT TestIsValidUploadKey/index.html1505=== CONT TestIsValidUploadKey/nix-cache-info1506=== CONT TestIsValidUploadKey/realisation_plus_in_output1507=== CONT TestIsValidUploadKey/realisation1508=== CONT TestIsValidUploadKey/build_log_equals1509=== CONT TestIsValidUploadKey/build_log_question_mark1510=== CONT TestIsValidUploadKey/build_log_plus_in_name1511=== CONT TestIsValidUploadKey/build_log_home-manager_file1512=== CONT TestIsValidUploadKey/build_log1513=== CONT TestParseSingleRange/suffix_exceeds_size1514=== CONT TestIsValidUploadKey/nar_plain1515=== CONT TestIsValidUploadKey/nar_xz1516=== CONT TestIsValidUploadKey/nar_zst1517--- PASS: TestIsValidUploadKey (0.05s)1518 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1519 --- PASS: TestIsValidUploadKey/listing (0.00s)1520 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1521 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1522 --- PASS: TestIsValidUploadKey/absolute (0.00s)1523 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1524 --- PASS: TestIsValidUploadKey/traversal (0.00s)1525 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1526 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1527 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1528 --- PASS: TestIsValidUploadKey/index.html (0.00s)1529 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1530 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1531 --- PASS: TestIsValidUploadKey/realisation (0.00s)1532 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1533 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1534 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1535 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1536 --- PASS: TestIsValidUploadKey/build_log (0.00s)1537 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1538 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1539 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1540=== CONT TestParseSingleRange/malformed_end_before_start1541=== CONT TestParseSingleRange/suffix1542=== CONT TestParseSingleRange/end_clamped_to_size1543=== CONT TestParseSingleRange/open-ended1544=== CONT TestParseSingleRange/closed1545=== CONT TestParseSingleRange/malformed_no_dash1546=== CONT TestParseSingleRange/malformed_both_empty1547=== CONT TestParseSingleRange/start_past_EOF1548=== CONT TestParseSingleRange/start_far_past_EOF1549=== CONT TestParseSingleRange/single_byte1550=== CONT TestIsValidCachePath/narinfo1551=== CONT TestParseSingleRange/multi-range_ignored1552=== CONT TestIsValidCachePath/short_hash1553=== CONT TestIsValidCachePath/wrong_extension1554=== CONT TestIsValidCachePath/leading_slash1555=== CONT TestIsValidCachePath/empty1556=== CONT TestIsValidCachePath/random_path1557=== CONT TestIsValidCachePath/invalid_char_u1558=== CONT TestIsValidCachePath/invalid_char_e1559=== CONT TestIsValidCachePath/traversal_in_middle1560=== CONT TestIsValidCachePath/traversal_parent1561=== CONT TestIsValidCachePath/index.html1562=== CONT TestIsValidCachePath/nix-cache-info1563=== CONT TestIsValidCachePath/realisation1564=== CONT TestIsValidCachePath/log1565=== CONT TestIsValidCachePath/ls1566=== CONT TestIsValidCachePath/nar_uncompressed1567=== CONT TestIsValidCachePath/nar_bz21568=== CONT TestIsValidCachePath/nar_xz1569=== CONT TestIsValidCachePath/nar_zst1570=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1571=== CONT TestParseSingleRange/unknown_unit1572=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1573--- PASS: TestIsValidCachePath (0.05s)1574 --- PASS: TestIsValidCachePath/narinfo (0.00s)1575 --- PASS: TestIsValidCachePath/short_hash (0.00s)1576 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1577 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1578 --- PASS: TestIsValidCachePath/empty (0.00s)1579 --- PASS: TestIsValidCachePath/random_path (0.00s)1580 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1581 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1582 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1583 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1584 --- PASS: TestIsValidCachePath/index.html (0.00s)1585 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1586 --- PASS: TestIsValidCachePath/realisation (0.00s)1587 --- PASS: TestIsValidCachePath/log (0.00s)1588 --- PASS: TestIsValidCachePath/ls (0.00s)1589 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1590 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1591 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1592 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1593 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1594--- PASS: TestParseSingleRange (0.05s)1595 --- PASS: TestParseSingleRange/none (0.00s)1596 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1597 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1598 --- PASS: TestParseSingleRange/suffix (0.00s)1599 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1600 --- PASS: TestParseSingleRange/open-ended (0.00s)1601 --- PASS: TestParseSingleRange/closed (0.00s)1602 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1603 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1604 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1605 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1606 --- PASS: TestParseSingleRange/single_byte (0.00s)1607 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1608 --- PASS: TestParseSingleRange/unknown_unit (0.00s)16092026/10/25 13:49:34 INFO Received uploads request method=POST path=/1610--- PASS: TestService_ReadScope_PublicByDefault (9.16s)1611=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16122026/10/25 13:49:34 INFO Received request for more parts method=POST path=/1613=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16142026/10/25 13:49:34 INFO Received complete multipart upload request method=POST path=/1615=== CONT TestPendingClosureWriteTimeout/empty1616=== CONT TestPendingClosureWriteTimeout/670k_objects1617=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1618--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)1619 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.31s)1620 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1621 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1622=== CONT TestPendingClosureWriteTimeout/400_objects1623=== CONT TestProxyWriteTimeout/narinfo1624=== CONT TestProxyWriteTimeout/10_GiB_nar1625=== CONT TestProxyWriteTimeout/unknown_size1626=== CONT TestProxyWriteTimeout/1_GiB_nar1627--- PASS: TestProxyWriteTimeout (0.00s)1628 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1629 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1630 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1631 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1632=== CONT TestPush_RejectsBadRequests/no_objects16332026/10/25 13:49:34 INFO Received push request method=POST path=/api/pushes1634=== CONT TestPush_RejectsBadRequests/root_not_in_objects16352026/10/25 13:49:34 INFO Received push request method=POST path=/api/pushes1636=== CONT TestPush_RejectsBadRequests/no_roots16372026/10/25 13:49:34 INFO Received push request method=POST path=/api/pushes1638=== CONT TestPush_RejectsBadRequests/bad_root16392026/10/25 13:49:34 INFO Received push request method=POST path=/api/pushes1640=== CONT TestServerTLSConfig/no_client_CA1641=== CONT TestServerTLSConfig/not_a_PEM_file1642--- PASS: TestPush_RejectsBadRequests (8.07s)1643 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)1644 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.01s)1645 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1646 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)1647=== CONT TestServerTLSConfig/missing_CA_file1648--- PASS: TestServerTLSConfig (0.00s)1649 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1650 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1651 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1652=== CONT TestGCEndsOnShutdown/before_the_run1653=== RUN TestService_RequireScope_OIDC/builder_may_write1654=== PAUSE TestService_RequireScope_OIDC/builder_may_write1655=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1656=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1657=== RUN TestService_RequireScope_OIDC/ops_may_admin1658=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1659=== RUN TestService_RequireScope_OIDC/ops_may_not_write1660=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1661=== RUN TestService_RequireScope_OIDC/reader_may_not_write1662=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1663=== RUN TestService_RequireScope_OIDC/static_token_may_admin1664=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1665=== RUN TestService_RequireScope_OIDC/static_token_may_write1666=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1667=== RUN TestService_RequireScope_OIDC/reader_may_read1668=== PAUSE TestService_RequireScope_OIDC/reader_may_read1669=== RUN TestService_RequireScope_OIDC/writer_implies_read1670=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1671=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1672=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1673=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1674=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1675=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1676=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1677=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1678=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1679=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1680=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1681=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1682=== NAME TestOrphanedObjectsGCStressTest1683 orphaned_objects_gc_test.go:503: Stress test completed successfully:1684 orphaned_objects_gc_test.go:504: - Active objects preserved: 201685 orphaned_objects_gc_test.go:505: - Objects deleted: 2101686 orphaned_objects_gc_test.go:506: - Total GC'd: 2101687--- PASS: TestOrphanedObjectsGCStressTest (29.55s)1688=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1689=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1690=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1691=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1692=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1693=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1694=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1695=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1696=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1697=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1698=== NAME TestClientCADerivations1699 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientCADerivations1780708562/001/store/p88ffkaznl93lwn5cb7xzzvxxrfaqy4g-ca-test1700 client_ca_test.go:139: Found 1 dependencies (including self)17012026/10/25 13:49:35 INFO Received push request method=POST path=/api/pushes1702=== NAME TestClientIntegration1703 client_integration_test.go:286: Created store path: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientIntegration844449801/002/store/sb1sy22gw7d5pk9x1qgwas3cv17bwrqj-test-file.txt17042026/10/25 13:49:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17052026/10/25 13:49:35 INFO Uploading p88ffkaznl93lwn5cb7xzzvxxrfaqy4g-ca-test (144B)17062026/10/25 13:49:35 WARN Failed to register uploaded object key=p88ffkaznl93lwn5cb7xzzvxxrfaqy4g.ls error="server returned 404: 404 page not found\n"17072026/10/25 13:49:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17082026/10/25 13:49:35 WARN Failed to register uploaded object key=log/wbjq2yjhi16vfdj830ks502gcys19n9z-ca-test.drv error="server returned 404: 404 page not found\n"17092026/10/25 13:49:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17102026/10/25 13:49:35 INFO Signed narinfos id=1 count=117112026/10/25 13:49:35 INFO Uploading 1 narinfos17122026/10/25 13:49:35 INFO Received push request method=POST path=/api/pushes17132026/10/25 13:49:35 INFO Received complete push request method=POST path=/api/pushes/1/complete17142026/10/25 13:49:35 WARN Failed to register uploaded object key=p88ffkaznl93lwn5cb7xzzvxxrfaqy4g.narinfo error="server returned 404: 404 page not found\n"17152026/10/25 13:49:36 INFO Completed push id=1 objects=4 duration=25.3685ms17162026/10/25 13:49:36 INFO Upload complete. (293ms)1717=== NAME TestClientCADerivations1718 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientCADerivations1780708562/001/store/p88ffkaznl93lwn5cb7xzzvxxrfaqy4g-ca-test1719 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1720 Compression: zstd1721 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1722 NarSize: 1441723 References: 1724 Deriver: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientCADerivations1780708562/001/store/wbjq2yjhi16vfdj830ks502gcys19n9z-ca-test.drv1725 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1726 client_ca_test.go:185: Checking for realisation files in S3...1727 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1728 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17292026/10/25 13:49:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17302026/10/25 13:49:36 INFO Uploading sb1sy22gw7d5pk9x1qgwas3cv17bwrqj-test-file.txt (152B)17312026/10/25 13:49:36 WARN Failed to register uploaded object key=sb1sy22gw7d5pk9x1qgwas3cv17bwrqj.ls error="server returned 404: 404 page not found\n"17322026/10/25 13:49:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17332026/10/25 13:49:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17342026/10/25 13:49:36 INFO Signed narinfos id=1 count=117352026/10/25 13:49:36 INFO Uploading 1 narinfos17362026/10/25 13:49:36 INFO Received complete push request method=POST path=/api/pushes/1/complete17372026/10/25 13:49:36 WARN Failed to register uploaded object key=sb1sy22gw7d5pk9x1qgwas3cv17bwrqj.narinfo error="server returned 404: 404 page not found\n"1738 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket74?endpoint=http://localhost:58674®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientCADerivations1780708562/001/store'1739 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117402026/10/25 13:49:36 INFO Completed push id=1 objects=3 duration=20.889375ms17412026/10/25 13:49:36 INFO Upload complete. (326ms)17422026/10/25 13:49:36 INFO All 1 paths already cached1743=== NAME TestClientIntegration1744 client_integration_test.go:312: Retrieved narinfo from S3:1745 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientIntegration844449801/002/store/sb1sy22gw7d5pk9x1qgwas3cv17bwrqj-test-file.txt1746 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1747 Compression: zstd1748 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11749 NarSize: 1521750 References: 1751 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11752 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1753 client_integration_test.go:313: Decompressed .ls content (64 bytes):1754 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1755 client_integration_test.go:316: Testing garbage collection...17562026/10/25 13:49:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17572026/10/25 13:49:36 WARN mTLS auth: bound subjects configured but subject DN unavailable17582026/10/25 13:49:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1759--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (8.45s)1760=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1761--- PASS: TestClientCADerivations (9.71s)1762=== CONT TestClientErrorHandling/InvalidStorePath17632026/10/25 13:49:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures17642026/10/25 13:49:36 INFO Garbage collection started17652026/10/25 13:49:36 INFO Aborted multipart uploads count=0 kept=017662026/10/25 13:49:36 WARN Force mode enabled - objects will be deleted immediately without grace period17672026/10/25 13:49:36 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=017682026/10/25 13:49:36 INFO Vacuumed table table=pending_closures17692026/10/25 13:49:36 INFO Vacuumed table table=pending_objects17702026/10/25 13:49:36 INFO Vacuumed table table=multipart_uploads17712026/10/25 13:49:36 INFO Vacuumed table table=closures17722026/10/25 13:49:36 INFO Vacuumed table table=objects1773--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (8.19s)1774=== CONT TestClientErrorHandling/ServerNotAvailable17752026/10/25 13:49:36 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/present17762026/10/25 13:49:36 WARN Request failed, retrying attempt=2 backoff=210.010816ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17772026/10/25 13:49:36 INFO lead: acquired remote=192.0.2.1:123417782026/10/25 13:49:36 INFO lead: released remote=192.0.2.1:12341779--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.60s)1780=== CONT TestClientErrorHandling/InvalidAuthToken17812026/10/25 13:49:37 WARN Request failed, retrying attempt=3 backoff=375.233258ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17822026/10/25 13:49:37 WARN Request failed, retrying attempt=4 backoff=798.348511ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1783--- PASS: TestCacheStatsHandler (7.04s)1784=== CONT TestCacheConfigHandler/full_config,_no_issuer1785=== CONT TestCacheConfigHandler/no_signing_keys1786=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1787=== CONT TestCacheConfigHandler/no_cache_url_configured1788--- PASS: TestCacheConfigHandler (0.01s)1789 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1790 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1791 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1792 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1793=== CONT TestResolveDBConnectionString/flag_wins1794=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1795=== CONT TestResolveDBConnectionString/nothing_configured1796=== CONT TestResolveDBConnectionString/missing_file_is_an_error1797=== CONT TestResolveDBConnectionString/file_when_flag_empty1798=== CONT TestService_RequireScope_OIDC/builder_may_write1799=== CONT TestService_RequireScope_OIDC/reader_may_read1800=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1801=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18022026/10/25 13:49:37 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]1803=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1804=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1805=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1806=== CONT TestService_RequireScope_OIDC/writer_implies_read1807=== CONT TestService_RequireScope_OIDC/reader_may_not_write1808=== CONT TestService_RequireScope_OIDC/static_token_may_write1809=== CONT TestService_RequireScope_OIDC/static_token_may_admin1810=== CONT TestService_RequireScope_OIDC/ops_may_admin1811=== CONT TestService_RequireScope_OIDC/ops_may_not_write1812=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1813=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1814--- PASS: TestResolveDBConnectionString (0.03s)1815 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1816 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1817 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1818 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1819 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1820--- PASS: TestService_RequireScope_OIDC (8.81s)1821 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1830 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1831 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1832 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1833 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1834 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1835=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18362026/10/25 13:49:37 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]1837=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1838=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18392026/10/25 13:49:37 WARN Authentication failed token_preview=eyJhbGciOi...kwWr-hyDaA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1840--- PASS: TestService_AuthMiddleware_OIDC (8.80s)1841 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1842 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1843 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1844 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)18452026/10/25 13:49:37 INFO lead: acquired remote=192.0.2.1:123418462026/10/25 13:49:37 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/25 13:49:37 INFO Received uploads request method=POST path=/api/pending_closures18482026/10/25 13:49:37 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18492026/10/25 13:49:37 INFO Uploading dq62a5dwxcw8jjgkclxg9vk5rvipva1z-b (256B)18502026/10/25 13:49:37 INFO Uploading hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh-shared-dep (136B)18512026/10/25 13:49:37 WARN Failed to register uploaded object key=dq62a5dwxcw8jjgkclxg9vk5rvipva1z.ls error="server returned 404: 404 page not found\n"18522026/10/25 13:49:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18532026/10/25 13:49:37 WARN Failed to register uploaded object key=nar/0lrqvh6bs9bjzgqksfqlkrq7sn13za65a7jaigy60yp9gndyfc09.nar.zst error="server returned 404: 404 page not found\n"18542026/10/25 13:49:37 WARN Failed to register uploaded object key=8gs7i60mc8ax8ns0nxlh9wpcs0dw3zak.ls error="server returned 404: 404 page not found\n"18552026/10/25 13:49:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18562026/10/25 13:49:37 WARN Failed to register uploaded object key=hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh.ls error="server returned 404: 404 page not found\n"18572026/10/25 13:49:37 INFO Signed narinfos id=2 count=218582026/10/25 13:49:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18592026/10/25 13:49:37 INFO Signed narinfos id=1 count=218602026/10/25 13:49:37 INFO Uploading 4 narinfos18612026/10/25 13:49:37 WARN Failed to register uploaded object key=hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh.narinfo error="server returned 404: 404 page not found\n"18622026/10/25 13:49:37 WARN Failed to register uploaded object key=8gs7i60mc8ax8ns0nxlh9wpcs0dw3zak.narinfo error="server returned 404: 404 page not found\n"18632026/10/25 13:49:37 WARN Failed to register uploaded object key=dq62a5dwxcw8jjgkclxg9vk5rvipva1z.narinfo error="server returned 404: 404 page not found\n"18642026/10/25 13:49:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18652026/10/25 13:49:37 WARN Failed to register uploaded object key=hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh.narinfo error="server returned 404: 404 page not found\n"18662026/10/25 13:49:37 INFO Completed upload id=1 objects=6 duration=10.960417ms18672026/10/25 13:49:37 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18682026/10/25 13:49:37 INFO Completed upload id=2 objects=6 duration=628.166µs18692026/10/25 13:49:37 INFO Upload complete. (286ms)1870=== NAME TestClientFallsBackToClosures1871 client_pushes_test.go:112: Retrieved narinfo from S3:1872 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientFallsBackToClosures2941171318/001/store/hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh-shared-dep1873 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1874 Compression: zstd1875 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821876 NarSize: 1361877 References: 1878 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1879 client_pushes_test.go:112: Retrieved narinfo from S3:1880 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientFallsBackToClosures2941171318/001/store/8gs7i60mc8ax8ns0nxlh9wpcs0dw3zak-a1881 URL: nar/0lrqvh6bs9bjzgqksfqlkrq7sn13za65a7jaigy60yp9gndyfc09.nar.zst1882 Compression: zstd1883 NarHash: sha256:0lrqvh6bs9bjzgqksfqlkrq7sn13za65a7jaigy60yp9gndyfc091884 NarSize: 2561885 References: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientFallsBackToClosures2941171318/001/store/hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh-shared-dep1886 CA: text:sha256:0ccdfn2j91m09djsb9zp47z36x9ia8k9x4r363cd99bd8lb97cnh1887 client_pushes_test.go:112: Retrieved narinfo from S3:1888 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientFallsBackToClosures2941171318/001/store/dq62a5dwxcw8jjgkclxg9vk5rvipva1z-b1889 URL: nar/0lrqvh6bs9bjzgqksfqlkrq7sn13za65a7jaigy60yp9gndyfc09.nar.zst1890 Compression: zstd1891 NarHash: sha256:0lrqvh6bs9bjzgqksfqlkrq7sn13za65a7jaigy60yp9gndyfc091892 NarSize: 2561893 References: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientFallsBackToClosures2941171318/001/store/hgcsg2glk0wdhj4k0v3y6rjq8dxwzvhh-shared-dep1894 CA: text:sha256:0ccdfn2j91m09djsb9zp47z36x9ia8k9x4r363cd99bd8lb97cnh1895--- PASS: TestClientFallsBackToClosures (7.85s)18962026/10/25 13:49:38 WARN Request failed, retrying attempt=5 backoff=1.715587012s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18972026/10/25 13:49:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01898=== NAME TestClientIntegration1899 client_integration_test.go:323: Objects in database after GC:1900 client_integration_test.go:323: Successfully deleted all objects with GC --force1901--- PASS: TestClientIntegration (11.05s)1902=== NAME TestClientWithDependencies1903 client_integration_test.go:613: Built derivation: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientWithDependencies2822546707/001/store/gjcwfqly5hhcfy0zbqgfjj9qq9wrx1di-test-script1904--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.52s)1905=== NAME TestClientWithDependencies1906 client_integration_test.go:615: Found 1 dependencies (including self)19072026/10/25 13:49:38 INFO Received push request method=POST path=/api/pushes19082026/10/25 13:49:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19092026/10/25 13:49:38 INFO Uploading gjcwfqly5hhcfy0zbqgfjj9qq9wrx1di-test-script (136B)19102026/10/25 13:49:38 WARN Failed to register uploaded object key=gjcwfqly5hhcfy0zbqgfjj9qq9wrx1di.ls error="server returned 404: 404 page not found\n"19112026/10/25 13:49:38 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19122026/10/25 13:49:38 WARN Failed to register uploaded object key=log/20806qrx4ziv4vb6kf7j3sxjfisys829-test-script.drv error="server returned 404: 404 page not found\n"19132026/10/25 13:49:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19142026/10/25 13:49:38 INFO Signed narinfos id=1 count=119152026/10/25 13:49:38 INFO Uploading 1 narinfos19162026/10/25 13:49:38 INFO Received push request method=POST path=/api/pushes19172026/10/25 13:49:38 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19182026/10/25 13:49:38 INFO Uploading bw2m0qsymd9pb3vli6vfcmc3js5jg4xm-shared-dep (136B)19192026/10/25 13:49:38 INFO Uploading 382fbm54x68fqjcp35gg0nn6rgj4yzbq-a (256B)19202026/10/25 13:49:38 INFO Received complete push request method=POST path=/api/pushes/1/complete19212026/10/25 13:49:38 WARN Failed to register uploaded object key=gjcwfqly5hhcfy0zbqgfjj9qq9wrx1di.narinfo error="server returned 404: 404 page not found\n"19222026/10/25 13:49:38 INFO Completed push id=1 objects=4 duration=20.327833ms19232026/10/25 13:49:38 INFO Upload complete. (209ms)1924 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientWithDependencies2822546707/001/store) requires matching store prefix19252026/10/25 13:49:38 WARN Failed to register uploaded object key=bw2m0qsymd9pb3vli6vfcmc3js5jg4xm.ls error="server returned 404: 404 page not found\n"19262026/10/25 13:49:38 WARN Failed to register uploaded object key=rnyg2gpv0c4lf98bzzn1nwj8i1ynpjbv.ls error="server returned 404: 404 page not found\n"19272026/10/25 13:49:38 WARN Failed to register uploaded object key=382fbm54x68fqjcp35gg0nn6rgj4yzbq.ls error="server returned 404: 404 page not found\n"19282026/10/25 13:49:38 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19292026/10/25 13:49:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19302026/10/25 13:49:38 WARN Failed to register uploaded object key=nar/0nz9m4shmizisw6zmq8scj71m41f45x4r1j2njm0di25gd88cfy5.nar.zst error="server returned 404: 404 page not found\n"19312026/10/25 13:49:38 INFO Signed narinfos id=1 count=319322026/10/25 13:49:38 INFO Uploading 3 narinfos19332026/10/25 13:49:38 WARN Failed to register uploaded object key=rnyg2gpv0c4lf98bzzn1nwj8i1ynpjbv.narinfo error="server returned 404: 404 page not found\n"19342026/10/25 13:49:38 WARN Failed to register uploaded object key=382fbm54x68fqjcp35gg0nn6rgj4yzbq.narinfo error="server returned 404: 404 page not found\n"19352026/10/25 13:49:38 INFO Received complete push request method=POST path=/api/pushes/1/complete19362026/10/25 13:49:38 WARN Failed to register uploaded object key=bw2m0qsymd9pb3vli6vfcmc3js5jg4xm.narinfo error="server returned 404: 404 page not found\n"1937--- PASS: TestClientWithDependencies (7.54s)19382026/10/25 13:49:38 INFO Completed push id=1 objects=8 duration=15.363917ms19392026/10/25 13:49:38 INFO lead: released remote=192.0.2.1:123419402026/10/25 13:49:38 INFO Upload complete. (241ms)1941=== NAME TestClientPushesUseOnePush1942 client_pushes_test.go:97: Retrieved narinfo from S3:1943 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientPushesUseOnePush836095535/001/store/bw2m0qsymd9pb3vli6vfcmc3js5jg4xm-shared-dep1944 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1945 Compression: zstd1946 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821947 NarSize: 1361948 References: 1949=== NAME TestPinProtectsFromGC1950 client_integration_test.go:731: Pinned store path: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestPinProtectsFromGC1387639887/001/store/bsj7p2iiyazfisd5ragjfyqhkvmb5p9f-pinned-file.txt1951=== NAME TestClientPushesUseOnePush1952 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1953=== NAME TestPinProtectsFromGC1954 client_integration_test.go:732: Unpinned store path: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestPinProtectsFromGC1387639887/001/store/kflp45pfg305fl48z1ghxwwi7a24ml6a-unpinned-file.txt1955=== NAME TestClientPushesUseOnePush1956 client_pushes_test.go:97: Retrieved narinfo from S3:1957 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientPushesUseOnePush836095535/001/store/382fbm54x68fqjcp35gg0nn6rgj4yzbq-a1958 URL: nar/0nz9m4shmizisw6zmq8scj71m41f45x4r1j2njm0di25gd88cfy5.nar.zst1959 Compression: zstd1960 NarHash: sha256:0nz9m4shmizisw6zmq8scj71m41f45x4r1j2njm0di25gd88cfy51961 NarSize: 2561962 References: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientPushesUseOnePush836095535/001/store/bw2m0qsymd9pb3vli6vfcmc3js5jg4xm-shared-dep1963 CA: text:sha256:1jyxv2kcnqfahwk7gkyhi9a8c9cwa29yw3935qrl84hf890y5maw1964 client_pushes_test.go:97: Retrieved narinfo from S3:1965 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientPushesUseOnePush836095535/001/store/rnyg2gpv0c4lf98bzzn1nwj8i1ynpjbv-b1966 URL: nar/0nz9m4shmizisw6zmq8scj71m41f45x4r1j2njm0di25gd88cfy5.nar.zst1967 Compression: zstd1968 NarHash: sha256:0nz9m4shmizisw6zmq8scj71m41f45x4r1j2njm0di25gd88cfy51969 NarSize: 2561970 References: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientPushesUseOnePush836095535/001/store/bw2m0qsymd9pb3vli6vfcmc3js5jg4xm-shared-dep1971 CA: text:sha256:1jyxv2kcnqfahwk7gkyhi9a8c9cwa29yw3935qrl84hf890y5maw19722026/10/25 13:49:38 INFO lead: acquired remote=192.0.2.1:12341973--- PASS: TestClientPushesUseOnePush (7.61s)19742026/10/25 13:49:38 INFO Received push request method=POST path=/api/pushes19752026/10/25 13:49:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19762026/10/25 13:49:38 INFO Uploading bsj7p2iiyazfisd5ragjfyqhkvmb5p9f-pinned-file.txt (128B)19772026/10/25 13:49:38 WARN Failed to register uploaded object key=bsj7p2iiyazfisd5ragjfyqhkvmb5p9f.ls error="server returned 404: 404 page not found\n"19782026/10/25 13:49:38 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19792026/10/25 13:49:38 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19802026/10/25 13:49:38 INFO Signed narinfos id=1 count=119812026/10/25 13:49:38 INFO Uploading 1 narinfos1982--- PASS: TestDeleteClosuresRacingPins (9.92s)19832026/10/25 13:49:39 INFO Received complete push request method=POST path=/api/pushes/1/complete19842026/10/25 13:49:39 WARN Failed to register uploaded object key=bsj7p2iiyazfisd5ragjfyqhkvmb5p9f.narinfo error="server returned 404: 404 page not found\n"19852026/10/25 13:49:39 INFO Completed push id=1 objects=3 duration=7.1385ms19862026/10/25 13:49:39 INFO Upload complete. (175ms)19872026/10/25 13:49:39 INFO Received push request method=POST path=/api/pushes19882026/10/25 13:49:39 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19892026/10/25 13:49:39 INFO Uploading gyz229ds2nqi59yhhd38h9phz4wavzya-top (264B)19902026/10/25 13:49:39 INFO Uploading x06wpqi3mja8d09xq1n6jv9szd4im2m8-shared-dep (136B)19912026/10/25 13:49:39 INFO Received push request method=POST path=/api/pushes19922026/10/25 13:49:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19932026/10/25 13:49:39 INFO Uploading kflp45pfg305fl48z1ghxwwi7a24ml6a-unpinned-file.txt (128B)19942026/10/25 13:49:39 WARN Failed to register uploaded object key=gyz229ds2nqi59yhhd38h9phz4wavzya.ls error="server returned 404: 404 page not found\n"19952026/10/25 13:49:39 WARN Failed to register uploaded object key=x06wpqi3mja8d09xq1n6jv9szd4im2m8.ls error="server returned 404: 404 page not found\n"19962026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19972026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/1fbvxq8pwa0hljfd81qnmmk7cxgxricwij618by3jjx258i9bavv.nar.zst error="server returned 404: 404 page not found\n"19982026/10/25 13:49:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19992026/10/25 13:49:39 INFO Signed narinfos id=1 count=220002026/10/25 13:49:39 INFO Uploading 2 narinfos20012026/10/25 13:49:39 WARN Failed to register uploaded object key=kflp45pfg305fl48z1ghxwwi7a24ml6a.ls error="server returned 404: 404 page not found\n"20022026/10/25 13:49:39 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20032026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20042026/10/25 13:49:39 INFO Signed narinfos id=2 count=120052026/10/25 13:49:39 INFO Uploading 1 narinfos20062026/10/25 13:49:39 WARN Failed to register uploaded object key=x06wpqi3mja8d09xq1n6jv9szd4im2m8.narinfo error="server returned 404: 404 page not found\n"20072026/10/25 13:49:39 INFO Received complete push request method=POST path=/api/pushes/1/complete20082026/10/25 13:49:39 WARN Failed to register uploaded object key=gyz229ds2nqi59yhhd38h9phz4wavzya.narinfo error="server returned 404: 404 page not found\n"20092026/10/25 13:49:39 INFO Completed push id=1 objects=6 duration=15.16575ms20102026/10/25 13:49:39 INFO Upload complete. (219ms)20112026/10/25 13:49:39 INFO Received complete push request method=POST path=/api/pushes/2/complete20122026/10/25 13:49:39 WARN Failed to register uploaded object key=kflp45pfg305fl48z1ghxwwi7a24ml6a.narinfo error="server returned 404: 404 page not found\n"2013=== NAME TestClientSharedPathCommittedMidPush2014 client_integration_test.go:680: Retrieved narinfo from S3:2015 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientSharedPathCommittedMidPush2965192580/001/store/x06wpqi3mja8d09xq1n6jv9szd4im2m8-shared-dep2016 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2017 Compression: zstd2018 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822019 NarSize: 1362020 References: 2021 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n20222026/10/25 13:49:39 INFO Completed push id=2 objects=3 duration=548.542µs20232026/10/25 13:49:39 INFO Upload complete. (186ms)2024 client_integration_test.go:680: Retrieved narinfo from S3:2025 StorePath: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientSharedPathCommittedMidPush2965192580/001/store/gyz229ds2nqi59yhhd38h9phz4wavzya-top2026 URL: nar/1fbvxq8pwa0hljfd81qnmmk7cxgxricwij618by3jjx258i9bavv.nar.zst2027 Compression: zstd2028 NarHash: sha256:1fbvxq8pwa0hljfd81qnmmk7cxgxricwij618by3jjx258i9bavv2029 NarSize: 2642030 References: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientSharedPathCommittedMidPush2965192580/001/store/x06wpqi3mja8d09xq1n6jv9szd4im2m8-shared-dep2031 CA: text:sha256:0sqaw42pvdma6fqfwkg990jcczs5d9cqy1nmgsfpvm1wmbgnx3y62032=== NAME TestClientMultipleUploads2033 client_integration_test.go:358: Created store path 0: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientMultipleUploads296246892/001/store/ph6ml88bbnk3dgqb7p0rgbjyvqp40z7c-test-file-0.txt20342026/10/25 13:49:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures20352026/10/25 13:49:39 INFO Garbage collection started20362026/10/25 13:49:39 INFO Aborted multipart uploads count=0 kept=02037--- PASS: TestClientSharedPathCommittedMidPush (6.82s)20382026/10/25 13:49:39 WARN Force mode enabled - objects will be deleted immediately without grace period2039=== NAME TestClientMultipleUploads2040 client_integration_test.go:358: Created store path 1: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientMultipleUploads296246892/001/store/0q2h69qdbr1x7rzvcw8l8rkavlc50ps1-test-file-1.txt20412026/10/25 13:49:39 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=020422026/10/25 13:49:39 INFO Vacuumed table table=pending_closures20432026/10/25 13:49:39 INFO Vacuumed table table=pending_objects20442026/10/25 13:49:39 INFO Vacuumed table table=multipart_uploads20452026/10/25 13:49:39 INFO Vacuumed table table=closures20462026/10/25 13:49:39 INFO Vacuumed table table=objects2047 client_integration_test.go:358: Created store path 2: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestClientMultipleUploads296246892/001/store/9yj35k663dmb2f0q7rxzvs9ixrwncr12-test-file-2.txt20482026/10/25 13:49:39 INFO Received push request method=POST path=/api/pushes20492026/10/25 13:49:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)20502026/10/25 13:49:39 INFO Uploading 0q2h69qdbr1x7rzvcw8l8rkavlc50ps1-test-file-1.txt (160B)20512026/10/25 13:49:39 INFO Uploading ph6ml88bbnk3dgqb7p0rgbjyvqp40z7c-test-file-0.txt (160B)20522026/10/25 13:49:39 INFO Uploading 9yj35k663dmb2f0q7rxzvs9ixrwncr12-test-file-2.txt (160B)20532026/10/25 13:49:39 WARN Failed to register uploaded object key=9yj35k663dmb2f0q7rxzvs9ixrwncr12.ls error="server returned 404: 404 page not found\n"20542026/10/25 13:49:39 WARN Failed to register uploaded object key=ph6ml88bbnk3dgqb7p0rgbjyvqp40z7c.ls error="server returned 404: 404 page not found\n"20552026/10/25 13:49:39 WARN Failed to register uploaded object key=0q2h69qdbr1x7rzvcw8l8rkavlc50ps1.ls error="server returned 404: 404 page not found\n"20562026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"20572026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"20582026/10/25 13:49:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20592026/10/25 13:49:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"20602026/10/25 13:49:39 INFO Signed narinfos id=1 count=320612026/10/25 13:49:39 INFO Uploading 3 narinfos20622026/10/25 13:49:39 WARN Failed to register uploaded object key=ph6ml88bbnk3dgqb7p0rgbjyvqp40z7c.narinfo error="server returned 404: 404 page not found\n"20632026/10/25 13:49:39 WARN Failed to register uploaded object key=9yj35k663dmb2f0q7rxzvs9ixrwncr12.narinfo error="server returned 404: 404 page not found\n"20642026/10/25 13:49:39 INFO Received complete push request method=POST path=/api/pushes/1/complete20652026/10/25 13:49:39 WARN Failed to register uploaded object key=0q2h69qdbr1x7rzvcw8l8rkavlc50ps1.narinfo error="server returned 404: 404 page not found\n"20662026/10/25 13:49:39 INFO Completed push id=1 objects=9 duration=11.053292ms20672026/10/25 13:49:39 INFO Upload complete. (182ms)2068 client_integration_test.go:369: Uploaded 3 paths in 216.6335ms2069--- PASS: TestClientMultipleUploads (6.09s)20702026/10/25 13:49:39 INFO Received uploads request method=POST path=/api/pending_closures2071--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2072 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.91s)2073 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.00s)20742026/10/25 13:49:39 INFO lead: released remote=192.0.2.1:12342075--- PASS: TestLeadElectsOneAndHandsOver (9.20s)20762026/10/25 13:49:40 INFO Aborted multipart uploads count=0 kept=020772026/10/25 13:49:40 WARN Force mode enabled - objects will be deleted immediately without grace period20782026/10/25 13:49:40 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-config20792026/10/25 13:49:40 WARN Request failed, retrying attempt=2 backoff=209.442146ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20802026/10/25 13:49:40 INFO Aborted multipart uploads count=0 kept=020812026/10/25 13:49:40 WARN Force mode enabled - objects will be deleted immediately without grace period20822026/10/25 13:49:40 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58674/bucket96/?delete=\": context canceled"2083--- PASS: TestGCEndsOnShutdown (0.00s)2084 --- PASS: TestGCEndsOnShutdown/before_the_run (5.06s)2085 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.12s)2086 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.96s)2087--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.28s)20882026/10/25 13:49:40 WARN Request failed, retrying attempt=3 backoff=427.480689ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/25 13:49:40 INFO Received uploads request method=POST path=/api/pending_closures20902026/10/25 13:49:40 INFO Aborted multipart uploads count=0 kept=020912026/10/25 13:49:40 WARN Force mode enabled - objects will be deleted immediately without grace period20922026/10/25 13:49:40 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=020932026/10/25 13:49:40 INFO Vacuumed table table=pending_closures20942026/10/25 13:49:40 INFO Vacuumed table table=pending_objects20952026/10/25 13:49:40 INFO Vacuumed table table=multipart_uploads20962026/10/25 13:49:40 INFO Vacuumed table table=closures20972026/10/25 13:49:40 INFO Vacuumed table table=objects2098--- PASS: TestPendingClosureWriteTimeout (0.01s)2099 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2100 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2101 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2102 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.04s)21032026/10/25 13:49:40 WARN Request failed, retrying attempt=4 backoff=879.096087ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2104--- PASS: TestConnectWaitsForAPeerMigration (7.69s)21052026/10/25 13:49:40 INFO Received uploads request method=POST path=/api/pending_closures21062026/10/25 13:49:40 INFO Aborted multipart uploads count=0 kept=021072026/10/25 13:49:41 WARN Force mode enabled - objects will be deleted immediately without grace period21082026/10/25 13:49:41 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=021092026/10/25 13:49:41 INFO Vacuumed table table=pending_closures21102026/10/25 13:49:41 INFO Vacuumed table table=pending_objects21112026/10/25 13:49:41 INFO Vacuumed table table=multipart_uploads21122026/10/25 13:49:41 INFO Vacuumed table table=closures21132026/10/25 13:49:41 INFO Vacuumed table table=objects2114--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2115 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.25s)2116 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (4.84s)21172026/10/25 13:49:41 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021182026/10/25 13:49:41 INFO Received create pin request method=POST path=/api/pins/myapp21192026/10/25 13:49:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21202026/10/25 13:49:41 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestPinProtectsFromGC1387639887/001/store/bsj7p2iiyazfisd5ragjfyqhkvmb5p9f-pinned-file.txt narinfo_key=bsj7p2iiyazfisd5ragjfyqhkvmb5p9f.narinfo21212026/10/25 13:49:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures21222026/10/25 13:49:41 INFO Garbage collection started21232026/10/25 13:49:41 INFO Aborted multipart uploads count=0 kept=021242026/10/25 13:49:41 WARN Force mode enabled - objects will be deleted immediately without grace period21252026/10/25 13:49:41 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=021262026/10/25 13:49:41 INFO Vacuumed table table=pending_closures21272026/10/25 13:49:41 INFO Vacuumed table table=pending_objects21282026/10/25 13:49:41 INFO Vacuumed table table=multipart_uploads21292026/10/25 13:49:41 INFO Vacuumed table table=closures21302026/10/25 13:49:41 INFO Vacuumed table table=objects21312026/10/25 13:49:41 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21322026/10/25 13:49:41 WARN Request failed, retrying attempt=5 backoff=1.526841866s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21332026/10/25 13:49:43 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"21342026/10/25 13:49:43 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-config21352026/10/25 13:49:43 WARN Request failed, retrying attempt=2 backoff=202.449109ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2136=== NAME TestPinProtectsFromGC2137 client_integration_test.go:840: Pin successfully protected closure from garbage collection2138--- PASS: TestPinProtectsFromGC (11.29s)21392026/10/25 13:49:43 WARN Request failed, retrying attempt=3 backoff=393.211364ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21402026/10/25 13:49:43 WARN Request failed, retrying attempt=4 backoff=824.402743ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/25 13:49:44 WARN Request failed, retrying attempt=5 backoff=1.753232295s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/25 13:49:46 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_closures21432026/10/25 13:49:46 WARN Request failed, retrying attempt=2 backoff=201.549165ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21442026/10/25 13:49:46 WARN Request failed, retrying attempt=3 backoff=384.785823ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21452026/10/25 13:49:47 WARN Request failed, retrying attempt=4 backoff=864.31297ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/25 13:49:48 WARN Request failed, retrying attempt=5 backoff=1.741054706s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2147--- PASS: TestClientErrorHandling (0.02s)2148 --- PASS: TestClientErrorHandling/InvalidStorePath (4.44s)2149 --- PASS: TestClientErrorHandling/InvalidAuthToken (4.41s)2150 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.27s)2151PASS21522026-10-25 13:49:49.973 UTC [40838] LOG: received smart shutdown request21532026-10-25 13:49:49.974 UTC [40838] LOG: background worker "logical replication launcher" (PID 40848) exited with exit code 121542026-10-25 13:49:49.978 UTC [40843] LOG: shutting down21552026-10-25 13:49:49.978 UTC [40843] LOG: checkpoint starting: shutdown immediate21562026-10-25 13:49:51.249 UTC [40843] LOG: checkpoint complete: wrote 11683 buffers (71.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=0.566 s, sync=0.660 s, total=1.272 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=502064 kB, estimate=502064 kB; lsn=0/201D92E0, redo lsn=0/201D92E021572026-10-25 13:49:51.256 UTC [40838] LOG: database system is shut down2158Running OIDC tests...2159=== RUN TestAudienceForIssuer2160=== PAUSE TestAudienceForIssuer2161=== RUN TestGlobMatch2162=== PAUSE TestGlobMatch2163=== RUN TestValidateToken_ValidToken2164=== PAUSE TestValidateToken_ValidToken2165=== RUN TestValidateToken_WrongAudience2166=== PAUSE TestValidateToken_WrongAudience2167=== RUN TestValidateToken_Expired2168=== PAUSE TestValidateToken_Expired2169=== RUN TestValidateToken_BoundClaimsMismatch2170=== PAUSE TestValidateToken_BoundClaimsMismatch2171=== RUN TestValidateToken_BoundSubjectMismatch2172=== PAUSE TestValidateToken_BoundSubjectMismatch2173=== RUN TestValidateToken_MultipleProviders2174=== PAUSE TestValidateToken_MultipleProviders2175=== RUN TestValidateToken_NoMatchingProvider2176=== PAUSE TestValidateToken_NoMatchingProvider2177=== RUN TestValidateToken_KubernetesServiceAccount2178=== PAUSE TestValidateToken_KubernetesServiceAccount2179=== RUN TestNewValidator_KubernetesRequiresCA2180=== PAUSE TestNewValidator_KubernetesRequiresCA2181=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2182=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2183=== RUN TestPins_ReservedForMatchingRule2184=== PAUSE TestPins_ReservedForMatchingRule2185=== RUN TestPins_TopLevelShorthand2186=== PAUSE TestPins_TopLevelShorthand2187=== RUN TestPins_ConfigValidation2188=== PAUSE TestPins_ConfigValidation2189=== RUN TestScopes_LegacyProviderDefaultsToWrite2190=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2191=== RUN TestScopes_Rules2192=== PAUSE TestScopes_Rules2193=== RUN TestScopes_ConfigValidation2194=== PAUSE TestScopes_ConfigValidation2195=== CONT TestAudienceForIssuer2196--- PASS: TestAudienceForIssuer (0.00s)2197=== CONT TestValidateToken_NoMatchingProvider2198=== CONT TestPins_ConfigValidation2199=== CONT TestValidateToken_Expired2200=== CONT TestValidateToken_WrongAudience2201=== CONT TestValidateToken_ValidToken2202=== CONT TestGlobMatch2203=== RUN TestGlobMatch/foo_foo2204=== PAUSE TestGlobMatch/foo_foo2205=== RUN TestGlobMatch/foo_bar2206=== PAUSE TestGlobMatch/foo_bar2207=== RUN TestGlobMatch/*_2208=== PAUSE TestGlobMatch/*_2209=== RUN TestGlobMatch/*_anything2210=== PAUSE TestGlobMatch/*_anything2211=== RUN TestGlobMatch/foo*_foo2212=== PAUSE TestGlobMatch/foo*_foo2213=== RUN TestGlobMatch/foo*_foobar2214=== PAUSE TestGlobMatch/foo*_foobar2215=== RUN TestGlobMatch/foo*_bar2216=== PAUSE TestGlobMatch/foo*_bar2217--- PASS: TestPins_ConfigValidation (0.00s)2218=== CONT TestValidateToken_BoundClaimsMismatch2219=== RUN TestGlobMatch/*bar_bar2220=== PAUSE TestGlobMatch/*bar_bar2221=== RUN TestGlobMatch/*bar_foobar2222=== PAUSE TestGlobMatch/*bar_foobar2223=== RUN TestGlobMatch/*bar_foo2224=== PAUSE TestGlobMatch/*bar_foo2225=== RUN TestGlobMatch/foo*bar_foobar2226=== PAUSE TestGlobMatch/foo*bar_foobar2227=== RUN TestGlobMatch/foo*bar_foo123bar2228=== PAUSE TestGlobMatch/foo*bar_foo123bar2229=== RUN TestGlobMatch/foo*bar_foobarbaz2230=== PAUSE TestGlobMatch/foo*bar_foobarbaz2231=== RUN TestGlobMatch/*/*_foo/bar2232=== PAUSE TestGlobMatch/*/*_foo/bar2233=== RUN TestGlobMatch/*/*_foo2234=== PAUSE TestGlobMatch/*/*_foo2235=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2236=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2237=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02238=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02239=== RUN TestGlobMatch/refs/*/main_refs/heads/main2240=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2241=== RUN TestGlobMatch/fo?_foo2242=== PAUSE TestGlobMatch/fo?_foo2243=== RUN TestGlobMatch/fo?_fo2244=== PAUSE TestGlobMatch/fo?_fo2245=== RUN TestGlobMatch/fo?_fooo2246=== PAUSE TestGlobMatch/fo?_fooo2247=== RUN TestGlobMatch/?oo_foo2248=== PAUSE TestGlobMatch/?oo_foo2249=== RUN TestGlobMatch/?oo_boo2250=== PAUSE TestGlobMatch/?oo_boo2251=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2252=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2253=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2254=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2255=== CONT TestGlobMatch/foo_foo2256=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2257=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2258=== CONT TestGlobMatch/?oo_boo2259=== CONT TestGlobMatch/?oo_foo2260=== CONT TestGlobMatch/fo?_fooo2261=== CONT TestGlobMatch/fo?_fo2262=== CONT TestGlobMatch/fo?_foo2263=== CONT TestGlobMatch/refs/*/main_refs/heads/main2264=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02265=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2266=== CONT TestGlobMatch/*/*_foo2267=== CONT TestGlobMatch/*/*_foo/bar2268=== CONT TestGlobMatch/foo*bar_foobarbaz2269=== CONT TestGlobMatch/foo*bar_foo123bar2270=== CONT TestGlobMatch/foo*bar_foobar2271=== CONT TestGlobMatch/*bar_foo2272=== CONT TestGlobMatch/*bar_foobar2273=== CONT TestGlobMatch/*bar_bar2274=== CONT TestGlobMatch/foo*_bar2275=== CONT TestGlobMatch/foo*_foobar2276=== CONT TestGlobMatch/foo*_foo2277=== CONT TestGlobMatch/*_anything2278=== CONT TestGlobMatch/*_2279=== CONT TestGlobMatch/foo_bar2280--- PASS: TestGlobMatch (0.00s)2281 --- PASS: TestGlobMatch/foo_foo (0.00s)2282 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2283 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2284 --- PASS: TestGlobMatch/?oo_boo (0.00s)2285 --- PASS: TestGlobMatch/?oo_foo (0.00s)2286 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2287 --- PASS: TestGlobMatch/fo?_fo (0.00s)2288 --- PASS: TestGlobMatch/fo?_foo (0.00s)2289 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2290 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2291 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2292 --- PASS: TestGlobMatch/*/*_foo (0.00s)2293 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2294 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2295 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2296 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2297 --- PASS: TestGlobMatch/*bar_foo (0.00s)2298 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2299 --- PASS: TestGlobMatch/*bar_bar (0.00s)2300 --- PASS: TestGlobMatch/foo*_bar (0.00s)2301 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2302 --- PASS: TestGlobMatch/foo*_foo (0.00s)2303 --- PASS: TestGlobMatch/*_anything (0.00s)2304 --- PASS: TestGlobMatch/*_ (0.00s)2305 --- PASS: TestGlobMatch/foo_bar (0.00s)2306=== CONT TestScopes_Rules2307=== CONT TestScopes_ConfigValidation2308=== CONT TestScopes_LegacyProviderDefaultsToWrite2309=== CONT TestPins_ReservedForMatchingRule2310=== CONT TestPins_TopLevelShorthand2311--- PASS: TestScopes_ConfigValidation (0.00s)2312=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2313=== CONT TestNewValidator_KubernetesRequiresCA2314=== CONT TestValidateToken_MultipleProviders2315=== CONT TestValidateToken_BoundSubjectMismatch2316=== CONT TestValidateToken_KubernetesServiceAccount23172026/10/25 13:49:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59161/oidc2318--- PASS: TestValidateToken_ValidToken (0.05s)23192026/10/25 13:49:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59163/oidc23202026/10/25 13:49:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59165/oidc2321--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)2322--- PASS: TestPins_ReservedForMatchingRule (0.06s)23232026/10/25 13:49:53 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232324--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.09s)23252026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59171/oidc23262026/10/25 13:49:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59170/oidc2327--- PASS: TestScopes_Rules (0.11s)2328--- PASS: TestValidateToken_NoMatchingProvider (0.12s)23292026/10/25 13:49:53 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:591752330--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)23312026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59177/oidc2332--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)23332026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59180/oidc23342026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59179/oidc2335--- PASS: TestValidateToken_Expired (0.14s)2336--- PASS: TestPins_TopLevelShorthand (0.13s)23372026/10/25 13:49:53 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59169/oidc23382026/10/25 13:49:53 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59183/oidc2339--- PASS: TestValidateToken_MultipleProviders (0.13s)23402026/10/25 13:49:53 http: TLS handshake error from 127.0.0.1:59187: read tcp 127.0.0.1:59186->127.0.0.1:59187: use of closed network connection2341--- PASS: TestNewValidator_KubernetesRequiresCA (0.14s)23422026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59188/oidc2343--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.17s)23442026/10/25 13:49:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59190/oidc2345--- PASS: TestValidateToken_WrongAudience (0.20s)2346PASS2347Running hook tests...2348=== RUN TestSendPathsEmpty2349=== PAUSE TestSendPathsEmpty2350=== RUN TestQueueEnqueueAndFetch2351=== PAUSE TestQueueEnqueueAndFetch2352=== RUN TestQueueDeduplication2353=== PAUSE TestQueueDeduplication2354=== RUN TestQueueRemove2355=== PAUSE TestQueueRemove2356=== RUN TestQueueFetchBatchLimit2357=== PAUSE TestQueueFetchBatchLimit2358=== RUN TestQueueRetryMovesToBack2359=== PAUSE TestQueueRetryMovesToBack2360=== RUN TestQueueFetchRemoveLifecycle2361=== PAUSE TestQueueFetchRemoveLifecycle2362=== RUN TestQueueConcurrentWriters2363=== PAUSE TestQueueConcurrentWriters2364=== RUN TestQueueRemoveLargeClosure2365=== PAUSE TestQueueRemoveLargeClosure2366=== RUN TestServerClientIntegration2367--- PASS: TestServerClientIntegration (0.00s)2368=== RUN TestServerQueueError23692026/10/25 13:49:53 ERROR Failed to queue paths error="permission denied" count=12370--- PASS: TestServerQueueError (0.00s)2371=== RUN TestGetListenerSocketActivation2372 server_test.go:146: systemd socket activation does not exist on darwin2373--- SKIP: TestGetListenerSocketActivation (0.00s)2374=== RUN TestDrainIsolatesPoisonPath2375=== PAUSE TestDrainIsolatesPoisonPath2376=== RUN TestRunNotBlockedByPoisonHead2377=== PAUSE TestRunNotBlockedByPoisonHead2378=== RUN TestDrainGivesUpWhenServerDown2379=== PAUSE TestDrainGivesUpWhenServerDown2380=== RUN TestFailedPathPrunedByLaterClosure2381=== PAUSE TestFailedPathPrunedByLaterClosure2382=== RUN TestWorkerUploadsAndRemoves2383=== PAUSE TestWorkerUploadsAndRemoves2384=== RUN TestWorkerSkipsGCdPaths2385=== PAUSE TestWorkerSkipsGCdPaths2386=== RUN TestWorkerPrunesClosureDeps2387=== PAUSE TestWorkerPrunesClosureDeps2388=== RUN TestDrainTimeout2389=== PAUSE TestDrainTimeout2390=== RUN TestWorkerRemoveFailureIsNotProgress2391=== PAUSE TestWorkerRemoveFailureIsNotProgress2392=== RUN TestWorkerKeepsPathItCannotStat2393=== PAUSE TestWorkerKeepsPathItCannotStat2394=== CONT TestSendPathsEmpty2395=== CONT TestWorkerSkipsGCdPaths2396--- PASS: TestSendPathsEmpty (0.00s)2397=== CONT TestWorkerKeepsPathItCannotStat2398=== CONT TestWorkerRemoveFailureIsNotProgress2399=== CONT TestDrainTimeout2400=== CONT TestWorkerPrunesClosureDeps2401=== CONT TestRunNotBlockedByPoisonHead2402=== CONT TestDrainIsolatesPoisonPath2403=== CONT TestQueueRemoveLargeClosure2404=== CONT TestQueueConcurrentWriters2405=== CONT TestFailedPathPrunedByLaterClosure2406=== CONT TestQueueFetchRemoveLifecycle2407=== CONT TestWorkerUploadsAndRemoves2408=== CONT TestQueueRetryMovesToBack2409=== CONT TestQueueFetchBatchLimit2410=== CONT TestQueueDeduplication2411=== CONT TestQueueEnqueueAndFetch2412=== CONT TestQueueRemove2413=== CONT TestDrainGivesUpWhenServerDown24142026/10/25 13:49:53 INFO Upload queue status pending=324152026/10/25 13:49:53 INFO Upload queue status pending=224162026/10/25 13:49:53 INFO Uploading batch count=124172026/10/25 13:49:53 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa error="stat /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa: permission denied"24182026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=12419--- PASS: TestQueueFetchBatchLimit (0.01s)24202026/10/25 13:49:53 INFO Uploading batch count=424212026/10/25 13:49:53 INFO Uploading batch count=124222026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=124232026/10/25 13:49:53 INFO Upload queue status pending=224242026/10/25 13:49:53 INFO Uploading batch count=224252026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=424262026/10/25 13:49:53 INFO Uploading batch count=124272026/10/25 13:49:53 INFO Upload queue status pending=224282026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainIsolatesPoisonPath1160709177/002/bbb24292026/10/25 13:49:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerSkipsGCdPaths3210429971/002/nonexistent24302026/10/25 13:49:53 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa error="stat /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa: permission denied"24312026/10/25 13:49:53 INFO Uploading batch count=12432--- PASS: TestQueueRemove (0.01s)24332026/10/25 13:49:53 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa error="stat /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerKeepsPathItCannotStat924803898/002/locked/aaa: permission denied"24342026/10/25 13:49:53 INFO Uploading batch count=12435--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24362026/10/25 13:49:53 INFO Uploading batch count=224372026/10/25 13:49:53 INFO Uploading batch count=224382026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=224392026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/a24402026/10/25 13:49:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerRemoveFailureIsNotProgress1643513810/002/nonexistent24412026/10/25 13:49:53 ERROR Drain finished with paths left in queue remaining=124422026/10/25 13:49:53 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124432026/10/25 13:49:53 INFO Uploading batch count=124442026/10/25 13:49:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerRemoveFailureIsNotProgress1643513810/002/nonexistent24452026/10/25 13:49:53 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124462026/10/25 13:49:53 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestWorkerRemoveFailureIsNotProgress1643513810/002/nonexistent24472026/10/25 13:49:53 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124482026/10/25 13:49:53 ERROR Drain finished with paths left in queue remaining=124492026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/b2450--- PASS: TestQueueEnqueueAndFetch (0.01s)24512026/10/25 13:49:53 INFO Uploading batch count=124522026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=12453--- PASS: TestQueueRetryMovesToBack (0.01s)2454--- PASS: TestQueueDeduplication (0.01s)24552026/10/25 13:49:53 INFO Uploading batch count=224562026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=224572026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/c24582026/10/25 13:49:53 INFO Uploading batch count=124592026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=12460--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)24612026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/d24622026/10/25 13:49:53 INFO Uploading batch count=224632026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=224642026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/e24652026/10/25 13:49:53 INFO Uploading batch count=124662026/10/25 13:49:53 ERROR Upload failed error="upload failed" count=124672026/10/25 13:49:53 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestDrainGivesUpWhenServerDown927698605/002/f24682026/10/25 13:49:53 ERROR Drain finished with paths left in queue remaining=124692026/10/25 13:49:53 ERROR Drain finished with paths left in queue remaining=102470--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2471--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2472--- PASS: TestDrainIsolatesPoisonPath (0.02s)2473--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2474--- PASS: TestWorkerSkipsGCdPaths (0.03s)2475--- PASS: TestWorkerPrunesClosureDeps (0.03s)2476--- PASS: TestWorkerUploadsAndRemoves (0.03s)2477--- PASS: TestQueueRemoveLargeClosure (0.05s)2478--- PASS: TestQueueConcurrentWriters (0.16s)24792026/10/25 13:49:53 ERROR Upload failed error="context deadline exceeded" count=224802026/10/25 13:49:53 ERROR Drain finished with paths left in queue remaining=42481--- PASS: TestDrainTimeout (0.22s)24822026/10/25 13:49:54 INFO Uploading batch count=124832026/10/25 13:49:54 INFO Uploading batch count=124842026/10/25 13:49:54 INFO Uploading batch count=124852026/10/25 13:49:54 ERROR Upload failed error="upload failed" count=124862026/10/25 13:49:54 INFO Uploading batch count=124872026/10/25 13:49:54 ERROR Upload failed error="upload failed" count=124882026/10/25 13:49:54 INFO Uploading batch count=124892026/10/25 13:49:54 ERROR Upload failed error="upload failed" count=124902026/10/25 13:49:54 INFO Uploading batch count=124912026/10/25 13:49:54 ERROR Upload failed error="upload failed" count=124922026/10/25 13:49:54 ERROR Drain finished with paths left in queue remaining=12493--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2494PASS2495Running signing tests...2496=== RUN TestExternalSigner2497=== PAUSE TestExternalSigner2498=== RUN TestExternalSignerWrongPublicKey2499=== PAUSE TestExternalSignerWrongPublicKey2500=== RUN TestExternalSignerErrors2501=== PAUSE TestExternalSignerErrors2502=== RUN TestExternalSignerRestartsAfterCrash2503=== PAUSE TestExternalSignerRestartsAfterCrash2504=== RUN TestExternalSignerProgramErrorKeepsProcess2505=== PAUSE TestExternalSignerProgramErrorKeepsProcess2506=== RUN TestExternalSignerClose2507=== PAUSE TestExternalSignerClose2508=== RUN TestExternalSignerRejectsInvalidPublicKey2509=== PAUSE TestExternalSignerRejectsInvalidPublicKey2510=== RUN TestExternalSignerCancellation2511=== PAUSE TestExternalSignerCancellation2512=== RUN TestGenerateFingerprint2513=== PAUSE TestGenerateFingerprint2514=== RUN TestParseSigningKey2515=== PAUSE TestParseSigningKey2516=== RUN TestSign2517=== PAUSE TestSign2518=== RUN TestSignBatch2519=== PAUSE TestSignBatch2520=== RUN TestNilKeyPublicKey2521=== PAUSE TestNilKeyPublicKey2522=== RUN TestSignErrors2523=== PAUSE TestSignErrors2524=== CONT TestExternalSigner2525=== CONT TestExternalSignerCancellation2526=== CONT TestGenerateFingerprint2527=== CONT TestExternalSignerRejectsInvalidPublicKey2528=== CONT TestExternalSignerErrors2529=== RUN TestExternalSignerRejectsInvalidPublicKey/#002530=== RUN TestGenerateFingerprint/basic_with_references2531=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002532=== CONT TestExternalSignerRestartsAfterCrash2533=== CONT TestExternalSignerClose2534=== CONT TestSignBatch2535=== CONT TestSignErrors2536=== CONT TestNilKeyPublicKey2537--- PASS: TestNilKeyPublicKey (0.00s)2538=== CONT TestParseSigningKey2539=== RUN TestParseSigningKey/valid_32-byte_key2540=== PAUSE TestParseSigningKey/valid_32-byte_key2541=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2542=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2543=== RUN TestParseSigningKey/no_colon2544=== PAUSE TestParseSigningKey/no_colon2545=== RUN TestParseSigningKey/empty_name2546=== PAUSE TestParseSigningKey/empty_name2547=== RUN TestParseSigningKey/invalid_base642548=== PAUSE TestParseSigningKey/invalid_base642549=== RUN TestParseSigningKey/wrong_length2550=== PAUSE TestParseSigningKey/wrong_length2551=== CONT TestParseSigningKey/valid_32-byte_key2552=== CONT TestSign2553=== CONT TestExternalSignerWrongPublicKey2554=== CONT TestParseSigningKey/empty_name2555=== CONT TestParseSigningKey/wrong_length2556=== CONT TestParseSigningKey/invalid_base642557=== CONT TestParseSigningKey/no_colon2558=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2559=== CONT TestExternalSignerProgramErrorKeepsProcess2560=== RUN TestExternalSignerErrors/exit_at_startup2561=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2562=== PAUSE TestExternalSignerErrors/exit_at_startup2563=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2564=== RUN TestExternalSignerErrors/unrequested_key2565=== PAUSE TestGenerateFingerprint/basic_with_references2566=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2567=== RUN TestGenerateFingerprint/no_references2568=== PAUSE TestExternalSignerErrors/unrequested_key2569=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2570=== PAUSE TestGenerateFingerprint/no_references2571=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2572=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2573=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2574=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2575=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2576=== RUN TestGenerateFingerprint/invalid_nar_hash_length2577=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2578=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2579=== RUN TestGenerateFingerprint/invalid_store_path_prefix2580=== RUN TestExternalSignerErrors/wrong_signature_name2581=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2582=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2583=== RUN TestGenerateFingerprint/invalid_reference_prefix2584=== PAUSE TestExternalSignerErrors/wrong_signature_name2585=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2586=== RUN TestExternalSignerErrors/wrong_signature_length2587=== CONT TestExternalSignerRejectsInvalidPublicKey/#002588=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2589=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2590=== PAUSE TestExternalSignerErrors/wrong_signature_length2591=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2592=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2593=== CONT TestGenerateFingerprint/basic_with_references2594=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2595--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2596 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2597 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2598 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2599 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2600 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2601=== CONT TestGenerateFingerprint/invalid_reference_prefix2602=== CONT TestGenerateFingerprint/invalid_store_path_prefix2603=== CONT TestGenerateFingerprint/invalid_nar_hash_length2604=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2605=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2606=== CONT TestGenerateFingerprint/no_references2607--- PASS: TestGenerateFingerprint (0.00s)2608 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2609 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2610 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2611 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2612 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2613 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2614 --- PASS: TestGenerateFingerprint/no_references (0.00s)2615=== RUN TestExternalSignerErrors/program_error2616=== PAUSE TestExternalSignerErrors/program_error2617=== RUN TestExternalSignerErrors/exit_on_request2618=== PAUSE TestExternalSignerErrors/exit_on_request2619=== RUN TestExternalSignerErrors/wrong_id2620=== PAUSE TestExternalSignerErrors/wrong_id2621=== RUN TestExternalSignerErrors/missing_signatures2622=== PAUSE TestExternalSignerErrors/missing_signatures2623=== RUN TestExternalSignerErrors/null_signatures2624=== PAUSE TestExternalSignerErrors/null_signatures2625=== RUN TestExternalSignerErrors/wrong_signatures_shape2626=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2627=== RUN TestExternalSignerErrors/too_few_signatures2628=== PAUSE TestExternalSignerErrors/too_few_signatures2629=== RUN TestExternalSignerErrors/invalid_JSON2630=== PAUSE TestExternalSignerErrors/invalid_JSON2631=== RUN TestExternalSignerErrors/wrong_shape2632=== PAUSE TestExternalSignerErrors/wrong_shape2633=== RUN TestExternalSignerErrors/null2634=== PAUSE TestExternalSignerErrors/null2635=== RUN TestExternalSignerErrors/missing_signature_name2636=== PAUSE TestExternalSignerErrors/missing_signature_name2637=== RUN TestExternalSignerErrors/invalid_signature_base642638=== PAUSE TestExternalSignerErrors/invalid_signature_base642639=== CONT TestExternalSignerErrors/exit_at_startup2640=== CONT TestExternalSignerErrors/null_signatures2641=== RUN TestSignErrors/nil_key2642=== CONT TestExternalSignerErrors/wrong_shape2643=== CONT TestExternalSignerErrors/missing_signature_name2644=== PAUSE TestSignErrors/nil_key2645=== RUN TestSignErrors/nil_narinfo2646=== CONT TestExternalSignerErrors/exit_on_request2647=== PAUSE TestSignErrors/nil_narinfo2648=== RUN TestSignErrors/invalid_narinfo2649=== PAUSE TestSignErrors/invalid_narinfo2650=== RUN TestSignErrors/canceled2651=== PAUSE TestSignErrors/canceled2652=== CONT TestSignErrors/nil_key2653=== CONT TestExternalSignerErrors/missing_signatures2654=== CONT TestExternalSignerErrors/null2655=== CONT TestExternalSignerErrors/invalid_signature_base642656=== CONT TestExternalSignerErrors/program_error2657=== CONT TestExternalSignerErrors/wrong_signature_name2658--- PASS: TestSignBatch (0.00s)2659=== CONT TestExternalSignerErrors/too_few_signatures2660=== CONT TestExternalSignerErrors/wrong_id2661--- PASS: TestSign (0.00s)2662=== CONT TestExternalSignerErrors/invalid_JSON2663--- PASS: TestParseSigningKey (0.00s)2664 --- PASS: TestParseSigningKey/empty_name (0.00s)2665 --- PASS: TestParseSigningKey/wrong_length (0.00s)2666 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2667 --- PASS: TestParseSigningKey/no_colon (0.00s)2668 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2669 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2670=== CONT TestExternalSignerErrors/wrong_signatures_shape2671=== CONT TestSignErrors/invalid_narinfo2672=== CONT TestSignErrors/nil_narinfo2673=== CONT TestExternalSignerErrors/wrong_signature_length2674=== CONT TestSignErrors/canceled2675--- PASS: TestSignErrors (0.00s)2676 --- PASS: TestSignErrors/nil_key (0.00s)2677 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2678 --- PASS: TestSignErrors/nil_narinfo (0.00s)2679 --- PASS: TestSignErrors/canceled (0.00s)2680=== CONT TestExternalSignerErrors/unrequested_key2681--- PASS: TestExternalSignerCancellation (0.24s)2682--- PASS: TestExternalSigner (0.42s)2683--- PASS: TestExternalSignerWrongPublicKey (0.59s)2684--- PASS: TestExternalSignerProgramErrorKeepsProcess (1.53s)2685--- PASS: TestExternalSignerClose (2.46s)2686--- PASS: TestExternalSignerRestartsAfterCrash (2.67s)2687/private/var/tb/3/scratch/8dda0facea84ca9b/build/TestExternalSignerRestartsAfterCrash2602625061/001/sign program: line 7: /private/var/tb/3/scratch/8dda0facea84ca9b/build/TestExternalSignerRestartsAfterCrash2602625061/001/sign program.starts: No such file or directory2688--- PASS: TestExternalSignerErrors (0.00s)2689 --- PASS: TestExternalSignerErrors/invalid_JSON (0.77s)2690 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.95s)2691 --- PASS: TestExternalSignerErrors/exit_on_request (1.15s)2692 --- PASS: TestExternalSignerErrors/wrong_id (1.34s)2693 --- PASS: TestExternalSignerErrors/wrong_shape (1.71s)2694 --- PASS: TestExternalSignerErrors/missing_signature_name (1.90s)2695 --- PASS: TestExternalSignerErrors/too_few_signatures (2.09s)2696 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.27s)2697 --- PASS: TestExternalSignerErrors/null (2.83s)2698 --- PASS: TestExternalSignerErrors/unrequested_key (3.02s)2699 --- PASS: TestExternalSignerErrors/missing_signatures (3.21s)2700 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.40s)2701 --- PASS: TestExternalSignerErrors/exit_at_startup (3.59s)2702 --- PASS: TestExternalSignerErrors/null_signatures (3.78s)2703 --- PASS: TestExternalSignerErrors/program_error (3.97s)2704 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (4.15s)2705PASS2706Running OpenBao signer tests...2707=== RUN TestSign2708=== PAUSE TestSign2709=== RUN TestSignErrors2710=== PAUSE TestSignErrors2711=== RUN TestServe2712=== PAUSE TestServe2713=== RUN TestServeRejectsGarbage2714=== PAUSE TestServeRejectsGarbage2715=== CONT TestSign2716=== CONT TestSignErrors2717=== RUN TestSignErrors/invalid_json2718=== CONT TestServeRejectsGarbage2719=== CONT TestServe2720=== PAUSE TestSignErrors/invalid_json2721=== RUN TestSignErrors/no_prefix2722=== PAUSE TestSignErrors/no_prefix2723--- PASS: TestServeRejectsGarbage (0.00s)2724=== RUN TestSignErrors/invalid_base642725=== PAUSE TestSignErrors/invalid_base642726=== RUN TestSignErrors/http_error2727=== PAUSE TestSignErrors/http_error2728=== CONT TestSignErrors/invalid_json2729=== CONT TestSignErrors/invalid_base642730=== CONT TestSignErrors/no_prefix2731=== CONT TestSignErrors/http_error2732--- PASS: TestServe (0.00s)2733--- PASS: TestSignErrors (0.00s)2734 --- PASS: TestSignErrors/http_error (0.00s)2735 --- PASS: TestSignErrors/invalid_base64 (0.00s)2736 --- PASS: TestSignErrors/invalid_json (0.00s)2737 --- PASS: TestSignErrors/no_prefix (0.00s)2738--- PASS: TestSign (0.00s)2739PASS