niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #445
· 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.22s)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 TestParsePathInfoJSONMultiplePaths117=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths118=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths119=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths120=== CONT TestDoWithRetry_BodyReplayedViaGetBody121=== CONT TestScriptTokenEmptyCommand122=== CONT TestScriptTokenScriptFails123--- PASS: TestScriptTokenEmptyCommand (0.00s)124=== CONT TestStreamPushGivesUpOnDeadServer125=== CONT TestScriptTokenBadJSON126=== CONT TestScriptTokenEmptyToken127=== CONT TestScriptTokenCachesUntilRefresh1282026/10/28 12:11:55 ERROR Upload failed error="connection refused" count=20129=== CONT TestScriptTokenNoExpiryRerunsEveryCall1302026/10/28 12:11:55 ERROR Server seems unavailable, giving up on batch untried=17131=== CONT TestFileTokenEmpty132=== CONT TestFileTokenMissing133=== CONT TestFileTokenReadsAndCaches134=== CONT TestStaticToken135=== CONT TestSetClientTLSErrors136=== CONT TestSetClientTLSDoesNotMutateDefaultTransport137=== CONT TestSetClientTLS138=== CONT TestStreamPushStopsWhenCanceled139=== CONT TestDumpPathWriterError140=== CONT TestClientSignaturesByStorePath141=== CONT TestStreamPushReportsSkippedPaths142=== CONT TestStreamPushReportsSignatures143=== CONT TestParsePathInfoJSON144=== CONT TestStreamPushRequestLine145=== CONT TestPathInfoHashCompatibility146=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths147=== RUN TestParsePathInfoJSON/Nix_format148=== CONT TestGetStorePathHash149--- PASS: TestStaticToken (0.00s)150=== RUN TestGetStorePathHash/valid_store_path151=== CONT TestStreamPushIsolatesFailures152--- PASS: TestClientSignaturesByStorePath (0.00s)153=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)154--- PASS: TestStreamPushStopsWhenCanceled (0.00s)155=== CONT TestStreamPushBatchesUnderLoad156=== CONT TestConvertHashToNix32157=== RUN TestConvertHashToNix32/SRI_format_to_Nix32158=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32159=== RUN TestConvertHashToNix32/already_Nix32_format160=== PAUSE TestConvertHashToNix32/already_Nix32_format161=== RUN TestConvertHashToNix32/invalid_format162=== PAUSE TestConvertHashToNix32/invalid_format163=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== CONT TestStreamPushReportsEveryPath165=== PAUSE TestParsePathInfoJSON/Nix_format166=== PAUSE TestGetStorePathHash/valid_store_path167--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)168=== CONT TestEncodeNixBase32WithRealHash169--- PASS: TestEncodeNixBase32WithRealHash (0.00s)170=== CONT TestEncodeNixBase32171--- PASS: TestFileTokenEmpty (0.01s)172=== CONT TestShellSplitErrors173=== CONT TestRateLimiterFeedback174=== CONT TestShellSplit175=== CONT TestDoWithRetry_FinalResponseBodyReadable176--- PASS: TestStreamPushReportsEveryPath (0.00s)177--- PASS: TestShellSplitErrors (0.00s)178--- PASS: TestShellSplit (0.00s)179--- PASS: TestScriptTokenScriptFails (0.01s)180=== CONT TestRetryTimeoutOutlastsMaxRetries181=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false184=== RUN TestEncodeNixBase32/test_string_hash185=== RUN TestParsePathInfoJSON/Lix_format186--- PASS: TestFileTokenMissing (0.01s)187=== CONT TestPathInfoCACompatibility188=== RUN TestPathInfoCACompatibility/null_ca_field189=== PAUSE TestPathInfoCACompatibility/null_ca_field190=== RUN TestPathInfoCACompatibility/old_string_format_-_text191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text192=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive193=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive194=== RUN TestPathInfoCACompatibility/new_structured_format_-_text195=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text196=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method197=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method198=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun199=== RUN TestSetClientTLSErrors/missing_cert_file200=== PAUSE TestSetClientTLSErrors/missing_cert_file201=== RUN TestSetClientTLS/rejects_connection_without_client_cert202=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert203=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA204=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA205=== RUN TestSetClientTLS/preserves_debug_logging_transport206=== PAUSE TestSetClientTLS/preserves_debug_logging_transport207=== RUN TestSetClientTLSErrors/missing_key_file208=== PAUSE TestSetClientTLSErrors/missing_key_file209=== RUN TestSetClientTLSErrors/missing_ca_file210=== RUN TestRateLimiterFeedback/429_enables_limiter211=== CONT TestFilterOversizedClosures212=== RUN TestFilterOversizedClosures/no_limit_keeps_everything213=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything214=== PAUSE TestRateLimiterFeedback/429_enables_limiter215=== RUN TestRateLimiterFeedback/503_enables_limiter216=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error217=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false218=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error219=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon220=== PAUSE TestParsePathInfoJSON/Lix_format221=== RUN TestParsePathInfoJSON/empty_input222=== PAUSE TestParsePathInfoJSON/empty_input223=== RUN TestParsePathInfoJSON/whitespace_only224=== PAUSE TestParsePathInfoJSON/whitespace_only225=== RUN TestParsePathInfoJSON/invalid_JSON226=== PAUSE TestParsePathInfoJSON/invalid_JSON227=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true228=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true229=== CONT TestCaseHackSuffix230--- PASS: TestStreamPushReportsSkippedPaths (0.01s)231=== CONT TestRegisterUploadedObjectReusesConnections2322026/10/28 12:11:55 ERROR Upload failed error="bad path" count=3233--- PASS: TestFileTokenReadsAndCaches (0.01s)234--- PASS: TestStreamPushIsolatesFailures (0.01s)235=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica236--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)237=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer2382026/10/28 12:11:55 ERROR Upload failed error=boom count=1239=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI240=== PAUSE TestSetClientTLSErrors/missing_ca_file241=== PAUSE TestRateLimiterFeedback/503_enables_limiter2422026/10/28 12:11:55 ERROR Upload failed error=boom count=1243--- PASS: TestStreamPushReportsSignatures (0.01s)244=== CONT TestSupersededNARStillUploadsListing2452026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=server-test rate=52462026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:610242472026/10/28 12:11:55 WARN Rate limiter backed off name=server-test rate=52482026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:61024249=== CONT TestResolveStorePath250=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess251=== PAUSE TestEncodeNixBase32/test_string_hash252=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error253=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped254=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2552026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=server-test rate=5256--- PASS: TestScriptTokenBadJSON (0.02s)257=== CONT TestDumpPathSingleFile258--- PASS: TestResolveStorePath (0.00s)259=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry260=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI261--- PASS: TestDoServerRequestAttachesToken (0.02s)262=== CONT TestDumpPathMatchesNix263=== RUN TestSetClientTLSErrors/invalid_ca_file264=== PAUSE TestSetClientTLSErrors/invalid_ca_file265=== RUN TestSupersededNARStillUploadsListing/small_NAR266=== PAUSE TestSupersededNARStillUploadsListing/small_NAR267=== RUN TestSupersededNARStillUploadsListing/dump_cut_short268=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short269=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails270=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails271=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter272=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter273=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter274=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter275=== CONT TestUploadMultipart_PartsInParallel2762026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=server-test rate=52772026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:610272782026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:61028279=== RUN TestEncodeNixBase32/empty_input280=== PAUSE TestEncodeNixBase32/empty_input281=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error282=== CONT TestPartSizeForNAR283=== CONT TestUploadMultipart_SupersededByPeer284--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)285=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths286=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths287--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290=== CONT TestConvertHashToNix32/SRI_format_to_Nix32291=== CONT TestConvertHashToNix32/invalid_format292=== CONT TestConvertHashToNix32/already_Nix32_format293--- PASS: TestConvertHashToNix32 (0.00s)294 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)295 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297=== CONT TestPathInfoCACompatibility/null_ca_field298=== CONT TestSetClientTLS/rejects_connection_without_client_cert2992026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:61028300=== CONT TestUploadMultipart_FailedPartBufferNotReused301=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error302=== RUN TestFilterOversizedClosures/all_closures_skipped303=== PAUSE TestFilterOversizedClosures/all_closures_skipped304=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3052026/10/28 12:11:55 INFO Garbage collection started306=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive307=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512308=== RUN TestPartSizeForNAR/zero_stays_at_minimum309=== RUN TestUploadMultipart_SupersededByPeer/exists310=== CONT TestPathInfoCACompatibility/new_structured_format_-_text311=== CONT TestPathInfoCACompatibility/old_string_format_-_text312=== CONT TestSetClientTLS/preserves_debug_logging_transport313=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA314--- PASS: TestPathInfoCACompatibility (0.00s)315 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)316 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)317 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)318 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)319 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)320=== PAUSE TestUploadMultipart_SupersededByPeer/exists321=== RUN TestUploadMultipart_SupersededByPeer/missing322=== PAUSE TestUploadMultipart_SupersededByPeer/missing323=== CONT TestParsePathInfoJSON/Nix_format324=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false325=== CONT TestParsePathInfoJSON/invalid_JSON326=== CONT TestParsePathInfoJSON/whitespace_only327=== CONT TestParsePathInfoJSON/empty_input328=== CONT TestParsePathInfoJSON/Lix_format3292026/10/28 12:11:55 WARN Rate limiter backed off name=server-test rate=5330--- PASS: TestParsePathInfoJSON (0.01s)331 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)332 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)333 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)334 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)335 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)336=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true337--- PASS: TestStreamPushBatchesUnderLoad (0.01s)338 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)339 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)340=== CONT TestSetClientTLSErrors/missing_cert_file341=== CONT TestSupersededNARStillUploadsListing/small_NAR342--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)343=== CONT TestRateLimiterFeedback/429_enables_limiter3442026/10/28 12:11:55 INFO Garbage collection started3452026/10/28 12:11:55 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=0346=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512347=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails348--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.04s)349=== CONT TestSetClientTLSErrors/missing_key_file350=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum351=== RUN TestPartSizeForNAR/small_stays_at_minimum352=== PAUSE TestPartSizeForNAR/small_stays_at_minimum353=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum354=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum355=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts356=== CONT TestSetClientTLSErrors/invalid_ca_file357=== CONT TestSetClientTLSErrors/missing_ca_file358--- PASS: TestSetClientTLSErrors (0.01s)359 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)361 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)362 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)363=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts364=== RUN TestPartSizeForNAR/1_TiB365=== PAUSE TestPartSizeForNAR/1_TiB366=== RUN TestPartSizeForNAR/5_TiB_S3_max_object367=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object368=== RUN TestPartSizeForNAR/capped_at_5_GiB369=== PAUSE TestPartSizeForNAR/capped_at_5_GiB370=== CONT TestEncodeNixBase32/test_string_hash371=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter372=== CONT TestSupersededNARStillUploadsListing/dump_cut_short373=== CONT TestEncodeNixBase32/empty_input374--- PASS: TestEncodeNixBase32 (0.01s)375 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)376 --- PASS: TestEncodeNixBase32/empty_input (0.00s)377=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3782026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:610283792026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=server-test rate=53802026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:61108381=== CONT TestRateLimiterFeedback/503_enables_limiter3822026/10/28 12:11:55 WARN Rate limiter backed off name=server-test rate=53832026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:61028384=== CONT TestGetStorePathHash/valid_store_path385=== CONT TestFilterOversizedClosures/no_limit_keeps_everything386=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error387=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error388=== CONT TestGetStorePathHash/basename_without_hyphen_should_error389--- PASS: TestGetStorePathHash (0.03s)390 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)391 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)392 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)393 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)394=== CONT TestFilterOversizedClosures/all_closures_skipped3952026/10/28 12:11:55 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50396=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3972026/10/28 12:11:55 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000398--- PASS: TestFilterOversizedClosures (0.02s)399 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)400 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)401 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)402=== CONT TestUploadMultipart_SupersededByPeer/exists4032026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=s3-test rate=54042026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:611224052026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=server-test rate=54062026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:611244072026/10/28 12:11:55 WARN Rate limiter backed off name=server-test rate=54082026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:61028409--- PASS: TestRateLimiterFeedback (0.01s)410 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)413 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)414=== CONT TestUploadMultipart_SupersededByPeer/missing415=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)416=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon417=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512418=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI419--- PASS: TestPathInfoHashCompatibility (0.04s)420 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)421 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)422 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)423 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)424=== CONT TestPartSizeForNAR/zero_stays_at_minimum425=== CONT TestPartSizeForNAR/capped_at_5_GiB426=== CONT TestPartSizeForNAR/5_TiB_S3_max_object427=== CONT TestPartSizeForNAR/1_TiB428=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts429=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum430=== CONT TestPartSizeForNAR/small_stays_at_minimum431--- PASS: TestPartSizeForNAR (0.03s)432 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)433 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)434 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)435 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)436 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)437 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)438 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)439--- PASS: TestScriptTokenEmptyToken (0.06s)440--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.04s)4412026/10/28 12:11:55 INFO Uploading abc-hello (1.0GB)442--- PASS: TestStreamPushRequestLine (0.05s)4432026/10/28 12:11:55 WARN Garbage collection finished on another replica. Its statistics are not available here444--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.05s)4452026/10/28 12:11:55 INFO Uploading abc-hello (1.0GB)446--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.06s)4472026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:61028448--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)449--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)450 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)451 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)4522026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:610284532026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:610284542026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:610284552026/10/28 12:11:55 WARN Rate limiter enabled after throttle name=s3-test rate=54562026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:610284572026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:610284582026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:610284592026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:610284602026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:610284612026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:61028462--- PASS: TestRegisterUploadedObjectReusesConnections (0.08s)4632026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:610284642026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:610284652026/10/28 12:11:55 http: TLS handshake error from 127.0.0.1:61105: read tcp 127.0.0.1:61031->127.0.0.1:61105: use of closed network connection466--- PASS: TestSetClientTLS (0.01s)467 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)468 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.07s)469 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.07s)4702026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:610284712026/10/28 12:11:55 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:61028472--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.10s)4732026/10/28 12:11:55 INFO Uploading abc-hello (1.0GB)474--- PASS: TestDumpPathSingleFile (0.11s)475--- PASS: TestCaseHackSuffix (0.12s)4762026/10/28 12:11:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:61119/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:61119/part/2477--- PASS: TestDumpPathWriterError (0.13s)4782026/10/28 12:11:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:61119/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:61119/part/34792026/10/28 12:11:56 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"480--- PASS: TestDumpPathMatchesNix (0.21s)481--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.60s)482--- PASS: TestSupersededNARStillUploadsListing (0.01s)483 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.03s)484 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.04s)485 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.58s)486--- PASS: TestUploadMultipart_PartsInParallel (0.67s)4872026/10/28 12:11:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:61039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:61039/api/uploads/complete4882026/10/28 12:11:56 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4892026/10/28 12:11:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:61039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:61039/api/uploads/complete4902026/10/28 12:11:56 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4912026/10/28 12:11:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:61039/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:61039/api/uploads/complete4922026/10/28 12:11:56 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"493--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)494--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)495PASS496Running server tests...497The files belonging to this database system will be owned by user "_tribuchetbld7".498This user must also own the server process.499500The database cluster will be initialized with locale "C".501The default database encoding has accordingly been set to "SQL_ASCII".502The default text search configuration will be set to "english".503504Data page checksums are enabled.505506creating directory /private/var/tb/7/scratch/13dd0e43ed626169/build/postgres3987032969/data ... ok507creating subdirectories ... ok508selecting dynamic shared memory implementation ... posix509selecting default "max_connections" ... 100510selecting default "shared_buffers" ... 128MB511selecting default time zone ... UTC512creating configuration files ... ok513running bootstrap script ... ok514performing post-bootstrap initialization ... ok515syncing data to disk ... ok516517initdb: warning: enabling "trust" authentication for local connections518initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.519520Success. You can now start the database server using:521522 pg_ctl -D /private/var/tb/7/scratch/13dd0e43ed626169/build/postgres3987032969/data -l logfile start5235242026-10-28 12:11:59.396 UTC [62687] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5252026-10-28 12:11:59.397 UTC [62687] LOG: listening on Unix socket "/private/var/tb/7/scratch/13dd0e43ed626169/build/postgres3987032969/.s.PGSQL.5432"5262026-10-28 12:11:59.403 UTC [62694] LOG: database system was shut down at 2026-10-28 12:11:59 UTC5272026-10-28 12:11:59.405 UTC [62687] LOG: database system is ready to accept connections528/private/var/tb/7/scratch/13dd0e43ed626169/build/postgres3987032969:5432 - accepting connections529{"timestamp":"2026-10-28T12:12:01.674148Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8ea86ad2-4798-4698-ba3e-33dcfcd48e32","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}530=== RUN TestService_AuthMiddleware531=== PAUSE TestService_AuthMiddleware532=== RUN TestService_AuthMiddleware_MTLSProxyHeader533=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader534=== RUN TestService_AuthMiddleware_MTLSBoundSubjects535=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects536=== RUN TestService_ReadAuthMiddleware537=== PAUSE TestService_ReadAuthMiddleware538=== RUN TestService_AuthMiddleware_OIDC539=== PAUSE TestService_AuthMiddleware_OIDC540=== RUN TestService_RequireScope_OIDC541=== PAUSE TestService_RequireScope_OIDC542=== RUN TestService_ReadScope_PublicByDefault543=== PAUSE TestService_ReadScope_PublicByDefault544=== RUN TestCacheConfigHandler545=== PAUSE TestCacheConfigHandler546=== RUN TestCacheStatsHandler547=== PAUSE TestCacheStatsHandler548=== RUN TestClientCADerivations549=== PAUSE TestClientCADerivations550=== RUN TestClientErrorHandling551=== PAUSE TestClientErrorHandling552=== RUN TestClientIntegration553=== PAUSE TestClientIntegration554=== RUN TestClientMultipleUploads555=== PAUSE TestClientMultipleUploads556=== RUN TestClientWithDependencies557=== PAUSE TestClientWithDependencies558=== RUN TestClientSharedPathCommittedMidPush559=== PAUSE TestClientSharedPathCommittedMidPush560=== RUN TestPinProtectsFromGC561=== PAUSE TestPinProtectsFromGC562=== RUN TestClientPushesUseOnePush563=== PAUSE TestClientPushesUseOnePush564=== RUN TestClientFallsBackToClosures565=== PAUSE TestClientFallsBackToClosures566=== RUN TestDeleteClosuresRacingPins567=== PAUSE TestDeleteClosuresRacingPins568=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock569=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== RUN TestResolveDBConnectionString571=== PAUSE TestResolveDBConnectionString572=== RUN TestConnectWaitsForAPeerMigration573=== PAUSE TestConnectWaitsForAPeerMigration574=== RUN TestLeadElectsOneAndHandsOver575=== PAUSE TestLeadElectsOneAndHandsOver576=== RUN TestLeadIncumbentWinsAfterRestart5772026/10/28 12:12:02 INFO lead: acquired remote=192.0.2.1:12345782026/10/28 12:12:02 INFO lead: released remote=192.0.2.1:12345792026/10/28 12:12:02 INFO lead: acquired remote=192.0.2.1:12345802026/10/28 12:12:03 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadIncumbentWinsAfterRestart (2.21s)582=== RUN TestLeadIncumbentAnnouncesAtOnce583=== PAUSE TestLeadIncumbentAnnouncesAtOnce584=== RUN TestLeadEndsOnShutdown585=== PAUSE TestLeadEndsOnShutdown586=== RUN TestLeadEndsWhenItsConnectionHangs5872026/10/28 12:12:04 INFO lead: acquired remote=192.0.2.1:12345882026-10-28 12:12:05.577 UTC [62763] FATAL: terminating connection due to administrator command5892026/10/28 12:12:05 INFO lead: acquired remote=192.0.2.1:12345902026/10/28 12:12:06 WARN lead: lock connection lost error="timeout: context deadline exceeded"5912026/10/28 12:12:06 INFO lead: released remote=192.0.2.1:12345922026/10/28 12:12:06 INFO lead: released remote=192.0.2.1:1234593--- PASS: TestLeadEndsWhenItsConnectionHangs (2.99s)594=== RUN TestGCAdvisoryLockBlocksConcurrentRun595=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun596=== RUN TestGCBugBareHashReferences597=== PAUSE TestGCBugBareHashReferences598=== RUN TestGCMetrics599=== PAUSE TestGCMetrics600=== RUN TestPushDedupSurvivesConcurrentGC601=== PAUSE TestPushDedupSurvivesConcurrentGC602=== RUN TestDeduplicatedObjectsRecordedAsPending603=== PAUSE TestDeduplicatedObjectsRecordedAsPending604=== RUN TestGCSweepSkipsPendingObjects605=== PAUSE TestGCSweepSkipsPendingObjects606=== RUN TestTombstonedObjectOfferedWithoutWaiting607=== PAUSE TestTombstonedObjectOfferedWithoutWaiting608=== RUN TestGCSweepDeliversEachKeyOnce609=== PAUSE TestGCSweepDeliversEachKeyOnce610=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection611=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== RUN TestForceGCDuringPushOffersSweptObject613=== PAUSE TestForceGCDuringPushOffersSweptObject614=== RUN TestFailedS3DeleteKeepsTombstone615=== PAUSE TestFailedS3DeleteKeepsTombstone616=== RUN TestSweepSkipsRowsLockedByPush617=== PAUSE TestSweepSkipsRowsLockedByPush618=== RUN TestRegisterCompletedObjectNeedsPendingRow619=== PAUSE TestRegisterCompletedObjectNeedsPendingRow620=== RUN TestGetExistingObjectsLocksRows621=== PAUSE TestGetExistingObjectsLocksRows622=== RUN TestSweepRechecksPendingAfterLocking623=== PAUSE TestSweepRechecksPendingAfterLocking624=== RUN TestPushWaitsForSweepHoldingRow625=== PAUSE TestPushWaitsForSweepHoldingRow626=== RUN TestCommitRacingPendingCleanupKeepsObjects627=== PAUSE TestCommitRacingPendingCleanupKeepsObjects628=== RUN TestGCEndsOnShutdown629=== PAUSE TestGCEndsOnShutdown630=== RUN TestGCTaskStore_StartNew631=== PAUSE TestGCTaskStore_StartNew632=== RUN TestGCTaskStore_DeduplicateSameParams633=== PAUSE TestGCTaskStore_DeduplicateSameParams634=== RUN TestGCTaskStore_ConflictDifferentParams635=== PAUSE TestGCTaskStore_ConflictDifferentParams636=== RUN TestGCTaskStore_GetEmpty637=== PAUSE TestGCTaskStore_GetEmpty638=== RUN TestGCTaskStore_GetReturnsLatest639=== PAUSE TestGCTaskStore_GetReturnsLatest640=== RUN TestGCTaskStore_CompletedAllowsNewTask641=== PAUSE TestGCTaskStore_CompletedAllowsNewTask642=== RUN TestGCTaskStore_PhaseUpdates643=== PAUSE TestGCTaskStore_PhaseUpdates644=== RUN TestGCTaskStore_Fail645=== PAUSE TestGCTaskStore_Fail646=== RUN TestGracefulShutdownDrainsInflight647=== PAUSE TestGracefulShutdownDrainsInflight648=== RUN TestService_healthCheckHandler649=== PAUSE TestService_healthCheckHandler650=== RUN TestService_readinessHandler651=== PAUSE TestService_readinessHandler652=== RUN TestGenerateLandingPage653=== PAUSE TestGenerateLandingPage654=== RUN TestCacheConfigHandlerMaxNarSize655=== PAUSE TestCacheConfigHandlerMaxNarSize656=== RUN TestCreatePendingClosureRejectsOversizedNAR657=== PAUSE TestCreatePendingClosureRejectsOversizedNAR658=== RUN TestNARDeduplicationMetadataUploadBug659=== PAUSE TestNARDeduplicationMetadataUploadBug660=== RUN TestMetricsInventory661=== PAUSE TestMetricsInventory662=== RUN TestMetricsCommit663=== PAUSE TestMetricsCommit664=== RUN TestService_NativeMTLS665=== PAUSE TestService_NativeMTLS666=== RUN TestServerTLSConfig667=== PAUSE TestServerTLSConfig668=== RUN TestMultipartCleanup669=== PAUSE TestMultipartCleanup670=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded671=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== RUN TestPendingCleanupUsesOneCutoff673=== PAUSE TestPendingCleanupUsesOneCutoff674=== RUN TestObjectStatsTrigger675=== PAUSE TestObjectStatsTrigger676=== RUN TestObjectStatsUpdatedOncePerCommit677=== PAUSE TestObjectStatsUpdatedOncePerCommit678=== RUN TestOrphanedObjectsGC679=== PAUSE TestOrphanedObjectsGC680=== RUN TestOrphanedObjectsGCStressTest681=== PAUSE TestOrphanedObjectsGCStressTest682=== RUN TestCreatePin_ReservedPins683=== PAUSE TestCreatePin_ReservedPins684=== RUN TestPresentReportsOnlyClosureRoots685=== PAUSE TestPresentReportsOnlyClosureRoots686=== RUN TestPresentRefreshesOnlyStaleClosures687=== PAUSE TestPresentRefreshesOnlyStaleClosures688=== RUN TestPresentNotReportedWhileGCDeletesClosure689=== PAUSE TestPresentNotReportedWhileGCDeletesClosure690=== RUN TestParseSingleRange691=== PAUSE TestParseSingleRange692=== RUN TestProxyHeadersOnlyTrustedOnSocket6932026/10/28 12:12:07 INFO Starting HTTP server address=127.0.0.1:613286942026/10/28 12:12:07 INFO Starting HTTP server address=proxy.sock6952026/10/28 12:12:07 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6962026/10/28 12:12:07 INFO Shutdown signal received, draining in-flight requests timeout=10s697--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.18s)698=== RUN TestIsValidCachePath699=== PAUSE TestIsValidCachePath700=== RUN TestReadProxyNarinfo701=== PAUSE TestReadProxyNarinfo702=== RUN TestReadProxyNarinfoAlreadyDecompressed703=== PAUSE TestReadProxyNarinfoAlreadyDecompressed704=== RUN TestReadProxyContentNegotiation705=== PAUSE TestReadProxyContentNegotiation706=== RUN TestReadProxyNarStreaming707=== PAUSE TestReadProxyNarStreaming708=== RUN TestReadProxy404709=== PAUSE TestReadProxy404710=== RUN TestReadProxyInvalidPath711=== PAUSE TestReadProxyInvalidPath712=== RUN TestReadProxyHead713=== PAUSE TestReadProxyHead714=== RUN TestReadProxyOutlastsServerWriteTimeout715=== PAUSE TestReadProxyOutlastsServerWriteTimeout716=== RUN TestReadProxyConditionalGet717=== PAUSE TestReadProxyConditionalGet718=== RUN TestReadProxyRootRedirectsToIndexHTML719=== PAUSE TestReadProxyRootRedirectsToIndexHTML720=== RUN TestReadProxyDisabled721=== PAUSE TestReadProxyDisabled722=== RUN TestReadRedirectNar723=== PAUSE TestReadRedirectNar724=== RUN TestReadRedirectKeepsNarinfoProxied725=== PAUSE TestReadRedirectKeepsNarinfoProxied726=== RUN TestReadProxyRangeRequest727=== PAUSE TestReadProxyRangeRequest728=== RUN TestReadRedirectUsesPublicS3URL729=== PAUSE TestReadRedirectUsesPublicS3URL730=== RUN TestPush_OverlappingRootsStoreOneRowPerKey731=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey732=== RUN TestPush_CompleteCommitsEveryRoot733=== PAUSE TestPush_CompleteCommitsEveryRoot734=== RUN TestPush_RepeatedRootCommitsOnce735=== PAUSE TestPush_RepeatedRootCommitsOnce736=== RUN TestPush_CompleteWaitsForCleanupOfThePush737=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush738=== RUN TestPush_RootsAreLockedInByteOrder739=== PAUSE TestPush_RootsAreLockedInByteOrder740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/28 12:12:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"775--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)776=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== RUN TestProxyWriteTimeout779=== PAUSE TestProxyWriteTimeout780=== RUN TestPendingClosureWriteTimeout781=== PAUSE TestPendingClosureWriteTimeout782=== RUN TestIsValidUploadKey783=== PAUSE TestIsValidUploadKey784=== RUN TestUploadHandlersRejectInvalidKeys785=== PAUSE TestUploadHandlersRejectInvalidKeys786=== RUN TestUploadHandlersRejectOversizedBody787=== PAUSE TestUploadHandlersRejectOversizedBody788=== RUN TestService_cleanupPendingClosuresHandler789=== PAUSE TestService_cleanupPendingClosuresHandler790=== RUN TestService_createPendingClosureHandler791=== PAUSE TestService_createPendingClosureHandler792=== RUN TestService_verifyS3Integrity793=== PAUSE TestService_verifyS3Integrity794=== RUN TestCompleteMultipartUnregistered795=== PAUSE TestCompleteMultipartUnregistered796=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT797=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestPush_SignsNarinfosOfItsPendingObjects799=== CONT TestGCTaskStore_PhaseUpdates800=== CONT TestPush_CompleteCommitsEveryRoot801=== CONT TestService_Rustfstest802=== CONT TestPendingClosureWriteTimeout803=== RUN TestPendingClosureWriteTimeout/empty804--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)805=== CONT TestCompleteMultipartUnregistered806=== CONT TestService_verifyS3Integrity807=== CONT TestService_createPendingClosureHandler808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestUploadHandlersRejectOversizedBody810=== CONT TestUploadHandlersRejectInvalidKeys811=== CONT TestIsValidUploadKey812=== RUN TestIsValidUploadKey/narinfo813=== PAUSE TestIsValidUploadKey/narinfo814=== RUN TestIsValidUploadKey/nar_zst815=== PAUSE TestIsValidUploadKey/nar_zst816=== RUN TestIsValidUploadKey/nar_xz817=== PAUSE TestIsValidUploadKey/nar_xz818=== CONT TestProxyWriteTimeout819=== RUN TestProxyWriteTimeout/narinfo820=== PAUSE TestProxyWriteTimeout/narinfo821=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle822=== RUN TestProxyWriteTimeout/1_GiB_nar823=== PAUSE TestProxyWriteTimeout/1_GiB_nar824=== RUN TestProxyWriteTimeout/10_GiB_nar825=== CONT TestSkippedUploadsHandler826=== PAUSE TestProxyWriteTimeout/10_GiB_nar827=== RUN TestProxyWriteTimeout/unknown_size828=== CONT TestParseSize829=== CONT TestParseSingleRange830=== PAUSE TestProxyWriteTimeout/unknown_size831=== CONT TestService_AuthMiddleware832=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit833=== CONT TestPush_RootsAreLockedInByteOrder834=== CONT TestPush_CompleteWaitsForCleanupOfThePush835=== CONT TestPush_RepeatedRootCommitsOnce836=== CONT TestGCTaskStore_CompletedAllowsNewTask837=== CONT TestGCTaskStore_ConflictDifferentParams838=== CONT TestGCTaskStore_DeduplicateSameParams839=== CONT TestGCTaskStore_StartNew840=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT841=== PAUSE TestPendingClosureWriteTimeout/empty842=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info843=== RUN TestIsValidUploadKey/nar_plain844=== CONT TestPush_RejectsBadRequests845=== CONT TestGCTaskStore_GetReturnsLatest846--- PASS: TestParseSize (0.00s)847--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)848--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)849--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)850--- PASS: TestGCTaskStore_StartNew (0.00s)851--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)852=== CONT TestGCTaskStore_GetEmpty853--- PASS: TestGCTaskStore_GetEmpty (0.00s)854=== CONT TestPushWaitsForSweepHoldingRow8552026/10/28 12:12:07 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000856=== CONT TestGCEndsOnShutdown857=== RUN TestParseSingleRange/none858=== PAUSE TestParseSingleRange/none859=== RUN TestParseSingleRange/unknown_unit860=== PAUSE TestParseSingleRange/unknown_unit861=== RUN TestParseSingleRange/multi-range_ignored862=== PAUSE TestParseSingleRange/multi-range_ignored863=== RUN TestParseSingleRange/malformed_no_dash864=== RUN TestGCEndsOnShutdown/before_the_run865=== CONT TestCommitRacingPendingCleanupKeepsObjects866--- PASS: TestSkippedUploadsHandler (0.00s)867=== CONT TestSweepRechecksPendingAfterLocking868=== PAUSE TestGCEndsOnShutdown/before_the_run869=== PAUSE TestParseSingleRange/malformed_no_dash870=== RUN TestPendingClosureWriteTimeout/400_objects871=== PAUSE TestPendingClosureWriteTimeout/400_objects872=== RUN TestPendingClosureWriteTimeout/670k_objects873=== PAUSE TestPendingClosureWriteTimeout/670k_objects874=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline875=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline876=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info877=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal878=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal879=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key880=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key881=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key882=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key883=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete884=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete885=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark886=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark887=== CONT TestServerTLSConfig888=== RUN TestServerTLSConfig/no_client_CA889=== PAUSE TestServerTLSConfig/no_client_CA890=== RUN TestServerTLSConfig/missing_CA_file891=== PAUSE TestServerTLSConfig/missing_CA_file892=== RUN TestServerTLSConfig/not_a_PEM_file893=== PAUSE TestIsValidUploadKey/nar_plain894=== RUN TestIsValidUploadKey/listing895=== PAUSE TestIsValidUploadKey/listing896=== RUN TestIsValidUploadKey/build_log897=== PAUSE TestIsValidUploadKey/build_log898=== RUN TestIsValidUploadKey/build_log_home-manager_file899=== PAUSE TestIsValidUploadKey/build_log_home-manager_file900=== RUN TestIsValidUploadKey/build_log_plus_in_name901=== PAUSE TestIsValidUploadKey/build_log_plus_in_name902=== RUN TestIsValidUploadKey/build_log_question_mark903=== PAUSE TestIsValidUploadKey/build_log_question_mark904=== RUN TestIsValidUploadKey/build_log_equals905=== PAUSE TestIsValidUploadKey/build_log_equals906=== RUN TestIsValidUploadKey/realisation907=== PAUSE TestIsValidUploadKey/realisation908=== RUN TestIsValidUploadKey/realisation_plus_in_output909=== PAUSE TestIsValidUploadKey/realisation_plus_in_output910=== RUN TestIsValidUploadKey/nix-cache-info911=== PAUSE TestIsValidUploadKey/nix-cache-info912=== RUN TestIsValidUploadKey/index.html913=== CONT TestService_NativeMTLS914=== RUN TestParseSingleRange/malformed_both_empty915=== PAUSE TestParseSingleRange/malformed_both_empty916=== RUN TestParseSingleRange/malformed_end_before_start917=== PAUSE TestParseSingleRange/malformed_end_before_start918=== RUN TestParseSingleRange/closed919=== PAUSE TestParseSingleRange/closed920=== RUN TestParseSingleRange/open-ended921=== PAUSE TestParseSingleRange/open-ended922=== RUN TestParseSingleRange/end_clamped_to_size923=== PAUSE TestParseSingleRange/end_clamped_to_size924=== RUN TestParseSingleRange/suffix925=== CONT TestGetExistingObjectsLocksRows926=== PAUSE TestServerTLSConfig/not_a_PEM_file927=== CONT TestMetricsCommit928=== PAUSE TestIsValidUploadKey/index.html929=== RUN TestIsValidUploadKey/narinfo_key,_nar_type930=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type931=== RUN TestIsValidUploadKey/nar_key,_narinfo_type932=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type933=== RUN TestIsValidUploadKey/listing_key,_narinfo_type934=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type935=== RUN TestIsValidUploadKey/traversal936=== PAUSE TestIsValidUploadKey/traversal937=== RUN TestIsValidUploadKey/traversal_nar938=== PAUSE TestIsValidUploadKey/traversal_nar939=== RUN TestIsValidUploadKey/absolute940=== PAUSE TestIsValidUploadKey/absolute941=== RUN TestIsValidUploadKey/empty_key942=== PAUSE TestIsValidUploadKey/empty_key943=== RUN TestIsValidUploadKey/unknown_type944=== PAUSE TestIsValidUploadKey/unknown_type945=== CONT TestRegisterCompletedObjectNeedsPendingRow946=== PAUSE TestParseSingleRange/suffix947=== RUN TestParseSingleRange/suffix_exceeds_size948=== PAUSE TestParseSingleRange/suffix_exceeds_size949=== RUN TestParseSingleRange/single_byte950=== PAUSE TestParseSingleRange/single_byte951=== RUN TestParseSingleRange/start_past_EOF952=== PAUSE TestParseSingleRange/start_past_EOF953=== RUN TestParseSingleRange/start_far_past_EOF954=== PAUSE TestParseSingleRange/start_far_past_EOF955=== CONT TestSweepSkipsRowsLockedByPush956=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts957=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts958=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure959=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure960=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart961=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart962=== CONT TestFailedS3DeleteKeepsTombstone9632026/10/28 12:12:08 INFO Received push request method=POST path=/api/pushes9642026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9652026/10/28 12:12:08 INFO Signed narinfos id=1 count=19662026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9672026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9682026/10/28 12:12:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9692026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9702026/10/28 12:12:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9712026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9722026/10/28 12:12:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19732026/10/28 12:12:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9742026/10/28 12:12:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo975--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.93s)976=== CONT TestForceGCDuringPushOffersSweptObject977=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows978=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows979=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check980=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check981=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection982--- PASS: TestService_Rustfstest (1.11s)983=== CONT TestGCSweepDeliversEachKeyOnce9842026/10/28 12:12:08 INFO Received push request method=POST path=/api/pushes9852026-10-28 12:12:08.931 UTC [62876] ERROR: could not obtain lock on row in relation "closures"9862026-10-28 12:12:08.931 UTC [62876] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9872026-10-28 12:12:08.931 UTC [62876] ERROR: could not obtain lock on row in relation "closures"9882026-10-28 12:12:08.931 UTC [62876] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9892026-10-28 12:12:08.931 UTC [62876] ERROR: could not obtain lock on row in relation "closures"9902026-10-28 12:12:08.931 UTC [62876] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9912026-10-28 12:12:08.931 UTC [62876] ERROR: could not obtain lock on row in relation "closures"9922026-10-28 12:12:08.931 UTC [62876] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9932026-10-28 12:12:08.931 UTC [62876] ERROR: could not obtain lock on row in relation "closures"9942026-10-28 12:12:08.931 UTC [62876] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT995--- PASS: TestPush_RootsAreLockedInByteOrder (1.56s)996=== CONT TestTombstonedObjectOfferedWithoutWaiting9972026/10/28 12:12:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/28 12:12:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst999--- PASS: TestCompleteMultipartUnregistered (1.72s)1000=== CONT TestGCSweepSkipsPendingObjects10012026/10/28 12:12:09 INFO Received push request method=POST path=/api/pushes10022026/10/28 12:12:09 INFO Received complete push request method=POST path=/api/pushes/1/complete10032026/10/28 12:12:09 INFO Completed push id=1 objects=4 duration=7.982292ms10042026/10/28 12:12:09 INFO Received push request method=POST path=/api/pushes10052026/10/28 12:12:09 INFO Aborted multipart uploads count=0 kept=010062026/10/28 12:12:09 WARN Force mode enabled - objects will be deleted immediately without grace period10072026/10/28 12:12:09 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/28 12:12:09 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=010092026/10/28 12:12:09 INFO Vacuumed table table=pending_closures10102026/10/28 12:12:09 INFO Vacuumed table table=pending_objects1011--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.32s)1012=== CONT TestMetricsInventory10132026/10/28 12:12:09 INFO Vacuumed table table=multipart_uploads10142026/10/28 12:12:09 INFO Vacuumed table table=closures10152026/10/28 12:12:09 INFO Vacuumed table table=objects10162026/10/28 12:12:09 INFO Received complete push request method=POST path=/api/pushes/2/complete10172026/10/28 12:12:09 INFO Completed push id=2 objects=4 duration=2.066542ms1018--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.36s)1019=== CONT TestDeduplicatedObjectsRecordedAsPending10202026/10/28 12:12:09 INFO Received push request method=POST path=/api/pushes10212026/10/28 12:12:10 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1022--- PASS: TestService_AuthMiddleware (2.62s)1023=== CONT TestNARDeduplicationMetadataUploadBug10242026-10-28 12:12:10.182 UTC [62930] ERROR: Push does not exist: id=110252026-10-28 12:12:10.182 UTC [62930] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10262026-10-28 12:12:10.182 UTC [62930] STATEMENT: SELECT commit_push($1)1027--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.79s)1028=== CONT TestPushDedupSurvivesConcurrentGC10292026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures10312026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures10332026/10/28 12:12:10 INFO Aborted multipart uploads count=0 kept=010342026/10/28 12:12:10 WARN Force mode enabled - objects will be deleted immediately without grace period10352026/10/28 12:12:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010362026/10/28 12:12:10 INFO Vacuumed table table=pending_closures10372026/10/28 12:12:10 INFO Vacuumed table table=pending_objects10382026/10/28 12:12:10 INFO Vacuumed table table=multipart_uploads10392026/10/28 12:12:10 INFO Vacuumed table table=closures1040--- PASS: TestPushWaitsForSweepHoldingRow (3.31s)1041=== CONT TestCreatePendingClosureRejectsOversizedNAR10422026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures1043--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1044=== CONT TestGCMetrics10452026/10/28 12:12:10 INFO Vacuumed table table=objects1046--- PASS: TestSweepRechecksPendingAfterLocking (3.34s)1047=== CONT TestCacheConfigHandlerMaxNarSize1048--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1049=== CONT TestPresentNotReportedWhileGCDeletesClosure1050=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1051=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1052=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1053=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1054=== CONT TestGCBugBareHashReferences10552026/10/28 12:12:10 INFO Received uploads request method=POST path=/api/pending_closures10562026/10/28 12:12:11 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/28 12:12:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/10/28 12:12:11 INFO Received cleanup request method=DELETE path=/api/pending_closures10592026/10/28 12:12:11 INFO Aborted multipart uploads count=0 kept=010602026/10/28 12:12:11 INFO Received uploads request method=POST path=/api/pending_closures10612026/10/28 12:12:11 INFO Received cleanup request method=DELETE path=/api/pending_closures10622026/10/28 12:12:11 INFO Aborted multipart uploads count=1 kept=010632026/10/28 12:12:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10642026-10-28 12:12:11.513 UTC [62883] ERROR: Closure does not exist: id=110652026-10-28 12:12:11.513 UTC [62883] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10662026-10-28 12:12:11.513 UTC [62883] STATEMENT: -- name: CommitPendingClosure :one1067 SELECT commit_pending_closure($1::bigint)::bigint1068 1069--- PASS: TestService_cleanupPendingClosuresHandler (4.12s)1070=== CONT TestGenerateLandingPage1071--- PASS: TestGenerateLandingPage (0.00s)1072=== CONT TestPresentRefreshesOnlyStaleClosures10732026/10/28 12:12:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1074=== RUN TestPush_RejectsBadRequests/bad_root1075=== PAUSE TestPush_RejectsBadRequests/bad_root1076=== RUN TestPush_RejectsBadRequests/root_not_in_objects1077=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1078=== RUN TestPush_RejectsBadRequests/no_roots1079=== PAUSE TestPush_RejectsBadRequests/no_roots1080=== RUN TestPush_RejectsBadRequests/no_objects1081=== PAUSE TestPush_RejectsBadRequests/no_objects1082=== CONT TestGCAdvisoryLockBlocksConcurrentRun10832026/10/28 12:12:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLjYwNmY0OTJiLWFiMWYtNDBhNS1hMTgwLWZjMGZjNGQwZGQ3YXgxNzkzMTg5NTMwMzYyMjU0MDAw parts=1010842026/10/28 12:12:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10852026/10/28 12:12:11 INFO Completed upload id=1 objects=2 duration=7.472417ms10862026/10/28 12:12:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010872026/10/28 12:12:11 INFO Received uploads request method=POST path=/api/pending_closures10882026/10/28 12:12:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures10892026/10/28 12:12:11 INFO Aborted multipart uploads count=0 kept=010902026/10/28 12:12: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=010912026/10/28 12:12:11 INFO Vacuumed table table=pending_closures10922026/10/28 12:12:11 INFO Vacuumed table table=pending_objects10932026/10/28 12:12:11 INFO Vacuumed table table=multipart_uploads10942026/10/28 12:12:11 INFO Vacuumed table table=closures10952026/10/28 12:12:11 INFO Vacuumed table table=objects10962026/10/28 12:12:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001097--- PASS: TestService_createPendingClosureHandler (4.45s)1098=== CONT TestService_readinessHandler10992026/10/28 12:12:11 INFO Received push request method=POST path=/api/pushes11002026/10/28 12:12:11 INFO Received complete push request method=POST path=/api/pushes/1/complete11012026/10/28 12:12:12 INFO Completed push id=1 objects=4 duration=33.288875ms1102--- PASS: TestPush_RepeatedRootCommitsOnce (4.64s)1103=== CONT TestPresentReportsOnlyClosureRoots11042026/10/28 12:12:12 INFO Received push request method=POST path=/api/pushes11052026/10/28 12:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete11062026/10/28 12:12:12 INFO Completed push id=1 objects=6 duration=35.949083ms1107--- PASS: TestPush_CompleteCommitsEveryRoot (4.88s)1108=== CONT TestLeadEndsOnShutdown11092026/10/28 12:12:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11102026/10/28 12:12:12 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLmVjZjM2NzQ2LTNmYzgtNGQ4Ny04ZWJkLTIyNjA0YmMzNjM2YngxNzkzMTg5NTMxMTA2NDIyMDAw parts=1011112026/10/28 12:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11122026/10/28 12:12:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11132026/10/28 12:12:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1114--- PASS: TestService_NativeMTLS (4.95s)1115=== CONT TestService_healthCheckHandler11162026/10/28 12:12:12 INFO Completed upload id=1 objects=2 duration=6.52275ms11172026/10/28 12:12:12 INFO Received uploads request method=POST path=/api/pending_closures11182026/10/28 12:12:12 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/28 12:12:12 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11202026/10/28 12:12:12 WARN Found objects in DB but missing from S3, will re-upload count=11121--- PASS: TestService_verifyS3Integrity (5.03s)1122=== CONT TestCreatePin_ReservedPins11232026/10/28 12:12:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61462/oidc11242026/10/28 12:12:12 INFO Received push request method=POST path=/api/pushes11252026/10/28 12:12:12 INFO Received complete push request method=POST path=/api/pushes/1/complete11262026/10/28 12:12:12 INFO Completed push id=1 objects=4 duration=24.902875ms11272026/10/28 12:12:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11282026/10/28 12:12:12 INFO Completed upload id=2 objects=2 duration=1.339833ms1129--- PASS: TestMetricsCommit (5.28s)1130=== CONT TestLeadIncumbentAnnouncesAtOnce11312026/10/28 12:12:12 INFO Aborted multipart uploads count=0 kept=011322026/10/28 12:12:12 WARN Force mode enabled - objects will be deleted immediately without grace period11332026/10/28 12:12:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011342026/10/28 12:12:12 INFO Vacuumed table table=pending_closures11352026/10/28 12:12:12 INFO Vacuumed table table=pending_objects11362026/10/28 12:12:12 INFO Vacuumed table table=multipart_uploads11372026/10/28 12:12:12 INFO Vacuumed table table=closures11382026/10/28 12:12:13 INFO Vacuumed table table=objects1139--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.58s)1140=== CONT TestGracefulShutdownDrainsInflight11412026/10/28 12:12:13 INFO Starting HTTP server address=127.0.0.1:6147811422026/10/28 12:12:13 INFO Shutdown signal received, draining in-flight requests timeout=10s11432026/10/28 12:12:13 INFO Aborted multipart uploads count=0 kept=01144--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1145=== CONT TestOrphanedObjectsGCStressTest11462026/10/28 12:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period11472026/10/28 12:12:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011482026/10/28 12:12:13 INFO Vacuumed table table=pending_closures11492026/10/28 12:12:13 INFO Vacuumed table table=pending_objects11502026/10/28 12:12:13 INFO Vacuumed table table=multipart_uploads11512026/10/28 12:12:13 INFO Vacuumed table table=closures11522026/10/28 12:12:13 INFO Vacuumed table table=objects11532026/10/28 12:12:13 INFO Aborted multipart uploads count=0 kept=011542026/10/28 12:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period11552026/10/28 12:12:13 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/28 12:12:13 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=011572026/10/28 12:12:13 INFO Vacuumed table table=pending_closures11582026/10/28 12:12:13 INFO Vacuumed table table=pending_objects11592026/10/28 12:12:13 INFO Vacuumed table table=multipart_uploads11602026/10/28 12:12:13 INFO Vacuumed table table=closures11612026/10/28 12:12:13 INFO Vacuumed table table=objects1162--- PASS: TestSweepSkipsRowsLockedByPush (5.95s)1163=== CONT TestGCTaskStore_Fail1164--- PASS: TestGCTaskStore_Fail (0.00s)1165=== CONT TestOrphanedObjectsGC11662026/10/28 12:12:13 INFO Aborted multipart uploads count=0 kept=011672026/10/28 12:12:13 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/28 12:12:13 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11692026/10/28 12:12:13 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1170--- PASS: TestGetExistingObjectsLocksRows (6.06s)1171=== CONT TestObjectStatsUpdatedOncePerCommit1172--- PASS: TestFailedS3DeleteKeepsTombstone (6.03s)1173=== CONT TestObjectStatsTrigger1174--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.22s)1175=== CONT TestPendingCleanupUsesOneCutoff11762026/10/28 12:12:13 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/28 12:12:13 INFO Aborted multipart uploads count=0 kept=011782026/10/28 12:12:14 WARN Force mode enabled - objects will be deleted immediately without grace period11792026/10/28 12:12:14 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=011802026/10/28 12:12:14 INFO Vacuumed table table=pending_closures11812026/10/28 12:12:14 INFO Vacuumed table table=pending_objects11822026/10/28 12:12:14 INFO Vacuumed table table=multipart_uploads11832026/10/28 12:12:14 INFO Vacuumed table table=closures11842026/10/28 12:12:14 INFO Vacuumed table table=objects1185--- PASS: TestGCSweepSkipsPendingObjects (5.09s)1186=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11872026/10/28 12:12:14 INFO Aborted multipart uploads count=0 kept=011882026/10/28 12:12:14 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/28 12:12:14 INFO Received uploads request method=POST path=/api/pending_closures1190--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.42s)1191=== CONT TestMultipartCleanup11922026/10/28 12:12:14 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=011932026/10/28 12:12:14 INFO Vacuumed table table=pending_closures11942026/10/28 12:12:14 INFO Vacuumed table table=pending_objects11952026/10/28 12:12:14 INFO Vacuumed table table=multipart_uploads11962026/10/28 12:12:14 INFO Vacuumed table table=closures11972026/10/28 12:12:14 INFO Vacuumed table table=objects1198--- PASS: TestGCSweepDeliversEachKeyOnce (6.38s)1199=== CONT TestCompletedNarNotReofferedAcrossClosures12002026/10/28 12:12:14 INFO Received uploads request method=POST path=/api/pending_closures1201--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.01s)1202=== CONT TestPresignedUploadRegisteredBeforeCommit1203--- PASS: TestMetricsInventory (5.51s)1204=== CONT TestReadProxyOutlastsServerWriteTimeout12052026/10/28 12:12:15 WARN Rate limiter enabled after throttle name=s3-test rate=512062026/10/28 12:12:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1207=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1208 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101209 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001210--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.96s)1211=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12122026/10/28 12:12:15 INFO Received uploads request method=POST path=/api/pending_closures1213--- PASS: TestDeduplicatedObjectsRecordedAsPending (5.68s)1214=== CONT TestReadRedirectUsesPublicS3URL1215=== NAME TestNARDeduplicationMetadataUploadBug1216 metadata_upload_test.go:48: First store path: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestNARDeduplicationMetadataUploadBug2971456473/001/store/mxbvzh88ycxgspsncrnndadlciw9zg0n-file1.txt12172026/10/28 12:12:16 INFO Received uploads request method=POST path=/api/pending_closures12182026/10/28 12:12:16 INFO Received push request method=POST path=/api/pushes12192026/10/28 12:12:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12202026/10/28 12:12:16 INFO Uploading mxbvzh88ycxgspsncrnndadlciw9zg0n-file1.txt (160B)12212026/10/28 12:12:16 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12222026/10/28 12:12:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12232026/10/28 12:12:16 WARN Failed to register uploaded object key=mxbvzh88ycxgspsncrnndadlciw9zg0n.ls error="server returned 404: 404 page not found\n"12242026/10/28 12:12:16 INFO Signed narinfos id=1 count=112252026/10/28 12:12:16 INFO Uploading 1 narinfos12262026/10/28 12:12:16 INFO Aborted multipart uploads count=0 kept=012272026/10/28 12:12:16 INFO Received complete push request method=POST path=/api/pushes/1/complete12282026/10/28 12:12:16 WARN Failed to register uploaded object key=mxbvzh88ycxgspsncrnndadlciw9zg0n.narinfo error="server returned 404: 404 page not found\n"12292026/10/28 12:12:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012302026/10/28 12:12:16 INFO Completed push id=1 objects=3 duration=16.183708ms12312026/10/28 12:12:16 INFO Upload complete. (303ms)1232 metadata_upload_test.go:54: Retrieved narinfo from S3:1233 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestNARDeduplicationMetadataUploadBug2971456473/001/store/mxbvzh88ycxgspsncrnndadlciw9zg0n-file1.txt1234 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1235 Compression: zstd1236 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1237 NarSize: 1601238 References: 1239 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12402026/10/28 12:12:16 INFO Vacuumed table table=pending_closures1241 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1242 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1243 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12442026/10/28 12:12:16 INFO Vacuumed table table=pending_objects12452026/10/28 12:12:16 INFO Vacuumed table table=multipart_uploads12462026/10/28 12:12:16 INFO Vacuumed table table=closures12472026/10/28 12:12:16 INFO Vacuumed table table=objects12482026/10/28 12:12:16 INFO Aborted multipart uploads count=0 kept=012492026/10/28 12:12:16 WARN Force mode enabled - objects will be deleted immediately without grace period12502026/10/28 12:12:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012512026/10/28 12:12:16 INFO Vacuumed table table=pending_closures1252 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/7/scratch/13dd0e43ed626169/build/TestNARDeduplicationMetadataUploadBug2971456473/001/store/fh8zwmja0lf2aj94nv40jq8ms85z523x-file2.txt12532026/10/28 12:12:16 INFO Vacuumed table table=pending_objects12542026/10/28 12:12:16 INFO Vacuumed table table=multipart_uploads12552026/10/28 12:12:16 INFO Vacuumed table table=closures12562026/10/28 12:12:16 INFO Vacuumed table table=objects1257--- PASS: TestPushDedupSurvivesConcurrentGC (6.23s)1258=== CONT TestReadProxyRangeRequest1259--- PASS: TestGCBugBareHashReferences (5.69s)1260=== CONT TestReadRedirectKeepsNarinfoProxied12612026/10/28 12:12:16 INFO Aborted multipart uploads count=0 kept=012622026/10/28 12:12:16 WARN Force mode enabled - objects will be deleted immediately without grace period12632026/10/28 12:12:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012642026/10/28 12:12:16 INFO Vacuumed table table=pending_closures12652026/10/28 12:12:16 INFO Vacuumed table table=pending_objects12662026/10/28 12:12:16 INFO Vacuumed table table=multipart_uploads12672026/10/28 12:12:16 INFO Vacuumed table table=closures12682026/10/28 12:12:16 INFO Vacuumed table table=objects1269--- PASS: TestGCMetrics (5.79s)1270=== CONT TestReadRedirectNar12712026/10/28 12:12:16 INFO Received push request method=POST path=/api/pushes12722026/10/28 12:12:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12732026/10/28 12:12:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12742026/10/28 12:12:16 WARN Failed to register uploaded object key=fh8zwmja0lf2aj94nv40jq8ms85z523x.ls error="server returned 404: 404 page not found\n"12752026/10/28 12:12:16 INFO Signed narinfos id=2 count=112762026/10/28 12:12:16 INFO Uploading 1 narinfos12772026/10/28 12:12:16 INFO Received complete push request method=POST path=/api/pushes/2/complete12782026/10/28 12:12:16 WARN Failed to register uploaded object key=fh8zwmja0lf2aj94nv40jq8ms85z523x.narinfo error="server returned 404: 404 page not found\n"12792026/10/28 12:12:16 INFO Completed push id=2 objects=3 duration=1.462042ms12802026/10/28 12:12:16 INFO Upload complete. (221ms)1281=== NAME TestNARDeduplicationMetadataUploadBug1282 metadata_upload_test.go:76: Retrieved narinfo from S3:1283 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestNARDeduplicationMetadataUploadBug2971456473/001/store/fh8zwmja0lf2aj94nv40jq8ms85z523x-file2.txt1284 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1285 Compression: zstd1286 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1287 NarSize: 1601288 References: 1289 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1290 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1291 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1292 {"version":1,"root":{"type":"regular","size":44}}1293--- PASS: TestNARDeduplicationMetadataUploadBug (6.72s)1294=== CONT TestReadProxyDisabled1295--- PASS: TestPresentRefreshesOnlyStaleClosures (5.25s)1296=== CONT TestLeadElectsOneAndHandsOver12972026/10/28 12:12:16 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld7 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1298--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.30s)1299=== CONT TestReadProxyRootRedirectsToIndexHTML13002026/10/28 12:12:17 WARN readiness check failed error="closed pool"1301--- PASS: TestService_readinessHandler (5.31s)1302=== CONT TestConnectWaitsForAPeerMigration1303--- PASS: TestPresentReportsOnlyClosureRoots (5.38s)1304=== CONT TestReadProxyConditionalGet13052026/10/28 12:12:17 INFO lead: acquired remote=192.0.2.1:12341306--- PASS: TestService_healthCheckHandler (5.39s)1307=== CONT TestCompleteMultipartUpload_ErrorButObjectExists13082026/10/28 12:12:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13092026/10/28 12:12:17 WARN Refused reserved pin name=worker-x86_64-linux13102026/10/28 12:12:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13112026/10/28 12:12:17 INFO Received create pin request method=POST path=/api/pins/my-app13122026/10/28 12:12:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1313--- PASS: TestCreatePin_ReservedPins (5.56s)1314=== CONT TestResolveDBConnectionString1315=== RUN TestResolveDBConnectionString/flag_wins1316=== PAUSE TestResolveDBConnectionString/flag_wins1317=== RUN TestResolveDBConnectionString/file_when_flag_empty1318=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1319=== RUN TestResolveDBConnectionString/missing_file_is_an_error1320=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1321=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1322=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1323=== RUN TestResolveDBConnectionString/nothing_configured1324=== PAUSE TestResolveDBConnectionString/nothing_configured1325=== CONT TestClientCADerivations13262026/10/28 12:12:18 INFO lead: acquired remote=192.0.2.1:123413272026/10/28 12:12:18 INFO lead: released remote=192.0.2.1:12341328--- PASS: TestLeadIncumbentAnnouncesAtOnce (5.46s)1329=== CONT TestClientErrorHandling1330=== RUN TestClientErrorHandling/InvalidStorePath1331=== PAUSE TestClientErrorHandling/InvalidStorePath1332=== RUN TestClientErrorHandling/InvalidAuthToken1333=== PAUSE TestClientErrorHandling/InvalidAuthToken1334=== RUN TestClientErrorHandling/ServerNotAvailable1335=== PAUSE TestClientErrorHandling/ServerNotAvailable1336=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13372026/10/28 12:12:18 INFO lead: released remote=192.0.2.1:12341338--- PASS: TestLeadEndsOnShutdown (6.40s)1339=== CONT TestCacheStatsHandler1340--- PASS: TestObjectStatsUpdatedOncePerCommit (5.45s)1341=== CONT TestDeleteClosuresRacingPins1342--- PASS: TestObjectStatsTrigger (5.49s)1343=== CONT TestCacheConfigHandler1344=== RUN TestCacheConfigHandler/full_config,_no_issuer1345=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1346=== RUN TestCacheConfigHandler/no_cache_url_configured1347=== PAUSE TestCacheConfigHandler/no_cache_url_configured1348=== RUN TestCacheConfigHandler/no_signing_keys1349=== PAUSE TestCacheConfigHandler/no_signing_keys1350=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1351=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1352=== CONT TestService_ReadScope_PublicByDefault13532026/10/28 12:12:19 INFO Received uploads request method=POST path=/api/pending_closures13542026/10/28 12:12:19 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/28 12:12:19 INFO Received cleanup request method=DELETE path=/api/pending_closures13562026/10/28 12:12:19 INFO Received uploads request method=POST path=/api/pending_closures1357--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.49s)1358=== CONT TestClientFallsBackToClosures1359=== NAME TestOrphanedObjectsGC1360 orphaned_objects_gc_test.go:287: GC Test Summary:1361 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1362 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1363 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1364 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1365 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1366--- PASS: TestOrphanedObjectsGC (6.56s)1367=== CONT TestService_RequireScope_OIDC13682026/10/28 12:12:20 INFO Received uploads request method=POST path=/api/pending_closures13692026/10/28 12:12:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61639/oidc13702026/10/28 12:12:20 INFO Received cleanup request method=DELETE path=/api/pending_closures13712026/10/28 12:12:20 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket52/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13722026/10/28 12:12:20 INFO Aborted multipart uploads count=0 kept=113732026/10/28 12:12:20 INFO Received cleanup request method=DELETE path=/api/pending_closures13742026/10/28 12:12:20 INFO Aborted multipart uploads count=1 kept=01375--- PASS: TestMultipartCleanup (5.49s)1376=== CONT TestService_AuthMiddleware_OIDC13772026/10/28 12:12:20 INFO Received uploads request method=POST path=/api/pending_closures13782026/10/28 12:12:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61646/oidc13792026/10/28 12:12:20 INFO Received uploads request method=POST path=/api/pending_closures13802026/10/28 12:12:20 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13812026/10/28 12:12:20 INFO Received uploads request method=POST path=/api/pending_closures1382--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.67s)1383=== CONT TestService_ReadAuthMiddleware13842026/10/28 12:12:21 INFO Received push request method=POST path=/api/pushes1385--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.89s)1386=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1387--- PASS: TestReadRedirectUsesPublicS3URL (6.07s)1388=== CONT TestService_AuthMiddleware_MTLSProxyHeader1389--- PASS: TestReadProxyRangeRequest (5.39s)1390=== CONT TestClientPushesUseOnePush13912026/10/28 12:12:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1392--- PASS: TestReadRedirectKeepsNarinfoProxied (5.68s)1393=== CONT TestClientMultipleUploads13942026/10/28 12:12:22 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLjc3NWEwMjQ2LTQwOTEtNGFkMS1hZDQ2LTcwNTZkM2U0OTdiMHgxNzkzMTg5NTQwMzAxMzA5MDAw parts=1213952026/10/28 12:12:22 INFO Received uploads request method=POST path=/api/pending_closures1396--- PASS: TestCompletedNarNotReofferedAcrossClosures (7.30s)1397=== CONT TestClientWithDependencies1398--- PASS: TestReadRedirectNar (5.94s)1399=== CONT TestClientIntegration1400--- PASS: TestReadProxyDisabled (5.93s)1401=== CONT TestRedundantMultipartUpload14022026/10/28 12:12:22 INFO lead: acquired remote=192.0.2.1:12341403--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.31s)1404=== CONT TestPinProtectsFromGC1405--- PASS: TestReadProxyConditionalGet (6.17s)1406=== CONT TestReadProxyNarStreaming1407--- PASS: TestConnectWaitsForAPeerMigration (6.45s)1408=== CONT TestClientSharedPathCommittedMidPush14092026/10/28 12:12:23 INFO Received uploads request method=POST path=/api/pending_closures14102026/10/28 12:12:24 INFO lead: released remote=192.0.2.1:123414112026/10/28 12:12:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14122026/10/28 12:12:24 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLmQ5MWIwNjRiLWYyM2YtNDU2My1hMmY1LWQzYWYzOTMyZTk0N3gxNzkzMTg5NTQzODg2OTU1MDAw14132026/10/28 12:12:24 INFO lead: acquired remote=192.0.2.1:123414142026/10/28 12:12:24 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLmQ5MWIwNjRiLWYyM2YtNDU2My1hMmY1LWQzYWYzOTMyZTk0N3gxNzkzMTg5NTQzODg2OTU1MDAw parts=11415--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.44s)1416=== CONT TestReadProxyHead1417=== NAME TestClientCADerivations1418 client_ca_test.go:136: Built CA derivation: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientCADerivations1800313022/001/store/f36i1a2i70cfn51qi9jp3fj47yfnyysy-ca-test1419--- PASS: TestCacheStatsHandler (6.10s)1420=== CONT TestReadProxyInvalidPath1421=== NAME TestClientCADerivations1422 client_ca_test.go:139: Found 1 dependencies (including self)1423--- PASS: TestService_ReadScope_PublicByDefault (6.01s)1424=== CONT TestReadProxyNarinfoAlreadyDecompressed1425--- PASS: TestReadProxyOutlastsServerWriteTimeout (9.89s)1426=== CONT TestReadProxy40414272026/10/28 12:12:25 INFO Received push request method=POST path=/api/pushes14282026/10/28 12:12:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14292026/10/28 12:12:25 INFO Uploading f36i1a2i70cfn51qi9jp3fj47yfnyysy-ca-test (144B)14302026/10/28 12:12:25 WARN Failed to register uploaded object key=f36i1a2i70cfn51qi9jp3fj47yfnyysy.ls error="server returned 404: 404 page not found\n"14312026/10/28 12:12:25 INFO lead: released remote=192.0.2.1:12341432--- PASS: TestLeadElectsOneAndHandsOver (8.48s)14332026/10/28 12:12:25 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1434=== CONT TestReadProxyContentNegotiation14352026/10/28 12:12:25 WARN Failed to register uploaded object key=log/kkmhxic6lhbkivawc0bdqrncxpn4gg73-ca-test.drv error="server returned 404: 404 page not found\n"14362026/10/28 12:12:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14372026/10/28 12:12:25 INFO Signed narinfos id=1 count=114382026/10/28 12:12:25 INFO Uploading 1 narinfos14392026/10/28 12:12:25 INFO Received complete push request method=POST path=/api/pushes/1/complete14402026/10/28 12:12:25 WARN Failed to register uploaded object key=f36i1a2i70cfn51qi9jp3fj47yfnyysy.narinfo error="server returned 404: 404 page not found\n"14412026/10/28 12:12:25 INFO Completed push id=1 objects=4 duration=22.2435ms14422026/10/28 12:12:25 INFO Upload complete. (477ms)1443=== NAME TestClientCADerivations1444 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientCADerivations1800313022/001/store/f36i1a2i70cfn51qi9jp3fj47yfnyysy-ca-test1445 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1446 Compression: zstd1447 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1448 NarSize: 1441449 References: 1450 Deriver: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientCADerivations1800313022/001/store/kkmhxic6lhbkivawc0bdqrncxpn4gg73-ca-test.drv1451 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1452 client_ca_test.go:185: Checking for realisation files in S3...1453 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1454 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14552026/10/28 12:12:25 INFO Aborted multipart uploads count=1 kept=01456--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.25s)1457=== CONT TestReadProxyNarinfo14582026/10/28 12:12:25 INFO Received cleanup request method=DELETE path=/api/pending_closures14592026/10/28 12:12:25 INFO Aborted multipart uploads count=1 kept=01460--- PASS: TestPendingCleanupUsesOneCutoff (11.82s)1461=== CONT TestIsValidCachePath1462=== RUN TestIsValidCachePath/narinfo1463=== PAUSE TestIsValidCachePath/narinfo1464=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1465=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1466=== RUN TestIsValidCachePath/nar_zst1467=== PAUSE TestIsValidCachePath/nar_zst1468=== RUN TestIsValidCachePath/nar_xz1469=== PAUSE TestIsValidCachePath/nar_xz1470=== RUN TestIsValidCachePath/nar_bz21471=== PAUSE TestIsValidCachePath/nar_bz21472=== RUN TestIsValidCachePath/nar_uncompressed1473=== PAUSE TestIsValidCachePath/nar_uncompressed1474=== RUN TestIsValidCachePath/ls1475=== PAUSE TestIsValidCachePath/ls1476=== RUN TestIsValidCachePath/log1477=== PAUSE TestIsValidCachePath/log1478=== RUN TestIsValidCachePath/realisation1479=== PAUSE TestIsValidCachePath/realisation1480=== RUN TestIsValidCachePath/nix-cache-info1481=== PAUSE TestIsValidCachePath/nix-cache-info1482=== RUN TestIsValidCachePath/index.html1483=== PAUSE TestIsValidCachePath/index.html1484=== RUN TestIsValidCachePath/traversal_parent1485=== PAUSE TestIsValidCachePath/traversal_parent1486=== RUN TestIsValidCachePath/traversal_in_middle1487=== PAUSE TestIsValidCachePath/traversal_in_middle1488=== RUN TestIsValidCachePath/invalid_char_e1489=== PAUSE TestIsValidCachePath/invalid_char_e1490=== RUN TestIsValidCachePath/invalid_char_u1491=== PAUSE TestIsValidCachePath/invalid_char_u1492=== RUN TestIsValidCachePath/random_path1493=== PAUSE TestIsValidCachePath/random_path1494=== RUN TestIsValidCachePath/empty1495=== PAUSE TestIsValidCachePath/empty1496=== RUN TestIsValidCachePath/leading_slash1497=== PAUSE TestIsValidCachePath/leading_slash1498=== RUN TestIsValidCachePath/wrong_extension1499=== PAUSE TestIsValidCachePath/wrong_extension1500=== RUN TestIsValidCachePath/short_hash1501=== PAUSE TestIsValidCachePath/short_hash1502=== CONT TestProxyWriteTimeout/narinfo1503=== CONT TestProxyWriteTimeout/unknown_size1504=== CONT TestProxyWriteTimeout/10_GiB_nar1505=== CONT TestProxyWriteTimeout/1_GiB_nar1506--- PASS: TestProxyWriteTimeout (0.00s)1507 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1508 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1509 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1510 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1511=== CONT TestPendingClosureWriteTimeout/empty1512=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15132026/10/28 12:12:25 INFO Received uploads request method=POST path=/1514=== CONT TestGCEndsOnShutdown/before_the_run1515=== NAME TestClientCADerivations1516 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket66?endpoint=http://localhost:61189®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientCADerivations1800313022/001/store'1517 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11518--- PASS: TestClientCADerivations (7.55s)1519=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1520=== RUN TestService_RequireScope_OIDC/builder_may_write1521=== PAUSE TestService_RequireScope_OIDC/builder_may_write1522=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1523=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1524=== RUN TestService_RequireScope_OIDC/ops_may_admin1525=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1526=== RUN TestService_RequireScope_OIDC/ops_may_not_write1527=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1528=== RUN TestService_RequireScope_OIDC/reader_may_not_write1529=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1530=== RUN TestService_RequireScope_OIDC/static_token_may_admin1531=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1532=== RUN TestService_RequireScope_OIDC/static_token_may_write1533=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1534=== RUN TestService_RequireScope_OIDC/reader_may_read1535=== PAUSE TestService_RequireScope_OIDC/reader_may_read1536=== RUN TestService_RequireScope_OIDC/writer_implies_read1537=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1538=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1539=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1540=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1541=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1542=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1543=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1544=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1545=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1546=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1547=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1548=== CONT TestPendingClosureWriteTimeout/670k_objects1549=== CONT TestPendingClosureWriteTimeout/400_objects1550=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15512026/10/28 12:12:25 INFO Received request for more parts method=POST path=/1552=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15532026/10/28 12:12:25 INFO Received complete multipart upload request method=POST path=/1554=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15552026/10/28 12:12:25 INFO Received uploads request method=POST path=/1556--- PASS: TestUploadHandlersRejectInvalidKeys (0.05s)1557 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1558 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1559 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1560 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1561=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1562=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1563=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1564=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1565=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1566=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1567=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1568=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1569=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1570=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15712026/10/28 12:12:26 INFO Received uploads request method=POST path=/api/pending_closures15722026/10/28 12:12:26 INFO Received uploads request method=POST path=/api/pending_closures15732026/10/28 12:12:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15742026/10/28 12:12:26 INFO Uploading 8cxxg76jq7mb7jqay44vr99v046f2dxy-shared-dep (136B)15752026/10/28 12:12:26 INFO Uploading zam937irmpk05gknjvjad4lfdnk665lh-b (256B)15762026/10/28 12:12:26 WARN Failed to register uploaded object key=8cxxg76jq7mb7jqay44vr99v046f2dxy.ls error="server returned 404: 404 page not found\n"15772026/10/28 12:12:26 WARN Failed to register uploaded object key=x5c8pzzc9l4zjg9vki2yflj5scdhsfn8.ls error="server returned 404: 404 page not found\n"15782026/10/28 12:12:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15792026/10/28 12:12:26 WARN Failed to register uploaded object key=zam937irmpk05gknjvjad4lfdnk665lh.ls error="server returned 404: 404 page not found\n"15802026/10/28 12:12:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15812026/10/28 12:12:26 WARN Failed to register uploaded object key=nar/1qzrr8favvknnp1h5svnsiwjkqh6axf1jnl840jasg575fii4f96.nar.zst error="server returned 404: 404 page not found\n"15822026/10/28 12:12:26 INFO Signed narinfos id=1 count=215832026/10/28 12:12:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15842026/10/28 12:12:26 INFO Signed narinfos id=2 count=215852026/10/28 12:12:26 INFO Uploading 4 narinfos1586--- PASS: TestService_ReadAuthMiddleware (5.95s)1587=== CONT TestServerTLSConfig/no_client_CA1588=== CONT TestServerTLSConfig/not_a_PEM_file1589=== CONT TestServerTLSConfig/missing_CA_file1590--- PASS: TestServerTLSConfig (0.00s)1591 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1592 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1593 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1594=== CONT TestIsValidUploadKey/narinfo1595=== CONT TestParseSingleRange/none1596=== CONT TestParseSingleRange/start_far_past_EOF1597=== CONT TestParseSingleRange/start_past_EOF1598=== CONT TestParseSingleRange/single_byte1599=== CONT TestParseSingleRange/suffix_exceeds_size1600=== CONT TestParseSingleRange/suffix1601=== CONT TestParseSingleRange/end_clamped_to_size1602=== CONT TestParseSingleRange/open-ended1603=== CONT TestParseSingleRange/closed1604=== CONT TestParseSingleRange/malformed_end_before_start1605=== CONT TestParseSingleRange/malformed_both_empty1606=== CONT TestParseSingleRange/malformed_no_dash1607=== CONT TestParseSingleRange/multi-range_ignored1608=== CONT TestParseSingleRange/unknown_unit1609--- PASS: TestParseSingleRange (0.05s)1610 --- PASS: TestParseSingleRange/none (0.00s)1611 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1612 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1613 --- PASS: TestParseSingleRange/single_byte (0.00s)1614 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1615 --- PASS: TestParseSingleRange/suffix (0.00s)1616 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1617 --- PASS: TestParseSingleRange/open-ended (0.00s)1618 --- PASS: TestParseSingleRange/closed (0.00s)1619 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1620 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1621 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1622 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1623 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1624=== CONT TestIsValidUploadKey/realisation_plus_in_output1625=== CONT TestIsValidUploadKey/unknown_type1626=== CONT TestIsValidUploadKey/empty_key1627=== CONT TestIsValidUploadKey/absolute1628=== CONT TestIsValidUploadKey/traversal_nar1629=== CONT TestIsValidUploadKey/traversal1630=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1631=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1632=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1633=== CONT TestIsValidUploadKey/index.html1634=== CONT TestIsValidUploadKey/nix-cache-info1635=== CONT TestIsValidUploadKey/build_log_home-manager_file1636=== CONT TestIsValidUploadKey/realisation1637=== CONT TestIsValidUploadKey/build_log_equals1638=== CONT TestIsValidUploadKey/build_log_question_mark1639=== CONT TestIsValidUploadKey/build_log_plus_in_name1640=== CONT TestIsValidUploadKey/nar_plain1641=== CONT TestIsValidUploadKey/build_log1642=== CONT TestIsValidUploadKey/listing1643=== CONT TestIsValidUploadKey/nar_xz1644=== CONT TestIsValidUploadKey/nar_zst1645--- PASS: TestIsValidUploadKey (0.05s)1646 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1647 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1648 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1649 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1650 --- PASS: TestIsValidUploadKey/absolute (0.00s)1651 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1652 --- PASS: TestIsValidUploadKey/traversal (0.00s)1653 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1654 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1655 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1656 --- PASS: TestIsValidUploadKey/index.html (0.00s)1657 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1658 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1659 --- PASS: TestIsValidUploadKey/realisation (0.00s)1660 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1662 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1663 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1664 --- PASS: TestIsValidUploadKey/build_log (0.00s)1665 --- PASS: TestIsValidUploadKey/listing (0.00s)1666 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1667 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1668=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16692026/10/28 12:12:26 INFO Received request for more parts method=POST path=/1670=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16712026/10/28 12:12:26 INFO Received complete multipart upload request method=POST path=/16722026/10/28 12:12:26 WARN Failed to register uploaded object key=x5c8pzzc9l4zjg9vki2yflj5scdhsfn8.narinfo error="server returned 404: 404 page not found\n"16732026/10/28 12:12:26 WARN Failed to register uploaded object key=zam937irmpk05gknjvjad4lfdnk665lh.narinfo error="server returned 404: 404 page not found\n"16742026/10/28 12:12:26 WARN Failed to register uploaded object key=8cxxg76jq7mb7jqay44vr99v046f2dxy.narinfo error="server returned 404: 404 page not found\n"1675=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16762026/10/28 12:12:26 INFO Received uploads request method=POST path=/16772026/10/28 12:12:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16782026/10/28 12:12:26 WARN Failed to register uploaded object key=8cxxg76jq7mb7jqay44vr99v046f2dxy.narinfo error="server returned 404: 404 page not found\n"16792026/10/28 12:12:26 INFO Completed upload id=1 objects=6 duration=38.243041ms16802026/10/28 12:12:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16812026/10/28 12:12:26 INFO Completed upload id=2 objects=6 duration=1.570708ms16822026/10/28 12:12:26 INFO Upload complete. (629ms)1683=== NAME TestClientFallsBackToClosures1684 client_pushes_test.go:112: Retrieved narinfo from S3:1685 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientFallsBackToClosures3347752740/001/store/8cxxg76jq7mb7jqay44vr99v046f2dxy-shared-dep1686 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1687 Compression: zstd1688 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821689 NarSize: 1361690 References: 1691 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1692 client_pushes_test.go:112: Retrieved narinfo from S3:1693 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientFallsBackToClosures3347752740/001/store/x5c8pzzc9l4zjg9vki2yflj5scdhsfn8-a1694 URL: nar/1qzrr8favvknnp1h5svnsiwjkqh6axf1jnl840jasg575fii4f96.nar.zst1695 Compression: zstd1696 NarHash: sha256:1qzrr8favvknnp1h5svnsiwjkqh6axf1jnl840jasg575fii4f961697 NarSize: 2561698 References: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientFallsBackToClosures3347752740/001/store/8cxxg76jq7mb7jqay44vr99v046f2dxy-shared-dep1699 CA: text:sha256:1svnnrzai1yz1grykyyrxqkxrmb73x8s1ndzy46x101ml382x3cl1700 client_pushes_test.go:112: Retrieved narinfo from S3:1701 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientFallsBackToClosures3347752740/001/store/zam937irmpk05gknjvjad4lfdnk665lh-b1702 URL: nar/1qzrr8favvknnp1h5svnsiwjkqh6axf1jnl840jasg575fii4f96.nar.zst1703 Compression: zstd1704 NarHash: sha256:1qzrr8favvknnp1h5svnsiwjkqh6axf1jnl840jasg575fii4f961705 NarSize: 2561706 References: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientFallsBackToClosures3347752740/001/store/8cxxg76jq7mb7jqay44vr99v046f2dxy-shared-dep1707 CA: text:sha256:1svnnrzai1yz1grykyyrxqkxrmb73x8s1ndzy46x101ml382x3cl1708--- PASS: TestClientFallsBackToClosures (7.20s)1709=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows17102026/10/28 12:12:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17112026/10/28 12:12:26 WARN mTLS auth: bound subjects configured but subject DN unavailable17122026/10/28 12:12:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1713--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.70s)1714=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1715--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)1716 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1717 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1718 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.55s)1719=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1720--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (5.75s)1721=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1722=== NAME TestClientMultipleUploads1723 client_integration_test.go:405: Created store path 0: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientMultipleUploads2952647921/001/store/83gwq27zk0bzhcbg036k5ai1jdhsq5cl-test-file-0.txt1724 client_integration_test.go:405: Created store path 1: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientMultipleUploads2952647921/001/store/5sq2vb3dvhflgg6f0giink4ibn69cn9d-test-file-1.txt17252026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes1726 client_integration_test.go:405: Created store path 2: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientMultipleUploads2952647921/001/store/86pkaky54qksj6xh2aw248jrykyazhg0-test-file-2.txt17272026/10/28 12:12:28 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17282026/10/28 12:12:28 INFO Uploading bm1h0cigf8ib9bc7nw64q66gc013426d-a (256B)17292026/10/28 12:12:28 INFO Uploading 5yj4a5nfm8hgx71y3n22l96bfbplmfid-shared-dep (136B)17302026/10/28 12:12:28 WARN Failed to register uploaded object key=8nwsr7m73sgk3wq8zfckammbzwazqm4y.ls error="server returned 404: 404 page not found\n"17312026/10/28 12:12:28 WARN Failed to register uploaded object key=bm1h0cigf8ib9bc7nw64q66gc013426d.ls error="server returned 404: 404 page not found\n"17322026/10/28 12:12:28 WARN Failed to register uploaded object key=nar/0pmqqljg374q297g43spcdn791s612dd6l2f7spsdzc1pnqgmhmp.nar.zst error="server returned 404: 404 page not found\n"17332026/10/28 12:12:28 WARN Failed to register uploaded object key=5yj4a5nfm8hgx71y3n22l96bfbplmfid.ls error="server returned 404: 404 page not found\n"17342026/10/28 12:12:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17352026/10/28 12:12:28 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17362026/10/28 12:12:28 INFO Signed narinfos id=1 count=317372026/10/28 12:12:28 INFO Uploading 3 narinfos17382026/10/28 12:12:28 WARN Failed to register uploaded object key=bm1h0cigf8ib9bc7nw64q66gc013426d.narinfo error="server returned 404: 404 page not found\n"17392026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes17402026/10/28 12:12:28 WARN Failed to register uploaded object key=5yj4a5nfm8hgx71y3n22l96bfbplmfid.narinfo error="server returned 404: 404 page not found\n"17412026/10/28 12:12:28 INFO Received complete push request method=POST path=/api/pushes/1/complete17422026/10/28 12:12:28 WARN Failed to register uploaded object key=8nwsr7m73sgk3wq8zfckammbzwazqm4y.narinfo error="server returned 404: 404 page not found\n"17432026/10/28 12:12:28 INFO Completed push id=1 objects=8 duration=9.120667ms17442026/10/28 12:12:28 INFO Upload complete. (455ms)1745=== NAME TestClientPushesUseOnePush17462026/10/28 12:12:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1747 client_pushes_test.go:97: Retrieved narinfo from S3:1748 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientPushesUseOnePush2872442971/001/store/5yj4a5nfm8hgx71y3n22l96bfbplmfid-shared-dep1749 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1750 Compression: zstd1751 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821752 NarSize: 1361753 References: 1754 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17552026/10/28 12:12:28 INFO Uploading 83gwq27zk0bzhcbg036k5ai1jdhsq5cl-test-file-0.txt (160B)17562026/10/28 12:12:28 INFO Uploading 86pkaky54qksj6xh2aw248jrykyazhg0-test-file-2.txt (160B)17572026/10/28 12:12:28 INFO Uploading 5sq2vb3dvhflgg6f0giink4ibn69cn9d-test-file-1.txt (160B)1758 client_pushes_test.go:97: Retrieved narinfo from S3:1759 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientPushesUseOnePush2872442971/001/store/bm1h0cigf8ib9bc7nw64q66gc013426d-a1760 URL: nar/0pmqqljg374q297g43spcdn791s612dd6l2f7spsdzc1pnqgmhmp.nar.zst1761 Compression: zstd1762 NarHash: sha256:0pmqqljg374q297g43spcdn791s612dd6l2f7spsdzc1pnqgmhmp1763 NarSize: 2561764 References: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientPushesUseOnePush2872442971/001/store/5yj4a5nfm8hgx71y3n22l96bfbplmfid-shared-dep1765 CA: text:sha256:0w1wnf91f32w27hyll5c9gxzciawx14i3yvjr99lkh993fc6pirx1766 client_pushes_test.go:97: Retrieved narinfo from S3:1767 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientPushesUseOnePush2872442971/001/store/8nwsr7m73sgk3wq8zfckammbzwazqm4y-b1768 URL: nar/0pmqqljg374q297g43spcdn791s612dd6l2f7spsdzc1pnqgmhmp.nar.zst1769 Compression: zstd1770 NarHash: sha256:0pmqqljg374q297g43spcdn791s612dd6l2f7spsdzc1pnqgmhmp1771 NarSize: 2561772 References: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientPushesUseOnePush2872442971/001/store/5yj4a5nfm8hgx71y3n22l96bfbplmfid-shared-dep1773 CA: text:sha256:0w1wnf91f32w27hyll5c9gxzciawx14i3yvjr99lkh993fc6pirx17742026/10/28 12:12:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17752026/10/28 12:12:28 WARN Failed to register uploaded object key=86pkaky54qksj6xh2aw248jrykyazhg0.ls error="server returned 404: 404 page not found\n"17762026/10/28 12:12:28 WARN Failed to register uploaded object key=5sq2vb3dvhflgg6f0giink4ibn69cn9d.ls error="server returned 404: 404 page not found\n"17772026/10/28 12:12:28 WARN Failed to register uploaded object key=83gwq27zk0bzhcbg036k5ai1jdhsq5cl.ls error="server returned 404: 404 page not found\n"17782026/10/28 12:12:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17792026/10/28 12:12:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17802026/10/28 12:12:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17812026/10/28 12:12:28 INFO Signed narinfos id=1 count=31782--- PASS: TestClientPushesUseOnePush (7.00s)1783=== CONT TestPush_RejectsBadRequests/bad_root17842026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes1785=== CONT TestPush_RejectsBadRequests/no_roots1786=== NAME TestClientWithDependencies1787 client_integration_test.go:660: Built derivation: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientWithDependencies1319743244/001/store/c7l98xfws7gi86m9z2ib3wvkxlwyjg6i-test-script17882026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes17892026/10/28 12:12:28 INFO Uploading 3 narinfos1790=== CONT TestPush_RejectsBadRequests/no_objects17912026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes1792=== CONT TestPush_RejectsBadRequests/root_not_in_objects17932026/10/28 12:12:28 INFO Received push request method=POST path=/api/pushes1794--- PASS: TestPush_RejectsBadRequests (4.22s)1795 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1796 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1797 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)1798 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1799=== CONT TestResolveDBConnectionString/flag_wins1800=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1801=== CONT TestResolveDBConnectionString/nothing_configured1802=== CONT TestResolveDBConnectionString/missing_file_is_an_error1803=== CONT TestResolveDBConnectionString/file_when_flag_empty1804--- PASS: TestResolveDBConnectionString (0.00s)1805 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1806 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1807 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1808 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1809 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1810=== CONT TestClientErrorHandling/InvalidStorePath18112026/10/28 12:12:28 WARN Failed to register uploaded object key=83gwq27zk0bzhcbg036k5ai1jdhsq5cl.narinfo error="server returned 404: 404 page not found\n"18122026/10/28 12:12:28 WARN Failed to register uploaded object key=5sq2vb3dvhflgg6f0giink4ibn69cn9d.narinfo error="server returned 404: 404 page not found\n"1813=== NAME TestClientWithDependencies1814 client_integration_test.go:662: Found 1 dependencies (including self)18152026/10/28 12:12:28 INFO Received complete push request method=POST path=/api/pushes/1/complete18162026/10/28 12:12:28 WARN Failed to register uploaded object key=86pkaky54qksj6xh2aw248jrykyazhg0.narinfo error="server returned 404: 404 page not found\n"18172026/10/28 12:12:28 INFO Completed push id=1 objects=9 duration=13.5845ms18182026/10/28 12:12:28 INFO Upload complete. (505ms)1819=== NAME TestClientMultipleUploads1820 client_integration_test.go:416: Uploaded 3 paths in 596.303541ms1821--- PASS: TestDeleteClosuresRacingPins (10.02s)1822=== CONT TestClientErrorHandling/ServerNotAvailable1823=== NAME TestClientIntegration1824 client_integration_test.go:291: Created store path: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientIntegration3143698691/002/store/q8v96g65c0n0qzvz8nmvllz5f5d3na8k-test-file.txt1825--- PASS: TestClientMultipleUploads (6.88s)1826=== CONT TestClientErrorHandling/InvalidAuthToken18272026/10/28 12:12:29 INFO Received uploads request method=POST path=/api/pending_closures18282026/10/28 12:12:29 INFO Received uploads request method=POST path=/api/pending_closures18292026/10/28 12:12:29 INFO Received push request method=POST path=/api/pushes18302026/10/28 12:12:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18312026/10/28 12:12:29 INFO Uploading c7l98xfws7gi86m9z2ib3wvkxlwyjg6i-test-script (136B)18322026/10/28 12:12:29 INFO Received push request method=POST path=/api/pushes18332026/10/28 12:12:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18342026/10/28 12:12:29 INFO Uploading q8v96g65c0n0qzvz8nmvllz5f5d3na8k-test-file.txt (152B)18352026/10/28 12:12:29 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/present18362026/10/28 12:12:29 WARN Failed to register uploaded object key=c7l98xfws7gi86m9z2ib3wvkxlwyjg6i.ls error="server returned 404: 404 page not found\n"18372026/10/28 12:12:29 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18382026/10/28 12:12:29 WARN Failed to register uploaded object key=log/apavpppm5ybhcgg3i9ibb2il9gjzxf4r-test-script.drv error="server returned 404: 404 page not found\n"18392026/10/28 12:12:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18402026/10/28 12:12:29 INFO Signed narinfos id=1 count=118412026/10/28 12:12:29 INFO Uploading 1 narinfos18422026/10/28 12:12:29 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18432026/10/28 12:12:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18442026/10/28 12:12:29 WARN Failed to register uploaded object key=q8v96g65c0n0qzvz8nmvllz5f5d3na8k.ls error="server returned 404: 404 page not found\n"18452026/10/28 12:12:29 INFO Signed narinfos id=1 count=118462026/10/28 12:12:29 INFO Uploading 1 narinfos18472026/10/28 12:12:29 INFO Received complete push request method=POST path=/api/pushes/1/complete18482026/10/28 12:12:29 WARN Failed to register uploaded object key=c7l98xfws7gi86m9z2ib3wvkxlwyjg6i.narinfo error="server returned 404: 404 page not found\n"18492026/10/28 12:12:29 WARN Request failed, retrying attempt=2 backoff=206.020819ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18502026/10/28 12:12:29 INFO Completed push id=1 objects=4 duration=19.565875ms18512026/10/28 12:12:29 INFO Upload complete. (347ms)1852=== NAME TestClientWithDependencies1853 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientWithDependencies1319743244/001/store) requires matching store prefix18542026/10/28 12:12:29 INFO Received complete push request method=POST path=/api/pushes/1/complete18552026/10/28 12:12:29 WARN Failed to register uploaded object key=q8v96g65c0n0qzvz8nmvllz5f5d3na8k.narinfo error="server returned 404: 404 page not found\n"18562026/10/28 12:12:29 INFO Completed push id=1 objects=3 duration=23.283958ms18572026/10/28 12:12:29 INFO Upload complete. (379ms)1858--- PASS: TestClientWithDependencies (7.29s)1859=== CONT TestCacheConfigHandler/full_config,_no_issuer1860=== CONT TestCacheConfigHandler/no_signing_keys1861=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1862=== CONT TestCacheConfigHandler/no_cache_url_configured1863--- PASS: TestCacheConfigHandler (0.00s)1864 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1865 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1866 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1867 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1868=== CONT TestIsValidCachePath/narinfo1869=== CONT TestIsValidCachePath/short_hash1870=== CONT TestIsValidCachePath/index.html1871=== CONT TestIsValidCachePath/wrong_extension1872=== CONT TestIsValidCachePath/leading_slash1873=== CONT TestIsValidCachePath/empty1874=== CONT TestIsValidCachePath/random_path1875=== CONT TestIsValidCachePath/invalid_char_u1876=== CONT TestIsValidCachePath/invalid_char_e1877=== CONT TestIsValidCachePath/traversal_in_middle1878=== CONT TestIsValidCachePath/traversal_parent1879=== CONT TestIsValidCachePath/nar_uncompressed1880=== CONT TestIsValidCachePath/nix-cache-info1881=== CONT TestIsValidCachePath/realisation1882=== CONT TestIsValidCachePath/log1883=== CONT TestIsValidCachePath/ls1884=== CONT TestIsValidCachePath/nar_xz1885=== CONT TestIsValidCachePath/nar_bz21886=== CONT TestIsValidCachePath/nar_zst1887=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1888--- PASS: TestIsValidCachePath (0.01s)1889 --- PASS: TestIsValidCachePath/narinfo (0.00s)1890 --- PASS: TestIsValidCachePath/short_hash (0.00s)1891 --- PASS: TestIsValidCachePath/index.html (0.00s)1892 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1893 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1894 --- PASS: TestIsValidCachePath/empty (0.00s)1895 --- PASS: TestIsValidCachePath/random_path (0.00s)1896 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1897 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1898 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1899 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1900 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1901 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1902 --- PASS: TestIsValidCachePath/realisation (0.00s)1903 --- PASS: TestIsValidCachePath/log (0.00s)1904 --- PASS: TestIsValidCachePath/ls (0.00s)1905 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1906 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1907 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1908 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1909=== CONT TestService_RequireScope_OIDC/builder_may_write1910=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1911=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19122026/10/28 12:12:29 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]1913=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1914=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1915=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1916=== CONT TestService_RequireScope_OIDC/writer_implies_read1917=== CONT TestService_RequireScope_OIDC/reader_may_read1918=== CONT TestService_RequireScope_OIDC/static_token_may_write1919=== CONT TestService_RequireScope_OIDC/static_token_may_admin1920=== CONT TestService_RequireScope_OIDC/reader_may_not_write1921=== CONT TestService_RequireScope_OIDC/ops_may_not_write1922=== CONT TestService_RequireScope_OIDC/ops_may_admin1923=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1924=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1925--- PASS: TestService_RequireScope_OIDC (5.95s)1926 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1927 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1928 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1929 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1930 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1931 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1932 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1933 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1934 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1935 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1936 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1937 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1938 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1939 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)19402026/10/28 12:12:29 INFO All 1 paths already cached1941=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19422026/10/28 12:12:29 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]1943=== NAME TestClientIntegration1944 client_integration_test.go:317: Retrieved narinfo from S3:1945 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientIntegration3143698691/002/store/q8v96g65c0n0qzvz8nmvllz5f5d3na8k-test-file.txt1946 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1947 Compression: zstd1948 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11949 NarSize: 1521950 References: 1951 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11952=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1953=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1954=== NAME TestClientIntegration19552026/10/28 12:12:29 WARN Authentication failed token_preview=eyJhbGciOi...m6gxcN7KEw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1956 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1957 client_integration_test.go:318: Decompressed .ls content (64 bytes):1958 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1959--- PASS: TestService_AuthMiddleware_OIDC (6.00s)1960 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1961 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1962 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1963 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)19642026/10/28 12:12:29 WARN Request failed, retrying attempt=3 backoff=427.947661ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1965=== NAME TestPinProtectsFromGC1966 client_integration_test.go:778: Pinned store path: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestPinProtectsFromGC421363797/001/store/k4lbwhq6kifmvi124z697k71k6pn0lr3-pinned-file.txt1967 client_integration_test.go:779: Unpinned store path: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestPinProtectsFromGC421363797/001/store/z17v7bjm9l44xkmwdh9wk75n7pz645ai-unpinned-file.txt19682026/10/28 12:12:30 INFO Received push request method=POST path=/api/pushes19692026/10/28 12:12:30 WARN Request failed, retrying attempt=4 backoff=807.260719ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19702026/10/28 12:12:30 INFO Object in database but missing from S3 key=q8v96g65c0n0qzvz8nmvllz5f5d3na8k.ls19712026/10/28 12:12:30 WARN Found objects in DB but missing from S3, will re-upload count=119722026/10/28 12:12:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19732026/10/28 12:12:30 INFO Received push request method=POST path=/api/pushes19742026/10/28 12:12:30 INFO Received complete push request method=POST path=/api/pushes/2/complete19752026/10/28 12:12:30 WARN Failed to register uploaded object key=q8v96g65c0n0qzvz8nmvllz5f5d3na8k.ls error="server returned 404: 404 page not found\n"19762026/10/28 12:12:30 INFO Completed push id=2 objects=3 duration=3.34775ms19772026/10/28 12:12:30 INFO Upload complete. (211ms)1978=== NAME TestClientIntegration1979 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1980 client_integration_test.go:335: Decompressed .ls content (49 bytes):1981 {"version":1,"root":{"type":"regular","size":39}}19822026/10/28 12:12:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19832026/10/28 12:12:30 INFO Uploading k4lbwhq6kifmvi124z697k71k6pn0lr3-pinned-file.txt (128B)1984--- PASS: TestReadProxyNarStreaming (6.58s)19852026/10/28 12:12:30 WARN Failed to register uploaded object key=k4lbwhq6kifmvi124z697k71k6pn0lr3.ls error="server returned 404: 404 page not found\n"19862026/10/28 12:12:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19872026/10/28 12:12:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"19882026/10/28 12:12:30 INFO Signed narinfos id=1 count=119892026/10/28 12:12:30 INFO Uploading 1 narinfos19902026/10/28 12:12:30 INFO Received complete push request method=POST path=/api/pushes/1/complete19912026/10/28 12:12:30 WARN Failed to register uploaded object key=k4lbwhq6kifmvi124z697k71k6pn0lr3.narinfo error="server returned 404: 404 page not found\n"19922026/10/28 12:12:30 INFO Completed push id=1 objects=3 duration=14.225917ms19932026/10/28 12:12:30 INFO Upload complete. (346ms)19942026/10/28 12:12:30 INFO Received push request method=POST path=/api/pushes19952026/10/28 12:12:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19962026/10/28 12:12:30 INFO Uploading xrbxxcwcxmsgqk27ir73bnh4xicmq4yv-top (264B)19972026/10/28 12:12:30 INFO Uploading f83afn9f13jv8lkpp4g6r0a4199f5wrn-shared-dep (136B)1998=== NAME TestOrphanedObjectsGCStressTest1999 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20002026/10/28 12:12:30 WARN Failed to register uploaded object key=xrbxxcwcxmsgqk27ir73bnh4xicmq4yv.ls error="server returned 404: 404 page not found\n"2001 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion20022026/10/28 12:12:30 INFO Received push request method=POST path=/api/pushes20032026/10/28 12:12:30 WARN Failed to register uploaded object key=f83afn9f13jv8lkpp4g6r0a4199f5wrn.ls error="server returned 404: 404 page not found\n"20042026/10/28 12:12:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20052026/10/28 12:12:30 INFO Uploading z17v7bjm9l44xkmwdh9wk75n7pz645ai-unpinned-file.txt (128B)20062026/10/28 12:12:30 WARN Failed to register uploaded object key=nar/05x4l3h9z39mqw6a0dxwbmwvffy03z02wscj4h4d6xs2g04gnzk3.nar.zst error="server returned 404: 404 page not found\n"20072026/10/28 12:12:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20082026/10/28 12:12:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20092026/10/28 12:12:30 INFO Signed narinfos id=1 count=220102026/10/28 12:12:30 INFO Uploading 2 narinfos20112026/10/28 12:12:30 WARN Failed to register uploaded object key=z17v7bjm9l44xkmwdh9wk75n7pz645ai.ls error="server returned 404: 404 page not found\n"20122026/10/28 12:12:30 WARN Failed to register uploaded object key=xrbxxcwcxmsgqk27ir73bnh4xicmq4yv.narinfo error="server returned 404: 404 page not found\n"2013--- PASS: TestReadProxyHead (6.39s)20142026/10/28 12:12:30 INFO Received push request method=POST path=/api/pushes20152026/10/28 12:12:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20162026/10/28 12:12:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20172026/10/28 12:12:30 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20182026/10/28 12:12:30 INFO Signed narinfos id=2 count=120192026/10/28 12:12:30 INFO Received complete push request method=POST path=/api/pushes/1/complete20202026/10/28 12:12:30 WARN Failed to register uploaded object key=f83afn9f13jv8lkpp4g6r0a4199f5wrn.narinfo error="server returned 404: 404 page not found\n"20212026/10/28 12:12:30 INFO Uploading 1 narinfos20222026/10/28 12:12:30 INFO Completed push id=1 objects=6 duration=26.215125ms20232026/10/28 12:12:30 INFO Upload complete. (389ms)2024=== NAME TestClientSharedPathCommittedMidPush2025 client_integration_test.go:727: Retrieved narinfo from S3:2026 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientSharedPathCommittedMidPush1052676376/001/store/f83afn9f13jv8lkpp4g6r0a4199f5wrn-shared-dep2027 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2028 Compression: zstd2029 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822030 NarSize: 1362031 References: 2032 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2033 client_integration_test.go:727: Retrieved narinfo from S3:2034 StorePath: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientSharedPathCommittedMidPush1052676376/001/store/xrbxxcwcxmsgqk27ir73bnh4xicmq4yv-top2035 URL: nar/05x4l3h9z39mqw6a0dxwbmwvffy03z02wscj4h4d6xs2g04gnzk3.nar.zst2036 Compression: zstd2037 NarHash: sha256:05x4l3h9z39mqw6a0dxwbmwvffy03z02wscj4h4d6xs2g04gnzk32038 NarSize: 2642039 References: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestClientSharedPathCommittedMidPush1052676376/001/store/f83afn9f13jv8lkpp4g6r0a4199f5wrn-shared-dep2040 CA: text:sha256:0h7wcy8yxbxmylr66872dfmh0md11l05vr9lyh11innmmw66np7f20412026/10/28 12:12:30 INFO Received complete push request method=POST path=/api/pushes/3/complete20422026/10/28 12:12:30 WARN Failed to register uploaded object key=q8v96g65c0n0qzvz8nmvllz5f5d3na8k.ls error="server returned 404: 404 page not found\n"20432026/10/28 12:12:30 INFO Completed push id=3 objects=3 duration=1.374833ms20442026/10/28 12:12:30 INFO Upload complete. (219ms)20452026/10/28 12:12:30 INFO Received complete push request method=POST path=/api/pushes/2/complete20462026/10/28 12:12:30 WARN Failed to register uploaded object key=z17v7bjm9l44xkmwdh9wk75n7pz645ai.narinfo error="server returned 404: 404 page not found\n"20472026/10/28 12:12:30 INFO Completed push id=2 objects=3 duration=2.39725ms2048=== NAME TestClientIntegration2049 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2050 client_integration_test.go:352: Decompressed .ls content (49 bytes):20512026/10/28 12:12:30 INFO Upload complete. (295ms)2052 {"version":1,"root":{"type":"regular","size":39}}2053 client_integration_test.go:363: Testing garbage collection...2054--- PASS: TestClientSharedPathCommittedMidPush (7.17s)20552026/10/28 12:12:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures20562026/10/28 12:12:30 INFO Garbage collection started20572026/10/28 12:12:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures20582026/10/28 12:12:30 INFO Garbage collection started20592026/10/28 12:12:30 INFO Aborted multipart uploads count=0 kept=020602026/10/28 12:12:30 INFO Aborted multipart uploads count=0 kept=020612026/10/28 12:12:30 WARN Request failed, retrying attempt=5 backoff=1.446238356s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20622026/10/28 12:12:30 WARN Force mode enabled - objects will be deleted immediately without grace period20632026/10/28 12:12:30 WARN Force mode enabled - objects will be deleted immediately without grace period2064--- PASS: TestReadProxyInvalidPath (6.15s)20652026/10/28 12:12:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20662026/10/28 12:12:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLjAwN2NlMjdhLWY4OWMtNDFjZS1iMTY5LWUyNmZiNzVkYWI5NHgxNzkzMTg5NTQ5MDY1OTY4MDAw parts=1220672026/10/28 12:12:31 INFO Received uploads request method=POST path=/api/pending_closures20682026/10/28 12:12:31 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=020692026/10/28 12:12:31 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=020702026/10/28 12:12:31 INFO Received uploads request method=POST path=/api/pending_closures20712026/10/28 12:12:31 INFO Vacuumed table table=pending_closures20722026/10/28 12:12:31 INFO Vacuumed table table=pending_closures2073--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.43s)20742026/10/28 12:12:31 INFO Vacuumed table table=pending_objects20752026/10/28 12:12:31 INFO Vacuumed table table=multipart_uploads20762026/10/28 12:12:31 INFO Vacuumed table table=pending_objects20772026/10/28 12:12:31 INFO Vacuumed table table=multipart_uploads20782026/10/28 12:12:31 INFO Vacuumed table table=closures20792026/10/28 12:12:31 INFO Vacuumed table table=closures20802026/10/28 12:12:31 INFO Vacuumed table table=objects20812026/10/28 12:12:31 INFO Vacuumed table table=objects2082--- PASS: TestReadProxyContentNegotiation (6.67s)20832026/10/28 12:12:32 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-config20842026/10/28 12:12:32 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2085--- PASS: TestReadProxyNarinfo (7.05s)20862026/10/28 12:12:32 WARN Request failed, retrying attempt=2 backoff=189.940842ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2087--- PASS: TestReadProxy404 (7.42s)20882026/10/28 12:12:32 WARN Request failed, retrying attempt=3 backoff=405.458262ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20892026/10/28 12:12:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020902026/10/28 12:12:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02091=== NAME TestClientIntegration2092 client_integration_test.go:370: Objects in database after GC:20932026/10/28 12:12:32 INFO Received create pin request method=POST path=/api/pins/myapp2094 client_integration_test.go:370: Successfully deleted all objects with GC --force20952026/10/28 12:12:32 INFO Created/updated pin name=myapp store_path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestPinProtectsFromGC421363797/001/store/k4lbwhq6kifmvi124z697k71k6pn0lr3-pinned-file.txt narinfo_key=k4lbwhq6kifmvi124z697k71k6pn0lr3.narinfo20962026/10/28 12:12:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures20972026/10/28 12:12:32 INFO Garbage collection started20982026/10/28 12:12:32 INFO Aborted multipart uploads count=0 kept=020992026/10/28 12:12:32 WARN Force mode enabled - objects will be deleted immediately without grace period21002026/10/28 12:12: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=021012026/10/28 12:12:32 INFO Vacuumed table table=pending_closures21022026/10/28 12:12:32 INFO Vacuumed table table=pending_objects21032026/10/28 12:12:32 INFO Vacuumed table table=multipart_uploads21042026/10/28 12:12:32 INFO Vacuumed table table=closures21052026/10/28 12:12:32 INFO Vacuumed table table=objects2106--- PASS: TestClientIntegration (10.52s)21072026/10/28 12:12:32 INFO Received uploads request method=POST path=/api/pending_closures21082026/10/28 12:12:33 WARN Request failed, retrying attempt=4 backoff=741.340473ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21092026/10/28 12:12:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21102026/10/28 12:12:33 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLmE0NmNhN2VmLTI1NTEtNGNlNS1iNmFhLTQzMWUxYzI5NTU5MHgxNzkzMTg5NTUxNDAyMDIzMDAw error="Get \"http://127.0.0.1:1/bucket81/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21112026/10/28 12:12:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmUyNTE2YmItODFlMy00Njg0LWIzZGYtY2IzOWM2NDliYTViLjBlMDgzYjQ3LWFiZTQtNGVjNy1iYzA3LTRiZjcwOWFiZDFlMXgxNzkzMTg5NTUxMzYwMDM2MDAw parts=1221122026/10/28 12:12:33 INFO Received cleanup request method=DELETE path=/api/pending_closures21132026/10/28 12:12:33 INFO Aborted multipart uploads count=1 kept=02114--- PASS: TestRedundantMultipartUpload (10.57s)21152026/10/28 12:12:33 INFO Aborted multipart uploads count=0 kept=021162026/10/28 12:12:33 WARN Force mode enabled - objects will be deleted immediately without grace period21172026/10/28 12:12:33 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:61189/bucket93/?delete=\": context canceled"21182026/10/28 12:12:33 INFO Aborted multipart uploads count=0 kept=021192026/10/28 12:12:33 WARN Force mode enabled - objects will be deleted immediately without grace period21202026-10-28 12:12:33.684 UTC [63372] ERROR: canceling statement due to user request21212026-10-28 12:12:33.684 UTC [63372] STATEMENT: -- name: MarkStaleObjects :execrows2122 WITH RECURSIVE ct AS (2123 SELECT timezone('UTC', now()) AS now2124 ),2125 closure_reach AS (2126 -- Start with all closure keys2127 SELECT o.key, o.refs2128 FROM objects o2129 INNER JOIN closures c ON o.key = c.key2130 UNION2131 -- Recursively add all referenced objects2132 SELECT o.key, o.refs2133 FROM objects o2134 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2135 ),2136 reachable_objects AS (2137 SELECT DISTINCT key FROM closure_reach2138 ),2139 stale_objects AS (2140 SELECT o.key2141 FROM objects AS o, ct2142 WHERE2143 NOT EXISTS (2144 SELECT 12145 FROM reachable_objects ro2146 WHERE ro.key = o.key2147 )2148 AND NOT EXISTS (2149 SELECT 12150 FROM pending_objects AS po2151 WHERE po.key = o.key2152 )2153 AND o.deleted_at IS NULL -- Only mark fresh objects2154 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2155 FOR UPDATE2156 )2157 UPDATE objects2158 SET2159 deleted_at = ct.now,2160 first_deleted_at = COALESCE(first_deleted_at, ct.now)2161 FROM stale_objects, ct2162 WHERE objects.key = stale_objects.key2163 2164--- PASS: TestGCEndsOnShutdown (0.04s)2165 --- PASS: TestGCEndsOnShutdown/before_the_run (7.20s)2166 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.45s)2167 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.46s)2168--- PASS: TestPendingClosureWriteTimeout (0.05s)2169 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2170 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2171 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2172 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (8.27s)21732026/10/28 12:12:33 WARN Request failed, retrying attempt=5 backoff=1.68861481s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21742026/10/28 12:12:34 INFO Received uploads request method=POST path=/api/pending_closures21752026/10/28 12:12:34 INFO Aborted multipart uploads count=0 kept=021762026/10/28 12:12:34 WARN Force mode enabled - objects will be deleted immediately without grace period21772026/10/28 12:12:34 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=021782026/10/28 12:12:34 INFO Vacuumed table table=pending_closures21792026/10/28 12:12:34 INFO Vacuumed table table=pending_objects21802026/10/28 12:12:34 INFO Vacuumed table table=multipart_uploads21812026/10/28 12:12:34 INFO Vacuumed table table=closures21822026/10/28 12:12:34 INFO Received uploads request method=POST path=/api/pending_closures21832026/10/28 12:12:34 INFO Vacuumed table table=objects21842026/10/28 12:12:34 INFO Aborted multipart uploads count=0 kept=021852026/10/28 12:12:34 WARN Force mode enabled - objects will be deleted immediately without grace period21862026/10/28 12:12:34 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=021872026/10/28 12:12:34 INFO Vacuumed table table=pending_closures21882026/10/28 12:12:34 INFO Vacuumed table table=pending_objects21892026/10/28 12:12:34 INFO Vacuumed table table=multipart_uploads21902026/10/28 12:12:34 INFO Vacuumed table table=closures21912026/10/28 12:12:34 INFO Vacuumed table table=objects2192--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2193 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (7.56s)2194 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (7.57s)2195=== NAME TestPinProtectsFromGC2196 client_integration_test.go:887: Pin successfully protected closure from garbage collection2197--- PASS: TestPinProtectsFromGC (11.68s)2198--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2199 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (7.79s)2200 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (8.01s)22012026/10/28 12:12:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22022026/10/28 12:12:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22032026/10/28 12:12:35 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"22042026/10/28 12:12:35 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-config22052026/10/28 12:12:35 WARN Request failed, retrying attempt=2 backoff=184.995869ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22062026/10/28 12:12:35 WARN Request failed, retrying attempt=3 backoff=405.79254ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22072026/10/28 12:12:36 WARN Request failed, retrying attempt=4 backoff=786.14074ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/10/28 12:12:37 WARN Request failed, retrying attempt=5 backoff=1.655244485s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/10/28 12:12:38 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_closures22102026/10/28 12:12:38 WARN Request failed, retrying attempt=2 backoff=206.174786ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22112026/10/28 12:12:39 WARN Request failed, retrying attempt=3 backoff=401.618145ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22122026/10/28 12:12:39 WARN Request failed, retrying attempt=4 backoff=818.634772ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22132026/10/28 12:12:40 WARN Request failed, retrying attempt=5 backoff=1.756617878s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2214--- PASS: TestClientErrorHandling (0.00s)2215 --- PASS: TestClientErrorHandling/InvalidStorePath (6.13s)2216 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.43s)2217 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.21s)2218=== NAME TestOrphanedObjectsGCStressTest2219 orphaned_objects_gc_test.go:503: Stress test completed successfully:2220 orphaned_objects_gc_test.go:504: - Active objects preserved: 202221 orphaned_objects_gc_test.go:505: - Objects deleted: 2102222 orphaned_objects_gc_test.go:506: - Total GC'd: 2102223--- PASS: TestOrphanedObjectsGCStressTest (30.11s)2224PASS2225{"timestamp":"2026-10-28T12:12:43.209902Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61922","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}2226{"timestamp":"2026-10-28T12:12:43.210323Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61923","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}22272026-10-28 12:12:43.362 UTC [62687] LOG: received smart shutdown request22282026-10-28 12:12:43.365 UTC [62687] LOG: background worker "logical replication launcher" (PID 62698) exited with exit code 122292026-10-28 12:12:43.376 UTC [62692] LOG: shutting down22302026-10-28 12:12:43.377 UTC [62692] LOG: checkpoint starting: shutdown immediate22312026-10-28 12:12:45.384 UTC [62692] LOG: checkpoint complete: wrote 12232 buffers (74.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=0.969 s, sync=1.011 s, total=2.008 s; sync files=34045, longest=0.004 s, average=0.001 s; distance=501913 kB, estimate=501913 kB; lsn=0/201B3620, redo lsn=0/201B362022322026-10-28 12:12:45.398 UTC [62687] LOG: database system is shut down2233Running OIDC tests...2234=== RUN TestAudienceForIssuer2235=== PAUSE TestAudienceForIssuer2236=== RUN TestGlobMatch2237=== PAUSE TestGlobMatch2238=== RUN TestValidateToken_ValidToken2239=== PAUSE TestValidateToken_ValidToken2240=== RUN TestValidateToken_WrongAudience2241=== PAUSE TestValidateToken_WrongAudience2242=== RUN TestValidateToken_Expired2243=== PAUSE TestValidateToken_Expired2244=== RUN TestValidateToken_BoundClaimsMismatch2245=== PAUSE TestValidateToken_BoundClaimsMismatch2246=== RUN TestValidateToken_BoundSubjectMismatch2247=== PAUSE TestValidateToken_BoundSubjectMismatch2248=== RUN TestValidateToken_MultipleProviders2249=== PAUSE TestValidateToken_MultipleProviders2250=== RUN TestValidateToken_NoMatchingProvider2251=== PAUSE TestValidateToken_NoMatchingProvider2252=== RUN TestValidateToken_KubernetesServiceAccount2253=== PAUSE TestValidateToken_KubernetesServiceAccount2254=== RUN TestNewValidator_KubernetesRequiresCA2255=== PAUSE TestNewValidator_KubernetesRequiresCA2256=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2257=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2258=== RUN TestPins_ReservedForMatchingRule2259=== PAUSE TestPins_ReservedForMatchingRule2260=== RUN TestPins_TopLevelShorthand2261=== PAUSE TestPins_TopLevelShorthand2262=== RUN TestPins_ConfigValidation2263=== PAUSE TestPins_ConfigValidation2264=== RUN TestScopes_LegacyProviderDefaultsToWrite2265=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2266=== RUN TestScopes_Rules2267=== PAUSE TestScopes_Rules2268=== RUN TestScopes_ConfigValidation2269=== PAUSE TestScopes_ConfigValidation2270=== CONT TestAudienceForIssuer2271--- PASS: TestAudienceForIssuer (0.00s)2272=== CONT TestPins_ConfigValidation2273=== CONT TestValidateToken_BoundClaimsMismatch2274=== CONT TestValidateToken_Expired2275=== CONT TestValidateToken_WrongAudience2276=== CONT TestValidateToken_ValidToken2277=== CONT TestGlobMatch2278=== RUN TestGlobMatch/foo_foo2279=== PAUSE TestGlobMatch/foo_foo2280=== RUN TestGlobMatch/foo_bar2281=== PAUSE TestGlobMatch/foo_bar2282=== RUN TestGlobMatch/*_2283=== PAUSE TestGlobMatch/*_2284=== RUN TestGlobMatch/*_anything2285=== PAUSE TestGlobMatch/*_anything2286=== RUN TestGlobMatch/foo*_foo2287=== PAUSE TestGlobMatch/foo*_foo2288=== RUN TestGlobMatch/foo*_foobar2289=== PAUSE TestGlobMatch/foo*_foobar2290=== RUN TestGlobMatch/foo*_bar2291=== PAUSE TestGlobMatch/foo*_bar2292=== RUN TestGlobMatch/*bar_bar2293=== PAUSE TestGlobMatch/*bar_bar2294=== RUN TestGlobMatch/*bar_foobar2295=== PAUSE TestGlobMatch/*bar_foobar2296=== RUN TestGlobMatch/*bar_foo2297=== PAUSE TestGlobMatch/*bar_foo2298=== RUN TestGlobMatch/foo*bar_foobar2299=== PAUSE TestGlobMatch/foo*bar_foobar2300=== RUN TestGlobMatch/foo*bar_foo123bar2301=== PAUSE TestGlobMatch/foo*bar_foo123bar2302=== RUN TestGlobMatch/foo*bar_foobarbaz2303=== PAUSE TestGlobMatch/foo*bar_foobarbaz2304=== RUN TestGlobMatch/*/*_foo/bar2305=== PAUSE TestGlobMatch/*/*_foo/bar2306=== RUN TestGlobMatch/*/*_foo2307=== PAUSE TestGlobMatch/*/*_foo2308=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2309=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2310=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02311=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02312=== RUN TestGlobMatch/refs/*/main_refs/heads/main2313=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2314=== RUN TestGlobMatch/fo?_foo2315=== PAUSE TestGlobMatch/fo?_foo2316=== RUN TestGlobMatch/fo?_fo2317=== PAUSE TestGlobMatch/fo?_fo2318=== RUN TestGlobMatch/fo?_fooo2319=== PAUSE TestGlobMatch/fo?_fooo2320=== RUN TestGlobMatch/?oo_foo2321=== PAUSE TestGlobMatch/?oo_foo2322=== RUN TestGlobMatch/?oo_boo2323=== PAUSE TestGlobMatch/?oo_boo2324=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2325=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2326=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2327=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2328=== CONT TestGlobMatch/foo_foo2329=== CONT TestValidateToken_KubernetesServiceAccount2330=== CONT TestGlobMatch/*/*_foo/bar2331=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2332=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2333=== CONT TestGlobMatch/?oo_boo2334=== CONT TestGlobMatch/?oo_foo2335=== CONT TestGlobMatch/fo?_fooo2336=== CONT TestGlobMatch/fo?_fo2337=== CONT TestGlobMatch/fo?_foo2338=== CONT TestGlobMatch/refs/*/main_refs/heads/main2339=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02340=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2341=== CONT TestGlobMatch/*/*_foo2342=== CONT TestGlobMatch/*bar_bar2343=== CONT TestGlobMatch/foo*bar_foobarbaz2344=== CONT TestGlobMatch/foo*bar_foo123bar2345=== CONT TestGlobMatch/foo*bar_foobar2346=== CONT TestGlobMatch/*bar_foo2347=== CONT TestGlobMatch/*bar_foobar2348=== CONT TestGlobMatch/foo*_foo2349=== CONT TestGlobMatch/foo*_bar2350=== CONT TestGlobMatch/foo*_foobar2351=== CONT TestGlobMatch/*_2352=== CONT TestGlobMatch/*_anything2353=== CONT TestGlobMatch/foo_bar2354--- PASS: TestGlobMatch (0.00s)2355 --- PASS: TestGlobMatch/foo_foo (0.00s)2356 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2357 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2358 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2359 --- PASS: TestGlobMatch/?oo_boo (0.00s)2360 --- PASS: TestGlobMatch/?oo_foo (0.00s)2361 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2362 --- PASS: TestGlobMatch/fo?_fo (0.00s)2363 --- PASS: TestGlobMatch/fo?_foo (0.00s)2364 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2365 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2366 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2367 --- PASS: TestGlobMatch/*/*_foo (0.00s)2368 --- PASS: TestGlobMatch/*bar_bar (0.00s)2369 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2370 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2371 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2372 --- PASS: TestGlobMatch/*bar_foo (0.00s)2373 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2374 --- PASS: TestGlobMatch/foo*_foo (0.00s)2375 --- PASS: TestGlobMatch/foo*_bar (0.00s)2376 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2377 --- PASS: TestGlobMatch/*_ (0.00s)2378 --- PASS: TestGlobMatch/*_anything (0.00s)2379 --- PASS: TestGlobMatch/foo_bar (0.00s)2380--- PASS: TestPins_ConfigValidation (0.01s)2381=== CONT TestScopes_Rules2382=== CONT TestScopes_ConfigValidation2383=== CONT TestPins_TopLevelShorthand2384--- PASS: TestScopes_ConfigValidation (0.00s)2385=== CONT TestPins_ReservedForMatchingRule2386=== CONT TestScopes_LegacyProviderDefaultsToWrite2387=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2388=== CONT TestValidateToken_MultipleProviders2389=== CONT TestNewValidator_KubernetesRequiresCA2390=== CONT TestValidateToken_NoMatchingProvider2391=== CONT TestValidateToken_BoundSubjectMismatch23922026/10/28 12:12:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62065/oidc23932026/10/28 12:12:47 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6206623942026/10/28 12:12:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62070/oidc2395--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)2396--- PASS: TestValidateToken_Expired (0.12s)2397--- PASS: TestValidateToken_ValidToken (0.15s)23982026/10/28 12:12:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62074/oidc23992026/10/28 12:12:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62073/oidc2400--- PASS: TestValidateToken_WrongAudience (0.19s)24012026/10/28 12:12:47 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232402--- PASS: TestValidateToken_BoundSubjectMismatch (0.17s)24032026/10/28 12:12:48 http: TLS handshake error from 127.0.0.1:62076: read tcp 127.0.0.1:62075->127.0.0.1:62076: use of closed network connection2404--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)24052026/10/28 12:12:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62081/oidc2406--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.20s)2407--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.20s)24082026/10/28 12:12:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62085/oidc2409--- PASS: TestPins_ReservedForMatchingRule (0.22s)24102026/10/28 12:12:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62087/oidc2411--- PASS: TestPins_TopLevelShorthand (0.23s)24122026/10/28 12:12:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62089/oidc2413--- PASS: TestScopes_Rules (0.26s)24142026/10/28 12:12:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62069/oidc2415--- PASS: TestValidateToken_NoMatchingProvider (0.26s)24162026/10/28 12:12:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62093/oidc2417--- PASS: TestValidateToken_BoundClaimsMismatch (0.32s)24182026/10/28 12:12:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62079/oidc24192026/10/28 12:12:48 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62095/oidc2420--- PASS: TestValidateToken_MultipleProviders (0.33s)2421PASS2422Running hook tests...2423=== RUN TestSendPathsEmpty2424=== PAUSE TestSendPathsEmpty2425=== RUN TestQueueEnqueueAndFetch2426=== PAUSE TestQueueEnqueueAndFetch2427=== RUN TestQueueDeduplication2428=== PAUSE TestQueueDeduplication2429=== RUN TestQueueRemove2430=== PAUSE TestQueueRemove2431=== RUN TestQueueFetchBatchLimit2432=== PAUSE TestQueueFetchBatchLimit2433=== RUN TestQueueRetryMovesToBack2434=== PAUSE TestQueueRetryMovesToBack2435=== RUN TestQueueFetchRemoveLifecycle2436=== PAUSE TestQueueFetchRemoveLifecycle2437=== RUN TestQueueConcurrentWriters2438=== PAUSE TestQueueConcurrentWriters2439=== RUN TestQueueRemoveLargeClosure2440=== PAUSE TestQueueRemoveLargeClosure2441=== RUN TestServerClientIntegration2442--- PASS: TestServerClientIntegration (0.00s)2443=== RUN TestServerQueueError24442026/10/28 12:12:48 ERROR Failed to queue paths error="permission denied" count=12445--- PASS: TestServerQueueError (0.00s)2446=== RUN TestGetListenerSocketActivation2447 server_test.go:145: systemd socket activation does not exist on darwin2448--- SKIP: TestGetListenerSocketActivation (0.00s)2449=== RUN TestServerStalledClientDoesNotBlockShutdown2450=== PAUSE TestServerStalledClientDoesNotBlockShutdown2451=== RUN TestServerBacksOffOnAcceptErrors2452=== PAUSE TestServerBacksOffOnAcceptErrors2453=== RUN TestDrainIsolatesPoisonPath2454=== PAUSE TestDrainIsolatesPoisonPath2455=== RUN TestRunNotBlockedByPoisonHead2456=== PAUSE TestRunNotBlockedByPoisonHead2457=== RUN TestDrainGivesUpWhenServerDown2458=== PAUSE TestDrainGivesUpWhenServerDown2459=== RUN TestFailedPathPrunedByLaterClosure2460=== PAUSE TestFailedPathPrunedByLaterClosure2461=== RUN TestWorkerUploadsAndRemoves2462=== PAUSE TestWorkerUploadsAndRemoves2463=== RUN TestWorkerSkipsGCdPaths2464=== PAUSE TestWorkerSkipsGCdPaths2465=== RUN TestWorkerPrunesClosureDeps2466=== PAUSE TestWorkerPrunesClosureDeps2467=== RUN TestDrainTimeout2468=== PAUSE TestDrainTimeout2469=== RUN TestWorkerRemoveFailureIsNotProgress2470=== PAUSE TestWorkerRemoveFailureIsNotProgress2471=== RUN TestWorkerKeepsPathItCannotStat2472=== PAUSE TestWorkerKeepsPathItCannotStat2473=== CONT TestSendPathsEmpty2474=== CONT TestWorkerPrunesClosureDeps2475--- PASS: TestSendPathsEmpty (0.00s)2476=== CONT TestWorkerKeepsPathItCannotStat2477=== CONT TestWorkerRemoveFailureIsNotProgress2478=== CONT TestDrainTimeout2479=== CONT TestDrainIsolatesPoisonPath2480=== CONT TestQueueRetryMovesToBack2481=== CONT TestQueueFetchRemoveLifecycle2482=== CONT TestQueueFetchBatchLimit2483=== CONT TestServerBacksOffOnAcceptErrors24842026/10/28 12:12:48 ERROR Accept failed error="too many open files"2485=== CONT TestServerStalledClientDoesNotBlockShutdown2486=== CONT TestQueueRemove2487=== CONT TestQueueRemoveLargeClosure2488=== CONT TestQueueDeduplication2489=== CONT TestQueueConcurrentWriters2490=== CONT TestQueueEnqueueAndFetch2491=== CONT TestFailedPathPrunedByLaterClosure2492=== CONT TestWorkerUploadsAndRemoves24932026/10/28 12:12:48 ERROR Accept failed error="too many open files"2494=== CONT TestDrainGivesUpWhenServerDown2495=== CONT TestRunNotBlockedByPoisonHead2496=== CONT TestWorkerSkipsGCdPaths24972026/10/28 12:12:48 INFO Upload queue status pending=224982026/10/28 12:12:48 INFO Uploading batch count=424992026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=425002026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainIsolatesPoisonPath2277409927/002/bbb25012026/10/28 12:12:48 INFO Uploading batch count=125022026/10/28 12:12:48 INFO Uploading batch count=125032026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=125042026/10/28 12:12:48 INFO Uploading batch count=125052026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=125062026/10/28 12:12:48 ERROR Accept failed error="too many open files"2507--- PASS: TestQueueDeduplication (0.03s)2508--- PASS: TestQueueFetchBatchLimit (0.03s)2509--- PASS: TestQueueRemove (0.03s)25102026/10/28 12:12:48 INFO Uploading batch count=125112026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=125122026/10/28 12:12:48 INFO Upload queue status pending=225132026/10/28 12:12:48 ERROR Drain finished with paths left in queue remaining=125142026/10/28 12:12:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerSkipsGCdPaths3625549934/002/nonexistent25152026/10/28 12:12:48 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa error="stat /private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa: permission denied"25162026/10/28 12:12:48 INFO Upload queue status pending=225172026/10/28 12:12:48 INFO Uploading batch count=22518--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2519--- PASS: TestDrainIsolatesPoisonPath (0.04s)25202026/10/28 12:12:48 INFO Uploading batch count=22521--- PASS: TestQueueEnqueueAndFetch (0.03s)25222026/10/28 12:12:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerRemoveFailureIsNotProgress3853962149/002/nonexistent25232026/10/28 12:12:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125242026/10/28 12:12:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerRemoveFailureIsNotProgress3853962149/002/nonexistent25252026/10/28 12:12:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125262026/10/28 12:12:48 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerRemoveFailureIsNotProgress3853962149/002/nonexistent25272026/10/28 12:12:48 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125282026/10/28 12:12:48 ERROR Drain finished with paths left in queue remaining=125292026/10/28 12:12:48 INFO Uploading batch count=125302026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=125312026/10/28 12:12:48 INFO Uploading batch count=125322026/10/28 12:12:48 INFO Uploading batch count=125332026/10/28 12:12:48 INFO Uploading batch count=12534--- PASS: TestWorkerRemoveFailureIsNotProgress (0.04s)25352026/10/28 12:12:48 INFO Uploading batch count=225362026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=225372026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/a25382026/10/28 12:12:48 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa error="stat /private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa: permission denied"25392026/10/28 12:12:48 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa error="stat /private/var/tb/7/scratch/13dd0e43ed626169/build/TestWorkerKeepsPathItCannotStat245407792/002/locked/aaa: permission denied"25402026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/b2541--- PASS: TestQueueRetryMovesToBack (0.04s)25422026/10/28 12:12:48 ERROR Drain finished with paths left in queue remaining=125432026/10/28 12:12:48 INFO Upload queue status pending=325442026/10/28 12:12:48 INFO Uploading batch count=125452026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=12546--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)25472026/10/28 12:12:48 INFO Uploading batch count=225482026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=225492026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/c25502026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/d25512026/10/28 12:12:48 INFO Uploading batch count=225522026/10/28 12:12:48 ERROR Upload failed error="upload failed" count=225532026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/e2554--- PASS: TestWorkerPrunesClosureDeps (0.04s)25552026/10/28 12:12:48 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/13dd0e43ed626169/build/TestDrainGivesUpWhenServerDown1489842063/002/f25562026/10/28 12:12:48 ERROR Drain finished with paths left in queue remaining=102557--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)2558--- PASS: TestDrainGivesUpWhenServerDown (0.03s)25592026/10/28 12:12:48 ERROR Accept failed error="too many open files"2560--- PASS: TestWorkerUploadsAndRemoves (0.04s)2561--- PASS: TestWorkerSkipsGCdPaths (0.04s)25622026/10/28 12:12:48 ERROR Accept failed error="too many open files"2563--- PASS: TestQueueRemoveLargeClosure (0.09s)2564--- PASS: TestQueueConcurrentWriters (0.09s)25652026/10/28 12:12:48 ERROR Accept failed error="too many open files"25662026/10/28 12:12:48 ERROR Failed to decode request error="read unix /private/var/tb/7/scratch/13dd0e43ed626169/build/hook2872960911/test.sock->: i/o timeout"25672026/10/28 12:12:48 ERROR Failed to write response error="write unix /private/var/tb/7/scratch/13dd0e43ed626169/build/hook2872960911/test.sock->: i/o timeout"2568--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25692026/10/28 12:12:48 ERROR Upload failed error="context deadline exceeded" count=225702026/10/28 12:12:48 ERROR Drain finished with paths left in queue remaining=42571--- PASS: TestDrainTimeout (0.24s)25722026/10/28 12:12:48 ERROR Accept failed error="too many open files"25732026/10/28 12:12:49 ERROR Accept failed error="too many open files"2574--- PASS: TestServerBacksOffOnAcceptErrors (0.65s)25752026/10/28 12:12:49 INFO Uploading batch count=125762026/10/28 12:12:49 INFO Uploading batch count=125772026/10/28 12:12:49 INFO Uploading batch count=125782026/10/28 12:12:49 ERROR Upload failed error="upload failed" count=125792026/10/28 12:12:49 INFO Uploading batch count=125802026/10/28 12:12:49 ERROR Upload failed error="upload failed" count=125812026/10/28 12:12:49 INFO Uploading batch count=125822026/10/28 12:12:49 ERROR Upload failed error="upload failed" count=125832026/10/28 12:12:49 INFO Uploading batch count=125842026/10/28 12:12:49 ERROR Upload failed error="upload failed" count=125852026/10/28 12:12:49 ERROR Drain finished with paths left in queue remaining=12586--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2587PASS2588Running signing tests...2589=== RUN TestExternalSigner2590=== PAUSE TestExternalSigner2591=== RUN TestExternalSignerWrongPublicKey2592=== PAUSE TestExternalSignerWrongPublicKey2593=== RUN TestExternalSignerErrors2594=== PAUSE TestExternalSignerErrors2595=== RUN TestExternalSignerRestartsAfterCrash2596=== PAUSE TestExternalSignerRestartsAfterCrash2597=== RUN TestExternalSignerProgramErrorKeepsProcess2598=== PAUSE TestExternalSignerProgramErrorKeepsProcess2599=== RUN TestExternalSignerClose2600=== PAUSE TestExternalSignerClose2601=== RUN TestExternalSignerRejectsInvalidPublicKey2602=== PAUSE TestExternalSignerRejectsInvalidPublicKey2603=== RUN TestExternalSignerCancellation2604=== PAUSE TestExternalSignerCancellation2605=== RUN TestGenerateFingerprint2606=== PAUSE TestGenerateFingerprint2607=== RUN TestParseSigningKey2608=== PAUSE TestParseSigningKey2609=== RUN TestSign2610=== PAUSE TestSign2611=== RUN TestSignBatch2612=== PAUSE TestSignBatch2613=== RUN TestNilKeyPublicKey2614=== PAUSE TestNilKeyPublicKey2615=== RUN TestSignErrors2616=== PAUSE TestSignErrors2617=== CONT TestExternalSigner2618=== CONT TestSignBatch2619=== CONT TestParseSigningKey2620=== CONT TestExternalSignerCancellation2621=== CONT TestGenerateFingerprint2622=== RUN TestGenerateFingerprint/basic_with_references2623=== PAUSE TestGenerateFingerprint/basic_with_references2624=== RUN TestGenerateFingerprint/no_references2625=== PAUSE TestGenerateFingerprint/no_references2626=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2627=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2628=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2629=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2630=== RUN TestGenerateFingerprint/invalid_nar_hash_length2631=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2632=== RUN TestGenerateFingerprint/invalid_store_path_prefix2633=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2634=== RUN TestGenerateFingerprint/invalid_reference_prefix2635=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2636=== CONT TestGenerateFingerprint/basic_with_references2637=== CONT TestSign2638=== CONT TestSignErrors2639=== CONT TestExternalSignerProgramErrorKeepsProcess2640=== CONT TestGenerateFingerprint/invalid_nar_hash_length2641=== CONT TestExternalSignerRejectsInvalidPublicKey2642=== RUN TestExternalSignerRejectsInvalidPublicKey/#002643=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002644=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2645=== CONT TestExternalSignerClose2646=== CONT TestExternalSignerErrors2647=== RUN TestExternalSignerErrors/wrong_shape2648=== PAUSE TestExternalSignerErrors/wrong_shape2649=== RUN TestExternalSignerErrors/null2650=== PAUSE TestExternalSignerErrors/null2651=== RUN TestExternalSignerErrors/null_signatures2652=== PAUSE TestExternalSignerErrors/null_signatures2653=== RUN TestExternalSignerErrors/exit_at_startup2654=== PAUSE TestExternalSignerErrors/exit_at_startup2655=== RUN TestExternalSignerErrors/invalid_JSON2656=== PAUSE TestExternalSignerErrors/invalid_JSON2657=== RUN TestExternalSignerErrors/wrong_id2658=== CONT TestExternalSignerRestartsAfterCrash2659=== CONT TestExternalSignerWrongPublicKey2660=== CONT TestNilKeyPublicKey2661=== RUN TestParseSigningKey/valid_32-byte_key2662=== CONT TestGenerateFingerprint/invalid_reference_prefix2663=== CONT TestGenerateFingerprint/invalid_store_path_prefix2664=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2665=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2666=== CONT TestGenerateFingerprint/no_references2667=== PAUSE TestParseSigningKey/valid_32-byte_key2668=== PAUSE TestExternalSignerErrors/wrong_id2669=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2670=== RUN TestExternalSignerErrors/wrong_signatures_shape2671=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2672=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2673--- PASS: TestGenerateFingerprint (0.00s)2674 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2675 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2676 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2677 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2678 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2679 --- PASS: TestGenerateFingerprint/no_references (0.00s)2680 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2681=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2682=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2683=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2684=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2685=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2686=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2687=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2688=== RUN TestParseSigningKey/no_colon2689=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2690=== PAUSE TestParseSigningKey/no_colon2691=== RUN TestParseSigningKey/empty_name2692=== PAUSE TestParseSigningKey/empty_name2693--- PASS: TestNilKeyPublicKey (0.00s)2694=== CONT TestExternalSignerRejectsInvalidPublicKey/#002695=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2696=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2697=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2698--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2699 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2700 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2701 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2702 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2703 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2704=== RUN TestExternalSignerErrors/unrequested_key2705=== RUN TestSignErrors/nil_key2706=== PAUSE TestExternalSignerErrors/unrequested_key2707=== RUN TestExternalSignerErrors/missing_signature_name2708=== RUN TestParseSigningKey/invalid_base642709=== PAUSE TestSignErrors/nil_key2710=== RUN TestSignErrors/nil_narinfo2711=== PAUSE TestSignErrors/nil_narinfo2712--- PASS: TestSign (0.00s)2713=== PAUSE TestParseSigningKey/invalid_base642714=== RUN TestParseSigningKey/wrong_length2715=== PAUSE TestExternalSignerErrors/missing_signature_name2716=== RUN TestExternalSignerErrors/invalid_signature_base642717=== RUN TestSignErrors/invalid_narinfo2718=== PAUSE TestSignErrors/invalid_narinfo2719=== PAUSE TestParseSigningKey/wrong_length2720=== CONT TestParseSigningKey/valid_32-byte_key2721=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2722=== CONT TestParseSigningKey/invalid_base642723=== RUN TestSignErrors/canceled2724=== PAUSE TestSignErrors/canceled2725=== CONT TestSignErrors/nil_key2726=== PAUSE TestExternalSignerErrors/invalid_signature_base642727=== RUN TestExternalSignerErrors/exit_on_request2728=== PAUSE TestExternalSignerErrors/exit_on_request2729=== RUN TestExternalSignerErrors/wrong_signature_name2730=== PAUSE TestExternalSignerErrors/wrong_signature_name2731=== RUN TestExternalSignerErrors/wrong_signature_length2732=== PAUSE TestExternalSignerErrors/wrong_signature_length2733=== RUN TestExternalSignerErrors/program_error2734=== PAUSE TestExternalSignerErrors/program_error2735=== RUN TestExternalSignerErrors/missing_signatures2736=== PAUSE TestExternalSignerErrors/missing_signatures2737=== RUN TestExternalSignerErrors/too_few_signatures2738=== CONT TestParseSigningKey/wrong_length2739=== CONT TestParseSigningKey/no_colon2740=== CONT TestParseSigningKey/empty_name2741--- PASS: TestParseSigningKey (0.00s)2742 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2743 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2744 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2745 --- PASS: TestParseSigningKey/wrong_length (0.00s)2746 --- PASS: TestParseSigningKey/no_colon (0.00s)2747 --- PASS: TestParseSigningKey/empty_name (0.00s)2748=== CONT TestSignErrors/invalid_narinfo2749=== CONT TestSignErrors/canceled2750--- PASS: TestSignBatch (0.00s)2751=== CONT TestSignErrors/nil_narinfo2752--- PASS: TestSignErrors (0.00s)2753 --- PASS: TestSignErrors/nil_key (0.00s)2754 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2755 --- PASS: TestSignErrors/canceled (0.00s)2756 --- PASS: TestSignErrors/nil_narinfo (0.00s)2757=== PAUSE TestExternalSignerErrors/too_few_signatures2758=== CONT TestExternalSignerErrors/wrong_shape2759=== CONT TestExternalSignerErrors/missing_signature_name2760=== CONT TestExternalSignerErrors/exit_on_request2761=== CONT TestExternalSignerErrors/invalid_JSON2762=== CONT TestExternalSignerErrors/wrong_signature_length2763=== CONT TestExternalSignerErrors/null_signatures2764=== CONT TestExternalSignerErrors/missing_signatures2765=== CONT TestExternalSignerErrors/exit_at_startup2766=== CONT TestExternalSignerErrors/wrong_signatures_shape2767=== CONT TestExternalSignerErrors/wrong_signature_name2768=== CONT TestExternalSignerErrors/program_error2769=== CONT TestExternalSignerErrors/wrong_id2770=== CONT TestExternalSignerErrors/unrequested_key2771=== CONT TestExternalSignerErrors/null2772=== CONT TestExternalSignerErrors/invalid_signature_base642773=== CONT TestExternalSignerErrors/too_few_signatures2774--- PASS: TestExternalSigner (0.25s)2775--- PASS: TestExternalSignerCancellation (0.46s)2776--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.64s)2777--- PASS: TestExternalSignerWrongPublicKey (1.24s)2778--- PASS: TestExternalSignerClose (2.85s)2779--- PASS: TestExternalSignerRestartsAfterCrash (3.47s)2780/private/var/tb/7/scratch/13dd0e43ed626169/build/TestExternalSignerRestartsAfterCrash1700101159/001/sign program: line 7: /private/var/tb/7/scratch/13dd0e43ed626169/build/TestExternalSignerRestartsAfterCrash1700101159/001/sign program.starts: No such file or directory2781--- PASS: TestExternalSignerErrors (0.00s)2782 --- PASS: TestExternalSignerErrors/null (0.84s)2783 --- PASS: TestExternalSignerErrors/missing_signatures (1.04s)2784 --- PASS: TestExternalSignerErrors/program_error (1.43s)2785 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.64s)2786 --- PASS: TestExternalSignerErrors/exit_at_startup (1.84s)2787 --- PASS: TestExternalSignerErrors/too_few_signatures (2.05s)2788 --- PASS: TestExternalSignerErrors/wrong_id (2.25s)2789 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.45s)2790 --- PASS: TestExternalSignerErrors/exit_on_request (2.64s)2791 --- PASS: TestExternalSignerErrors/null_signatures (3.05s)2792 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.24s)2793 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.64s)2794 --- PASS: TestExternalSignerErrors/wrong_shape (3.84s)2795 --- PASS: TestExternalSignerErrors/unrequested_key (4.04s)2796 --- PASS: TestExternalSignerErrors/missing_signature_name (4.24s)2797 --- PASS: TestExternalSignerErrors/invalid_JSON (4.44s)2798PASS2799Running OpenBao signer tests...2800=== RUN TestSign2801=== PAUSE TestSign2802=== RUN TestSignErrors2803=== PAUSE TestSignErrors2804=== RUN TestServe2805=== PAUSE TestServe2806=== RUN TestServeRejectsGarbage2807=== PAUSE TestServeRejectsGarbage2808=== CONT TestSign2809=== CONT TestSignErrors2810=== RUN TestSignErrors/invalid_base642811=== PAUSE TestSignErrors/invalid_base642812=== CONT TestServeRejectsGarbage2813=== RUN TestSignErrors/http_error2814--- PASS: TestServeRejectsGarbage (0.00s)2815=== PAUSE TestSignErrors/http_error2816=== CONT TestServe2817=== RUN TestSignErrors/invalid_json2818=== PAUSE TestSignErrors/invalid_json2819=== RUN TestSignErrors/no_prefix2820=== PAUSE TestSignErrors/no_prefix2821=== CONT TestSignErrors/invalid_base642822=== CONT TestSignErrors/invalid_json2823=== CONT TestSignErrors/http_error2824=== CONT TestSignErrors/no_prefix2825--- PASS: TestServe (0.00s)2826--- PASS: TestSignErrors (0.00s)2827 --- PASS: TestSignErrors/invalid_base64 (0.00s)2828 --- PASS: TestSignErrors/invalid_json (0.00s)2829 --- PASS: TestSignErrors/no_prefix (0.00s)2830 --- PASS: TestSignErrors/http_error (0.00s)2831--- PASS: TestSign (0.00s)2832PASS