niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #427
· 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.09s)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 TestStreamPushBatchesUnderLoad117=== CONT TestConvertHashToNix32118=== CONT TestStaticToken119--- PASS: TestStaticToken (0.00s)120=== RUN TestConvertHashToNix32/SRI_format_to_Nix32121=== CONT TestStreamPushReportsEveryPath122=== CONT TestShellSplitErrors123--- PASS: TestShellSplitErrors (0.00s)124=== CONT TestEncodeNixBase32125=== RUN TestEncodeNixBase32/test_string_hash126=== PAUSE TestEncodeNixBase32/test_string_hash127=== RUN TestEncodeNixBase32/empty_input128=== PAUSE TestEncodeNixBase32/empty_input129=== CONT TestShellSplit130=== CONT TestDoWithRetry_FinalResponseBodyReadable131=== CONT TestRetryTimeoutOutlastsMaxRetries132=== CONT TestDoWithRetry_BodyReplayedViaGetBody133=== CONT TestResolveStorePath134=== CONT TestParsePathInfoJSONMultiplePaths135=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths136=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths137=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess1382026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=server-test rate=5139=== CONT TestRateLimiterFeedback140=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== CONT TestScriptTokenCachesUntilRefresh144=== CONT TestSupersededNARStillUploadsListing145=== CONT TestDumpPathMatchesNix146=== CONT TestScriptTokenEmptyCommand147=== CONT TestUploadMultipart_SupersededByPeer148=== RUN TestUploadMultipart_SupersededByPeer/exists149=== PAUSE TestUploadMultipart_SupersededByPeer/exists150=== RUN TestUploadMultipart_SupersededByPeer/missing151=== PAUSE TestUploadMultipart_SupersededByPeer/missing152=== RUN TestSupersededNARStillUploadsListing/small_NAR153=== PAUSE TestSupersededNARStillUploadsListing/small_NAR154=== RUN TestSupersededNARStillUploadsListing/dump_cut_short155=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short156=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails157=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails158=== CONT TestScriptTokenBadJSON159=== CONT TestCaseHackSuffix160=== CONT TestFileTokenMissing161=== CONT TestFileTokenEmpty162=== CONT TestScriptTokenEmptyToken163=== CONT TestPathInfoHashCompatibility164=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1672026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:493571682026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=server-test rate=51692026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:493561702026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:493571712026/10/25 16:38:50 WARN Rate limiter backed off name=server-test rate=51722026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=server-test rate=51732026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:49358174=== CONT TestPartSizeForNAR175=== RUN TestPartSizeForNAR/zero_stays_at_minimum176=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica177=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun178=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum1792026/10/25 16:38:50 WARN Rate limiter backed off name=server-test rate=51802026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:49358181=== RUN TestPartSizeForNAR/small_stays_at_minimum182=== PAUSE TestPartSizeForNAR/small_stays_at_minimum183=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum184=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum185=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts186=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts187=== RUN TestPartSizeForNAR/1_TiB188=== PAUSE TestPartSizeForNAR/1_TiB189=== RUN TestPartSizeForNAR/5_TiB_S3_max_object190=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object191=== RUN TestPartSizeForNAR/capped_at_5_GiB192=== PAUSE TestPartSizeForNAR/capped_at_5_GiB193=== CONT TestFileTokenReadsAndCaches194=== CONT TestEncodeNixBase32WithRealHash195=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32196=== CONT TestDumpPathWriterError197--- PASS: TestShellSplit (0.00s)198--- PASS: TestStreamPushReportsEveryPath (0.00s)199--- PASS: TestScriptTokenEmptyCommand (0.00s)200--- PASS: TestResolveStorePath (0.00s)201=== CONT TestDumpPathSingleFile202=== CONT TestPathInfoCACompatibility203=== PAUSE TestRateLimiterFeedback/429_enables_limiter204=== CONT TestScriptTokenScriptFails205=== CONT TestScriptTokenNoExpiryRerunsEveryCall206=== CONT TestParsePathInfoJSON207=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon208=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer209=== CONT TestUploadMultipart_FailedPartBufferNotReused210=== RUN TestConvertHashToNix32/already_Nix32_format211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== RUN TestConvertHashToNix32/invalid_format213=== PAUSE TestConvertHashToNix32/invalid_format214=== CONT TestUploadMultipart_PartsInParallel215=== CONT TestSetClientTLS216=== RUN TestRateLimiterFeedback/503_enables_limiter217=== PAUSE TestRateLimiterFeedback/503_enables_limiter218=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter219=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter220=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter221=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter222=== RUN TestPathInfoCACompatibility/null_ca_field223=== CONT TestFilterOversizedClosures224=== CONT TestGetStorePathHash225--- PASS: TestFileTokenEmpty (0.00s)226--- PASS: TestFileTokenMissing (0.00s)227--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)228--- PASS: TestEncodeNixBase32WithRealHash (0.00s)229--- PASS: TestFileTokenReadsAndCaches (0.00s)230--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)231--- PASS: TestDoServerRequestAttachesToken (0.01s)232=== PAUSE TestPathInfoCACompatibility/null_ca_field233=== RUN TestPathInfoCACompatibility/old_string_format_-_text234=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text235=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive237=== RUN TestPathInfoCACompatibility/new_structured_format_-_text238=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text239=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method240=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method241=== CONT TestRegisterUploadedObjectReusesConnections242=== CONT TestSetClientTLSErrors243=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI244=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI245=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512246=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512247=== RUN TestParsePathInfoJSON/Nix_format248=== PAUSE TestParsePathInfoJSON/Nix_format249=== RUN TestParsePathInfoJSON/Lix_format250=== PAUSE TestParsePathInfoJSON/Lix_format251=== RUN TestParsePathInfoJSON/empty_input252=== PAUSE TestParsePathInfoJSON/empty_input253=== RUN TestParsePathInfoJSON/whitespace_only254=== PAUSE TestParsePathInfoJSON/whitespace_only255=== RUN TestParsePathInfoJSON/invalid_JSON256=== PAUSE TestParsePathInfoJSON/invalid_JSON257=== CONT TestSetClientTLSDoesNotMutateDefaultTransport2582026/10/25 16:38:50 INFO Garbage collection started259=== RUN TestSetClientTLSErrors/missing_cert_file260=== CONT TestStreamPushStopsWhenCanceled2612026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:49357262=== PAUSE TestSetClientTLSErrors/missing_cert_file263--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)264=== CONT TestClientSignaturesByStorePath265--- PASS: TestClientSignaturesByStorePath (0.00s)266=== CONT TestStreamPushGivesUpOnDeadServer267--- PASS: TestScriptTokenEmptyToken (0.01s)2682026/10/25 16:38:50 INFO Garbage collection started2692026/10/25 16:38:50 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=0270--- PASS: TestStreamPushStopsWhenCanceled (0.00s)271=== CONT TestStreamPushIsolatesFailures272=== RUN TestGetStorePathHash/valid_store_path273=== PAUSE TestGetStorePathHash/valid_store_path274=== RUN TestGetStorePathHash/basename_without_hyphen_should_error2752026/10/25 16:38:50 ERROR Upload failed error="bad path" count=32762026/10/25 16:38:50 ERROR Upload failed error="connection refused" count=202772026/10/25 16:38:50 ERROR Server seems unavailable, giving up on batch untried=17278=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error279=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error280=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error281=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error282=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error283=== RUN TestSetClientTLS/rejects_connection_without_client_cert284=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert285=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA2862026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:49357287=== CONT TestEncodeNixBase32/test_string_hash288=== CONT TestEncodeNixBase32/empty_input289=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths290=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths291=== CONT TestUploadMultipart_SupersededByPeer/exists292=== CONT TestStreamPushReportsSkippedPaths293=== CONT TestUploadMultipart_SupersededByPeer/missing294=== RUN TestSetClientTLSErrors/missing_key_file295=== PAUSE TestSetClientTLSErrors/missing_key_file296--- PASS: TestStreamPushIsolatesFailures (0.00s)297=== CONT TestStreamPushRequestLine298=== RUN TestFilterOversizedClosures/no_limit_keeps_everything299=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry300=== RUN TestSetClientTLSErrors/missing_ca_file301=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything302=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped304=== RUN TestFilterOversizedClosures/all_closures_skipped305=== PAUSE TestFilterOversizedClosures/all_closures_skipped306=== PAUSE TestSetClientTLSErrors/missing_ca_file307=== RUN TestSetClientTLSErrors/invalid_ca_file308=== PAUSE TestSetClientTLSErrors/invalid_ca_file309=== CONT TestSupersededNARStillUploadsListing/small_NAR310=== CONT TestSupersededNARStillUploadsListing/dump_cut_short311--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)312--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)313--- PASS: TestEncodeNixBase32 (0.00s)314 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)315 --- PASS: TestEncodeNixBase32/empty_input (0.00s)316--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)317 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)318 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)319--- PASS: TestStreamPushReportsSkippedPaths (0.00s)320--- PASS: TestScriptTokenBadJSON (0.02s)321=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails322--- PASS: TestScriptTokenScriptFails (0.01s)323=== CONT TestPartSizeForNAR/zero_stays_at_minimum324=== CONT TestPartSizeForNAR/1_TiB325=== CONT TestPartSizeForNAR/capped_at_5_GiB326=== CONT TestPartSizeForNAR/5_TiB_S3_max_object3272026/10/25 16:38:50 WARN Garbage collection finished on another replica. Its statistics are not available here328=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum329=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts330--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)331=== CONT TestConvertHashToNix32/SRI_format_to_Nix32332=== CONT TestPartSizeForNAR/small_stays_at_minimum333--- PASS: TestPartSizeForNAR (0.00s)334 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)335 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)336 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)337 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)338 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)339 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)340 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)341=== CONT TestConvertHashToNix32/invalid_format342=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA343=== CONT TestConvertHashToNix32/already_Nix32_format344=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter345=== CONT TestStreamPushReportsSignatures346--- PASS: TestConvertHashToNix32 (0.01s)347 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)348 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)349 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)350=== CONT TestRateLimiterFeedback/429_enables_limiter351=== RUN TestSetClientTLS/preserves_debug_logging_transport352=== PAUSE TestSetClientTLS/preserves_debug_logging_transport353=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter354=== CONT TestRateLimiterFeedback/503_enables_limiter3552026/10/25 16:38:50 INFO Uploading abc-hello (1.0GB)3562026/10/25 16:38:50 ERROR Upload failed error=boom count=13572026/10/25 16:38:50 ERROR Upload failed error=boom count=13582026/10/25 16:38:50 INFO Uploading abc-hello (1.0GB)359=== CONT TestPathInfoCACompatibility/null_ca_field360=== CONT TestPathInfoCACompatibility/new_structured_format_-_text361=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive362=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method363=== CONT TestPathInfoCACompatibility/old_string_format_-_text364--- PASS: TestPathInfoCACompatibility (0.00s)365 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)366 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)367 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)369 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)370=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)371=== CONT TestParsePathInfoJSON/Nix_format372=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512373=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI374=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon375--- PASS: TestPathInfoHashCompatibility (0.01s)376 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)377 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)378 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)379 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)380=== CONT TestParsePathInfoJSON/invalid_JSON381=== CONT TestParsePathInfoJSON/whitespace_only382=== CONT TestParsePathInfoJSON/empty_input383=== CONT TestParsePathInfoJSON/Lix_format384--- PASS: TestParsePathInfoJSON (0.00s)385 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)386 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)387 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)388 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)389 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)390=== CONT TestGetStorePathHash/valid_store_path391=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error392=== CONT TestGetStorePathHash/basename_without_hyphen_should_error393=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error394--- PASS: TestGetStorePathHash (0.01s)395 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)396 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)397 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)398 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)399=== CONT TestFilterOversizedClosures/no_limit_keeps_everything400=== CONT TestSetClientTLSErrors/missing_cert_file401=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped4022026/10/25 16:38:50 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=2000403--- PASS: TestStreamPushReportsSignatures (0.01s)404=== CONT TestFilterOversizedClosures/all_closures_skipped405=== CONT TestSetClientTLSErrors/missing_ca_file406--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)407 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)408 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)409=== CONT TestSetClientTLSErrors/invalid_ca_file410=== CONT TestSetClientTLSErrors/missing_key_file411=== CONT TestSetClientTLS/rejects_connection_without_client_cert4122026/10/25 16:38:50 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=50413--- PASS: TestFilterOversizedClosures (0.01s)414 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)415 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)416 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)417=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA4182026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:49357419=== CONT TestSetClientTLS/preserves_debug_logging_transport4202026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:493574212026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=server-test rate=54222026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:494534232026/10/25 16:38:50 WARN Rate limiter backed off name=server-test rate=54242026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=server-test rate=54252026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:494554262026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:493574272026/10/25 16:38:50 WARN Rate limiter backed off name=server-test rate=5428--- PASS: TestRateLimiterFeedback (0.01s)429 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)430 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)431 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)432 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)433--- PASS: TestSetClientTLSErrors (0.02s)434 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)435 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)436 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)437 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4382026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:493574392026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=s3-test rate=54402026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:49463441--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)4422026/10/25 16:38:50 WARN Rate limiter enabled after throttle name=s3-test rate=5443--- PASS: TestStreamPushRequestLine (0.02s)4442026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:493574452026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:493574462026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:493574472026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:49357448--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4492026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:493574502026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:493574512026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:493574522026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:493574532026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:493574542026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:49357455--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)456--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)4572026/10/25 16:38:50 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:49357458--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)4592026/10/25 16:38:50 http: TLS handshake error from 127.0.0.1:49458: remote error: tls: bad certificate460--- PASS: TestSetClientTLS (0.02s)461 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)462 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)463 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)464--- PASS: TestCaseHackSuffix (0.06s)4652026/10/25 16:38:50 INFO Uploading abc-hello (1.0GB)466--- PASS: TestDumpPathSingleFile (0.08s)467--- PASS: TestDumpPathWriterError (0.08s)4682026/10/25 16:38:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:49445/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:49445/part/24692026/10/25 16:38:50 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:49445/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:49445/part/34702026/10/25 16:38:50 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"471--- PASS: TestStreamPushBatchesUnderLoad (0.10s)472--- PASS: TestDumpPathMatchesNix (0.10s)473--- PASS: TestSupersededNARStillUploadsListing (0.00s)474 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)475 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)476 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.56s)477--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.58s)478--- PASS: TestUploadMultipart_PartsInParallel (0.62s)479--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4802026/10/25 16:38:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49426/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49426/api/uploads/complete4812026/10/25 16:38:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49426/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49426/api/uploads/complete4822026/10/25 16:38:51 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4832026/10/25 16:38:51 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4842026/10/25 16:38:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:49426/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:49426/api/uploads/complete4852026/10/25 16:38:51 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"486--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)487PASS488Running server tests...489The files belonging to this database system will be owned by user "_tribuchetbld8".490This user must also own the server process.491492The database cluster will be initialized with locale "C".493The default database encoding has accordingly been set to "SQL_ASCII".494The default text search configuration will be set to "english".495496Data page checksums are enabled.497498creating directory /private/var/tb/8/scratch/021d280b068cf186/build/postgres2545935436/data ... ok499creating subdirectories ... ok500selecting dynamic shared memory implementation ... posix501selecting default "max_connections" ... 100502selecting default "shared_buffers" ... 128MB503selecting default time zone ... UTC504creating configuration files ... ok505running bootstrap script ... ok506performing post-bootstrap initialization ... ok507syncing data to disk ... ok508509initdb: warning: enabling "trust" authentication for local connections510initdb: 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.511512Success. You can now start the database server using:513514 pg_ctl -D /private/var/tb/8/scratch/021d280b068cf186/build/postgres2545935436/data -l logfile start515516/private/var/tb/8/scratch/021d280b068cf186/build/postgres2545935436:5432 - no response5172026-10-25 16:38:51.962 UTC [45534] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5182026-10-25 16:38:51.962 UTC [45534] LOG: listening on Unix socket "/private/var/tb/8/scratch/021d280b068cf186/build/postgres2545935436/.s.PGSQL.5432"5192026-10-25 16:38:51.965 UTC [45542] LOG: database system was shut down at 2026-10-25 16:38:51 UTC5202026-10-25 16:38:51.966 UTC [45534] LOG: database system is ready to accept connections521/private/var/tb/8/scratch/021d280b068cf186/build/postgres2545935436:5432 - accepting connections522{"timestamp":"2026-10-25T16:38:52.198163Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a64372a9-f58c-47e8-b0ee-6df6475d605c","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":9,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}523{"timestamp":"2026-10-25T16:38:52.305465Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"285acaef-5842-4100-add8-e0794cf2d9ef","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}524{"timestamp":"2026-10-25T16:38:52.408909Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1ae98311-de3b-4b30-a138-5ea26511abca","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}525=== RUN TestService_AuthMiddleware526=== PAUSE TestService_AuthMiddleware527=== RUN TestService_AuthMiddleware_MTLSProxyHeader528=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader529=== RUN TestService_AuthMiddleware_MTLSBoundSubjects530=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects531=== RUN TestService_ReadAuthMiddleware532=== PAUSE TestService_ReadAuthMiddleware533=== RUN TestService_AuthMiddleware_OIDC534=== PAUSE TestService_AuthMiddleware_OIDC535=== RUN TestService_RequireScope_OIDC536=== PAUSE TestService_RequireScope_OIDC537=== RUN TestService_ReadScope_PublicByDefault538=== PAUSE TestService_ReadScope_PublicByDefault539=== RUN TestCacheConfigHandler540=== PAUSE TestCacheConfigHandler541=== RUN TestCacheStatsHandler542=== PAUSE TestCacheStatsHandler543=== RUN TestClientCADerivations544=== PAUSE TestClientCADerivations545=== RUN TestClientErrorHandling546=== PAUSE TestClientErrorHandling547=== RUN TestClientIntegration548=== PAUSE TestClientIntegration549=== RUN TestClientMultipleUploads550=== PAUSE TestClientMultipleUploads551=== RUN TestClientWithDependencies552=== PAUSE TestClientWithDependencies553=== RUN TestClientSharedPathCommittedMidPush554=== PAUSE TestClientSharedPathCommittedMidPush555=== RUN TestPinProtectsFromGC556=== PAUSE TestPinProtectsFromGC557=== RUN TestClientPushesUseOnePush558=== PAUSE TestClientPushesUseOnePush559=== RUN TestClientFallsBackToClosures560=== PAUSE TestClientFallsBackToClosures561=== RUN TestDeleteClosuresRacingPins562=== PAUSE TestDeleteClosuresRacingPins563=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock564=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock565=== RUN TestResolveDBConnectionString566=== PAUSE TestResolveDBConnectionString567=== RUN TestConnectWaitsForAPeerMigration568=== PAUSE TestConnectWaitsForAPeerMigration569=== RUN TestLeadElectsOneAndHandsOver570=== PAUSE TestLeadElectsOneAndHandsOver571=== RUN TestLeadIncumbentWinsAfterRestart5722026/10/25 16:38:52 INFO lead: acquired remote=192.0.2.1:12345732026/10/25 16:38:53 INFO lead: released remote=192.0.2.1:12345742026/10/25 16:38:53 INFO lead: acquired remote=192.0.2.1:12345752026/10/25 16:38:54 INFO lead: released remote=192.0.2.1:1234576--- PASS: TestLeadIncumbentWinsAfterRestart (2.04s)577=== RUN TestLeadIncumbentAnnouncesAtOnce578=== PAUSE TestLeadIncumbentAnnouncesAtOnce579=== RUN TestLeadEndsOnShutdown580=== PAUSE TestLeadEndsOnShutdown581=== RUN TestLeadEndsWhenItsConnectionHangs5822026/10/25 16:38:54 INFO lead: acquired remote=192.0.2.1:12345832026-10-25 16:38:55.934 UTC [45891] FATAL: terminating connection due to administrator command5842026/10/25 16:38:56 INFO lead: acquired remote=192.0.2.1:12345852026/10/25 16:38:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"5862026/10/25 16:38:57 INFO lead: released remote=192.0.2.1:12345872026/10/25 16:38:57 INFO lead: released remote=192.0.2.1:1234588--- PASS: TestLeadEndsWhenItsConnectionHangs (2.78s)589=== RUN TestGCAdvisoryLockBlocksConcurrentRun590=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun591=== RUN TestGCBugBareHashReferences592=== PAUSE TestGCBugBareHashReferences593=== RUN TestGCMetrics594=== PAUSE TestGCMetrics595=== RUN TestPushDedupSurvivesConcurrentGC596=== PAUSE TestPushDedupSurvivesConcurrentGC597=== RUN TestDeduplicatedObjectsRecordedAsPending598=== PAUSE TestDeduplicatedObjectsRecordedAsPending599=== RUN TestGCSweepSkipsPendingObjects600=== PAUSE TestGCSweepSkipsPendingObjects601=== RUN TestTombstonedObjectOfferedWithoutWaiting602=== PAUSE TestTombstonedObjectOfferedWithoutWaiting603=== RUN TestGCSweepDeliversEachKeyOnce604=== PAUSE TestGCSweepDeliversEachKeyOnce605=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection606=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection607=== RUN TestForceGCDuringPushOffersSweptObject608=== PAUSE TestForceGCDuringPushOffersSweptObject609=== RUN TestFailedS3DeleteKeepsTombstone610=== PAUSE TestFailedS3DeleteKeepsTombstone611=== RUN TestSweepSkipsRowsLockedByPush612=== PAUSE TestSweepSkipsRowsLockedByPush613=== RUN TestRegisterCompletedObjectNeedsPendingRow614=== PAUSE TestRegisterCompletedObjectNeedsPendingRow615=== RUN TestGetExistingObjectsLocksRows616=== PAUSE TestGetExistingObjectsLocksRows617=== RUN TestSweepRechecksPendingAfterLocking618=== PAUSE TestSweepRechecksPendingAfterLocking619=== RUN TestPushWaitsForSweepHoldingRow620=== PAUSE TestPushWaitsForSweepHoldingRow621=== RUN TestCommitRacingPendingCleanupKeepsObjects622=== PAUSE TestCommitRacingPendingCleanupKeepsObjects623=== RUN TestGCEndsOnShutdown624=== PAUSE TestGCEndsOnShutdown625=== RUN TestGCTaskStore_StartNew626=== PAUSE TestGCTaskStore_StartNew627=== RUN TestGCTaskStore_DeduplicateSameParams628=== PAUSE TestGCTaskStore_DeduplicateSameParams629=== RUN TestGCTaskStore_ConflictDifferentParams630=== PAUSE TestGCTaskStore_ConflictDifferentParams631=== RUN TestGCTaskStore_GetEmpty632=== PAUSE TestGCTaskStore_GetEmpty633=== RUN TestGCTaskStore_GetReturnsLatest634=== PAUSE TestGCTaskStore_GetReturnsLatest635=== RUN TestGCTaskStore_CompletedAllowsNewTask636=== PAUSE TestGCTaskStore_CompletedAllowsNewTask637=== RUN TestGCTaskStore_PhaseUpdates638=== PAUSE TestGCTaskStore_PhaseUpdates639=== RUN TestGCTaskStore_Fail640=== PAUSE TestGCTaskStore_Fail641=== RUN TestGracefulShutdownDrainsInflight642=== PAUSE TestGracefulShutdownDrainsInflight643=== RUN TestService_healthCheckHandler644=== PAUSE TestService_healthCheckHandler645=== RUN TestService_readinessHandler646=== PAUSE TestService_readinessHandler647=== RUN TestGenerateLandingPage648=== PAUSE TestGenerateLandingPage649=== RUN TestCacheConfigHandlerMaxNarSize650=== PAUSE TestCacheConfigHandlerMaxNarSize651=== RUN TestCreatePendingClosureRejectsOversizedNAR652=== PAUSE TestCreatePendingClosureRejectsOversizedNAR653=== RUN TestNARDeduplicationMetadataUploadBug654=== PAUSE TestNARDeduplicationMetadataUploadBug655=== RUN TestMetricsInventory656=== PAUSE TestMetricsInventory657=== RUN TestMetricsCommit658=== PAUSE TestMetricsCommit659=== RUN TestService_NativeMTLS660=== PAUSE TestService_NativeMTLS661=== RUN TestServerTLSConfig662=== PAUSE TestServerTLSConfig663=== RUN TestMultipartCleanup664=== PAUSE TestMultipartCleanup665=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded666=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded667=== RUN TestPendingCleanupUsesOneCutoff668=== PAUSE TestPendingCleanupUsesOneCutoff669=== RUN TestObjectStatsTrigger670=== PAUSE TestObjectStatsTrigger671=== RUN TestObjectStatsUpdatedOncePerCommit672=== PAUSE TestObjectStatsUpdatedOncePerCommit673=== RUN TestOrphanedObjectsGC674=== PAUSE TestOrphanedObjectsGC675=== RUN TestOrphanedObjectsGCStressTest676=== PAUSE TestOrphanedObjectsGCStressTest677=== RUN TestCreatePin_ReservedPins678=== PAUSE TestCreatePin_ReservedPins679=== RUN TestPresentReportsOnlyClosureRoots680=== PAUSE TestPresentReportsOnlyClosureRoots681=== RUN TestPresentRefreshesOnlyStaleClosures682=== PAUSE TestPresentRefreshesOnlyStaleClosures683=== RUN TestPresentNotReportedWhileGCDeletesClosure684=== PAUSE TestPresentNotReportedWhileGCDeletesClosure685=== RUN TestParseSingleRange686=== PAUSE TestParseSingleRange687=== RUN TestProxyHeadersOnlyTrustedOnSocket6882026/10/25 16:38:57 INFO Starting HTTP server address=proxy.sock6892026/10/25 16:38:57 INFO Starting HTTP server address=127.0.0.1:495016902026/10/25 16:38:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6912026/10/25 16:38:57 INFO Shutdown signal received, draining in-flight requests timeout=10s692--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)693=== RUN TestIsValidCachePath694=== PAUSE TestIsValidCachePath695=== RUN TestReadProxyNarinfo696=== PAUSE TestReadProxyNarinfo697=== RUN TestReadProxyNarinfoAlreadyDecompressed698=== PAUSE TestReadProxyNarinfoAlreadyDecompressed699=== RUN TestReadProxyContentNegotiation700=== PAUSE TestReadProxyContentNegotiation701=== RUN TestReadProxyNarStreaming702=== PAUSE TestReadProxyNarStreaming703=== RUN TestReadProxy404704=== PAUSE TestReadProxy404705=== RUN TestReadProxyInvalidPath706=== PAUSE TestReadProxyInvalidPath707=== RUN TestReadProxyHead708=== PAUSE TestReadProxyHead709=== RUN TestReadProxyOutlastsServerWriteTimeout710=== PAUSE TestReadProxyOutlastsServerWriteTimeout711=== RUN TestReadProxyConditionalGet712=== PAUSE TestReadProxyConditionalGet713=== RUN TestReadProxyRootRedirectsToIndexHTML714=== PAUSE TestReadProxyRootRedirectsToIndexHTML715=== RUN TestReadProxyDisabled716=== PAUSE TestReadProxyDisabled717=== RUN TestReadRedirectNar718=== PAUSE TestReadRedirectNar719=== RUN TestReadRedirectKeepsNarinfoProxied720=== PAUSE TestReadRedirectKeepsNarinfoProxied721=== RUN TestReadProxyRangeRequest722=== PAUSE TestReadProxyRangeRequest723=== RUN TestReadRedirectUsesPublicS3URL724=== PAUSE TestReadRedirectUsesPublicS3URL725=== RUN TestPush_OverlappingRootsStoreOneRowPerKey726=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey727=== RUN TestPush_CompleteCommitsEveryRoot728=== PAUSE TestPush_CompleteCommitsEveryRoot729=== RUN TestPush_RepeatedRootCommitsOnce730=== PAUSE TestPush_RepeatedRootCommitsOnce731=== RUN TestPush_CompleteWaitsForCleanupOfThePush732=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush733=== RUN TestPush_RootsAreLockedInByteOrder734=== PAUSE TestPush_RootsAreLockedInByteOrder735=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit736=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit737=== RUN TestPush_RejectsBadRequests738=== PAUSE TestPush_RejectsBadRequests739=== RUN TestPush_SignsNarinfosOfItsPendingObjects740=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects741=== RUN TestRedundantMultipartUpload742=== PAUSE TestRedundantMultipartUpload743=== RUN TestCompleteMultipartUpload_ErrorButObjectExists744=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists745=== RUN TestCompletedNarNotReofferedAcrossClosures746=== PAUSE TestCompletedNarNotReofferedAcrossClosures747=== RUN TestPresignedUploadRegisteredBeforeCommit748=== PAUSE TestPresignedUploadRegisteredBeforeCommit749=== RUN TestService_Rustfstest750=== PAUSE TestService_Rustfstest751=== RUN TestParseSize752=== PAUSE TestParseSize753=== RUN TestSkippedUploadsHandler754=== PAUSE TestSkippedUploadsHandler755=== RUN TestSystemdListenerNotActivated756--- PASS: TestSystemdListenerNotActivated (0.00s)757=== RUN TestWatchdogBeatsWhenHealthy758--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)759=== RUN TestWatchdogSkipsWhenUnhealthy7602026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/25 16:38:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"770--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)771=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle772=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle773=== RUN TestProxyWriteTimeout774=== PAUSE TestProxyWriteTimeout775=== RUN TestPendingClosureWriteTimeout776=== PAUSE TestPendingClosureWriteTimeout777=== RUN TestIsValidUploadKey778=== PAUSE TestIsValidUploadKey779=== RUN TestUploadHandlersRejectInvalidKeys780=== PAUSE TestUploadHandlersRejectInvalidKeys781=== RUN TestUploadHandlersRejectOversizedBody782=== PAUSE TestUploadHandlersRejectOversizedBody783=== RUN TestService_cleanupPendingClosuresHandler784=== PAUSE TestService_cleanupPendingClosuresHandler785=== RUN TestService_createPendingClosureHandler786=== PAUSE TestService_createPendingClosureHandler787=== RUN TestService_verifyS3Integrity788=== PAUSE TestService_verifyS3Integrity789=== RUN TestCompleteMultipartUnregistered790=== PAUSE TestCompleteMultipartUnregistered791=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT792=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT793=== CONT TestPush_RootsAreLockedInByteOrder794=== CONT TestGCTaskStore_ConflictDifferentParams795=== CONT TestPendingCleanupUsesOneCutoff796=== CONT TestPresentReportsOnlyClosureRoots797=== CONT TestPush_RepeatedRootCommitsOnce798=== CONT TestGCTaskStore_GetReturnsLatest799=== CONT TestReadProxyHead800=== CONT TestGCTaskStore_GetEmpty801=== CONT TestReadProxyInvalidPath802=== CONT TestCreatePin_ReservedPins803=== CONT TestOrphanedObjectsGCStressTest804=== CONT TestOrphanedObjectsGC805=== CONT TestPresentRefreshesOnlyStaleClosures806=== CONT TestObjectStatsUpdatedOncePerCommit807=== CONT TestObjectStatsTrigger808=== CONT TestPush_CompleteWaitsForCleanupOfThePush809=== CONT TestPush_CompleteCommitsEveryRoot810=== CONT TestPush_OverlappingRootsStoreOneRowPerKey811=== CONT TestReadRedirectUsesPublicS3URL812=== CONT TestReadProxyRangeRequest813=== CONT TestReadRedirectKeepsNarinfoProxied814=== CONT TestReadRedirectNar815=== CONT TestReadProxyDisabled816=== CONT TestReadProxyRootRedirectsToIndexHTML817=== CONT TestReadProxyConditionalGet818--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)819--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)820--- PASS: TestGCTaskStore_GetEmpty (0.00s)821=== CONT TestReadProxyOutlastsServerWriteTimeout822=== CONT TestService_AuthMiddleware8232026/10/25 16:38:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49503/oidc824--- PASS: TestPresentRefreshesOnlyStaleClosures (0.77s)825=== CONT TestReadProxy404826--- PASS: TestReadRedirectKeepsNarinfoProxied (1.05s)827=== CONT TestReadProxyNarStreaming828--- PASS: TestReadProxyRangeRequest (1.34s)829=== CONT TestReadProxyContentNegotiation830--- PASS: TestReadProxyInvalidPath (1.65s)831=== CONT TestReadProxyNarinfoAlreadyDecompressed8322026/10/25 16:38:59 INFO Received uploads request method=POST path=/api/pending_closures8332026/10/25 16:38:59 INFO Received uploads request method=POST path=/api/pending_closures8342026/10/25 16:38:59 INFO Received cleanup request method=DELETE path=/api/pending_closures835--- PASS: TestPresentReportsOnlyClosureRoots (2.39s)836=== CONT TestReadProxyNarinfo8372026/10/25 16:39:00 INFO Received push request method=POST path=/api/pushes8382026/10/25 16:39:00 INFO Received complete push request method=POST path=/api/pushes/1/complete8392026/10/25 16:39:00 INFO Completed push id=1 objects=6 duration=22.07775ms840--- PASS: TestPush_CompleteCommitsEveryRoot (2.95s)841=== CONT TestIsValidCachePath842=== RUN TestIsValidCachePath/narinfo843=== PAUSE TestIsValidCachePath/narinfo844=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars845=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars846=== RUN TestIsValidCachePath/nar_zst847=== PAUSE TestIsValidCachePath/nar_zst848=== RUN TestIsValidCachePath/nar_xz849=== PAUSE TestIsValidCachePath/nar_xz850=== RUN TestIsValidCachePath/nar_bz2851=== PAUSE TestIsValidCachePath/nar_bz2852=== RUN TestIsValidCachePath/nar_uncompressed853=== PAUSE TestIsValidCachePath/nar_uncompressed854=== RUN TestIsValidCachePath/ls855=== PAUSE TestIsValidCachePath/ls856=== RUN TestIsValidCachePath/log857=== PAUSE TestIsValidCachePath/log858=== RUN TestIsValidCachePath/realisation859=== PAUSE TestIsValidCachePath/realisation860=== RUN TestIsValidCachePath/nix-cache-info861=== PAUSE TestIsValidCachePath/nix-cache-info862=== RUN TestIsValidCachePath/index.html863=== PAUSE TestIsValidCachePath/index.html864=== RUN TestIsValidCachePath/traversal_parent865=== PAUSE TestIsValidCachePath/traversal_parent866=== RUN TestIsValidCachePath/traversal_in_middle867=== PAUSE TestIsValidCachePath/traversal_in_middle868=== RUN TestIsValidCachePath/invalid_char_e869=== PAUSE TestIsValidCachePath/invalid_char_e870=== RUN TestIsValidCachePath/invalid_char_u871=== PAUSE TestIsValidCachePath/invalid_char_u872=== RUN TestIsValidCachePath/random_path873=== PAUSE TestIsValidCachePath/random_path874=== RUN TestIsValidCachePath/empty875=== PAUSE TestIsValidCachePath/empty876=== RUN TestIsValidCachePath/leading_slash877=== PAUSE TestIsValidCachePath/leading_slash878=== RUN TestIsValidCachePath/wrong_extension879=== PAUSE TestIsValidCachePath/wrong_extension880=== RUN TestIsValidCachePath/short_hash881=== PAUSE TestIsValidCachePath/short_hash882=== CONT TestParseSingleRange883=== RUN TestParseSingleRange/none884=== PAUSE TestParseSingleRange/none885=== RUN TestParseSingleRange/unknown_unit886=== PAUSE TestParseSingleRange/unknown_unit887=== RUN TestParseSingleRange/multi-range_ignored888=== PAUSE TestParseSingleRange/multi-range_ignored889=== RUN TestParseSingleRange/malformed_no_dash890=== PAUSE TestParseSingleRange/malformed_no_dash891=== RUN TestParseSingleRange/malformed_both_empty892=== PAUSE TestParseSingleRange/malformed_both_empty893=== RUN TestParseSingleRange/malformed_end_before_start894=== PAUSE TestParseSingleRange/malformed_end_before_start895=== RUN TestParseSingleRange/closed896=== PAUSE TestParseSingleRange/closed897=== RUN TestParseSingleRange/open-ended898=== PAUSE TestParseSingleRange/open-ended899=== RUN TestParseSingleRange/end_clamped_to_size900=== PAUSE TestParseSingleRange/end_clamped_to_size901=== RUN TestParseSingleRange/suffix902=== PAUSE TestParseSingleRange/suffix903=== RUN TestParseSingleRange/suffix_exceeds_size904=== PAUSE TestParseSingleRange/suffix_exceeds_size905=== RUN TestParseSingleRange/single_byte906=== PAUSE TestParseSingleRange/single_byte907=== RUN TestParseSingleRange/start_past_EOF908=== PAUSE TestParseSingleRange/start_past_EOF909=== RUN TestParseSingleRange/start_far_past_EOF910=== PAUSE TestParseSingleRange/start_far_past_EOF911=== CONT TestPresentNotReportedWhileGCDeletesClosure912=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale913=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale914=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh915=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh916=== CONT TestCreatePendingClosureRejectsOversizedNAR9172026/10/25 16:39:00 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)919=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded920--- PASS: TestReadRedirectNar (3.25s)921=== CONT TestMultipartCleanup922--- PASS: TestObjectStatsUpdatedOncePerCommit (3.72s)923=== CONT TestServerTLSConfig924=== RUN TestServerTLSConfig/no_client_CA925=== PAUSE TestServerTLSConfig/no_client_CA926=== RUN TestServerTLSConfig/missing_CA_file927=== PAUSE TestServerTLSConfig/missing_CA_file928=== RUN TestServerTLSConfig/not_a_PEM_file929=== PAUSE TestServerTLSConfig/not_a_PEM_file930=== CONT TestService_NativeMTLS931=== NAME TestOrphanedObjectsGC932 orphaned_objects_gc_test.go:287: GC Test Summary:933 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A934 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B935 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)936 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)937 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects938--- PASS: TestOrphanedObjectsGC (3.74s)939=== CONT TestLeadElectsOneAndHandsOver9402026/10/25 16:39:01 INFO Received push request method=POST path=/api/pushes941--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.94s)942=== CONT TestGCTaskStore_DeduplicateSameParams943--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)944=== CONT TestConnectWaitsForAPeerMigration9452026/10/25 16:39:01 INFO Received push request method=POST path=/api/pushes946--- PASS: TestReadProxyHead (4.31s)947=== CONT TestResolveDBConnectionString948=== RUN TestResolveDBConnectionString/flag_wins949=== PAUSE TestResolveDBConnectionString/flag_wins950=== RUN TestResolveDBConnectionString/file_when_flag_empty951=== PAUSE TestResolveDBConnectionString/file_when_flag_empty952=== RUN TestResolveDBConnectionString/missing_file_is_an_error953=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error954=== RUN TestResolveDBConnectionString/PGHOST_allows_empty955=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty956=== RUN TestResolveDBConnectionString/nothing_configured957=== PAUSE TestResolveDBConnectionString/nothing_configured958=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9592026-10-25 16:39:02.200 UTC [48034] ERROR: Push does not exist: id=19602026-10-25 16:39:02.200 UTC [48034] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9612026-10-25 16:39:02.200 UTC [48034] STATEMENT: SELECT commit_push($1)962--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (4.45s)963=== CONT TestGCTaskStore_StartNew964--- PASS: TestGCTaskStore_StartNew (0.00s)965=== CONT TestGCEndsOnShutdown966=== RUN TestGCEndsOnShutdown/before_the_run967=== PAUSE TestGCEndsOnShutdown/before_the_run968=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete969=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete970=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark971=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark972=== CONT TestMetricsCommit973--- PASS: TestReadProxyRootRedirectsToIndexHTML (4.53s)974=== CONT TestCommitRacingPendingCleanupKeepsObjects9752026/10/25 16:39:02 INFO Received push request method=POST path=/api/pushes9762026/10/25 16:39:02 INFO Received complete push request method=POST path=/api/pushes/1/complete9772026/10/25 16:39:02 INFO Completed push id=1 objects=4 duration=26.251791ms978--- PASS: TestPush_RepeatedRootCommitsOnce (4.87s)979=== CONT TestMetricsInventory9802026/10/25 16:39:03 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"981--- PASS: TestService_AuthMiddleware (5.28s)982=== CONT TestPushWaitsForSweepHoldingRow983--- PASS: TestObjectStatsTrigger (5.62s)984=== CONT TestNARDeduplicationMetadataUploadBug985--- PASS: TestReadProxyConditionalGet (5.95s)986=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle987--- PASS: TestReadProxyDisabled (6.27s)988=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9892026/10/25 16:39:04 INFO Received push request method=POST path=/api/pushes9902026-10-25 16:39:05.204 UTC [49279] ERROR: could not obtain lock on row in relation "closures"9912026-10-25 16:39:05.204 UTC [49279] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9922026-10-25 16:39:05.207 UTC [49279] ERROR: could not obtain lock on row in relation "closures"9932026-10-25 16:39:05.207 UTC [49279] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9942026-10-25 16:39:05.210 UTC [49279] ERROR: could not obtain lock on row in relation "closures"9952026-10-25 16:39:05.210 UTC [49279] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9962026-10-25 16:39:05.211 UTC [49279] ERROR: could not obtain lock on row in relation "closures"9972026-10-25 16:39:05.211 UTC [49279] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9982026-10-25 16:39:05.226 UTC [49279] ERROR: could not obtain lock on row in relation "closures"9992026-10-25 16:39:05.226 UTC [49279] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1000--- PASS: TestPush_RootsAreLockedInByteOrder (7.49s)1001=== CONT TestCompleteMultipartUnregistered1002--- PASS: TestReadRedirectUsesPublicS3URL (7.71s)1003=== CONT TestService_verifyS3Integrity10042026/10/25 16:39:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10052026/10/25 16:39:05 WARN Refused reserved pin name=worker-x86_64-linux10062026/10/25 16:39:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10072026/10/25 16:39:05 INFO Received create pin request method=POST path=/api/pins/my-app10082026/10/25 16:39:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1009--- PASS: TestCreatePin_ReservedPins (8.10s)1010=== CONT TestService_createPendingClosureHandler10112026/10/25 16:39:05 INFO Aborted multipart uploads count=1 kept=010122026/10/25 16:39:05 INFO Received cleanup request method=DELETE path=/api/pending_closures10132026/10/25 16:39:06 INFO Aborted multipart uploads count=1 kept=01014--- PASS: TestPendingCleanupUsesOneCutoff (8.27s)1015=== CONT TestSweepRechecksPendingAfterLocking1016--- PASS: TestReadProxyNarStreaming (7.46s)1017=== CONT TestService_cleanupPendingClosuresHandler1018--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.39s)1019=== CONT TestGetExistingObjectsLocksRows1020--- PASS: TestReadProxyContentNegotiation (8.36s)1021=== CONT TestUploadHandlersRejectOversizedBody1022=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1023=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1024=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1025=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1026=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1027=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1028=== CONT TestRegisterCompletedObjectNeedsPendingRow1029--- PASS: TestReadProxy404 (9.41s)1030=== CONT TestUploadHandlersRejectInvalidKeys1031=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1032=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1033=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1034=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1035=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1036=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1037=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1038=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1039=== CONT TestIsValidUploadKey1040=== RUN TestIsValidUploadKey/narinfo1041=== PAUSE TestIsValidUploadKey/narinfo1042=== RUN TestIsValidUploadKey/nar_zst1043=== PAUSE TestIsValidUploadKey/nar_zst1044=== RUN TestIsValidUploadKey/nar_xz1045=== PAUSE TestIsValidUploadKey/nar_xz1046=== RUN TestIsValidUploadKey/nar_plain1047=== PAUSE TestIsValidUploadKey/nar_plain1048=== RUN TestIsValidUploadKey/listing1049=== PAUSE TestIsValidUploadKey/listing1050=== RUN TestIsValidUploadKey/build_log1051=== PAUSE TestIsValidUploadKey/build_log1052=== RUN TestIsValidUploadKey/build_log_home-manager_file1053=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1054=== RUN TestIsValidUploadKey/build_log_plus_in_name1055=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1056=== RUN TestIsValidUploadKey/build_log_question_mark1057=== PAUSE TestIsValidUploadKey/build_log_question_mark1058=== RUN TestIsValidUploadKey/build_log_equals1059=== PAUSE TestIsValidUploadKey/build_log_equals1060=== RUN TestIsValidUploadKey/realisation1061=== PAUSE TestIsValidUploadKey/realisation1062=== RUN TestIsValidUploadKey/realisation_plus_in_output1063=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1064=== RUN TestIsValidUploadKey/nix-cache-info1065=== PAUSE TestIsValidUploadKey/nix-cache-info1066=== RUN TestIsValidUploadKey/index.html1067=== PAUSE TestIsValidUploadKey/index.html1068=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1069=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1070=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1071=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1072=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1073=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1074=== RUN TestIsValidUploadKey/traversal1075=== PAUSE TestIsValidUploadKey/traversal1076=== RUN TestIsValidUploadKey/traversal_nar1077=== PAUSE TestIsValidUploadKey/traversal_nar1078=== RUN TestIsValidUploadKey/absolute1079=== PAUSE TestIsValidUploadKey/absolute1080=== RUN TestIsValidUploadKey/empty_key1081=== PAUSE TestIsValidUploadKey/empty_key1082=== RUN TestIsValidUploadKey/unknown_type1083=== PAUSE TestIsValidUploadKey/unknown_type1084=== CONT TestSweepSkipsRowsLockedByPush10852026/10/25 16:39:08 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1086--- PASS: TestReadProxyNarinfo (8.25s)1087=== CONT TestPendingClosureWriteTimeout1088=== RUN TestPendingClosureWriteTimeout/empty1089=== PAUSE TestPendingClosureWriteTimeout/empty1090=== RUN TestPendingClosureWriteTimeout/400_objects1091=== PAUSE TestPendingClosureWriteTimeout/400_objects1092=== RUN TestPendingClosureWriteTimeout/670k_objects1093=== PAUSE TestPendingClosureWriteTimeout/670k_objects1094=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1095=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1096=== CONT TestDeleteClosuresRacingPins10972026/10/25 16:39:08 INFO Received uploads request method=POST path=/api/pending_closures1098--- PASS: TestConnectWaitsForAPeerMigration (7.07s)1099=== CONT TestProxyWriteTimeout1100=== RUN TestProxyWriteTimeout/narinfo1101=== PAUSE TestProxyWriteTimeout/narinfo1102=== RUN TestProxyWriteTimeout/1_GiB_nar1103=== PAUSE TestProxyWriteTimeout/1_GiB_nar1104=== RUN TestProxyWriteTimeout/10_GiB_nar1105=== PAUSE TestProxyWriteTimeout/10_GiB_nar1106=== RUN TestProxyWriteTimeout/unknown_size1107=== PAUSE TestProxyWriteTimeout/unknown_size1108=== CONT TestClientFallsBackToClosures1109--- PASS: TestReadProxyOutlastsServerWriteTimeout (11.08s)1110=== CONT TestFailedS3DeleteKeepsTombstone1111--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (8.15s)1112=== CONT TestForceGCDuringPushOffersSweptObject1113=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1114=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1115=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1116=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1117=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11182026/10/25 16:39:09 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/25 16:39:09 INFO Received cleanup request method=DELETE path=/api/pending_closures11202026/10/25 16:39:09 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket34/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11212026/10/25 16:39:09 INFO Aborted multipart uploads count=0 kept=111222026/10/25 16:39:09 INFO Received cleanup request method=DELETE path=/api/pending_closures11232026/10/25 16:39:09 INFO Aborted multipart uploads count=1 kept=01124--- PASS: TestMultipartCleanup (8.51s)1125=== CONT TestGCSweepDeliversEachKeyOnce11262026/10/25 16:39:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11272026/10/25 16:39:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1128--- PASS: TestService_NativeMTLS (8.26s)1129=== CONT TestTombstonedObjectOfferedWithoutWaiting11302026/10/25 16:39:10 INFO lead: acquired remote=192.0.2.1:123411312026/10/25 16:39:11 INFO Received push request method=POST path=/api/pushes11322026/10/25 16:39:11 INFO Received complete push request method=POST path=/api/pushes/1/complete11332026/10/25 16:39:11 INFO Completed push id=1 objects=4 duration=118.576ms11342026/10/25 16:39:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11352026/10/25 16:39:11 INFO Completed upload id=2 objects=2 duration=2.438709ms1136--- PASS: TestMetricsCommit (9.24s)1137=== CONT TestGCSweepSkipsPendingObjects11382026/10/25 16:39:11 INFO lead: released remote=192.0.2.1:123411392026/10/25 16:39:11 INFO lead: acquired remote=192.0.2.1:123411402026/10/25 16:39:11 INFO Aborted multipart uploads count=0 kept=011412026/10/25 16:39:11 WARN Force mode enabled - objects will be deleted immediately without grace period11422026/10/25 16:39:11 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=011432026/10/25 16:39:11 INFO Vacuumed table table=pending_closures11442026/10/25 16:39:12 INFO Vacuumed table table=pending_objects11452026/10/25 16:39:12 INFO Vacuumed table table=multipart_uploads11462026/10/25 16:39:12 INFO Vacuumed table table=closures11472026/10/25 16:39:12 INFO Vacuumed table table=objects1148--- PASS: TestCommitRacingPendingCleanupKeepsObjects (9.82s)1149=== CONT TestDeduplicatedObjectsRecordedAsPending1150--- PASS: TestMetricsInventory (9.54s)1151=== CONT TestPushDedupSurvivesConcurrentGC11522026/10/25 16:39:12 INFO Received uploads request method=POST path=/api/pending_closures11532026/10/25 16:39:12 INFO lead: released remote=192.0.2.1:12341154--- PASS: TestLeadElectsOneAndHandsOver (11.13s)1155=== CONT TestGCMetrics1156--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.63s)1157=== CONT TestGCBugBareHashReferences1158--- PASS: TestPushWaitsForSweepHoldingRow (10.02s)1159=== CONT TestGCAdvisoryLockBlocksConcurrentRun1160=== NAME TestNARDeduplicationMetadataUploadBug1161 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/021d280b068cf186/build/TestNARDeduplicationMetadataUploadBug519651299/001/store/q4bkvpsgh8rz9p284ppgwgycvs1w1waz-file1.txt11622026/10/25 16:39:13 INFO Received uploads request method=POST path=/api/pending_closures11632026/10/25 16:39:13 INFO Received push request method=POST path=/api/pushes11642026/10/25 16:39:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11652026/10/25 16:39:13 INFO Uploading q4bkvpsgh8rz9p284ppgwgycvs1w1waz-file1.txt (160B)11662026/10/25 16:39:13 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11672026/10/25 16:39:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11682026/10/25 16:39:13 WARN Failed to register uploaded object key=q4bkvpsgh8rz9p284ppgwgycvs1w1waz.ls error="server returned 404: 404 page not found\n"11692026/10/25 16:39:13 INFO Signed narinfos id=1 count=111702026/10/25 16:39:13 INFO Uploading 1 narinfos11712026/10/25 16:39:13 INFO Received complete push request method=POST path=/api/pushes/1/complete11722026/10/25 16:39:13 WARN Failed to register uploaded object key=q4bkvpsgh8rz9p284ppgwgycvs1w1waz.narinfo error="server returned 404: 404 page not found\n"11732026/10/25 16:39:13 INFO Completed push id=1 objects=3 duration=56.73175ms11742026/10/25 16:39:13 INFO Upload complete. (313ms)1175 metadata_upload_test.go:54: Retrieved narinfo from S3:1176 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestNARDeduplicationMetadataUploadBug519651299/001/store/q4bkvpsgh8rz9p284ppgwgycvs1w1waz-file1.txt1177 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1178 Compression: zstd1179 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1180 NarSize: 1601181 References: 1182 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1183 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1184 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1185 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11862026/10/25 16:39:13 INFO Received uploads request method=POST path=/api/pending_closures11872026/10/25 16:39:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1188--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (9.90s)1189=== CONT TestLeadEndsOnShutdown1190=== NAME TestNARDeduplicationMetadataUploadBug1191 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/021d280b068cf186/build/TestNARDeduplicationMetadataUploadBug519651299/001/store/gxw52aml716439rig3fggw6as6s5qjfw-file2.txt11922026/10/25 16:39:14 INFO Received push request method=POST path=/api/pushes11932026/10/25 16:39:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11942026/10/25 16:39:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11952026/10/25 16:39:14 WARN Failed to register uploaded object key=gxw52aml716439rig3fggw6as6s5qjfw.ls error="server returned 404: 404 page not found\n"11962026/10/25 16:39:14 INFO Signed narinfos id=2 count=111972026/10/25 16:39:14 INFO Uploading 1 narinfos11982026/10/25 16:39:14 INFO Received uploads request method=POST path=/api/pending_closures11992026/10/25 16:39:14 INFO Received complete push request method=POST path=/api/pushes/2/complete12002026/10/25 16:39:14 WARN Failed to register uploaded object key=gxw52aml716439rig3fggw6as6s5qjfw.narinfo error="server returned 404: 404 page not found\n"12012026/10/25 16:39:14 INFO Completed push id=2 objects=3 duration=860.75µs12022026/10/25 16:39:14 INFO Upload complete. (210ms)1203 metadata_upload_test.go:76: Retrieved narinfo from S3:1204 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestNARDeduplicationMetadataUploadBug519651299/001/store/gxw52aml716439rig3fggw6as6s5qjfw-file2.txt1205 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1206 Compression: zstd1207 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1208 NarSize: 1601209 References: 1210 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1211 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1212 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1213 {"version":1,"root":{"type":"regular","size":44}}1214--- PASS: TestNARDeduplicationMetadataUploadBug (11.01s)1215=== CONT TestLeadIncumbentAnnouncesAtOnce12162026/10/25 16:39:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12172026/10/25 16:39:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1218--- PASS: TestCompleteMultipartUnregistered (9.47s)1219=== CONT TestCacheStatsHandler12202026/10/25 16:39:15 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/25 16:39:15 INFO Received uploads request method=POST path=/api/pending_closures12222026/10/25 16:39:15 INFO Received uploads request method=POST path=/api/pending_closures12232026/10/25 16:39:15 INFO Aborted multipart uploads count=0 kept=012242026/10/25 16:39:15 WARN Force mode enabled - objects will be deleted immediately without grace period12252026/10/25 16:39:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012262026/10/25 16:39:16 INFO Vacuumed table table=pending_closures12272026/10/25 16:39:16 INFO Vacuumed table table=pending_objects12282026/10/25 16:39:16 INFO Vacuumed table table=multipart_uploads12292026/10/25 16:39:16 INFO Vacuumed table table=closures12302026/10/25 16:39:16 INFO Vacuumed table table=objects1231--- PASS: TestSweepRechecksPendingAfterLocking (10.11s)1232=== CONT TestCacheConfigHandler1233=== RUN TestCacheConfigHandler/full_config,_no_issuer1234=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1235=== RUN TestCacheConfigHandler/no_cache_url_configured1236=== PAUSE TestCacheConfigHandler/no_cache_url_configured1237=== RUN TestCacheConfigHandler/no_signing_keys1238=== PAUSE TestCacheConfigHandler/no_signing_keys1239=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1240=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1241=== CONT TestService_ReadScope_PublicByDefault12422026/10/25 16:39:16 INFO Received cleanup request method=DELETE path=/api/pending_closures12432026/10/25 16:39:16 INFO Aborted multipart uploads count=0 kept=012442026/10/25 16:39:16 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/25 16:39:16 INFO Received cleanup request method=DELETE path=/api/pending_closures12462026/10/25 16:39:16 INFO Aborted multipart uploads count=1 kept=012472026/10/25 16:39:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12482026-10-25 16:39:16.430 UTC [49394] ERROR: Closure does not exist: id=112492026-10-25 16:39:16.430 UTC [49394] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12502026-10-25 16:39:16.430 UTC [49394] STATEMENT: -- name: CommitPendingClosure :one1251 SELECT commit_pending_closure($1::bigint)::bigint1252 1253--- PASS: TestService_cleanupPendingClosuresHandler (10.14s)1254=== CONT TestClientWithDependencies12552026/10/25 16:39:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12562026/10/25 16:39:16 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LmNjMjVkMWZlLWE5NzQtNDU0Yi05ZTdhLTY0OTdhZjk0NDNmN3gxNzkyOTQ2MzU0MjY0NzkwMDAw parts=1012572026/10/25 16:39:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12582026/10/25 16:39:16 INFO Completed upload id=1 objects=2 duration=23.556916ms12592026/10/25 16:39:16 INFO Received uploads request method=POST path=/api/pending_closures12602026/10/25 16:39:16 INFO Received uploads request method=POST path=/api/pending_closures1261--- PASS: TestGetExistingObjectsLocksRows (9.99s)12622026/10/25 16:39:16 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo1263=== CONT TestClientPushesUseOnePush12642026/10/25 16:39:16 WARN Found objects in DB but missing from S3, will re-upload count=11265--- PASS: TestService_verifyS3Integrity (11.32s)1266=== CONT TestPinProtectsFromGC1267--- PASS: TestRegisterCompletedObjectNeedsPendingRow (9.66s)1268=== CONT TestClientMultipleUploads12692026/10/25 16:39:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12702026/10/25 16:39:17 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LjJjNDcyMTY4LWY1YzAtNDg1NS04MDM2LTYwODA3YTI5ZmVlZngxNzkyOTQ2MzU1Mjc3NjA4MDAw parts=1012712026/10/25 16:39:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12722026/10/25 16:39:17 INFO Completed upload id=1 objects=2 duration=11.638166ms12732026/10/25 16:39:17 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012742026/10/25 16:39:17 INFO Received uploads request method=POST path=/api/pending_closures12752026/10/25 16:39:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures12762026/10/25 16:39:17 INFO Aborted multipart uploads count=0 kept=012772026/10/25 16:39:17 INFO Aborted multipart uploads count=0 kept=012782026/10/25 16:39:17 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=012792026/10/25 16:39:17 WARN Force mode enabled - objects will be deleted immediately without grace period12802026/10/25 16:39:17 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=012812026/10/25 16:39:17 INFO Vacuumed table table=pending_closures12822026/10/25 16:39:17 INFO Vacuumed table table=pending_objects12832026/10/25 16:39:17 INFO Vacuumed table table=multipart_uploads12842026/10/25 16:39:17 INFO Vacuumed table table=closures12852026/10/25 16:39:17 INFO Vacuumed table table=pending_closures12862026/10/25 16:39:17 INFO Vacuumed table table=pending_objects12872026/10/25 16:39:17 INFO Vacuumed table table=objects12882026/10/25 16:39:17 INFO Aborted multipart uploads count=0 kept=012892026/10/25 16:39:17 WARN Force mode enabled - objects will be deleted immediately without grace period12902026/10/25 16:39:17 INFO Vacuumed table table=multipart_uploads12912026/10/25 16:39:17 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=012922026/10/25 16:39:17 INFO Vacuumed table table=pending_closures12932026/10/25 16:39:17 INFO Vacuumed table table=pending_objects12942026/10/25 16:39:17 INFO Vacuumed table table=multipart_uploads12952026/10/25 16:39:17 INFO Vacuumed table table=closures12962026/10/25 16:39:17 INFO Vacuumed table table=closures12972026/10/25 16:39:17 INFO Vacuumed table table=objects1298--- PASS: TestSweepSkipsRowsLockedByPush (10.00s)1299=== CONT TestClientSharedPathCommittedMidPush13002026/10/25 16:39:18 INFO Vacuumed table table=objects13012026/10/25 16:39:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001302--- PASS: TestService_createPendingClosureHandler (12.22s)1303=== CONT TestClientIntegration13042026/10/25 16:39:18 WARN Rate limiter enabled after throttle name=s3-test rate=513052026/10/25 16:39:18 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1306=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1307 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101308 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001309--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (14.53s)1310=== CONT TestClientErrorHandling1311=== RUN TestClientErrorHandling/InvalidStorePath1312=== PAUSE TestClientErrorHandling/InvalidStorePath1313=== RUN TestClientErrorHandling/InvalidAuthToken1314=== PAUSE TestClientErrorHandling/InvalidAuthToken1315=== RUN TestClientErrorHandling/ServerNotAvailable1316=== PAUSE TestClientErrorHandling/ServerNotAvailable1317=== CONT TestService_healthCheckHandler13182026/10/25 16:39:18 INFO Received uploads request method=POST path=/api/pending_closures1319--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (10.23s)1320=== CONT TestClientCADerivations1321=== NAME TestOrphanedObjectsGCStressTest1322 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13232026/10/25 16:39:19 INFO Received uploads request method=POST path=/api/pending_closures1324 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion13252026/10/25 16:39:19 INFO Received uploads request method=POST path=/api/pending_closures13262026/10/25 16:39:19 INFO Received uploads request method=POST path=/api/pending_closures13272026/10/25 16:39:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13282026/10/25 16:39:19 INFO Uploading j06bxa4924r9fsa5rrfxj958bfy5vzjq-a (256B)13292026/10/25 16:39:19 INFO Uploading a4c3cvf0xsagyildf696i90l6j6g1va4-shared-dep (136B)13302026/10/25 16:39:19 WARN Failed to register uploaded object key=j06bxa4924r9fsa5rrfxj958bfy5vzjq.ls error="server returned 404: 404 page not found\n"13312026/10/25 16:39:19 WARN Failed to register uploaded object key=8y2w8pav83ac34kp2vrjdwzyvskj40lk.ls error="server returned 404: 404 page not found\n"13322026/10/25 16:39:19 WARN Failed to register uploaded object key=a4c3cvf0xsagyildf696i90l6j6g1va4.ls error="server returned 404: 404 page not found\n"13332026/10/25 16:39:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13342026/10/25 16:39:19 WARN Failed to register uploaded object key=nar/0d9cl91f7hp8wj789nhlxfw1rl4zjg9vsrjjkchfq25vaasjyp54.nar.zst error="server returned 404: 404 page not found\n"13352026/10/25 16:39:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13362026/10/25 16:39:19 INFO Aborted multipart uploads count=0 kept=013372026/10/25 16:39:19 INFO Signed narinfos id=1 count=213382026/10/25 16:39:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13392026/10/25 16:39:19 INFO Signed narinfos id=2 count=213402026/10/25 16:39:19 INFO Uploading 4 narinfos13412026/10/25 16:39:19 WARN Force mode enabled - objects will be deleted immediately without grace period13422026/10/25 16:39:19 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13432026/10/25 16:39:19 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1344--- PASS: TestFailedS3DeleteKeepsTombstone (10.78s)1345=== CONT TestService_RequireScope_OIDC13462026/10/25 16:39:19 WARN Failed to register uploaded object key=j06bxa4924r9fsa5rrfxj958bfy5vzjq.narinfo error="server returned 404: 404 page not found\n"13472026/10/25 16:39:19 WARN Failed to register uploaded object key=8y2w8pav83ac34kp2vrjdwzyvskj40lk.narinfo error="server returned 404: 404 page not found\n"13482026/10/25 16:39:19 WARN Failed to register uploaded object key=a4c3cvf0xsagyildf696i90l6j6g1va4.narinfo error="server returned 404: 404 page not found\n"13492026/10/25 16:39:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49722/oidc13502026/10/25 16:39:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13512026/10/25 16:39:19 WARN Failed to register uploaded object key=a4c3cvf0xsagyildf696i90l6j6g1va4.narinfo error="server returned 404: 404 page not found\n"13522026/10/25 16:39:19 INFO Completed upload id=1 objects=6 duration=66.042667ms13532026/10/25 16:39:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13542026/10/25 16:39:19 INFO Completed upload id=2 objects=6 duration=4.195875ms13552026/10/25 16:39:19 INFO Upload complete. (666ms)1356=== NAME TestClientFallsBackToClosures1357 client_pushes_test.go:112: Retrieved narinfo from S3:1358 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientFallsBackToClosures1850896538/001/store/a4c3cvf0xsagyildf696i90l6j6g1va4-shared-dep1359 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1360 Compression: zstd1361 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821362 NarSize: 1361363 References: 1364 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1365 client_pushes_test.go:112: Retrieved narinfo from S3:1366 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientFallsBackToClosures1850896538/001/store/j06bxa4924r9fsa5rrfxj958bfy5vzjq-a1367 URL: nar/0d9cl91f7hp8wj789nhlxfw1rl4zjg9vsrjjkchfq25vaasjyp54.nar.zst1368 Compression: zstd1369 NarHash: sha256:0d9cl91f7hp8wj789nhlxfw1rl4zjg9vsrjjkchfq25vaasjyp541370 NarSize: 2561371 References: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientFallsBackToClosures1850896538/001/store/a4c3cvf0xsagyildf696i90l6j6g1va4-shared-dep1372 CA: text:sha256:03vxfrk1labnryqb3fmr5rrz57k8ymrcbz1agfcsfxw9h1dgiq451373 client_pushes_test.go:112: Retrieved narinfo from S3:1374 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientFallsBackToClosures1850896538/001/store/8y2w8pav83ac34kp2vrjdwzyvskj40lk-b1375 URL: nar/0d9cl91f7hp8wj789nhlxfw1rl4zjg9vsrjjkchfq25vaasjyp54.nar.zst1376 Compression: zstd1377 NarHash: sha256:0d9cl91f7hp8wj789nhlxfw1rl4zjg9vsrjjkchfq25vaasjyp541378 NarSize: 2561379 References: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientFallsBackToClosures1850896538/001/store/a4c3cvf0xsagyildf696i90l6j6g1va4-shared-dep1380 CA: text:sha256:03vxfrk1labnryqb3fmr5rrz57k8ymrcbz1agfcsfxw9h1dgiq4513812026/10/25 16:39:20 INFO Aborted multipart uploads count=0 kept=01382--- PASS: TestClientFallsBackToClosures (11.28s)1383=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13842026/10/25 16:39:20 WARN Force mode enabled - objects will be deleted immediately without grace period13852026/10/25 16:39:20 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=013862026/10/25 16:39:20 INFO Vacuumed table table=pending_closures13872026/10/25 16:39:20 INFO Vacuumed table table=pending_objects13882026/10/25 16:39:20 INFO Received uploads request method=POST path=/api/pending_closures13892026/10/25 16:39:20 INFO Vacuumed table table=multipart_uploads13902026/10/25 16:39:20 INFO Vacuumed table table=closures13912026/10/25 16:39:20 INFO Vacuumed table table=objects1392--- PASS: TestGCSweepDeliversEachKeyOnce (10.84s)1393=== CONT TestService_AuthMiddleware_OIDC1394--- PASS: TestTombstonedObjectOfferedWithoutWaiting (10.63s)1395=== CONT TestService_AuthMiddleware_MTLSProxyHeader13962026/10/25 16:39:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49726/oidc13972026/10/25 16:39:20 INFO Received uploads request method=POST path=/api/pending_closures13982026/10/25 16:39:20 INFO Aborted multipart uploads count=0 kept=013992026/10/25 16:39:20 WARN Force mode enabled - objects will be deleted immediately without grace period14002026/10/25 16:39:20 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=014012026/10/25 16:39:20 INFO Vacuumed table table=pending_closures14022026/10/25 16:39:21 INFO Vacuumed table table=pending_objects14032026/10/25 16:39:21 INFO Vacuumed table table=multipart_uploads14042026/10/25 16:39:21 INFO Vacuumed table table=closures14052026/10/25 16:39:21 INFO Vacuumed table table=objects1406--- PASS: TestGCSweepSkipsPendingObjects (9.67s)1407=== CONT TestService_ReadAuthMiddleware14082026/10/25 16:39:21 INFO Received uploads request method=POST path=/api/pending_closures1409--- PASS: TestDeduplicatedObjectsRecordedAsPending (9.13s)1410=== CONT TestCacheConfigHandlerMaxNarSize1411--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1412=== CONT TestGenerateLandingPage1413--- PASS: TestGenerateLandingPage (0.00s)1414=== CONT TestCompletedNarNotReofferedAcrossClosures14152026/10/25 16:39:21 INFO Received uploads request method=POST path=/api/pending_closures14162026/10/25 16:39:21 INFO Aborted multipart uploads count=0 kept=014172026/10/25 16:39:21 WARN Force mode enabled - objects will be deleted immediately without grace period14182026/10/25 16:39:21 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=014192026/10/25 16:39:21 INFO Vacuumed table table=pending_closures14202026/10/25 16:39:21 INFO Vacuumed table table=pending_objects14212026/10/25 16:39:21 INFO Vacuumed table table=multipart_uploads14222026/10/25 16:39:21 INFO Vacuumed table table=closures14232026/10/25 16:39:21 INFO Vacuumed table table=objects14242026/10/25 16:39:21 INFO Aborted multipart uploads count=0 kept=01425--- PASS: TestGCMetrics (9.32s)1426=== CONT TestService_readinessHandler14272026/10/25 16:39:21 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=014282026/10/25 16:39:22 INFO Vacuumed table table=pending_closures14292026/10/25 16:39:22 INFO Vacuumed table table=pending_objects14302026/10/25 16:39:22 INFO Vacuumed table table=multipart_uploads14312026/10/25 16:39:22 INFO Vacuumed table table=closures14322026/10/25 16:39:22 INFO Vacuumed table table=objects14332026/10/25 16:39:22 INFO Aborted multipart uploads count=0 kept=014342026/10/25 16:39:22 WARN Force mode enabled - objects will be deleted immediately without grace period14352026/10/25 16:39:22 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=014362026/10/25 16:39:22 INFO Vacuumed table table=pending_closures14372026/10/25 16:39:22 INFO Vacuumed table table=pending_objects14382026/10/25 16:39:22 INFO Vacuumed table table=multipart_uploads14392026/10/25 16:39:22 INFO Vacuumed table table=closures14402026/10/25 16:39:22 INFO Vacuumed table table=objects1441--- PASS: TestPushDedupSurvivesConcurrentGC (9.99s)1442=== CONT TestSkippedUploadsHandler14432026/10/25 16:39:22 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001444--- PASS: TestSkippedUploadsHandler (0.01s)1445=== CONT TestPush_SignsNarinfosOfItsPendingObjects14462026/10/25 16:39:22 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1447--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (9.38s)1448=== CONT TestParseSize1449--- PASS: TestParseSize (0.00s)1450=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1451--- PASS: TestGCBugBareHashReferences (9.75s)1452=== CONT TestService_Rustfstest14532026/10/25 16:39:22 INFO lead: acquired remote=192.0.2.1:123414542026/10/25 16:39:22 INFO lead: acquired remote=192.0.2.1:123414552026/10/25 16:39:22 INFO lead: released remote=192.0.2.1:12341456--- PASS: TestLeadIncumbentAnnouncesAtOnce (8.54s)1457=== CONT TestRedundantMultipartUpload1458--- PASS: TestDeleteClosuresRacingPins (14.84s)1459=== CONT TestPresignedUploadRegisteredBeforeCommit1460--- PASS: TestCacheStatsHandler (8.57s)1461=== CONT TestPush_RejectsBadRequests1462--- PASS: TestService_ReadScope_PublicByDefault (7.36s)1463=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit14642026/10/25 16:39:23 INFO lead: released remote=192.0.2.1:12341465--- PASS: TestLeadEndsOnShutdown (9.83s)1466=== CONT TestGCTaskStore_Fail1467--- PASS: TestGCTaskStore_Fail (0.00s)1468=== CONT TestGCTaskStore_PhaseUpdates1469--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1470=== CONT TestGracefulShutdownDrainsInflight14712026/10/25 16:39:23 INFO Starting HTTP server address=127.0.0.1:4974814722026/10/25 16:39:23 INFO Shutdown signal received, draining in-flight requests timeout=10s1473--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1474=== CONT TestGCTaskStore_CompletedAllowsNewTask1475--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1476=== CONT TestIsValidCachePath/narinfo1477=== CONT TestIsValidCachePath/leading_slash1478=== CONT TestIsValidCachePath/empty1479=== CONT TestIsValidCachePath/random_path1480=== CONT TestIsValidCachePath/invalid_char_u1481=== CONT TestIsValidCachePath/invalid_char_e1482=== CONT TestIsValidCachePath/traversal_in_middle1483=== CONT TestIsValidCachePath/wrong_extension1484=== CONT TestIsValidCachePath/traversal_parent1485=== CONT TestIsValidCachePath/index.html1486=== CONT TestIsValidCachePath/nix-cache-info1487=== CONT TestIsValidCachePath/realisation1488=== CONT TestIsValidCachePath/log1489=== CONT TestIsValidCachePath/ls1490=== CONT TestIsValidCachePath/nar_uncompressed1491=== CONT TestIsValidCachePath/nar_bz21492=== CONT TestIsValidCachePath/nar_xz1493=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1494=== CONT TestIsValidCachePath/short_hash1495=== CONT TestIsValidCachePath/nar_zst1496=== CONT TestParseSingleRange/none1497--- PASS: TestIsValidCachePath (0.01s)1498 --- PASS: TestIsValidCachePath/narinfo (0.00s)1499 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1500 --- PASS: TestIsValidCachePath/empty (0.00s)1501 --- PASS: TestIsValidCachePath/random_path (0.00s)1502 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1503 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1504 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1505 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1506 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1507 --- PASS: TestIsValidCachePath/index.html (0.00s)1508 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1509 --- PASS: TestIsValidCachePath/realisation (0.00s)1510 --- PASS: TestIsValidCachePath/log (0.00s)1511 --- PASS: TestIsValidCachePath/ls (0.00s)1512 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1513 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1514 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1515 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1516 --- PASS: TestIsValidCachePath/short_hash (0.00s)1517 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1518=== CONT TestParseSingleRange/open-ended1519=== CONT TestParseSingleRange/start_far_past_EOF1520=== CONT TestParseSingleRange/start_past_EOF1521=== CONT TestParseSingleRange/single_byte1522=== CONT TestParseSingleRange/suffix_exceeds_size1523=== CONT TestParseSingleRange/suffix1524=== CONT TestParseSingleRange/end_clamped_to_size1525=== CONT TestParseSingleRange/malformed_both_empty1526=== CONT TestParseSingleRange/closed1527=== CONT TestParseSingleRange/malformed_end_before_start1528=== CONT TestParseSingleRange/multi-range_ignored1529=== CONT TestParseSingleRange/malformed_no_dash1530=== CONT TestParseSingleRange/unknown_unit1531--- PASS: TestParseSingleRange (0.00s)1532 --- PASS: TestParseSingleRange/none (0.00s)1533 --- PASS: TestParseSingleRange/open-ended (0.00s)1534 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1535 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1536 --- PASS: TestParseSingleRange/single_byte (0.00s)1537 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1538 --- PASS: TestParseSingleRange/suffix (0.00s)1539 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1540 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1541 --- PASS: TestParseSingleRange/closed (0.00s)1542 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1543 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1544 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1545 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1546=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1547=== NAME TestOrphanedObjectsGCStressTest1548 orphaned_objects_gc_test.go:503: Stress test completed successfully:1549 orphaned_objects_gc_test.go:504: - Active objects preserved: 201550 orphaned_objects_gc_test.go:505: - Objects deleted: 2101551 orphaned_objects_gc_test.go:506: - Total GC'd: 2101552--- PASS: TestOrphanedObjectsGCStressTest (26.64s)1553=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1554=== NAME TestClientWithDependencies1555 client_integration_test.go:613: Built derivation: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientWithDependencies898540226/001/store/wgwdcdvr6k57l7bd0by9gsx347l8vys8-test-script1556 client_integration_test.go:615: Found 1 dependencies (including self)1557=== NAME TestPinProtectsFromGC1558 client_integration_test.go:731: Pinned store path: /private/var/tb/8/scratch/021d280b068cf186/build/TestPinProtectsFromGC4140705267/001/store/0nj0j1q44civsqgx2m599zi8g5xwchv4-pinned-file.txt1559 client_integration_test.go:732: Unpinned store path: /private/var/tb/8/scratch/021d280b068cf186/build/TestPinProtectsFromGC4140705267/001/store/a4029q28z0mab5r61flp65dsqpxd7kfg-unpinned-file.txt15602026/10/25 16:39:24 INFO Received push request method=POST path=/api/pushes15612026/10/25 16:39:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15622026/10/25 16:39:24 INFO Uploading wgwdcdvr6k57l7bd0by9gsx347l8vys8-test-script (136B)15632026/10/25 16:39:24 INFO Received push request method=POST path=/api/pushes15642026/10/25 16:39:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15652026/10/25 16:39:24 INFO Uploading 0nj0j1q44civsqgx2m599zi8g5xwchv4-pinned-file.txt (128B)15662026/10/25 16:39:24 WARN Failed to register uploaded object key=wgwdcdvr6k57l7bd0by9gsx347l8vys8.ls error="server returned 404: 404 page not found\n"15672026/10/25 16:39:24 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15682026/10/25 16:39:24 WARN Failed to register uploaded object key=log/mrg3p62fgz5650rs55a445vci7y2linj-test-script.drv error="server returned 404: 404 page not found\n"15692026/10/25 16:39:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15702026/10/25 16:39:24 INFO Signed narinfos id=1 count=115712026/10/25 16:39:24 INFO Uploading 1 narinfos15722026/10/25 16:39:24 WARN Failed to register uploaded object key=0nj0j1q44civsqgx2m599zi8g5xwchv4.ls error="server returned 404: 404 page not found\n"15732026/10/25 16:39:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15742026/10/25 16:39:25 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15752026/10/25 16:39:25 INFO Signed narinfos id=1 count=115762026/10/25 16:39:25 INFO Uploading 1 narinfos15772026/10/25 16:39:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/25 16:39:25 WARN Failed to register uploaded object key=wgwdcdvr6k57l7bd0by9gsx347l8vys8.narinfo error="server returned 404: 404 page not found\n"15792026/10/25 16:39:25 INFO Received complete push request method=POST path=/api/pushes/1/complete15802026/10/25 16:39:25 WARN Failed to register uploaded object key=0nj0j1q44civsqgx2m599zi8g5xwchv4.narinfo error="server returned 404: 404 page not found\n"15812026/10/25 16:39:25 INFO Completed push id=1 objects=4 duration=48.673459ms15822026/10/25 16:39:25 INFO Upload complete. (496ms)1583=== NAME TestClientWithDependencies15842026/10/25 16:39:25 INFO Completed push id=1 objects=3 duration=39.403958ms1585 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/021d280b068cf186/build/TestClientWithDependencies898540226/001/store) requires matching store prefix15862026/10/25 16:39:25 INFO Upload complete. (417ms)1587--- PASS: TestClientWithDependencies (8.79s)1588=== CONT TestServerTLSConfig/no_client_CA1589=== CONT TestServerTLSConfig/not_a_PEM_file1590=== CONT TestServerTLSConfig/missing_CA_file1591--- PASS: TestServerTLSConfig (0.00s)1592 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1593 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1594 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1595=== CONT TestResolveDBConnectionString/flag_wins1596=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1597=== CONT TestResolveDBConnectionString/nothing_configured1598=== CONT TestResolveDBConnectionString/missing_file_is_an_error1599=== CONT TestResolveDBConnectionString/file_when_flag_empty1600=== CONT TestGCEndsOnShutdown/before_the_run1601--- PASS: TestResolveDBConnectionString (0.00s)1602 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1603 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1604 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1605 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1606 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1607=== NAME TestClientMultipleUploads1608 client_integration_test.go:358: Created store path 0: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientMultipleUploads1369676229/001/store/fhwx1xxjhagx02cafmnqihqj4ax9a0kk-test-file-0.txt16092026/10/25 16:39:25 INFO Received push request method=POST path=/api/pushes16102026/10/25 16:39:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16112026/10/25 16:39:25 INFO Uploading a4029q28z0mab5r61flp65dsqpxd7kfg-unpinned-file.txt (128B)16122026/10/25 16:39:25 WARN Failed to register uploaded object key=a4029q28z0mab5r61flp65dsqpxd7kfg.ls error="server returned 404: 404 page not found\n"16132026/10/25 16:39:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16142026/10/25 16:39:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16152026/10/25 16:39:25 INFO Signed narinfos id=2 count=116162026/10/25 16:39:25 INFO Uploading 1 narinfos1617 client_integration_test.go:358: Created store path 1: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientMultipleUploads1369676229/001/store/fwdmj3qcnvgk258lg8agqbacr6fs2i4l-test-file-1.txt16182026/10/25 16:39:25 INFO Received complete push request method=POST path=/api/pushes/2/complete16192026/10/25 16:39:25 WARN Failed to register uploaded object key=a4029q28z0mab5r61flp65dsqpxd7kfg.narinfo error="server returned 404: 404 page not found\n"16202026/10/25 16:39:25 INFO Completed push id=2 objects=3 duration=2.491375ms16212026/10/25 16:39:25 INFO Upload complete. (288ms)16222026/10/25 16:39:25 INFO Received push request method=POST path=/api/pushes16232026/10/25 16:39:25 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16242026/10/25 16:39:25 INFO Uploading sdzfrxli1ggg8qmy0x0yijjix20h3ahn-shared-dep (136B)16252026/10/25 16:39:25 INFO Uploading w11yms9kxy0zis8a6ccacc5gn4cx97z3-a (256B)16262026/10/25 16:39:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16272026/10/25 16:39:25 INFO Garbage collection started16282026/10/25 16:39:25 WARN Failed to register uploaded object key=w11yms9kxy0zis8a6ccacc5gn4cx97z3.ls error="server returned 404: 404 page not found\n"16292026/10/25 16:39:25 WARN Failed to register uploaded object key=sdzfrxli1ggg8qmy0x0yijjix20h3ahn.ls error="server returned 404: 404 page not found\n"16302026/10/25 16:39:25 WARN Failed to register uploaded object key=n3g8j6fcbx44bq9w2sk4ficy146k9jy2.ls error="server returned 404: 404 page not found\n"16312026/10/25 16:39:25 WARN Failed to register uploaded object key=nar/0isj0fcca6l9lnaja8a7llr2qvga8d2v00xihsd1rkffnmicdcim.nar.zst error="server returned 404: 404 page not found\n"16322026/10/25 16:39:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16332026/10/25 16:39:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16342026/10/25 16:39:25 INFO Aborted multipart uploads count=0 kept=016352026/10/25 16:39:25 INFO Signed narinfos id=1 count=316362026/10/25 16:39:25 INFO Uploading 3 narinfos16372026/10/25 16:39:25 WARN Force mode enabled - objects will be deleted immediately without grace period16382026/10/25 16:39:25 WARN Failed to register uploaded object key=n3g8j6fcbx44bq9w2sk4ficy146k9jy2.narinfo error="server returned 404: 404 page not found\n"16392026/10/25 16:39:25 WARN Failed to register uploaded object key=w11yms9kxy0zis8a6ccacc5gn4cx97z3.narinfo error="server returned 404: 404 page not found\n"16402026/10/25 16:39:25 INFO Received complete push request method=POST path=/api/pushes/1/complete16412026/10/25 16:39:25 WARN Failed to register uploaded object key=sdzfrxli1ggg8qmy0x0yijjix20h3ahn.narinfo error="server returned 404: 404 page not found\n"1642 client_integration_test.go:358: Created store path 2: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientMultipleUploads1369676229/001/store/ncharfg438scvqncf5d051fppj5qbp5j-test-file-2.txt16432026/10/25 16:39:25 INFO Completed push id=1 objects=8 duration=41.376083ms16442026/10/25 16:39:25 INFO Upload complete. (520ms)1645=== NAME TestClientPushesUseOnePush1646 client_pushes_test.go:97: Retrieved narinfo from S3:1647 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientPushesUseOnePush2969492362/001/store/sdzfrxli1ggg8qmy0x0yijjix20h3ahn-shared-dep1648 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1649 Compression: zstd1650--- PASS: TestService_healthCheckHandler (7.63s)1651=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1652=== NAME TestClientPushesUseOnePush1653 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y8216542026/10/25 16:39:25 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=01655 NarSize: 1361656 References: 1657 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1658 client_pushes_test.go:97: Retrieved narinfo from S3:1659 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientPushesUseOnePush2969492362/001/store/w11yms9kxy0zis8a6ccacc5gn4cx97z3-a1660 URL: nar/0isj0fcca6l9lnaja8a7llr2qvga8d2v00xihsd1rkffnmicdcim.nar.zst1661 Compression: zstd1662 NarHash: sha256:0isj0fcca6l9lnaja8a7llr2qvga8d2v00xihsd1rkffnmicdcim1663 NarSize: 2561664 References: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientPushesUseOnePush2969492362/001/store/sdzfrxli1ggg8qmy0x0yijjix20h3ahn-shared-dep1665 CA: text:sha256:1arcx0byd161b5r7gzqzlddqg8l2xzpcdrgbb3fxk5qfdp8kfwfm1666 client_pushes_test.go:97: Retrieved narinfo from S3:1667 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientPushesUseOnePush2969492362/001/store/n3g8j6fcbx44bq9w2sk4ficy146k9jy2-b1668 URL: nar/0isj0fcca6l9lnaja8a7llr2qvga8d2v00xihsd1rkffnmicdcim.nar.zst1669 Compression: zstd1670 NarHash: sha256:0isj0fcca6l9lnaja8a7llr2qvga8d2v00xihsd1rkffnmicdcim1671 NarSize: 2561672 References: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientPushesUseOnePush2969492362/001/store/sdzfrxli1ggg8qmy0x0yijjix20h3ahn-shared-dep1673 CA: text:sha256:1arcx0byd161b5r7gzqzlddqg8l2xzpcdrgbb3fxk5qfdp8kfwfm16742026/10/25 16:39:25 INFO Vacuumed table table=pending_closures16752026/10/25 16:39:25 INFO Vacuumed table table=pending_objects16762026/10/25 16:39:26 INFO Received push request method=POST path=/api/pushes16772026/10/25 16:39:26 INFO Vacuumed table table=multipart_uploads16782026/10/25 16:39:26 INFO Vacuumed table table=closures16792026/10/25 16:39:26 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16802026/10/25 16:39:26 INFO Uploading fwdmj3qcnvgk258lg8agqbacr6fs2i4l-test-file-1.txt (160B)16812026/10/25 16:39:26 INFO Uploading fhwx1xxjhagx02cafmnqihqj4ax9a0kk-test-file-0.txt (160B)16822026/10/25 16:39:26 INFO Uploading ncharfg438scvqncf5d051fppj5qbp5j-test-file-2.txt (160B)1683--- PASS: TestClientPushesUseOnePush (9.27s)1684=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16852026/10/25 16:39:26 INFO Vacuumed table table=objects16862026/10/25 16:39:26 WARN Failed to register uploaded object key=fhwx1xxjhagx02cafmnqihqj4ax9a0kk.ls error="server returned 404: 404 page not found\n"16872026/10/25 16:39:26 WARN Failed to register uploaded object key=ncharfg438scvqncf5d051fppj5qbp5j.ls error="server returned 404: 404 page not found\n"16882026/10/25 16:39:26 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16892026/10/25 16:39:26 WARN Failed to register uploaded object key=fwdmj3qcnvgk258lg8agqbacr6fs2i4l.ls error="server returned 404: 404 page not found\n"16902026/10/25 16:39:26 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16912026/10/25 16:39:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16922026/10/25 16:39:26 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16932026/10/25 16:39:26 INFO Signed narinfos id=1 count=316942026/10/25 16:39:26 INFO Uploading 3 narinfos16952026/10/25 16:39:26 WARN Failed to register uploaded object key=ncharfg438scvqncf5d051fppj5qbp5j.narinfo error="server returned 404: 404 page not found\n"16962026/10/25 16:39:26 WARN Failed to register uploaded object key=fwdmj3qcnvgk258lg8agqbacr6fs2i4l.narinfo error="server returned 404: 404 page not found\n"16972026/10/25 16:39:26 INFO Received complete push request method=POST path=/api/pushes/1/complete16982026/10/25 16:39:26 WARN Failed to register uploaded object key=fhwx1xxjhagx02cafmnqihqj4ax9a0kk.narinfo error="server returned 404: 404 page not found\n"16992026/10/25 16:39:26 INFO Completed push id=1 objects=9 duration=30.066ms17002026/10/25 16:39:26 INFO Upload complete. (407ms)1701=== NAME TestClientMultipleUploads1702 client_integration_test.go:369: Uploaded 3 paths in 473.610958ms17032026/10/25 16:39:26 INFO Received push request method=POST path=/api/pushes1704--- PASS: TestClientMultipleUploads (9.28s)1705=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17062026/10/25 16:39:26 INFO Received uploads request method=POST path=/17072026/10/25 16:39:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17082026/10/25 16:39:26 INFO Uploading 1m4hql0yp66amszzn7x8xg2iyngfnbrl-shared-dep (136B)17092026/10/25 16:39:26 INFO Uploading sdxmxw2fbmir1gc43bl6zw0ari4nxg90-top (264B)17102026/10/25 16:39:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17112026/10/25 16:39:26 WARN Failed to register uploaded object key=nar/0pjwx2p0v7v5nxcz3dm4d2fi8lbgzfn3gw8rj2pcngygzjknjv7r.nar.zst error="server returned 404: 404 page not found\n"17122026/10/25 16:39:26 WARN Failed to register uploaded object key=1m4hql0yp66amszzn7x8xg2iyngfnbrl.ls error="server returned 404: 404 page not found\n"17132026/10/25 16:39:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17142026/10/25 16:39:26 WARN Failed to register uploaded object key=sdxmxw2fbmir1gc43bl6zw0ari4nxg90.ls error="server returned 404: 404 page not found\n"17152026/10/25 16:39:26 INFO Signed narinfos id=1 count=217162026/10/25 16:39:26 INFO Uploading 2 narinfos17172026/10/25 16:39:26 WARN Failed to register uploaded object key=sdxmxw2fbmir1gc43bl6zw0ari4nxg90.narinfo error="server returned 404: 404 page not found\n"17182026/10/25 16:39:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17192026/10/25 16:39:26 WARN Failed to register uploaded object key=1m4hql0yp66amszzn7x8xg2iyngfnbrl.narinfo error="server returned 404: 404 page not found\n"17202026/10/25 16:39:26 INFO Completed push id=1 objects=6 duration=98.552125ms17212026/10/25 16:39:26 INFO Upload complete. (449ms)1722=== NAME TestClientSharedPathCommittedMidPush1723 client_integration_test.go:680: Retrieved narinfo from S3:1724 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientSharedPathCommittedMidPush39481902/001/store/1m4hql0yp66amszzn7x8xg2iyngfnbrl-shared-dep1725 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1726 Compression: zstd1727 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821728 NarSize: 1361729 References: 1730 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1731 client_integration_test.go:680: Retrieved narinfo from S3:1732 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientSharedPathCommittedMidPush39481902/001/store/sdxmxw2fbmir1gc43bl6zw0ari4nxg90-top1733 URL: nar/0pjwx2p0v7v5nxcz3dm4d2fi8lbgzfn3gw8rj2pcngygzjknjv7r.nar.zst1734 Compression: zstd1735 NarHash: sha256:0pjwx2p0v7v5nxcz3dm4d2fi8lbgzfn3gw8rj2pcngygzjknjv7r1736 NarSize: 2641737 References: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientSharedPathCommittedMidPush39481902/001/store/1m4hql0yp66amszzn7x8xg2iyngfnbrl-shared-dep1738 CA: text:sha256:1y58d95qiai28g6nnmk7d6rgmy1kkr948344nknvs55b23a2p1dw1739=== NAME TestClientIntegration1740 client_integration_test.go:286: Created store path: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientIntegration1946675773/002/store/jr5n2rlnqj4hw6zr3cbf2xvpcgm8p97a-test-file.txt1741--- PASS: TestClientSharedPathCommittedMidPush (8.94s)1742=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17432026/10/25 16:39:26 INFO Received request for more parts method=POST path=/1744=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17452026/10/25 16:39:26 INFO Received complete multipart upload request method=POST path=/1746=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17472026/10/25 16:39:27 INFO Received uploads request method=POST path=/1748=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17492026/10/25 16:39:27 INFO Received complete multipart upload request method=POST path=/1750=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17512026/10/25 16:39:27 INFO Received request for more parts method=POST path=/1752=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17532026/10/25 16:39:27 INFO Received uploads request method=POST path=/1754--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1755 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1756 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1759=== CONT TestIsValidUploadKey/narinfo1760=== CONT TestIsValidUploadKey/realisation_plus_in_output1761=== CONT TestIsValidUploadKey/unknown_type1762=== CONT TestIsValidUploadKey/empty_key1763=== CONT TestIsValidUploadKey/absolute1764=== CONT TestIsValidUploadKey/traversal_nar1765=== CONT TestIsValidUploadKey/traversal1766=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1767=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1768=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1769=== CONT TestIsValidUploadKey/index.html1770=== CONT TestIsValidUploadKey/nix-cache-info1771=== CONT TestIsValidUploadKey/build_log_home-manager_file1772=== CONT TestIsValidUploadKey/realisation1773=== CONT TestIsValidUploadKey/build_log_equals1774=== CONT TestIsValidUploadKey/build_log_question_mark1775=== CONT TestIsValidUploadKey/build_log_plus_in_name1776=== CONT TestIsValidUploadKey/nar_plain1777=== CONT TestIsValidUploadKey/build_log1778=== CONT TestIsValidUploadKey/listing1779=== CONT TestIsValidUploadKey/nar_xz1780=== CONT TestIsValidUploadKey/nar_zst1781--- PASS: TestIsValidUploadKey (0.05s)1782 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1783 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1784 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1785 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1786 --- PASS: TestIsValidUploadKey/absolute (0.00s)1787 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1788 --- PASS: TestIsValidUploadKey/traversal (0.00s)1789 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1790 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1791 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1792 --- PASS: TestIsValidUploadKey/index.html (0.00s)1793 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1794 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1795 --- PASS: TestIsValidUploadKey/realisation (0.00s)1796 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1797 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1798 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1799 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1800 --- PASS: TestIsValidUploadKey/build_log (0.00s)1801 --- PASS: TestIsValidUploadKey/listing (0.00s)1802 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1803 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1804=== CONT TestPendingClosureWriteTimeout/empty1805=== CONT TestPendingClosureWriteTimeout/670k_objects1806=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1807--- PASS: TestUploadHandlersRejectOversizedBody (0.04s)1808 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1809 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.55s)1810 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)1811=== CONT TestPendingClosureWriteTimeout/400_objects1812=== CONT TestProxyWriteTimeout/narinfo1813=== CONT TestProxyWriteTimeout/10_GiB_nar1814=== CONT TestProxyWriteTimeout/unknown_size1815=== CONT TestProxyWriteTimeout/1_GiB_nar1816--- PASS: TestProxyWriteTimeout (0.01s)1817 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1818 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1819 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1820 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1821=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18222026/10/25 16:39:27 INFO Received push request method=POST path=/api/pushes18232026/10/25 16:39:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18242026/10/25 16:39:27 INFO Uploading jr5n2rlnqj4hw6zr3cbf2xvpcgm8p97a-test-file.txt (152B)1825=== RUN TestService_RequireScope_OIDC/builder_may_write1826=== PAUSE TestService_RequireScope_OIDC/builder_may_write1827=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1828=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1829=== RUN TestService_RequireScope_OIDC/ops_may_admin1830=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1831=== RUN TestService_RequireScope_OIDC/ops_may_not_write1832=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1833=== RUN TestService_RequireScope_OIDC/reader_may_not_write1834=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1835=== RUN TestService_RequireScope_OIDC/static_token_may_admin1836=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1837=== RUN TestService_RequireScope_OIDC/static_token_may_write1838=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1839=== RUN TestService_RequireScope_OIDC/reader_may_read1840=== PAUSE TestService_RequireScope_OIDC/reader_may_read1841=== RUN TestService_RequireScope_OIDC/writer_implies_read1842=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1843=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1844=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1845=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1846=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1847=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1848=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1849=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1850=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1851=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1852=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1853=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18542026/10/25 16:39:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18552026/10/25 16:39:27 WARN Failed to register uploaded object key=jr5n2rlnqj4hw6zr3cbf2xvpcgm8p97a.ls error="server returned 404: 404 page not found\n"18562026/10/25 16:39:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18572026/10/25 16:39:27 INFO Signed narinfos id=1 count=118582026/10/25 16:39:27 INFO Uploading 1 narinfos18592026/10/25 16:39:27 INFO Received complete push request method=POST path=/api/pushes/1/complete18602026/10/25 16:39:27 WARN Failed to register uploaded object key=jr5n2rlnqj4hw6zr3cbf2xvpcgm8p97a.narinfo error="server returned 404: 404 page not found\n"18612026/10/25 16:39:27 INFO Completed push id=1 objects=3 duration=34.154166ms18622026/10/25 16:39:27 INFO Upload complete. (394ms)1863=== NAME TestClientCADerivations1864 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientCADerivations1147961260/001/store/0n4ik3liz5r9xg94mz4rnrymb4p4pmps-ca-test18652026/10/25 16:39:27 INFO All 1 paths already cached1866=== NAME TestClientIntegration1867 client_integration_test.go:312: Retrieved narinfo from S3:1868 StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientIntegration1946675773/002/store/jr5n2rlnqj4hw6zr3cbf2xvpcgm8p97a-test-file.txt1869 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1870 Compression: zstd1871 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11872 NarSize: 1521873 References: 1874 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11875 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1876 client_integration_test.go:313: Decompressed .ls content (64 bytes):1877 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1878 client_integration_test.go:316: Testing garbage collection...18792026/10/25 16:39:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18802026/10/25 16:39:27 WARN mTLS auth: bound subjects configured but subject DN unavailable18812026/10/25 16:39:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1882--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (7.49s)1883=== CONT TestCacheConfigHandler/full_config,_no_issuer1884=== NAME TestClientCADerivations1885 client_ca_test.go:139: Found 1 dependencies (including self)1886=== CONT TestCacheConfigHandler/no_signing_keys1887=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1888=== CONT TestCacheConfigHandler/no_cache_url_configured1889--- PASS: TestCacheConfigHandler (0.05s)1890 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1891 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1892 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1893 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1894=== CONT TestClientErrorHandling/InvalidStorePath18952026/10/25 16:39:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures18962026/10/25 16:39:27 INFO Garbage collection started18972026/10/25 16:39:27 INFO Aborted multipart uploads count=0 kept=018982026/10/25 16:39:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018992026/10/25 16:39:27 INFO Received create pin request method=POST path=/api/pins/myapp19002026/10/25 16:39:27 WARN Force mode enabled - objects will be deleted immediately without grace period19012026/10/25 16:39:27 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/021d280b068cf186/build/TestPinProtectsFromGC4140705267/001/store/0nj0j1q44civsqgx2m599zi8g5xwchv4-pinned-file.txt narinfo_key=0nj0j1q44civsqgx2m599zi8g5xwchv4.narinfo19022026/10/25 16:39:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures19032026/10/25 16:39:27 INFO Garbage collection started19042026/10/25 16:39:27 INFO Aborted multipart uploads count=0 kept=019052026/10/25 16:39:27 WARN Force mode enabled - objects will be deleted immediately without grace period19062026/10/25 16:39:27 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=019072026/10/25 16:39:27 INFO Vacuumed table table=pending_closures19082026/10/25 16:39:27 INFO Vacuumed table table=pending_objects19092026/10/25 16:39:27 INFO Vacuumed table table=multipart_uploads19102026/10/25 16:39:27 INFO Vacuumed table table=closures19112026/10/25 16:39:27 INFO Vacuumed table table=objects19122026/10/25 16:39:27 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=019132026/10/25 16:39:27 INFO Vacuumed table table=pending_closures19142026/10/25 16:39:27 INFO Vacuumed table table=pending_objects19152026/10/25 16:39:27 INFO Vacuumed table table=multipart_uploads19162026/10/25 16:39:27 INFO Received push request method=POST path=/api/pushes1917=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1918=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1919=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1920=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1921=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1922=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected19232026/10/25 16:39:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1924=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19252026/10/25 16:39:28 INFO Uploading 0n4ik3liz5r9xg94mz4rnrymb4p4pmps-ca-test (144B)1926=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19272026/10/25 16:39:28 INFO Vacuumed table table=closures1928=== CONT TestClientErrorHandling/InvalidAuthToken19292026/10/25 16:39:28 WARN Failed to register uploaded object key=0n4ik3liz5r9xg94mz4rnrymb4p4pmps.ls error="server returned 404: 404 page not found\n"19302026/10/25 16:39:28 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19312026/10/25 16:39:28 WARN Failed to register uploaded object key=log/4dniq5cicprkx36pkk3n0m0c88z00rqm-ca-test.drv error="server returned 404: 404 page not found\n"19322026/10/25 16:39:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19332026/10/25 16:39:28 INFO Signed narinfos id=1 count=119342026/10/25 16:39:28 INFO Uploading 1 narinfos19352026/10/25 16:39:28 INFO Received complete push request method=POST path=/api/pushes/1/complete19362026/10/25 16:39:28 WARN Failed to register uploaded object key=0n4ik3liz5r9xg94mz4rnrymb4p4pmps.narinfo error="server returned 404: 404 page not found\n"19372026/10/25 16:39:28 INFO Vacuumed table table=objects19382026/10/25 16:39:28 INFO Completed push id=1 objects=4 duration=47.880875ms19392026/10/25 16:39:28 INFO Upload complete. (569ms)1940=== NAME TestClientCADerivations1941 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientCADerivations1147961260/001/store/0n4ik3liz5r9xg94mz4rnrymb4p4pmps-ca-test1942 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1943 Compression: zstd1944 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1945 NarSize: 1441946 References: 1947 Deriver: /private/var/tb/8/scratch/021d280b068cf186/build/TestClientCADerivations1147961260/001/store/4dniq5cicprkx36pkk3n0m0c88z00rqm-ca-test.drv1948 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1949 client_ca_test.go:185: Checking for realisation files in S3...1950 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1951 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1952--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (8.08s)1953=== CONT TestClientErrorHandling/ServerNotAvailable1954=== NAME TestClientCADerivations1955 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket76?endpoint=http://localhost:49477®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/021d280b068cf186/build/TestClientCADerivations1147961260/001/store'1956 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11957--- PASS: TestClientCADerivations (9.46s)1958=== CONT TestService_RequireScope_OIDC/builder_may_write1959=== CONT TestService_RequireScope_OIDC/reader_may_read1960=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1961=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19622026/10/25 16:39:28 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]1963=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1964=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1965=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1966=== CONT TestService_RequireScope_OIDC/writer_implies_read1967=== CONT TestService_RequireScope_OIDC/reader_may_not_write1968=== CONT TestService_RequireScope_OIDC/static_token_may_write1969=== CONT TestService_RequireScope_OIDC/static_token_may_admin1970=== CONT TestService_RequireScope_OIDC/ops_may_admin1971=== CONT TestService_RequireScope_OIDC/ops_may_not_write1972=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1973=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1974=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19752026/10/25 16:39:28 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]1976=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19772026/10/25 16:39:28 WARN Authentication failed token_preview=eyJhbGciOi...4BQaIXZ0zg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1978=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1979--- PASS: TestService_RequireScope_OIDC (7.60s)1980 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1981 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1982 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1983 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1984 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1985 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1986 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1987 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1988 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1989 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1990 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1991 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1992 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1993 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1994--- PASS: TestService_AuthMiddleware_OIDC (7.67s)1995 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1996 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1997 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1998 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1999--- PASS: TestService_ReadAuthMiddleware (7.64s)20002026/10/25 16:39:28 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/present20012026/10/25 16:39:28 WARN Request failed, retrying attempt=2 backoff=195.853503ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20022026/10/25 16:39:29 INFO Received uploads request method=POST path=/api/pending_closures20032026/10/25 16:39:29 WARN Request failed, retrying attempt=3 backoff=436.523091ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20042026/10/25 16:39:29 WARN readiness check failed error="closed pool"2005--- PASS: TestService_readinessHandler (7.48s)20062026/10/25 16:39:29 WARN Request failed, retrying attempt=4 backoff=739.277705ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20072026/10/25 16:39:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02008=== NAME TestClientIntegration2009 client_integration_test.go:323: Objects in database after GC:2010 client_integration_test.go:323: Successfully deleted all objects with GC --force2011=== NAME TestPinProtectsFromGC2012 client_integration_test.go:840: Pin successfully protected closure from garbage collection2013--- PASS: TestClientIntegration (11.70s)20142026/10/25 16:39:29 INFO Received push request method=POST path=/api/pushes2015--- PASS: TestPinProtectsFromGC (13.13s)20162026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20172026/10/25 16:39:30 INFO Signed narinfos id=1 count=120182026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20192026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20202026/10/25 16:39:30 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"20212026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20222026/10/25 16:39:30 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"20232026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20242026/10/25 16:39:30 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=120252026/10/25 16:39:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20262026/10/25 16:39:30 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo2027--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.94s)20282026/10/25 16:39:30 INFO Received uploads request method=POST path=/api/pending_closures20292026/10/25 16:39:30 WARN Request failed, retrying attempt=5 backoff=1.526613452s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2030--- PASS: TestService_Rustfstest (8.09s)20312026/10/25 16:39:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20322026/10/25 16:39:30 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2Ljc1ZDU4NDJhLWJiMTMtNDczMi1hZjJiLTRhYTgxNjI2MWYwZHgxNzkyOTQ2MzcwMjUyNjM4MDAw20332026/10/25 16:39:30 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2Ljc1ZDU4NDJhLWJiMTMtNDczMi1hZjJiLTRhYTgxNjI2MWYwZHgxNzkyOTQ2MzcwMjUyNjM4MDAw parts=12034--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.17s)20352026/10/25 16:39:30 INFO Received uploads request method=POST path=/api/pending_closures20362026/10/25 16:39:30 INFO Received uploads request method=POST path=/api/pending_closures20372026/10/25 16:39:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20382026/10/25 16:39:31 INFO Received uploads request method=POST path=/api/pending_closures20392026/10/25 16:39:31 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LjVkOTEwZGI2LWNiYTYtNDQ1NC04OGMzLWE3NDg5YzJlZDM1MHgxNzkyOTQ2MzY5MTQzMjM3MDAw parts=1220402026/10/25 16:39:31 INFO Received uploads request method=POST path=/api/pending_closures2041--- PASS: TestCompletedNarNotReofferedAcrossClosures (10.07s)20422026/10/25 16:39:31 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20432026/10/25 16:39:31 INFO Received uploads request method=POST path=/api/pending_closures2044--- PASS: TestPresignedUploadRegisteredBeforeCommit (8.13s)2045=== RUN TestPush_RejectsBadRequests/no_roots2046=== PAUSE TestPush_RejectsBadRequests/no_roots2047=== RUN TestPush_RejectsBadRequests/no_objects2048=== PAUSE TestPush_RejectsBadRequests/no_objects2049=== RUN TestPush_RejectsBadRequests/bad_root2050=== PAUSE TestPush_RejectsBadRequests/bad_root2051=== RUN TestPush_RejectsBadRequests/root_not_in_objects2052=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2053=== CONT TestPush_RejectsBadRequests/no_roots2054=== CONT TestPush_RejectsBadRequests/bad_root20552026/10/25 16:39:31 INFO Received push request method=POST path=/api/pushes2056=== CONT TestPush_RejectsBadRequests/no_objects20572026/10/25 16:39:31 INFO Received push request method=POST path=/api/pushes2058=== CONT TestPush_RejectsBadRequests/root_not_in_objects20592026/10/25 16:39:31 INFO Received push request method=POST path=/api/pushes20602026/10/25 16:39:31 INFO Received push request method=POST path=/api/pushes2061--- PASS: TestPush_RejectsBadRequests (8.30s)2062 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2063 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2064 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)2065 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)20662026/10/25 16:39:31 INFO Received push request method=POST path=/api/pushes20672026/10/25 16:39:31 INFO Received complete push request method=POST path=/api/pushes/1/complete20682026/10/25 16:39:31 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-config20692026/10/25 16:39:31 INFO Completed push id=1 objects=4 duration=17.983708ms20702026/10/25 16:39:32 INFO Received push request method=POST path=/api/pushes20712026/10/25 16:39:32 WARN Request failed, retrying attempt=2 backoff=215.496332ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20722026/10/25 16:39:32 INFO Aborted multipart uploads count=0 kept=020732026/10/25 16:39:32 WARN Force mode enabled - objects will be deleted immediately without grace period20742026/10/25 16:39:32 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=020752026/10/25 16:39:32 INFO Vacuumed table table=pending_closures20762026/10/25 16:39:32 INFO Vacuumed table table=pending_objects20772026/10/25 16:39:32 INFO Vacuumed table table=multipart_uploads20782026/10/25 16:39:32 INFO Vacuumed table table=closures20792026/10/25 16:39:32 INFO Vacuumed table table=objects20802026/10/25 16:39:32 INFO Received complete push request method=POST path=/api/pushes/2/complete20812026/10/25 16:39:32 INFO Completed push id=2 objects=4 duration=5.123959ms2082--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (8.67s)20832026/10/25 16:39:32 WARN Request failed, retrying attempt=3 backoff=392.46698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20842026/10/25 16:39:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20852026/10/25 16:39:32 WARN Request failed, retrying attempt=4 backoff=725.150072ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20862026/10/25 16:39:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LjcyYTExOTAzLTAzYTktNGZhMC1hOTM5LTg4NTc0Mzk2YzE3NngxNzkyOTQ2MzcwOTMxMDI3MDAw parts=1220872026/10/25 16:39:32 INFO Received uploads request method=POST path=/api/pending_closures20882026/10/25 16:39:32 INFO Received uploads request method=POST path=/api/pending_closures2089--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2090 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (8.79s)2091 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (8.51s)20922026/10/25 16:39:32 INFO Aborted multipart uploads count=0 kept=020932026/10/25 16:39:32 WARN Force mode enabled - objects will be deleted immediately without grace period20942026/10/25 16:39:33 INFO Aborted multipart uploads count=0 kept=020952026/10/25 16:39:33 WARN Force mode enabled - objects will be deleted immediately without grace period20962026/10/25 16:39:33 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:49477/bucket95/?delete=\": context canceled"2097--- PASS: TestGCEndsOnShutdown (0.00s)2098 --- PASS: TestGCEndsOnShutdown/before_the_run (7.39s)2099 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.06s)2100 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.11s)21012026/10/25 16:39:33 INFO Received uploads request method=POST path=/api/pending_closures21022026/10/25 16:39:33 INFO Aborted multipart uploads count=0 kept=021032026/10/25 16:39:33 WARN Force mode enabled - objects will be deleted immediately without grace period21042026/10/25 16:39:33 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=021052026/10/25 16:39:33 INFO Vacuumed table table=pending_closures21062026/10/25 16:39:33 INFO Vacuumed table table=pending_objects21072026/10/25 16:39:33 INFO Vacuumed table table=multipart_uploads21082026/10/25 16:39:33 INFO Vacuumed table table=closures21092026/10/25 16:39:33 WARN Request failed, retrying attempt=5 backoff=1.443947674s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21102026/10/25 16:39:33 INFO Vacuumed table table=objects21112026/10/25 16:39:33 INFO Received uploads request method=POST path=/api/pending_closures21122026/10/25 16:39:33 INFO Received uploads request method=POST path=/api/pending_closures21132026/10/25 16:39:33 INFO Aborted multipart uploads count=0 kept=021142026/10/25 16:39:33 WARN Force mode enabled - objects will be deleted immediately without grace period21152026/10/25 16:39:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021162026/10/25 16:39:33 INFO Vacuumed table table=pending_closures21172026/10/25 16:39:33 INFO Vacuumed table table=pending_objects21182026/10/25 16:39:34 INFO Vacuumed table table=multipart_uploads21192026/10/25 16:39:34 INFO Vacuumed table table=closures21202026/10/25 16:39:34 INFO Vacuumed table table=objects2121--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2122 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.57s)2123 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.84s)21242026/10/25 16:39:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21252026/10/25 16:39:34 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LjUyODgwOGM4LTM2OTgtNGZkNy1hMjE3LWQyMzVhMGZhMWZiY3gxNzkyOTQ2MzcyNzg5MzY2MDAw error="Get \"http://127.0.0.1:1/bucket87/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21262026/10/25 16:39:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzBlNDU0MjgtYzljMC00OGZhLWE2N2YtYjg3NzY1YzNlNjI2LjdlNmE3ZDMyLTQzNDYtNDdjNy1hZmE2LTNmOWM5ZWJlYjgxZngxNzkyOTQ2MzcyNzQ5MDIxMDAw parts=1221272026/10/25 16:39:34 INFO Received cleanup request method=DELETE path=/api/pending_closures2128--- PASS: TestPendingClosureWriteTimeout (0.00s)2129 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2130 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2131 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2132 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (7.42s)21332026/10/25 16:39:34 INFO Aborted multipart uploads count=1 kept=02134--- PASS: TestRedundantMultipartUpload (11.51s)21352026/10/25 16:39:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21362026/10/25 16:39:34 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21372026/10/25 16:39:34 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"21382026/10/25 16:39:34 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-config21392026/10/25 16:39:34 WARN Request failed, retrying attempt=2 backoff=218.650013ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21402026/10/25 16:39:35 WARN Request failed, retrying attempt=3 backoff=378.430656ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/25 16:39:35 WARN Request failed, retrying attempt=4 backoff=871.101897ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21422026/10/25 16:39:36 WARN Request failed, retrying attempt=5 backoff=1.483407326s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21432026/10/25 16:39:37 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_closures21442026/10/25 16:39:38 WARN Request failed, retrying attempt=2 backoff=210.502773ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21452026/10/25 16:39:38 WARN Request failed, retrying attempt=3 backoff=400.277862ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21462026/10/25 16:39:38 WARN Request failed, retrying attempt=4 backoff=805.920162ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21472026/10/25 16:39:39 WARN Request failed, retrying attempt=5 backoff=1.636425019s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2148--- PASS: TestClientErrorHandling (0.00s)2149 --- PASS: TestClientErrorHandling/InvalidStorePath (6.62s)2150 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.54s)2151 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.66s)2152PASS2153{"timestamp":"2026-10-25T16:39:41.135898Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49689","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}21542026-10-25 16:39:41.282 UTC [45534] LOG: received smart shutdown request21552026-10-25 16:39:41.282 UTC [45534] LOG: background worker "logical replication launcher" (PID 45545) exited with exit code 121562026-10-25 16:39:41.315 UTC [45540] LOG: shutting down21572026-10-25 16:39:41.315 UTC [45540] LOG: checkpoint starting: shutdown immediate21582026-10-25 16:39:42.673 UTC [45540] LOG: checkpoint complete: wrote 12112 buffers (73.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=0.617 s, sync=0.681 s, total=1.359 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=502002 kB, estimate=502002 kB; lsn=0/201C9898, redo lsn=0/201C989821592026-10-25 16:39:42.680 UTC [45534] LOG: database system is shut down2160Running OIDC tests...2161=== RUN TestAudienceForIssuer2162=== PAUSE TestAudienceForIssuer2163=== RUN TestGlobMatch2164=== PAUSE TestGlobMatch2165=== RUN TestValidateToken_ValidToken2166=== PAUSE TestValidateToken_ValidToken2167=== RUN TestValidateToken_WrongAudience2168=== PAUSE TestValidateToken_WrongAudience2169=== RUN TestValidateToken_Expired2170=== PAUSE TestValidateToken_Expired2171=== RUN TestValidateToken_BoundClaimsMismatch2172=== PAUSE TestValidateToken_BoundClaimsMismatch2173=== RUN TestValidateToken_BoundSubjectMismatch2174=== PAUSE TestValidateToken_BoundSubjectMismatch2175=== RUN TestValidateToken_MultipleProviders2176=== PAUSE TestValidateToken_MultipleProviders2177=== RUN TestValidateToken_NoMatchingProvider2178=== PAUSE TestValidateToken_NoMatchingProvider2179=== RUN TestValidateToken_KubernetesServiceAccount2180=== PAUSE TestValidateToken_KubernetesServiceAccount2181=== RUN TestNewValidator_KubernetesRequiresCA2182=== PAUSE TestNewValidator_KubernetesRequiresCA2183=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2184=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2185=== RUN TestPins_ReservedForMatchingRule2186=== PAUSE TestPins_ReservedForMatchingRule2187=== RUN TestPins_TopLevelShorthand2188=== PAUSE TestPins_TopLevelShorthand2189=== RUN TestPins_ConfigValidation2190=== PAUSE TestPins_ConfigValidation2191=== RUN TestScopes_LegacyProviderDefaultsToWrite2192=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2193=== RUN TestScopes_Rules2194=== PAUSE TestScopes_Rules2195=== RUN TestScopes_ConfigValidation2196=== PAUSE TestScopes_ConfigValidation2197=== CONT TestAudienceForIssuer2198--- PASS: TestAudienceForIssuer (0.00s)2199=== CONT TestValidateToken_NoMatchingProvider2200=== CONT TestPins_ReservedForMatchingRule2201=== CONT TestPins_ConfigValidation2202=== CONT TestScopes_Rules2203=== CONT TestValidateToken_KubernetesServiceAccount2204=== CONT TestScopes_LegacyProviderDefaultsToWrite2205=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2206--- PASS: TestPins_ConfigValidation (0.00s)2207=== CONT TestValidateToken_Expired2208=== CONT TestNewValidator_KubernetesRequiresCA2209=== CONT TestValidateToken_BoundSubjectMismatch2210=== CONT TestValidateToken_MultipleProviders2211=== CONT TestValidateToken_BoundClaimsMismatch2212=== CONT TestPins_TopLevelShorthand2213=== CONT TestValidateToken_ValidToken2214=== CONT TestScopes_ConfigValidation2215--- PASS: TestScopes_ConfigValidation (0.00s)2216=== CONT TestGlobMatch2217=== RUN TestGlobMatch/foo_foo2218=== PAUSE TestGlobMatch/foo_foo2219=== RUN TestGlobMatch/foo_bar2220=== PAUSE TestGlobMatch/foo_bar2221=== RUN TestGlobMatch/*_2222=== PAUSE TestGlobMatch/*_2223=== RUN TestGlobMatch/*_anything2224=== PAUSE TestGlobMatch/*_anything2225=== RUN TestGlobMatch/foo*_foo2226=== PAUSE TestGlobMatch/foo*_foo2227=== RUN TestGlobMatch/foo*_foobar2228=== PAUSE TestGlobMatch/foo*_foobar2229=== RUN TestGlobMatch/foo*_bar2230=== PAUSE TestGlobMatch/foo*_bar2231=== RUN TestGlobMatch/*bar_bar2232=== PAUSE TestGlobMatch/*bar_bar2233=== RUN TestGlobMatch/*bar_foobar2234=== PAUSE TestGlobMatch/*bar_foobar2235=== RUN TestGlobMatch/*bar_foo2236=== PAUSE TestGlobMatch/*bar_foo2237=== RUN TestGlobMatch/foo*bar_foobar2238=== PAUSE TestGlobMatch/foo*bar_foobar2239=== RUN TestGlobMatch/foo*bar_foo123bar2240=== PAUSE TestGlobMatch/foo*bar_foo123bar2241=== RUN TestGlobMatch/foo*bar_foobarbaz2242=== PAUSE TestGlobMatch/foo*bar_foobarbaz2243=== RUN TestGlobMatch/*/*_foo/bar2244=== PAUSE TestGlobMatch/*/*_foo/bar2245=== RUN TestGlobMatch/*/*_foo2246=== PAUSE TestGlobMatch/*/*_foo2247=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2248=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2249=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02250=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02251=== RUN TestGlobMatch/refs/*/main_refs/heads/main2252=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2253=== RUN TestGlobMatch/fo?_foo2254=== PAUSE TestGlobMatch/fo?_foo2255=== RUN TestGlobMatch/fo?_fo2256=== PAUSE TestGlobMatch/fo?_fo2257=== RUN TestGlobMatch/fo?_fooo2258=== PAUSE TestGlobMatch/fo?_fooo2259=== RUN TestGlobMatch/?oo_foo2260=== PAUSE TestGlobMatch/?oo_foo2261=== RUN TestGlobMatch/?oo_boo2262=== PAUSE TestGlobMatch/?oo_boo2263=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2264=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2265=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2266=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2267=== CONT TestGlobMatch/foo_foo2268=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2269=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2270=== CONT TestGlobMatch/?oo_boo2271=== CONT TestGlobMatch/?oo_foo2272=== CONT TestGlobMatch/fo?_fooo2273=== CONT TestGlobMatch/fo?_fo2274=== CONT TestGlobMatch/fo?_foo2275=== CONT TestGlobMatch/refs/*/main_refs/heads/main2276=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02277=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2278=== CONT TestGlobMatch/*/*_foo2279=== CONT TestGlobMatch/*/*_foo/bar2280=== CONT TestGlobMatch/foo*bar_foobarbaz2281=== CONT TestGlobMatch/foo*bar_foo123bar2282=== CONT TestGlobMatch/foo*bar_foobar2283=== CONT TestGlobMatch/*bar_foo2284=== CONT TestGlobMatch/*bar_foobar2285=== CONT TestGlobMatch/*bar_bar2286=== CONT TestGlobMatch/foo*_bar2287=== CONT TestGlobMatch/foo*_foobar2288=== CONT TestGlobMatch/foo*_foo2289=== CONT TestGlobMatch/*_anything2290=== CONT TestGlobMatch/*_2291=== CONT TestGlobMatch/foo_bar2292--- PASS: TestGlobMatch (0.00s)2293 --- PASS: TestGlobMatch/foo_foo (0.00s)2294 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2295 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2296 --- PASS: TestGlobMatch/?oo_boo (0.00s)2297 --- PASS: TestGlobMatch/?oo_foo (0.00s)2298 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2299 --- PASS: TestGlobMatch/fo?_fo (0.00s)2300 --- PASS: TestGlobMatch/fo?_foo (0.00s)2301 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2302 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2303 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2304 --- PASS: TestGlobMatch/*/*_foo (0.00s)2305 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2306 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2307 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2308 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2309 --- PASS: TestGlobMatch/*bar_foo (0.00s)2310 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2311 --- PASS: TestGlobMatch/*bar_bar (0.00s)2312 --- PASS: TestGlobMatch/foo*_bar (0.00s)2313 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2314 --- PASS: TestGlobMatch/foo*_foo (0.00s)2315 --- PASS: TestGlobMatch/*_anything (0.00s)2316 --- PASS: TestGlobMatch/*_ (0.00s)2317 --- PASS: TestGlobMatch/foo_bar (0.00s)2318=== CONT TestValidateToken_WrongAudience23192026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49968/oidc23202026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49970/oidc23212026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49972/oidc2322--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)2323--- PASS: TestValidateToken_BoundClaimsMismatch (0.07s)2324--- PASS: TestPins_ReservedForMatchingRule (0.08s)23252026/10/25 16:39:44 http: TLS handshake error from 127.0.0.1:49975: remote error: tls: bad certificate2326--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)23272026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49976/oidc23282026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49980/oidc23292026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49979/oidc2330--- PASS: TestScopes_Rules (0.12s)2331--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)2332--- PASS: TestValidateToken_ValidToken (0.11s)23332026/10/25 16:39:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323342026/10/25 16:39:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49977/oidc23352026/10/25 16:39:44 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:49985/oidc2336--- PASS: TestValidateToken_MultipleProviders (0.15s)23372026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49989/oidc2338--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)2339--- PASS: TestPins_TopLevelShorthand (0.15s)23402026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49991/oidc2341--- PASS: TestValidateToken_Expired (0.17s)23422026/10/25 16:39:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:49993/oidc2343--- PASS: TestValidateToken_WrongAudience (0.16s)23442026/10/25 16:39:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:49983/oidc2345--- PASS: TestValidateToken_NoMatchingProvider (0.18s)23462026/10/25 16:39:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:499972347--- PASS: TestValidateToken_KubernetesServiceAccount (0.20s)2348PASS2349Running hook tests...2350=== RUN TestSendPathsEmpty2351=== PAUSE TestSendPathsEmpty2352=== RUN TestQueueEnqueueAndFetch2353=== PAUSE TestQueueEnqueueAndFetch2354=== RUN TestQueueDeduplication2355=== PAUSE TestQueueDeduplication2356=== RUN TestQueueRemove2357=== PAUSE TestQueueRemove2358=== RUN TestQueueFetchBatchLimit2359=== PAUSE TestQueueFetchBatchLimit2360=== RUN TestQueueRetryMovesToBack2361=== PAUSE TestQueueRetryMovesToBack2362=== RUN TestQueueFetchRemoveLifecycle2363=== PAUSE TestQueueFetchRemoveLifecycle2364=== RUN TestQueueConcurrentWriters2365=== PAUSE TestQueueConcurrentWriters2366=== RUN TestQueueRemoveLargeClosure2367=== PAUSE TestQueueRemoveLargeClosure2368=== RUN TestServerClientIntegration2369--- PASS: TestServerClientIntegration (0.00s)2370=== RUN TestServerQueueError23712026/10/25 16:39:44 ERROR Failed to queue paths error="permission denied" count=12372--- PASS: TestServerQueueError (0.00s)2373=== RUN TestGetListenerSocketActivation2374 server_test.go:146: systemd socket activation does not exist on darwin2375--- SKIP: TestGetListenerSocketActivation (0.00s)2376=== RUN TestDrainIsolatesPoisonPath2377=== PAUSE TestDrainIsolatesPoisonPath2378=== RUN TestRunNotBlockedByPoisonHead2379=== PAUSE TestRunNotBlockedByPoisonHead2380=== RUN TestDrainGivesUpWhenServerDown2381=== PAUSE TestDrainGivesUpWhenServerDown2382=== RUN TestFailedPathPrunedByLaterClosure2383=== PAUSE TestFailedPathPrunedByLaterClosure2384=== RUN TestWorkerUploadsAndRemoves2385=== PAUSE TestWorkerUploadsAndRemoves2386=== RUN TestWorkerSkipsGCdPaths2387=== PAUSE TestWorkerSkipsGCdPaths2388=== RUN TestWorkerPrunesClosureDeps2389=== PAUSE TestWorkerPrunesClosureDeps2390=== RUN TestDrainTimeout2391=== PAUSE TestDrainTimeout2392=== RUN TestWorkerRemoveFailureIsNotProgress2393=== PAUSE TestWorkerRemoveFailureIsNotProgress2394=== RUN TestWorkerKeepsPathItCannotStat2395=== PAUSE TestWorkerKeepsPathItCannotStat2396=== CONT TestSendPathsEmpty2397=== CONT TestRunNotBlockedByPoisonHead2398--- PASS: TestSendPathsEmpty (0.00s)2399=== CONT TestDrainIsolatesPoisonPath2400=== CONT TestQueueRemoveLargeClosure2401=== CONT TestQueueConcurrentWriters2402=== CONT TestQueueFetchRemoveLifecycle2403=== CONT TestQueueRetryMovesToBack2404=== CONT TestQueueFetchBatchLimit2405=== CONT TestQueueRemove2406=== CONT TestQueueDeduplication2407=== CONT TestQueueEnqueueAndFetch2408=== CONT TestWorkerPrunesClosureDeps2409=== CONT TestWorkerKeepsPathItCannotStat2410=== CONT TestWorkerRemoveFailureIsNotProgress2411=== CONT TestDrainTimeout2412=== CONT TestWorkerUploadsAndRemoves2413=== CONT TestWorkerSkipsGCdPaths2414=== CONT TestFailedPathPrunedByLaterClosure2415=== CONT TestDrainGivesUpWhenServerDown24162026/10/25 16:39:44 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa error="stat /private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa: permission denied"24172026/10/25 16:39:44 INFO Uploading batch count=424182026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=42419--- PASS: TestQueueRemove (0.01s)24202026/10/25 16:39:44 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa error="stat /private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa: permission denied"24212026/10/25 16:39:44 INFO Uploading batch count=124222026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=124232026/10/25 16:39:44 INFO Uploading batch count=224242026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=224252026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/a24262026/10/25 16:39:44 INFO Upload queue status pending=324272026/10/25 16:39:44 INFO Uploading batch count=124282026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=124292026/10/25 16:39:44 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa error="stat /private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerKeepsPathItCannotStat2075786483/002/locked/aaa: permission denied"24302026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/b2431--- PASS: TestQueueFetchBatchLimit (0.01s)24322026/10/25 16:39:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerRemoveFailureIsNotProgress1531313706/002/nonexistent24332026/10/25 16:39:44 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124342026/10/25 16:39:44 INFO Uploading batch count=124352026/10/25 16:39:44 INFO Uploading batch count=224362026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=224372026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/c24382026/10/25 16:39:44 INFO Uploading batch count=12439--- PASS: TestQueueEnqueueAndFetch (0.01s)24402026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainIsolatesPoisonPath3949346456/002/bbb24412026/10/25 16:39:44 INFO Uploading batch count=224422026/10/25 16:39:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerRemoveFailureIsNotProgress1531313706/002/nonexistent24432026/10/25 16:39:44 INFO Upload queue status pending=224442026/10/25 16:39:44 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124452026/10/25 16:39:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerRemoveFailureIsNotProgress1531313706/002/nonexistent24462026/10/25 16:39:44 INFO Uploading batch count=124472026/10/25 16:39:44 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124482026/10/25 16:39:44 ERROR Drain finished with paths left in queue remaining=12449--- PASS: TestQueueDeduplication (0.01s)24502026/10/25 16:39:44 INFO Upload queue status pending=22451--- PASS: TestQueueFetchRemoveLifecycle (0.01s)24522026/10/25 16:39:44 INFO Uploading batch count=224532026/10/25 16:39:44 INFO Upload queue status pending=224542026/10/25 16:39:44 ERROR Drain finished with paths left in queue remaining=124552026/10/25 16:39:44 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/021d280b068cf186/build/TestWorkerSkipsGCdPaths907855303/002/nonexistent24562026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/d2457--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24582026/10/25 16:39:44 INFO Uploading batch count=124592026/10/25 16:39:44 INFO Uploading batch count=224602026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=224612026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/e2462--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)24632026/10/25 16:39:44 INFO Uploading batch count=12464--- PASS: TestQueueRetryMovesToBack (0.01s)24652026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=124662026/10/25 16:39:44 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/021d280b068cf186/build/TestDrainGivesUpWhenServerDown2259417779/002/f24672026/10/25 16:39:44 ERROR Drain finished with paths left in queue remaining=102468--- PASS: TestWorkerKeepsPathItCannotStat (0.01s)24692026/10/25 16:39:44 INFO Uploading batch count=124702026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=124712026/10/25 16:39:44 INFO Uploading batch count=124722026/10/25 16:39:44 ERROR Upload failed error="upload failed" count=124732026/10/25 16:39:44 ERROR Drain finished with paths left in queue remaining=12474--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2475--- PASS: TestDrainIsolatesPoisonPath (0.01s)2476--- PASS: TestWorkerPrunesClosureDeps (0.03s)2477--- PASS: TestWorkerUploadsAndRemoves (0.03s)2478--- PASS: TestWorkerSkipsGCdPaths (0.03s)2479--- PASS: TestQueueRemoveLargeClosure (0.04s)2480--- PASS: TestQueueConcurrentWriters (0.13s)24812026/10/25 16:39:45 ERROR Upload failed error="context deadline exceeded" count=224822026/10/25 16:39:45 ERROR Drain finished with paths left in queue remaining=42483--- PASS: TestDrainTimeout (0.21s)24842026/10/25 16:39:45 INFO Uploading batch count=124852026/10/25 16:39:45 INFO Uploading batch count=124862026/10/25 16:39:45 INFO Uploading batch count=124872026/10/25 16:39:45 ERROR Upload failed error="upload failed" count=124882026/10/25 16:39:45 INFO Uploading batch count=124892026/10/25 16:39:45 ERROR Upload failed error="upload failed" count=124902026/10/25 16:39:45 INFO Uploading batch count=124912026/10/25 16:39:45 ERROR Upload failed error="upload failed" count=124922026/10/25 16:39:45 INFO Uploading batch count=124932026/10/25 16:39:45 ERROR Upload failed error="upload failed" count=124942026/10/25 16:39:45 ERROR Drain finished with paths left in queue remaining=12495--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2496PASS2497Running signing tests...2498=== RUN TestExternalSigner2499=== PAUSE TestExternalSigner2500=== RUN TestExternalSignerWrongPublicKey2501=== PAUSE TestExternalSignerWrongPublicKey2502=== RUN TestExternalSignerErrors2503=== PAUSE TestExternalSignerErrors2504=== RUN TestExternalSignerRestartsAfterCrash2505=== PAUSE TestExternalSignerRestartsAfterCrash2506=== RUN TestExternalSignerProgramErrorKeepsProcess2507=== PAUSE TestExternalSignerProgramErrorKeepsProcess2508=== RUN TestExternalSignerClose2509=== PAUSE TestExternalSignerClose2510=== RUN TestExternalSignerRejectsInvalidPublicKey2511=== PAUSE TestExternalSignerRejectsInvalidPublicKey2512=== RUN TestExternalSignerCancellation2513=== PAUSE TestExternalSignerCancellation2514=== RUN TestGenerateFingerprint2515=== PAUSE TestGenerateFingerprint2516=== RUN TestParseSigningKey2517=== PAUSE TestParseSigningKey2518=== RUN TestSign2519=== PAUSE TestSign2520=== RUN TestSignBatch2521=== PAUSE TestSignBatch2522=== RUN TestNilKeyPublicKey2523=== PAUSE TestNilKeyPublicKey2524=== RUN TestSignErrors2525=== PAUSE TestSignErrors2526=== CONT TestExternalSigner2527=== CONT TestExternalSignerCancellation2528=== CONT TestExternalSignerErrors2529=== RUN TestExternalSignerErrors/wrong_id2530=== CONT TestExternalSignerProgramErrorKeepsProcess2531=== CONT TestExternalSignerRejectsInvalidPublicKey2532=== RUN TestExternalSignerRejectsInvalidPublicKey/#002533=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002534=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2535=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2536=== CONT TestExternalSignerClose2537=== CONT TestExternalSignerWrongPublicKey2538=== CONT TestSignBatch2539=== CONT TestSignErrors2540=== CONT TestNilKeyPublicKey2541--- PASS: TestNilKeyPublicKey (0.00s)2542=== CONT TestParseSigningKey2543=== CONT TestSign2544=== CONT TestExternalSignerRestartsAfterCrash2545=== CONT TestGenerateFingerprint2546=== PAUSE TestExternalSignerErrors/wrong_id2547=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2548=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2549=== RUN TestExternalSignerErrors/unrequested_key2550=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2551=== PAUSE TestExternalSignerErrors/unrequested_key2552=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2553=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2554=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2555=== CONT TestExternalSignerRejectsInvalidPublicKey/#002556=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2557=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2558=== RUN TestExternalSignerErrors/program_error2559=== PAUSE TestExternalSignerErrors/program_error2560=== RUN TestExternalSignerErrors/exit_at_startup2561=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2562=== RUN TestGenerateFingerprint/basic_with_references2563=== PAUSE TestGenerateFingerprint/basic_with_references2564=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2565=== RUN TestParseSigningKey/valid_32-byte_key2566--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2567 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2568 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2569 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2570 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2571 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2572=== PAUSE TestExternalSignerErrors/exit_at_startup2573=== PAUSE TestParseSigningKey/valid_32-byte_key2574=== RUN TestExternalSignerErrors/missing_signatures2575=== PAUSE TestExternalSignerErrors/missing_signatures2576=== RUN TestExternalSignerErrors/wrong_signature_name2577=== PAUSE TestExternalSignerErrors/wrong_signature_name2578=== RUN TestGenerateFingerprint/no_references2579=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2580=== PAUSE TestGenerateFingerprint/no_references2581=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2582=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2583=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2584=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2585=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2586=== RUN TestGenerateFingerprint/invalid_nar_hash_length2587=== RUN TestParseSigningKey/no_colon2588=== PAUSE TestParseSigningKey/no_colon2589=== RUN TestExternalSignerErrors/invalid_signature_base642590=== PAUSE TestExternalSignerErrors/invalid_signature_base642591=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2592=== RUN TestParseSigningKey/empty_name2593=== PAUSE TestParseSigningKey/empty_name2594=== RUN TestExternalSignerErrors/wrong_signature_length2595=== RUN TestParseSigningKey/invalid_base642596=== PAUSE TestParseSigningKey/invalid_base642597=== PAUSE TestExternalSignerErrors/wrong_signature_length2598=== RUN TestGenerateFingerprint/invalid_store_path_prefix2599=== RUN TestParseSigningKey/wrong_length2600=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2601=== PAUSE TestParseSigningKey/wrong_length2602=== RUN TestExternalSignerErrors/exit_on_request2603=== CONT TestParseSigningKey/valid_32-byte_key2604=== CONT TestParseSigningKey/empty_name2605=== CONT TestParseSigningKey/no_colon2606=== PAUSE TestExternalSignerErrors/exit_on_request2607=== RUN TestExternalSignerErrors/invalid_JSON2608=== PAUSE TestExternalSignerErrors/invalid_JSON2609=== RUN TestExternalSignerErrors/null2610=== PAUSE TestExternalSignerErrors/null2611=== RUN TestExternalSignerErrors/wrong_signatures_shape2612=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2613=== RUN TestExternalSignerErrors/wrong_shape2614=== PAUSE TestExternalSignerErrors/wrong_shape2615=== RUN TestExternalSignerErrors/null_signatures2616=== PAUSE TestExternalSignerErrors/null_signatures2617=== RUN TestExternalSignerErrors/too_few_signatures2618=== PAUSE TestExternalSignerErrors/too_few_signatures2619=== RUN TestExternalSignerErrors/missing_signature_name2620=== PAUSE TestExternalSignerErrors/missing_signature_name2621=== CONT TestExternalSignerErrors/wrong_id2622=== CONT TestParseSigningKey/invalid_base642623=== CONT TestExternalSignerErrors/wrong_signature_length2624=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2625=== CONT TestParseSigningKey/wrong_length2626=== CONT TestExternalSignerErrors/invalid_signature_base642627=== CONT TestExternalSignerErrors/invalid_JSON2628=== RUN TestGenerateFingerprint/invalid_reference_prefix2629=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2630=== CONT TestExternalSignerErrors/missing_signature_name2631=== CONT TestExternalSignerErrors/too_few_signatures2632=== CONT TestExternalSignerErrors/null_signatures2633=== RUN TestSignErrors/nil_key2634=== PAUSE TestSignErrors/nil_key2635=== CONT TestExternalSignerErrors/wrong_shape2636=== CONT TestExternalSignerErrors/wrong_signatures_shape2637=== CONT TestExternalSignerErrors/null2638=== CONT TestExternalSignerErrors/wrong_signature_name2639=== CONT TestExternalSignerErrors/exit_on_request2640=== CONT TestExternalSignerErrors/exit_at_startup2641--- PASS: TestSign (0.00s)2642=== CONT TestExternalSignerErrors/missing_signatures2643=== RUN TestSignErrors/nil_narinfo2644=== PAUSE TestSignErrors/nil_narinfo2645=== RUN TestSignErrors/invalid_narinfo2646=== PAUSE TestSignErrors/invalid_narinfo2647=== RUN TestSignErrors/canceled2648=== PAUSE TestSignErrors/canceled2649=== CONT TestGenerateFingerprint/basic_with_references2650--- PASS: TestSignBatch (0.00s)2651=== CONT TestExternalSignerErrors/unrequested_key2652--- PASS: TestParseSigningKey (0.00s)2653 --- PASS: TestParseSigningKey/empty_name (0.00s)2654 --- PASS: TestParseSigningKey/no_colon (0.00s)2655 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2656 --- PASS: TestParseSigningKey/wrong_length (0.00s)2657 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2658 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2659=== CONT TestGenerateFingerprint/invalid_store_path_prefix2660=== CONT TestGenerateFingerprint/invalid_nar_hash_length2661=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2662=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2663=== CONT TestGenerateFingerprint/no_references2664=== CONT TestSignErrors/nil_key2665=== CONT TestExternalSignerErrors/program_error2666=== CONT TestGenerateFingerprint/invalid_reference_prefix2667=== CONT TestSignErrors/invalid_narinfo2668=== CONT TestSignErrors/nil_narinfo2669--- PASS: TestGenerateFingerprint (0.00s)2670 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2671 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2672 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2673 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2674 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2675 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2676 --- PASS: TestGenerateFingerprint/no_references (0.00s)2677=== CONT TestSignErrors/canceled2678--- PASS: TestSignErrors (0.00s)2679 --- PASS: TestSignErrors/nil_key (0.00s)2680 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2681 --- PASS: TestSignErrors/nil_narinfo (0.00s)2682 --- PASS: TestSignErrors/canceled (0.00s)2683--- PASS: TestExternalSigner (0.21s)2684--- PASS: TestExternalSignerCancellation (0.41s)2685--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.57s)2686--- PASS: TestExternalSignerWrongPublicKey (1.30s)2687--- PASS: TestExternalSignerClose (1.67s)2688--- PASS: TestExternalSignerRestartsAfterCrash (3.72s)2689/private/var/tb/8/scratch/021d280b068cf186/build/TestExternalSignerRestartsAfterCrash4084395490/001/sign program: line 7: /private/var/tb/8/scratch/021d280b068cf186/build/TestExternalSignerRestartsAfterCrash4084395490/001/sign program.starts: No such file or directory2690--- PASS: TestExternalSignerErrors (0.00s)2691 --- PASS: TestExternalSignerErrors/exit_on_request (0.75s)2692 --- PASS: TestExternalSignerErrors/unrequested_key (0.93s)2693 --- PASS: TestExternalSignerErrors/null_signatures (1.11s)2694 --- PASS: TestExternalSignerErrors/program_error (1.48s)2695 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.84s)2696 --- PASS: TestExternalSignerErrors/invalid_JSON (2.03s)2697 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.21s)2698 --- PASS: TestExternalSignerErrors/exit_at_startup (2.39s)2699 --- PASS: TestExternalSignerErrors/too_few_signatures (2.57s)2700 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.75s)2701 --- PASS: TestExternalSignerErrors/wrong_id (2.94s)2702 --- PASS: TestExternalSignerErrors/missing_signature_name (3.12s)2703 --- PASS: TestExternalSignerErrors/wrong_shape (3.31s)2704 --- PASS: TestExternalSignerErrors/null (3.50s)2705 --- PASS: TestExternalSignerErrors/missing_signatures (3.88s)2706 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (4.07s)2707PASS2708Running OpenBao signer tests...2709=== RUN TestSign2710=== PAUSE TestSign2711=== RUN TestSignErrors2712=== PAUSE TestSignErrors2713=== RUN TestServe2714=== PAUSE TestServe2715=== RUN TestServeRejectsGarbage2716=== PAUSE TestServeRejectsGarbage2717=== CONT TestSign2718=== CONT TestSignErrors2719=== RUN TestSignErrors/http_error2720=== PAUSE TestSignErrors/http_error2721=== CONT TestServeRejectsGarbage2722=== RUN TestSignErrors/invalid_json2723=== PAUSE TestSignErrors/invalid_json2724=== RUN TestSignErrors/no_prefix2725=== CONT TestServe2726--- PASS: TestServeRejectsGarbage (0.00s)2727=== PAUSE TestSignErrors/no_prefix2728=== RUN TestSignErrors/invalid_base642729=== PAUSE TestSignErrors/invalid_base642730=== CONT TestSignErrors/http_error2731=== CONT TestSignErrors/no_prefix2732=== CONT TestSignErrors/invalid_base642733--- PASS: TestServe (0.00s)2734=== CONT TestSignErrors/invalid_json2735--- PASS: TestSignErrors (0.00s)2736 --- PASS: TestSignErrors/http_error (0.00s)2737 --- PASS: TestSignErrors/invalid_json (0.00s)2738 --- PASS: TestSignErrors/no_prefix (0.00s)2739 --- PASS: TestSignErrors/invalid_base64 (0.00s)2740--- PASS: TestSign (0.00s)2741PASS