niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #453
· 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.17s)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 TestScriptTokenScriptFails117=== CONT TestResolveStorePath118=== CONT TestDumpPathSingleFile119=== CONT TestClientSignaturesByStorePath120--- PASS: TestClientSignaturesByStorePath (0.00s)121=== CONT TestSupersededNARStillUploadsListing122=== RUN TestSupersededNARStillUploadsListing/small_NAR123=== PAUSE TestSupersededNARStillUploadsListing/small_NAR124=== RUN TestSupersededNARStillUploadsListing/dump_cut_short125=== CONT TestFileTokenMissing126=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short127=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails128=== CONT TestPartSizeForNAR129=== RUN TestPartSizeForNAR/zero_stays_at_minimum130=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum131=== RUN TestPartSizeForNAR/small_stays_at_minimum132=== PAUSE TestPartSizeForNAR/small_stays_at_minimum133=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum134=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum135=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts136=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts137=== RUN TestPartSizeForNAR/1_TiB138=== PAUSE TestPartSizeForNAR/1_TiB139=== CONT TestUploadMultipart_FailedPartBufferNotReused140=== CONT TestUploadMultipart_PartsInParallel141=== CONT TestFilterOversizedClosures142=== CONT TestCaseHackSuffix143=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun144=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica145=== CONT TestRegisterUploadedObjectReusesConnections146=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry147=== CONT TestScriptTokenEmptyToken148=== CONT TestFileTokenReadsAndCaches149=== CONT TestStaticToken150=== CONT TestSetClientTLSErrors151=== CONT TestScriptTokenNoExpiryRerunsEveryCall152=== CONT TestSetClientTLSDoesNotMutateDefaultTransport153=== CONT TestParsePathInfoJSON154=== RUN TestParsePathInfoJSON/Nix_format155=== PAUSE TestParsePathInfoJSON/Nix_format156=== RUN TestParsePathInfoJSON/Lix_format157=== PAUSE TestParsePathInfoJSON/Lix_format158=== RUN TestParsePathInfoJSON/empty_input159=== PAUSE TestParsePathInfoJSON/empty_input160=== RUN TestParsePathInfoJSON/whitespace_only161=== PAUSE TestParsePathInfoJSON/whitespace_only162=== RUN TestParsePathInfoJSON/invalid_JSON163=== PAUSE TestParsePathInfoJSON/invalid_JSON164=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer165=== CONT TestSetClientTLS166=== CONT TestStreamPushStopsWhenCanceled167=== CONT TestUploadMultipart_SupersededByPeer168=== CONT TestConvertHashToNix32169=== CONT TestScriptTokenEmptyCommand170=== CONT TestPathInfoHashCompatibility171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails173=== RUN TestPartSizeForNAR/5_TiB_S3_max_object174=== CONT TestGetStorePathHash175=== RUN TestGetStorePathHash/valid_store_path176=== PAUSE TestGetStorePathHash/valid_store_path177=== RUN TestGetStorePathHash/basename_without_hyphen_should_error178=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error179=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error180=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error181=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error182=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error183=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object184--- PASS: TestResolveStorePath (0.00s)185=== CONT TestScriptTokenCachesUntilRefresh186=== RUN TestSetClientTLSErrors/missing_cert_file187=== RUN TestSetClientTLS/rejects_connection_without_client_cert188=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert189=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA190=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA191=== RUN TestSetClientTLS/preserves_debug_logging_transport192=== PAUSE TestSetClientTLS/preserves_debug_logging_transport193=== CONT TestRateLimiterFeedback194=== CONT TestScriptTokenBadJSON195=== RUN TestFilterOversizedClosures/no_limit_keeps_everything196=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)197=== CONT TestDumpPathMatchesNix198=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess199=== RUN TestUploadMultipart_SupersededByPeer/exists200=== RUN TestConvertHashToNix32/SRI_format_to_Nix32201=== RUN TestPartSizeForNAR/capped_at_5_GiB202--- PASS: TestScriptTokenScriptFails (0.01s)203--- PASS: TestFileTokenMissing (0.04s)204--- PASS: TestStaticToken (0.00s)205--- PASS: TestFileTokenReadsAndCaches (0.00s)206--- PASS: TestStreamPushStopsWhenCanceled (0.00s)207--- PASS: TestScriptTokenEmptyCommand (0.00s)208=== RUN TestRateLimiterFeedback/429_enables_limiter209=== PAUSE TestRateLimiterFeedback/429_enables_limiter210=== RUN TestRateLimiterFeedback/503_enables_limiter211=== PAUSE TestRateLimiterFeedback/503_enables_limiter212=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter213=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter214=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter215=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped218=== RUN TestFilterOversizedClosures/all_closures_skipped219=== PAUSE TestFilterOversizedClosures/all_closures_skipped220=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon221=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon2222026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=server-test rate=5223=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI224=== CONT TestPathInfoCACompatibility225=== RUN TestPathInfoCACompatibility/null_ca_field226=== PAUSE TestPathInfoCACompatibility/null_ca_field227=== RUN TestPathInfoCACompatibility/old_string_format_-_text228=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text229=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive230=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== RUN TestPathInfoCACompatibility/new_structured_format_-_text232=== PAUSE TestUploadMultipart_SupersededByPeer/exists233=== RUN TestUploadMultipart_SupersededByPeer/missing234=== PAUSE TestSetClientTLSErrors/missing_cert_file235=== RUN TestSetClientTLSErrors/missing_key_file236=== PAUSE TestSetClientTLSErrors/missing_key_file237=== RUN TestSetClientTLSErrors/missing_ca_file238=== PAUSE TestSetClientTLSErrors/missing_ca_file239=== RUN TestSetClientTLSErrors/invalid_ca_file240=== PAUSE TestSetClientTLSErrors/invalid_ca_file241=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI242=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5122432026/11/01 17:34:31 INFO Garbage collection started2442026/11/01 17:34:31 INFO Garbage collection started2452026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=s3-test rate=52462026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:53599247=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512248=== CONT TestParsePathInfoJSONMultiplePaths249=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths250=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths251=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths252=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths253=== CONT TestStreamPushIsolatesFailures2542026/11/01 17:34:31 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=0255--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)256--- PASS: TestDoServerRequestAttachesToken (0.08s)257=== CONT TestShellSplit258--- PASS: TestScriptTokenEmptyToken (0.04s)259--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.04s)260--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.08s)261=== PAUSE TestPartSizeForNAR/capped_at_5_GiB262=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter263=== CONT TestShellSplitErrors264=== CONT TestEncodeNixBase32WithRealHash265=== CONT TestRetryTimeoutOutlastsMaxRetries266=== CONT TestStreamPushBatchesUnderLoad2672026/11/01 17:34:31 ERROR Upload failed error="bad path" count=32682026/11/01 17:34:31 WARN Garbage collection finished on another replica. Its statistics are not available here269=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false270=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false271=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true272=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true273=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text274=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method275=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method276=== CONT TestDoWithRetry_BodyReplayedViaGetBody277=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32278=== CONT TestStreamPushReportsSkippedPaths279=== CONT TestStreamPushReportsSignatures280=== CONT TestStreamPushRequestLine281=== CONT TestStreamPushGivesUpOnDeadServer282=== PAUSE TestUploadMultipart_SupersededByPeer/missing283--- PASS: TestShellSplit (0.00s)284=== CONT TestStreamPushReportsEveryPath285=== CONT TestEncodeNixBase32286=== RUN TestEncodeNixBase32/test_string_hash287=== PAUSE TestEncodeNixBase32/test_string_hash288=== RUN TestEncodeNixBase32/empty_input289=== PAUSE TestEncodeNixBase32/empty_input290=== RUN TestConvertHashToNix32/already_Nix32_format291=== PAUSE TestConvertHashToNix32/already_Nix32_format292=== RUN TestConvertHashToNix32/invalid_format293=== PAUSE TestConvertHashToNix32/invalid_format294=== CONT TestDoWithRetry_FinalResponseBodyReadable295--- PASS: TestShellSplitErrors (0.00s)296--- PASS: TestEncodeNixBase32WithRealHash (0.00s)297--- PASS: TestStreamPushIsolatesFailures (0.00s)298--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.09s)299=== CONT TestDumpPathWriterError300=== CONT TestParsePathInfoJSON/Nix_format301=== CONT TestParsePathInfoJSON/empty_input302=== CONT TestParsePathInfoJSON/Lix_format303=== CONT TestSupersededNARStillUploadsListing/small_NAR304=== CONT TestParsePathInfoJSON/whitespace_only305=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails306=== CONT TestParsePathInfoJSON/invalid_JSON307=== CONT TestGetStorePathHash/valid_store_path308=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error309=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error310--- PASS: TestStreamPushReportsEveryPath (0.00s)3112026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:53613312=== CONT TestSupersededNARStillUploadsListing/dump_cut_short313=== CONT TestFileTokenEmpty314=== CONT TestGetStorePathHash/basename_without_hyphen_should_error315=== CONT TestSetClientTLS/preserves_debug_logging_transport3162026/11/01 17:34:31 INFO Uploading abc-hello (1.0GB)3172026/11/01 17:34:31 ERROR Upload failed error="connection refused" count=203182026/11/01 17:34:31 ERROR Server seems unavailable, giving up on batch untried=173192026/11/01 17:34:31 ERROR Upload failed error=boom count=1320=== CONT TestSetClientTLS/rejects_connection_without_client_cert321--- PASS: TestParsePathInfoJSON (0.00s)322 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)323 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)324 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)325 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)326 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)327=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA328=== CONT TestFilterOversizedClosures/no_limit_keeps_everything329=== CONT TestFilterOversizedClosures/all_closures_skipped330=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3312026/11/01 17:34:31 ERROR Upload failed error=boom count=1332--- PASS: TestStreamPushReportsSkippedPaths (0.00s)3332026/11/01 17:34:31 INFO Uploading abc-hello (1.0GB)334--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)335--- PASS: TestFileTokenEmpty (0.00s)336--- PASS: TestScriptTokenBadJSON (0.03s)337=== CONT TestSetClientTLSErrors/missing_cert_file3382026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=server-test rate=53392026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=server-test rate=53402026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:536193412026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:536133422026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:53617343--- PASS: TestGetStorePathHash (0.00s)344 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)345 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)346 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)347 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)348--- PASS: TestStreamPushReportsSignatures (0.01s)349=== CONT TestSetClientTLSErrors/invalid_ca_file3502026/11/01 17:34:31 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=20003512026/11/01 17:34:31 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=503522026/11/01 17:34:31 WARN Rate limiter backed off name=server-test rate=53532026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:53617354=== CONT TestSetClientTLSErrors/missing_key_file355=== CONT TestSetClientTLSErrors/missing_ca_file356--- PASS: TestFilterOversizedClosures (0.06s)357 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)358 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.01s)359 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.01s)360=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)361--- PASS: TestSetClientTLSErrors (0.02s)362 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)363 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)364 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)365 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)366=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512367=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI368=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths369=== CONT TestPartSizeForNAR/zero_stays_at_minimum370=== CONT TestRateLimiterFeedback/429_enables_limiter371=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths372--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)373 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)374 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)375=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon376--- PASS: TestPathInfoHashCompatibility (0.03s)377 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)378 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)379 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)380 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)381=== CONT TestPartSizeForNAR/small_stays_at_minimum382=== CONT TestPartSizeForNAR/capped_at_5_GiB383=== CONT TestPartSizeForNAR/1_TiB384=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts385=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum386=== CONT TestPartSizeForNAR/5_TiB_S3_max_object387--- PASS: TestPartSizeForNAR (0.09s)388 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)389 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)391 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)392 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)393 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)394 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)395=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter396=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3972026/11/01 17:34:31 WARN Rate limiter backed off name=server-test rate=53982026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:53613399=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false400=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true401--- PASS: TestStreamPushBatchesUnderLoad (0.00s)402 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)403 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)404=== CONT TestPathInfoCACompatibility/null_ca_field405=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method406=== CONT TestPathInfoCACompatibility/new_structured_format_-_text407=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive408=== CONT TestPathInfoCACompatibility/old_string_format_-_text409--- PASS: TestPathInfoCACompatibility (0.02s)410 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)411 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)412 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)413 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)414 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)415=== CONT TestEncodeNixBase32/test_string_hash416=== CONT TestConvertHashToNix32/SRI_format_to_Nix32417=== CONT TestUploadMultipart_SupersededByPeer/exists4182026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=server-test rate=54192026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:53632420--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)421=== CONT TestEncodeNixBase32/empty_input422--- PASS: TestEncodeNixBase32 (0.00s)423 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)424 --- PASS: TestEncodeNixBase32/empty_input (0.00s)425--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)426=== CONT TestConvertHashToNix32/invalid_format427=== CONT TestConvertHashToNix32/already_Nix32_format428--- PASS: TestConvertHashToNix32 (0.03s)429 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)430 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)431 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)432=== CONT TestRateLimiterFeedback/503_enables_limiter4332026/11/01 17:34:31 WARN Rate limiter backed off name=server-test rate=54342026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=s3-test rate=5435=== CONT TestUploadMultipart_SupersededByPeer/missing436--- PASS: TestStreamPushRequestLine (0.03s)4372026/11/01 17:34:31 WARN Rate limiter enabled after throttle name=server-test rate=54382026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:536384392026/11/01 17:34:31 WARN Rate limiter backed off name=server-test rate=5440--- PASS: TestRateLimiterFeedback (0.02s)441 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)442 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)443 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)444 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)445--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)446 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)447 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)4482026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:536134492026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:536134502026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:536134512026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:536134522026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:536134532026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:536134542026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:536134552026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:536134562026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:536134572026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:536134582026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:53613459--- PASS: TestDumpPathSingleFile (0.19s)460--- PASS: TestRegisterUploadedObjectReusesConnections (0.18s)4612026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:536134622026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:536134632026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:536134642026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:536134652026/11/01 17:34:31 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:53613466--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.13s)4672026/11/01 17:34:31 http: TLS handshake error from 127.0.0.1:53629: read tcp 127.0.0.1:53597->127.0.0.1:53629: use of closed network connection468--- PASS: TestSetClientTLS (0.01s)469 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.06s)470 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.09s)471 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.13s)472--- PASS: TestDumpPathWriterError (0.17s)4732026/11/01 17:34:32 INFO Uploading abc-hello (1.0GB)474--- PASS: TestScriptTokenCachesUntilRefresh (0.24s)475--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.26s)4762026/11/01 17:34:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:53623/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:53623/part/24772026/11/01 17:34:32 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"478--- PASS: TestCaseHackSuffix (0.38s)479--- PASS: TestDumpPathMatchesNix (0.36s)480--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.69s)481--- PASS: TestUploadMultipart_PartsInParallel (0.74s)482--- PASS: TestSupersededNARStillUploadsListing (0.05s)483 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)484 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.09s)485 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.74s)4862026/11/01 17:34:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:53549/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:53549/api/uploads/complete4872026/11/01 17:34:32 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4882026/11/01 17:34:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:53549/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:53549/api/uploads/complete4892026/11/01 17:34:32 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4902026/11/01 17:34:32 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:53549/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:53549/api/uploads/complete4912026/11/01 17:34:32 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"492--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)493--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)494PASS495Running server tests...496The files belonging to this database system will be owned by user "_tribuchetbld2".497This user must also own the server process.498499The database cluster will be initialized with locale "C".500The default database encoding has accordingly been set to "SQL_ASCII".501The default text search configuration will be set to "english".502503Data page checksums are enabled.504505creating directory /private/var/tb/2/scratch/8135d018037c16fe/build/postgres881472793/data ... ok506creating subdirectories ... ok507selecting dynamic shared memory implementation ... posix508selecting default "max_connections" ... 100509selecting default "shared_buffers" ... 128MB510selecting default time zone ... UTC511creating configuration files ... ok512running bootstrap script ... ok513performing post-bootstrap initialization ... ok514syncing data to disk ... ok515516initdb: warning: enabling "trust" authentication for local connections517initdb: 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.518519Success. You can now start the database server using:520521 pg_ctl -D /private/var/tb/2/scratch/8135d018037c16fe/build/postgres881472793/data -l logfile start522523/private/var/tb/2/scratch/8135d018037c16fe/build/postgres881472793:5432 - no response5242026-11-01 17:34:33.958 UTC [11332] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5252026-11-01 17:34:33.958 UTC [11332] LOG: listening on Unix socket "/private/var/tb/2/scratch/8135d018037c16fe/build/postgres881472793/.s.PGSQL.5432"5262026-11-01 17:34:33.972 UTC [11340] LOG: database system was shut down at 2026-11-01 17:34:33 UTC5272026-11-01 17:34:33.973 UTC [11332] LOG: database system is ready to accept connections528/private/var/tb/2/scratch/8135d018037c16fe/build/postgres881472793:5432 - accepting connections529{"timestamp":"2026-11-01T17:34:34.204205Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"be0f35d2-d020-4051-8f53-9be6842355ca","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":502,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}530{"timestamp":"2026-11-01T17:34:34.310532Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"40b7d906-3e81-41f0-9f93-4c8f5690d4f4","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}531{"timestamp":"2026-11-01T17:34:34.413857Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1179d347-62da-4ae1-b771-707e0a568061","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}532=== RUN TestService_AuthMiddleware533=== PAUSE TestService_AuthMiddleware534=== RUN TestService_AuthMiddleware_MTLSProxyHeader535=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader536=== RUN TestService_AuthMiddleware_MTLSBoundSubjects537=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects538=== RUN TestService_ReadAuthMiddleware539=== PAUSE TestService_ReadAuthMiddleware540=== RUN TestService_AuthMiddleware_OIDC541=== PAUSE TestService_AuthMiddleware_OIDC542=== RUN TestService_RequireScope_OIDC543=== PAUSE TestService_RequireScope_OIDC544=== RUN TestService_ReadScope_PublicByDefault545=== PAUSE TestService_ReadScope_PublicByDefault546=== RUN TestCacheConfigHandler547=== PAUSE TestCacheConfigHandler548=== RUN TestCacheStatsHandler549=== PAUSE TestCacheStatsHandler550=== RUN TestClientCADerivations551=== PAUSE TestClientCADerivations552=== RUN TestClientErrorHandling553=== PAUSE TestClientErrorHandling554=== RUN TestClientIntegration555=== PAUSE TestClientIntegration556=== RUN TestClientMultipleUploads557=== PAUSE TestClientMultipleUploads558=== RUN TestClientWithDependencies559=== PAUSE TestClientWithDependencies560=== RUN TestClientSharedPathCommittedMidPush561=== PAUSE TestClientSharedPathCommittedMidPush562=== RUN TestPinProtectsFromGC563=== PAUSE TestPinProtectsFromGC564=== RUN TestClientPushesUseOnePush565=== PAUSE TestClientPushesUseOnePush566=== RUN TestClientFallsBackToClosures567=== PAUSE TestClientFallsBackToClosures568=== RUN TestDeleteClosuresRacingPins569=== PAUSE TestDeleteClosuresRacingPins570=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock571=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock572=== RUN TestResolveDBConnectionString573=== PAUSE TestResolveDBConnectionString574=== RUN TestConnectWaitsForAPeerMigration575=== PAUSE TestConnectWaitsForAPeerMigration576=== RUN TestLeadElectsOneAndHandsOver577=== PAUSE TestLeadElectsOneAndHandsOver578=== RUN TestLeadIncumbentWinsAfterRestart5792026/11/01 17:34:34 INFO lead: acquired remote=192.0.2.1:12345802026/11/01 17:34:35 INFO lead: released remote=192.0.2.1:12345812026/11/01 17:34:35 INFO lead: acquired remote=192.0.2.1:12345822026/11/01 17:34:36 INFO lead: released remote=192.0.2.1:1234583--- PASS: TestLeadIncumbentWinsAfterRestart (1.99s)584=== RUN TestLeadIncumbentAnnouncesAtOnce585=== PAUSE TestLeadIncumbentAnnouncesAtOnce586=== RUN TestLeadEndsOnShutdown587=== PAUSE TestLeadEndsOnShutdown588=== RUN TestLeadEndsWhenItsConnectionHangs5892026/11/01 17:34:36 INFO lead: acquired remote=192.0.2.1:12345902026-11-01 17:34:38.115 UTC [11514] FATAL: terminating connection due to administrator command5912026/11/01 17:34:38 INFO lead: acquired remote=192.0.2.1:12345922026/11/01 17:34:39 WARN lead: lock connection lost error="timeout: context deadline exceeded"5932026/11/01 17:34:39 INFO lead: released remote=192.0.2.1:12345942026/11/01 17:34:39 INFO lead: released remote=192.0.2.1:1234595--- PASS: TestLeadEndsWhenItsConnectionHangs (3.01s)596=== RUN TestGCAdvisoryLockBlocksConcurrentRun597=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun598=== RUN TestGCBugBareHashReferences599=== PAUSE TestGCBugBareHashReferences600=== RUN TestGCMetrics601=== PAUSE TestGCMetrics602=== RUN TestPushDedupSurvivesConcurrentGC603=== PAUSE TestPushDedupSurvivesConcurrentGC604=== RUN TestDeduplicatedObjectsRecordedAsPending605=== PAUSE TestDeduplicatedObjectsRecordedAsPending606=== RUN TestGCSweepSkipsPendingObjects607=== PAUSE TestGCSweepSkipsPendingObjects608=== RUN TestTombstonedObjectOfferedWithoutWaiting609=== PAUSE TestTombstonedObjectOfferedWithoutWaiting610=== RUN TestGCSweepDeliversEachKeyOnce611=== PAUSE TestGCSweepDeliversEachKeyOnce612=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection613=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection614=== RUN TestForceGCDuringPushOffersSweptObject615=== PAUSE TestForceGCDuringPushOffersSweptObject616=== RUN TestFailedS3DeleteKeepsTombstone617=== PAUSE TestFailedS3DeleteKeepsTombstone618=== RUN TestSweepSkipsRowsLockedByPush619=== PAUSE TestSweepSkipsRowsLockedByPush620=== RUN TestRegisterCompletedObjectNeedsPendingRow621=== PAUSE TestRegisterCompletedObjectNeedsPendingRow622=== RUN TestGetExistingObjectsLocksRows623=== PAUSE TestGetExistingObjectsLocksRows624=== RUN TestSweepRechecksPendingAfterLocking625=== PAUSE TestSweepRechecksPendingAfterLocking626=== RUN TestPushWaitsForSweepHoldingRow627=== PAUSE TestPushWaitsForSweepHoldingRow628=== RUN TestCommitRacingPendingCleanupKeepsObjects629=== PAUSE TestCommitRacingPendingCleanupKeepsObjects630=== RUN TestGCEndsOnShutdown631=== PAUSE TestGCEndsOnShutdown632=== RUN TestGCTaskStore_StartNew633=== PAUSE TestGCTaskStore_StartNew634=== RUN TestGCTaskStore_DeduplicateSameParams635=== PAUSE TestGCTaskStore_DeduplicateSameParams636=== RUN TestGCTaskStore_ConflictDifferentParams637=== PAUSE TestGCTaskStore_ConflictDifferentParams638=== RUN TestGCTaskStore_GetEmpty639=== PAUSE TestGCTaskStore_GetEmpty640=== RUN TestGCTaskStore_GetReturnsLatest641=== PAUSE TestGCTaskStore_GetReturnsLatest642=== RUN TestGCTaskStore_CompletedAllowsNewTask643=== PAUSE TestGCTaskStore_CompletedAllowsNewTask644=== RUN TestGCTaskStore_PhaseUpdates645=== PAUSE TestGCTaskStore_PhaseUpdates646=== RUN TestGCTaskStore_Fail647=== PAUSE TestGCTaskStore_Fail648=== RUN TestGracefulShutdownDrainsInflight649=== PAUSE TestGracefulShutdownDrainsInflight650=== RUN TestService_healthCheckHandler651=== PAUSE TestService_healthCheckHandler652=== RUN TestService_readinessHandler653=== PAUSE TestService_readinessHandler654=== RUN TestGenerateLandingPage655=== PAUSE TestGenerateLandingPage656=== RUN TestCacheConfigHandlerMaxNarSize657=== PAUSE TestCacheConfigHandlerMaxNarSize658=== RUN TestCreatePendingClosureRejectsOversizedNAR659=== PAUSE TestCreatePendingClosureRejectsOversizedNAR660=== RUN TestNARDeduplicationMetadataUploadBug661=== PAUSE TestNARDeduplicationMetadataUploadBug662=== RUN TestMetricsInventory663=== PAUSE TestMetricsInventory664=== RUN TestMetricsCommit665=== PAUSE TestMetricsCommit666=== RUN TestService_NativeMTLS667=== PAUSE TestService_NativeMTLS668=== RUN TestServerTLSConfig669=== PAUSE TestServerTLSConfig670=== RUN TestMultipartCleanup671=== PAUSE TestMultipartCleanup672=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded673=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded674=== RUN TestPendingCleanupUsesOneCutoff675=== PAUSE TestPendingCleanupUsesOneCutoff676=== RUN TestObjectStatsTrigger677=== PAUSE TestObjectStatsTrigger678=== RUN TestObjectStatsUpdatedOncePerCommit679=== PAUSE TestObjectStatsUpdatedOncePerCommit680=== RUN TestOrphanedObjectsGC681=== PAUSE TestOrphanedObjectsGC682=== RUN TestOrphanedObjectsGCStressTest683=== PAUSE TestOrphanedObjectsGCStressTest684=== RUN TestCreatePin_ReservedPins685=== PAUSE TestCreatePin_ReservedPins686=== RUN TestPresentReportsOnlyClosureRoots687=== PAUSE TestPresentReportsOnlyClosureRoots688=== RUN TestPresentRefreshesOnlyStaleClosures689=== PAUSE TestPresentRefreshesOnlyStaleClosures690=== RUN TestPresentNotReportedWhileGCDeletesClosure691=== PAUSE TestPresentNotReportedWhileGCDeletesClosure692=== RUN TestParseSingleRange693=== PAUSE TestParseSingleRange694=== RUN TestProxyHeadersOnlyTrustedOnSocket6952026/11/01 17:34:39 INFO Starting HTTP server address=127.0.0.1:536736962026/11/01 17:34:39 INFO Starting HTTP server address=proxy.sock6972026/11/01 17:34:39 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6982026/11/01 17:34:39 INFO Shutdown signal received, draining in-flight requests timeout=10s699--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.20s)700=== RUN TestIsValidCachePath701=== PAUSE TestIsValidCachePath702=== RUN TestReadProxyNarinfo703=== PAUSE TestReadProxyNarinfo704=== RUN TestReadProxyNarinfoAlreadyDecompressed705=== PAUSE TestReadProxyNarinfoAlreadyDecompressed706=== RUN TestReadProxyContentNegotiation707=== PAUSE TestReadProxyContentNegotiation708=== RUN TestReadProxyNarStreaming709=== PAUSE TestReadProxyNarStreaming710=== RUN TestReadProxy404711=== PAUSE TestReadProxy404712=== RUN TestReadProxyInvalidPath713=== PAUSE TestReadProxyInvalidPath714=== RUN TestReadProxyHead715=== PAUSE TestReadProxyHead716=== RUN TestReadProxyOutlastsServerWriteTimeout717=== PAUSE TestReadProxyOutlastsServerWriteTimeout718=== RUN TestReadProxyConditionalGet719=== PAUSE TestReadProxyConditionalGet720=== RUN TestReadProxyRootRedirectsToIndexHTML721=== PAUSE TestReadProxyRootRedirectsToIndexHTML722=== RUN TestReadProxyDisabled723=== PAUSE TestReadProxyDisabled724=== RUN TestReadRedirectNar725=== PAUSE TestReadRedirectNar726=== RUN TestReadRedirectKeepsNarinfoProxied727=== PAUSE TestReadRedirectKeepsNarinfoProxied728=== RUN TestReadProxyRangeRequest729=== PAUSE TestReadProxyRangeRequest730=== RUN TestReadRedirectUsesPublicS3URL731=== PAUSE TestReadRedirectUsesPublicS3URL732=== RUN TestPush_OverlappingRootsStoreOneRowPerKey733=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey734=== RUN TestPush_CompleteCommitsEveryRoot735=== PAUSE TestPush_CompleteCommitsEveryRoot736=== RUN TestPush_RepeatedRootCommitsOnce737=== PAUSE TestPush_RepeatedRootCommitsOnce738=== RUN TestPush_CompleteWaitsForCleanupOfThePush739=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush740=== RUN TestPush_RootsAreLockedInByteOrder741=== PAUSE TestPush_RootsAreLockedInByteOrder742=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit743=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit744=== RUN TestPush_RejectsBadRequests745=== PAUSE TestPush_RejectsBadRequests746=== RUN TestPush_SignsNarinfosOfItsPendingObjects747=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects748=== RUN TestRedundantMultipartUpload749=== PAUSE TestRedundantMultipartUpload750=== RUN TestCompleteMultipartUpload_ErrorButObjectExists751=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists752=== RUN TestCompletedNarNotReofferedAcrossClosures753=== PAUSE TestCompletedNarNotReofferedAcrossClosures754=== RUN TestPresignedUploadRegisteredBeforeCommit755=== PAUSE TestPresignedUploadRegisteredBeforeCommit756=== RUN TestService_Rustfstest757=== PAUSE TestService_Rustfstest758=== RUN TestParseSize759=== PAUSE TestParseSize760=== RUN TestSkippedUploadsHandler761=== PAUSE TestSkippedUploadsHandler762=== RUN TestSystemdListenerNotActivated763--- PASS: TestSystemdListenerNotActivated (0.00s)764=== RUN TestWatchdogBeatsWhenHealthy765--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)766=== RUN TestWatchdogSkipsWhenUnhealthy7672026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/01 17:34:39 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"777--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)778=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== RUN TestProxyWriteTimeout781=== PAUSE TestProxyWriteTimeout782=== RUN TestPendingClosureWriteTimeout783=== PAUSE TestPendingClosureWriteTimeout784=== RUN TestIsValidUploadKey785=== PAUSE TestIsValidUploadKey786=== RUN TestUploadHandlersRejectInvalidKeys787=== PAUSE TestUploadHandlersRejectInvalidKeys788=== RUN TestUploadHandlersRejectOversizedBody789=== PAUSE TestUploadHandlersRejectOversizedBody790=== RUN TestService_cleanupPendingClosuresHandler791=== PAUSE TestService_cleanupPendingClosuresHandler792=== RUN TestService_createPendingClosureHandler793=== PAUSE TestService_createPendingClosureHandler794=== RUN TestService_verifyS3Integrity795=== PAUSE TestService_verifyS3Integrity796=== RUN TestCompleteMultipartUnregistered797=== PAUSE TestCompleteMultipartUnregistered798=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT799=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestService_AuthMiddleware801=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit802=== CONT TestPush_RejectsBadRequests803=== CONT TestSkippedUploadsHandler804=== CONT TestParseSize805--- PASS: TestParseSize (0.00s)806=== CONT TestPush_RepeatedRootCommitsOnce807=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle808=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT809=== CONT TestCompleteMultipartUnregistered810=== CONT TestService_verifyS3Integrity811=== CONT TestService_createPendingClosureHandler812=== CONT TestService_Rustfstest813=== CONT TestService_cleanupPendingClosuresHandler8142026/11/01 17:34:39 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000815=== CONT TestPresignedUploadRegisteredBeforeCommit816=== CONT TestUploadHandlersRejectOversizedBody817=== CONT TestCompletedNarNotReofferedAcrossClosures818=== CONT TestUploadHandlersRejectInvalidKeys819=== CONT TestIsValidUploadKey820=== RUN TestIsValidUploadKey/narinfo821=== CONT TestPendingClosureWriteTimeout822=== CONT TestCompleteMultipartUpload_ErrorButObjectExists823=== CONT TestProxyWriteTimeout824=== CONT TestRedundantMultipartUpload825=== CONT TestPush_SignsNarinfosOfItsPendingObjects826=== CONT TestGCTaskStore_GetReturnsLatest827=== CONT TestPush_CompleteWaitsForCleanupOfThePush828=== PAUSE TestIsValidUploadKey/narinfo829=== RUN TestPendingClosureWriteTimeout/empty830=== PAUSE TestPendingClosureWriteTimeout/empty831=== RUN TestPendingClosureWriteTimeout/400_objects832=== PAUSE TestPendingClosureWriteTimeout/400_objects833=== RUN TestPendingClosureWriteTimeout/670k_objects834=== PAUSE TestPendingClosureWriteTimeout/670k_objects835=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline836=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline837=== RUN TestIsValidUploadKey/nar_zst838=== PAUSE TestIsValidUploadKey/nar_zst839=== RUN TestIsValidUploadKey/nar_xz840=== PAUSE TestIsValidUploadKey/nar_xz841=== RUN TestIsValidUploadKey/nar_plain842--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)843=== CONT TestOrphanedObjectsGCStressTest844=== RUN TestProxyWriteTimeout/narinfo845=== PAUSE TestProxyWriteTimeout/narinfo846=== RUN TestProxyWriteTimeout/1_GiB_nar847=== PAUSE TestProxyWriteTimeout/1_GiB_nar848=== RUN TestProxyWriteTimeout/10_GiB_nar849=== PAUSE TestProxyWriteTimeout/10_GiB_nar850=== RUN TestProxyWriteTimeout/unknown_size851=== PAUSE TestProxyWriteTimeout/unknown_size852=== PAUSE TestIsValidUploadKey/nar_plain853--- PASS: TestSkippedUploadsHandler (0.05s)854=== RUN TestIsValidUploadKey/listing855=== PAUSE TestIsValidUploadKey/listing856=== RUN TestIsValidUploadKey/build_log857=== PAUSE TestIsValidUploadKey/build_log858=== RUN TestIsValidUploadKey/build_log_home-manager_file859=== PAUSE TestIsValidUploadKey/build_log_home-manager_file860=== RUN TestIsValidUploadKey/build_log_plus_in_name861=== PAUSE TestIsValidUploadKey/build_log_plus_in_name862=== RUN TestIsValidUploadKey/build_log_question_mark863=== PAUSE TestIsValidUploadKey/build_log_question_mark864=== RUN TestIsValidUploadKey/build_log_equals865=== CONT TestPresentReportsOnlyClosureRoots866=== PAUSE TestIsValidUploadKey/build_log_equals867=== RUN TestIsValidUploadKey/realisation868=== PAUSE TestIsValidUploadKey/realisation869=== RUN TestIsValidUploadKey/realisation_plus_in_output870=== PAUSE TestIsValidUploadKey/realisation_plus_in_output871=== RUN TestIsValidUploadKey/nix-cache-info872=== PAUSE TestIsValidUploadKey/nix-cache-info873=== RUN TestIsValidUploadKey/index.html874=== PAUSE TestIsValidUploadKey/index.html875=== RUN TestIsValidUploadKey/narinfo_key,_nar_type876=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type877=== RUN TestIsValidUploadKey/nar_key,_narinfo_type878=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type879=== RUN TestIsValidUploadKey/listing_key,_narinfo_type880=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type881=== RUN TestIsValidUploadKey/traversal882=== PAUSE TestIsValidUploadKey/traversal883=== RUN TestIsValidUploadKey/traversal_nar884=== PAUSE TestIsValidUploadKey/traversal_nar885=== RUN TestIsValidUploadKey/absolute886=== PAUSE TestIsValidUploadKey/absolute887=== RUN TestIsValidUploadKey/empty_key888=== PAUSE TestIsValidUploadKey/empty_key889=== RUN TestIsValidUploadKey/unknown_type890=== PAUSE TestIsValidUploadKey/unknown_type891=== CONT TestOrphanedObjectsGC892=== CONT TestCreatePin_ReservedPins893=== CONT TestPush_CompleteCommitsEveryRoot894=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info895=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info896=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal897=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal898=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key899=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key900=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key901=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key902=== CONT TestPush_OverlappingRootsStoreOneRowPerKey903=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure904=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure905=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart906=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart907=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts908=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts909=== CONT TestReadRedirectUsesPublicS3URL9102026/11/01 17:34:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53678/oidc911--- PASS: TestService_Rustfstest (1.31s)912=== CONT TestObjectStatsUpdatedOncePerCommit9132026/11/01 17:34:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"914--- PASS: TestService_AuthMiddleware (1.75s)915=== CONT TestObjectStatsTrigger9162026/11/01 17:34:42 INFO Received push request method=POST path=/api/pushes9172026/11/01 17:34:42 INFO Received complete push request method=POST path=/api/pushes/1/complete9182026/11/01 17:34:42 INFO Completed push id=1 objects=4 duration=26.845167ms919--- PASS: TestPush_RepeatedRootCommitsOnce (2.32s)920=== CONT TestReadProxyRangeRequest9212026/11/01 17:34:42 INFO Received push request method=POST path=/api/pushes9222026/11/01 17:34:42 INFO Received complete push request method=POST path=/api/pushes/1/complete9232026/11/01 17:34:42 INFO Completed push id=1 objects=4 duration=12.336834ms9242026/11/01 17:34:42 INFO Received push request method=POST path=/api/pushes9252026/11/01 17:34:42 INFO Received push request method=POST path=/api/pushes9262026/11/01 17:34:42 INFO Aborted multipart uploads count=0 kept=09272026/11/01 17:34:42 WARN Force mode enabled - objects will be deleted immediately without grace period9282026/11/01 17:34:42 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=09292026/11/01 17:34:42 INFO Vacuumed table table=pending_closures9302026/11/01 17:34:42 INFO Vacuumed table table=pending_objects9312026/11/01 17:34:42 INFO Vacuumed table table=multipart_uploads9322026/11/01 17:34:42 INFO Vacuumed table table=closures9332026/11/01 17:34:42 INFO Vacuumed table table=objects9342026/11/01 17:34:42 INFO Received complete push request method=POST path=/api/pushes/2/complete9352026/11/01 17:34:42 INFO Completed push id=2 objects=4 duration=6.811791ms936--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.72s)937=== CONT TestPendingCleanupUsesOneCutoff9382026/11/01 17:34:42 INFO Received uploads request method=POST path=/api/pending_closures9392026/11/01 17:34:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9402026/11/01 17:34:42 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst941--- PASS: TestCompleteMultipartUnregistered (2.95s)942=== CONT TestReadRedirectKeepsNarinfoProxied9432026-11-01 17:34:42.955 UTC [11738] ERROR: Push does not exist: id=19442026-11-01 17:34:42.955 UTC [11738] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9452026-11-01 17:34:42.955 UTC [11738] STATEMENT: SELECT commit_push($1)946--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (3.00s)947=== CONT TestReadRedirectNar948=== RUN TestPush_RejectsBadRequests/no_roots949=== PAUSE TestPush_RejectsBadRequests/no_roots950=== RUN TestPush_RejectsBadRequests/no_objects951=== PAUSE TestPush_RejectsBadRequests/no_objects952=== RUN TestPush_RejectsBadRequests/bad_root953=== PAUSE TestPush_RejectsBadRequests/bad_root954=== RUN TestPush_RejectsBadRequests/root_not_in_objects955=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects956=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9572026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures9582026/11/01 17:34:43 INFO Received cleanup request method=DELETE path=/api/pending_closures9592026/11/01 17:34:43 INFO Aborted multipart uploads count=0 kept=09602026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures9612026/11/01 17:34:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9622026/11/01 17:34:43 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjE2ZGY3YzE5LTg4NjgtNDFmMC04MmUyLTgwY2ZhNmFiMGY0YXgxNzkzNTU0NDgzMzQ0NjQ5MDAw9632026/11/01 17:34:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjE2ZGY3YzE5LTg4NjgtNDFmMC04MmUyLTgwY2ZhNmFiMGY0YXgxNzkzNTU0NDgzMzQ0NjQ5MDAw parts=1964--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.66s)965=== CONT TestReadProxyDisabled9662026/11/01 17:34:43 INFO Received cleanup request method=DELETE path=/api/pending_closures9672026/11/01 17:34:43 INFO Aborted multipart uploads count=1 kept=09682026/11/01 17:34:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9692026-11-01 17:34:43.657 UTC [11587] ERROR: Closure does not exist: id=19702026-11-01 17:34:43.657 UTC [11587] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9712026-11-01 17:34:43.657 UTC [11587] STATEMENT: -- name: CommitPendingClosure :one972 SELECT commit_pending_closure($1::bigint)::bigint973 974--- PASS: TestService_cleanupPendingClosuresHandler (3.71s)975=== CONT TestMultipartCleanup9762026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures9772026/11/01 17:34:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9782026/11/01 17:34:43 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjE3N2Y2NzMzLWJhNDQtNDA3MS1iMGU4LWVmN2U4OGE2MDI1M3gxNzkzNTU0NDgyNzA1NzUxMDAw parts=109792026/11/01 17:34:43 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9802026/11/01 17:34:43 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9812026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures982--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.92s)983=== CONT TestReadProxyRootRedirectsToIndexHTML9842026/11/01 17:34:43 INFO Completed upload id=1 objects=2 duration=20.217667ms9852026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures9862026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures9872026/11/01 17:34:43 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9882026/11/01 17:34:43 WARN Found objects in DB but missing from S3, will re-upload count=1989--- PASS: TestService_verifyS3Integrity (3.95s)990=== CONT TestServerTLSConfig991=== RUN TestServerTLSConfig/no_client_CA992=== PAUSE TestServerTLSConfig/no_client_CA993=== RUN TestServerTLSConfig/missing_CA_file994=== PAUSE TestServerTLSConfig/missing_CA_file995=== RUN TestServerTLSConfig/not_a_PEM_file996=== PAUSE TestServerTLSConfig/not_a_PEM_file997=== CONT TestService_NativeMTLS9982026/11/01 17:34:43 INFO Received uploads request method=POST path=/api/pending_closures999--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.10s)1000=== CONT TestReadProxyConditionalGet10012026/11/01 17:34:44 INFO Received uploads request method=POST path=/api/pending_closures10022026/11/01 17:34:44 INFO Received uploads request method=POST path=/api/pending_closures10032026/11/01 17:34:44 INFO Received uploads request method=POST path=/api/pending_closures10042026/11/01 17:34:44 INFO Received uploads request method=POST path=/api/pending_closures10052026/11/01 17:34:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1006--- PASS: TestReadRedirectUsesPublicS3URL (4.84s)1007=== CONT TestReadProxyOutlastsServerWriteTimeout10082026/11/01 17:34:45 INFO Received push request method=POST path=/api/pushes1009--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.47s)1010=== CONT TestReadProxyHead10112026/11/01 17:34:45 INFO Received push request method=POST path=/api/pushes10122026/11/01 17:34:45 INFO Received complete push request method=POST path=/api/pushes/1/complete10132026/11/01 17:34:45 INFO Completed push id=1 objects=6 duration=49.371541ms1014--- PASS: TestPush_CompleteCommitsEveryRoot (5.81s)1015=== CONT TestMetricsCommit10162026/11/01 17:34:46 INFO Received push request method=POST path=/api/pushes1017=== NAME TestOrphanedObjectsGC1018 orphaned_objects_gc_test.go:287: GC Test Summary:1019 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1020 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1021 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1022 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1023 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1024--- PASS: TestOrphanedObjectsGC (6.22s)1025=== CONT TestReadProxyInvalidPath10262026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10272026/11/01 17:34:46 INFO Signed narinfos id=1 count=110282026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10292026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10302026/11/01 17:34:46 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10312026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10322026/11/01 17:34:46 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10332026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10342026/11/01 17:34:46 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110352026/11/01 17:34:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10362026/11/01 17:34:46 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1037--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (6.30s)1038=== CONT TestMetricsInventory10392026/11/01 17:34:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1040--- PASS: TestPresentReportsOnlyClosureRoots (6.46s)1041=== CONT TestReadProxy40410422026/11/01 17:34:46 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjc2ZjY5MzM2LWU1MjItNGRlOC1hZDVlLTJhYTBhOWM4OTg1YngxNzkzNTU0NDg0NzAxODQzMDAw parts=1010432026/11/01 17:34:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10442026/11/01 17:34:46 INFO Completed upload id=1 objects=2 duration=23.842709ms10452026/11/01 17:34:46 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010462026/11/01 17:34:46 INFO Received uploads request method=POST path=/api/pending_closures10472026/11/01 17:34:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures10482026/11/01 17:34:46 INFO Aborted multipart uploads count=0 kept=010492026/11/01 17:34:46 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=010502026/11/01 17:34:46 INFO Vacuumed table table=pending_closures10512026/11/01 17:34:46 INFO Vacuumed table table=pending_objects10522026/11/01 17:34:46 INFO Vacuumed table table=multipart_uploads10532026/11/01 17:34:46 INFO Vacuumed table table=closures10542026/11/01 17:34:46 INFO Vacuumed table table=objects10552026/11/01 17:34:46 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001056--- PASS: TestService_createPendingClosureHandler (6.77s)1057=== CONT TestNARDeduplicationMetadataUploadBug10582026/11/01 17:34:46 INFO Received uploads request method=POST path=/api/pending_closures10592026/11/01 17:34:46 INFO Received uploads request method=POST path=/api/pending_closures10602026/11/01 17:34:47 INFO Received uploads request method=POST path=/api/pending_closures10612026/11/01 17:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10622026/11/01 17:34:47 WARN Refused reserved pin name=worker-x86_64-linux10632026/11/01 17:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10642026/11/01 17:34:47 INFO Received create pin request method=POST path=/api/pins/my-app10652026/11/01 17:34:47 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1066--- PASS: TestCreatePin_ReservedPins (7.29s)1067=== CONT TestReadProxyNarStreaming1068--- PASS: TestObjectStatsUpdatedOncePerCommit (6.83s)1069=== CONT TestCreatePendingClosureRejectsOversizedNAR10702026/11/01 17:34:48 INFO Received uploads request method=POST path=/api/pending_closures1071--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1072=== CONT TestReadProxyContentNegotiation1073--- PASS: TestObjectStatsTrigger (6.47s)1074=== CONT TestReadProxyNarinfoAlreadyDecompressed10752026/11/01 17:34:48 WARN Rate limiter enabled after throttle name=s3-test rate=510762026/11/01 17:34:48 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1077=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1078 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101079 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001080--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.54s)1081=== CONT TestReadProxyNarinfo1082--- PASS: TestReadProxyRangeRequest (6.29s)1083=== CONT TestIsValidCachePath1084=== RUN TestIsValidCachePath/narinfo1085=== PAUSE TestIsValidCachePath/narinfo1086=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1087=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1088=== RUN TestIsValidCachePath/nar_zst1089=== PAUSE TestIsValidCachePath/nar_zst1090=== RUN TestIsValidCachePath/nar_xz1091=== PAUSE TestIsValidCachePath/nar_xz1092=== RUN TestIsValidCachePath/nar_bz21093=== PAUSE TestIsValidCachePath/nar_bz21094=== RUN TestIsValidCachePath/nar_uncompressed1095=== PAUSE TestIsValidCachePath/nar_uncompressed1096=== RUN TestIsValidCachePath/ls1097=== PAUSE TestIsValidCachePath/ls1098=== RUN TestIsValidCachePath/log1099=== PAUSE TestIsValidCachePath/log1100=== RUN TestIsValidCachePath/realisation1101=== PAUSE TestIsValidCachePath/realisation1102=== RUN TestIsValidCachePath/nix-cache-info1103=== PAUSE TestIsValidCachePath/nix-cache-info1104=== RUN TestIsValidCachePath/index.html1105=== PAUSE TestIsValidCachePath/index.html1106=== RUN TestIsValidCachePath/traversal_parent1107=== PAUSE TestIsValidCachePath/traversal_parent1108=== RUN TestIsValidCachePath/traversal_in_middle1109=== PAUSE TestIsValidCachePath/traversal_in_middle1110=== RUN TestIsValidCachePath/invalid_char_e1111=== PAUSE TestIsValidCachePath/invalid_char_e1112=== RUN TestIsValidCachePath/invalid_char_u1113=== PAUSE TestIsValidCachePath/invalid_char_u1114=== RUN TestIsValidCachePath/random_path1115=== PAUSE TestIsValidCachePath/random_path1116=== RUN TestIsValidCachePath/empty1117=== PAUSE TestIsValidCachePath/empty1118=== RUN TestIsValidCachePath/leading_slash1119=== PAUSE TestIsValidCachePath/leading_slash1120=== RUN TestIsValidCachePath/wrong_extension1121=== PAUSE TestIsValidCachePath/wrong_extension1122=== RUN TestIsValidCachePath/short_hash1123=== PAUSE TestIsValidCachePath/short_hash1124=== CONT TestCacheConfigHandlerMaxNarSize1125--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1126=== CONT TestGenerateLandingPage1127--- PASS: TestGenerateLandingPage (0.00s)1128=== CONT TestService_readinessHandler11292026/11/01 17:34:48 INFO Received uploads request method=POST path=/api/pending_closures11302026/11/01 17:34:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11312026/11/01 17:34:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjczMTc1OWE0LTIzNmUtNDdmZC05NmZkLWM3NmQ1ZmEzNTBjYngxNzkzNTU0NDg2ODE5NTQzMDAw parts=1211322026/11/01 17:34:49 INFO Received uploads request method=POST path=/api/pending_closures11332026/11/01 17:34:49 INFO Received uploads request method=POST path=/api/pending_closures11342026/11/01 17:34:49 INFO Received uploads request method=POST path=/api/pending_closures11352026/11/01 17:34:49 INFO Received cleanup request method=DELETE path=/api/pending_closures11362026/11/01 17:34:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1137--- PASS: TestReadRedirectKeepsNarinfoProxied (7.00s)1138=== CONT TestService_healthCheckHandler11392026/11/01 17:34:50 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjFmNGNiZWI5LTRjZmQtNDc0My1iZTA4LTVmOGUxMTcxNTZmNXgxNzkzNTU0NDg3MDg4MjI4MDAw parts=1211402026/11/01 17:34:50 INFO Received uploads request method=POST path=/api/pending_closures1141--- PASS: TestCompletedNarNotReofferedAcrossClosures (10.14s)1142=== CONT TestParseSingleRange1143=== RUN TestParseSingleRange/none1144=== PAUSE TestParseSingleRange/none1145=== RUN TestParseSingleRange/unknown_unit1146=== PAUSE TestParseSingleRange/unknown_unit1147=== RUN TestParseSingleRange/multi-range_ignored1148=== PAUSE TestParseSingleRange/multi-range_ignored1149=== RUN TestParseSingleRange/malformed_no_dash1150=== PAUSE TestParseSingleRange/malformed_no_dash1151=== RUN TestParseSingleRange/malformed_both_empty1152=== PAUSE TestParseSingleRange/malformed_both_empty1153=== RUN TestParseSingleRange/malformed_end_before_start1154=== PAUSE TestParseSingleRange/malformed_end_before_start1155=== RUN TestParseSingleRange/closed1156=== PAUSE TestParseSingleRange/closed1157=== RUN TestParseSingleRange/open-ended1158=== PAUSE TestParseSingleRange/open-ended1159=== RUN TestParseSingleRange/end_clamped_to_size1160=== PAUSE TestParseSingleRange/end_clamped_to_size1161=== RUN TestParseSingleRange/suffix1162=== PAUSE TestParseSingleRange/suffix1163=== RUN TestParseSingleRange/suffix_exceeds_size1164=== PAUSE TestParseSingleRange/suffix_exceeds_size1165=== RUN TestParseSingleRange/single_byte1166=== PAUSE TestParseSingleRange/single_byte1167=== RUN TestParseSingleRange/start_past_EOF1168=== PAUSE TestParseSingleRange/start_past_EOF1169=== RUN TestParseSingleRange/start_far_past_EOF1170=== PAUSE TestParseSingleRange/start_far_past_EOF1171=== CONT TestPresentNotReportedWhileGCDeletesClosure1172=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1173=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1174=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1175=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1176=== CONT TestPresentRefreshesOnlyStaleClosures1177--- PASS: TestReadRedirectNar (7.77s)1178=== CONT TestLeadEndsOnShutdown11792026/11/01 17:34:51 INFO Received uploads request method=POST path=/api/pending_closures1180--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (8.25s)1181=== CONT TestGCTaskStore_GetEmpty1182--- PASS: TestGCTaskStore_GetEmpty (0.00s)1183=== CONT TestGCTaskStore_ConflictDifferentParams1184--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1185=== CONT TestGracefulShutdownDrainsInflight11862026/11/01 17:34:51 INFO Starting HTTP server address=127.0.0.1:5378911872026/11/01 17:34:51 INFO Shutdown signal received, draining in-flight requests timeout=10s1188--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1189=== CONT TestGCTaskStore_DeduplicateSameParams1190--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1191=== CONT TestGCTaskStore_Fail1192--- PASS: TestGCTaskStore_Fail (0.00s)1193=== CONT TestGCTaskStore_PhaseUpdates1194--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1195=== CONT TestGCTaskStore_CompletedAllowsNewTask1196--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1197=== CONT TestGCTaskStore_StartNew1198--- PASS: TestGCTaskStore_StartNew (0.00s)1199=== CONT TestForceGCDuringPushOffersSweptObject1200=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1201=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1202=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1203=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1204=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12052026/11/01 17:34:51 INFO Received uploads request method=POST path=/api/pending_closures12062026/11/01 17:34:51 INFO Received cleanup request method=DELETE path=/api/pending_closures12072026/11/01 17:34:51 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket35/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12082026/11/01 17:34:51 INFO Aborted multipart uploads count=0 kept=112092026/11/01 17:34:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12102026/11/01 17:34:52 INFO Aborted multipart uploads count=1 kept=01211--- PASS: TestMultipartCleanup (8.42s)1212=== CONT TestGCEndsOnShutdown1213=== RUN TestGCEndsOnShutdown/before_the_run1214=== PAUSE TestGCEndsOnShutdown/before_the_run1215=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1216=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1217=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1218=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1219=== CONT TestGCSweepDeliversEachKeyOnce1220--- PASS: TestReadProxyDisabled (8.70s)1221=== CONT TestCommitRacingPendingCleanupKeepsObjects12222026/11/01 17:34:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1223--- PASS: TestReadProxyRootRedirectsToIndexHTML (9.02s)1224=== CONT TestTombstonedObjectOfferedWithoutWaiting12252026/11/01 17:34:52 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLjE3ODk2N2ExLWVkMjYtNGQ4NC05ZTU5LWRmOTRhYjBjMzVmYngxNzkzNTU0NDg5MjYwMDAxMDAw error="Get \"http://127.0.0.1:1/bucket25/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12262026/11/01 17:34:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2JmMGU4NzMtNjU0ZC00ZWZjLWFhYjYtM2ZjZmNkMTM1YjIxLmYyMmI2OWY2LWZiNWYtNDU1Zi05OGE3LTgyMjkzMjhlM2Q2MngxNzkzNTU0NDg5MTk0NDA1MDAw parts=1212272026/11/01 17:34:52 INFO Received cleanup request method=DELETE path=/api/pending_closures12282026/11/01 17:34:52 INFO Aborted multipart uploads count=1 kept=01229--- PASS: TestRedundantMultipartUpload (13.01s)1230=== CONT TestPushWaitsForSweepHoldingRow1231--- PASS: TestReadProxyConditionalGet (9.47s)1232=== CONT TestSweepRechecksPendingAfterLocking12332026/11/01 17:34:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12342026/11/01 17:34:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1235--- PASS: TestService_NativeMTLS (10.04s)1236=== CONT TestGetExistingObjectsLocksRows1237--- PASS: TestReadProxyHead (9.40s)1238=== CONT TestRegisterCompletedObjectNeedsPendingRow12392026/11/01 17:34:55 INFO Received push request method=POST path=/api/pushes12402026/11/01 17:34:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12412026/11/01 17:34:55 INFO Aborted multipart uploads count=1 kept=012422026/11/01 17:34:55 INFO Completed push id=1 objects=4 duration=47.885792ms12432026/11/01 17:34:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12442026/11/01 17:34:55 INFO Completed upload id=2 objects=2 duration=1.357833ms1245--- PASS: TestMetricsCommit (9.51s)12462026/11/01 17:34:55 INFO Received cleanup request method=DELETE path=/api/pending_closures1247=== CONT TestSweepSkipsRowsLockedByPush12482026/11/01 17:34:55 INFO Aborted multipart uploads count=1 kept=01249--- PASS: TestPendingCleanupUsesOneCutoff (12.70s)1250=== CONT TestFailedS3DeleteKeepsTombstone1251--- PASS: TestReadProxyInvalidPath (9.24s)1252=== CONT TestGCSweepSkipsPendingObjects1253--- PASS: TestMetricsInventory (9.63s)1254=== CONT TestGCMetrics1255--- PASS: TestReadProxy404 (10.43s)1256=== CONT TestGCBugBareHashReferences1257--- PASS: TestReadProxyNarStreaming (9.72s)1258=== CONT TestDeduplicatedObjectsRecordedAsPending1259=== NAME TestNARDeduplicationMetadataUploadBug1260 metadata_upload_test.go:48: First store path: /private/var/tb/2/scratch/8135d018037c16fe/build/TestNARDeduplicationMetadataUploadBug1609594630/001/store/cd25sawm2n1vsv9qdy6qdx3svkia8fyc-file1.txt12612026/11/01 17:34:57 INFO Received push request method=POST path=/api/pushes12622026/11/01 17:34:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12632026/11/01 17:34:57 INFO Uploading cd25sawm2n1vsv9qdy6qdx3svkia8fyc-file1.txt (160B)12642026/11/01 17:34:57 WARN Failed to register uploaded object key=cd25sawm2n1vsv9qdy6qdx3svkia8fyc.ls error="server returned 404: 404 page not found\n"12652026/11/01 17:34:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12662026/11/01 17:34:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12672026/11/01 17:34:57 INFO Signed narinfos id=1 count=112682026/11/01 17:34:57 INFO Uploading 1 narinfos12692026/11/01 17:34:57 INFO Received complete push request method=POST path=/api/pushes/1/complete12702026/11/01 17:34:57 WARN Failed to register uploaded object key=cd25sawm2n1vsv9qdy6qdx3svkia8fyc.narinfo error="server returned 404: 404 page not found\n"12712026/11/01 17:34:57 INFO Completed push id=1 objects=3 duration=51.862ms12722026/11/01 17:34:57 INFO Upload complete. (367ms)1273--- PASS: TestReadProxyContentNegotiation (9.47s)1274=== CONT TestPushDedupSurvivesConcurrentGC1275=== NAME TestNARDeduplicationMetadataUploadBug1276 metadata_upload_test.go:54: Retrieved narinfo from S3:1277 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestNARDeduplicationMetadataUploadBug1609594630/001/store/cd25sawm2n1vsv9qdy6qdx3svkia8fyc-file1.txt1278 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1279 Compression: zstd1280 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1281 NarSize: 1601282 References: 1283 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1284 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1285 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1286 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1287 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/2/scratch/8135d018037c16fe/build/TestNARDeduplicationMetadataUploadBug1609594630/001/store/lb8fpvjpklacl7cr4g9cpzqwh46rl8a4-file2.txt1288--- PASS: TestReadProxyNarinfoAlreadyDecompressed (9.64s)1289=== CONT TestGCAdvisoryLockBlocksConcurrentRun12902026/11/01 17:34:57 INFO Received push request method=POST path=/api/pushes12912026/11/01 17:34:57 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12922026/11/01 17:34:57 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12932026/11/01 17:34:57 WARN Failed to register uploaded object key=lb8fpvjpklacl7cr4g9cpzqwh46rl8a4.ls error="server returned 404: 404 page not found\n"12942026/11/01 17:34:57 INFO Signed narinfos id=2 count=112952026/11/01 17:34:57 INFO Uploading 1 narinfos12962026/11/01 17:34:57 INFO Received complete push request method=POST path=/api/pushes/2/complete12972026/11/01 17:34:57 WARN Failed to register uploaded object key=lb8fpvjpklacl7cr4g9cpzqwh46rl8a4.narinfo error="server returned 404: 404 page not found\n"12982026/11/01 17:34:57 INFO Completed push id=2 objects=3 duration=1.510375ms12992026/11/01 17:34:58 INFO Upload complete. (190ms)1300=== NAME TestNARDeduplicationMetadataUploadBug1301 metadata_upload_test.go:76: Retrieved narinfo from S3:1302 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestNARDeduplicationMetadataUploadBug1609594630/001/store/lb8fpvjpklacl7cr4g9cpzqwh46rl8a4-file2.txt1303 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1304 Compression: zstd1305 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1306 NarSize: 1601307 References: 1308 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1309 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1310 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1311 {"version":1,"root":{"type":"regular","size":44}}1312--- PASS: TestNARDeduplicationMetadataUploadBug (11.41s)1313=== CONT TestPush_RootsAreLockedInByteOrder13142026/11/01 17:34:58 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1315--- PASS: TestReadProxyNarinfo (9.79s)1316=== CONT TestClientMultipleUploads13172026/11/01 17:34:58 WARN readiness check failed error="closed pool"1318--- PASS: TestService_readinessHandler (9.87s)1319=== CONT TestService_ReadScope_PublicByDefault1320--- PASS: TestReadProxyOutlastsServerWriteTimeout (13.87s)1321=== CONT TestClientIntegration1322--- PASS: TestPresentRefreshesOnlyStaleClosures (8.84s)1323=== CONT TestLeadIncumbentAnnouncesAtOnce1324--- PASS: TestService_healthCheckHandler (9.34s)1325=== CONT TestClientErrorHandling1326=== RUN TestClientErrorHandling/InvalidStorePath1327=== PAUSE TestClientErrorHandling/InvalidStorePath1328=== RUN TestClientErrorHandling/InvalidAuthToken1329=== PAUSE TestClientErrorHandling/InvalidAuthToken1330=== RUN TestClientErrorHandling/ServerNotAvailable1331=== PAUSE TestClientErrorHandling/ServerNotAvailable1332=== CONT TestClientCADerivations13332026/11/01 17:34:59 INFO lead: acquired remote=192.0.2.1:123413342026/11/01 17:34:59 INFO Received uploads request method=POST path=/api/pending_closures1335--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (8.83s)1336=== CONT TestCacheStatsHandler13372026/11/01 17:35:00 INFO Aborted multipart uploads count=0 kept=013382026/11/01 17:35:00 WARN Force mode enabled - objects will be deleted immediately without grace period13392026/11/01 17:35:00 INFO lead: released remote=192.0.2.1:12341340--- PASS: TestLeadEndsOnShutdown (10.01s)1341=== CONT TestCacheConfigHandler1342=== RUN TestCacheConfigHandler/full_config,_no_issuer1343=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1344=== RUN TestCacheConfigHandler/no_cache_url_configured1345=== PAUSE TestCacheConfigHandler/no_cache_url_configured1346=== RUN TestCacheConfigHandler/no_signing_keys1347=== PAUSE TestCacheConfigHandler/no_signing_keys1348=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1349=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1350=== CONT TestService_ReadAuthMiddleware13512026/11/01 17:35:01 INFO Aborted multipart uploads count=0 kept=013522026/11/01 17:35:01 WARN Force mode enabled - objects will be deleted immediately without grace period13532026/11/01 17:35:01 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=013542026/11/01 17:35:01 INFO Vacuumed table table=pending_closures13552026/11/01 17:35:01 INFO Vacuumed table table=pending_objects13562026/11/01 17:35:01 INFO Vacuumed table table=multipart_uploads13572026/11/01 17:35:01 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=013582026/11/01 17:35:01 INFO Vacuumed table table=closures13592026/11/01 17:35:01 INFO Vacuumed table table=objects13602026/11/01 17:35:01 INFO Vacuumed table table=pending_closures13612026/11/01 17:35:01 INFO Vacuumed table table=pending_objects13622026/11/01 17:35:01 INFO Vacuumed table table=multipart_uploads13632026/11/01 17:35:01 INFO Vacuumed table table=closures13642026/11/01 17:35:01 INFO Received uploads request method=POST path=/api/pending_closures1365--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.96s)1366=== CONT TestService_RequireScope_OIDC13672026/11/01 17:35:01 INFO Vacuumed table table=objects1368--- PASS: TestGCSweepDeliversEachKeyOnce (9.22s)1369=== CONT TestService_AuthMiddleware_OIDC1370--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.41s)1371=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13722026/11/01 17:35:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53882/oidc13732026/11/01 17:35:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:53884/oidc13742026/11/01 17:35:01 INFO Received uploads request method=POST path=/api/pending_closures13752026/11/01 17:35:02 INFO Aborted multipart uploads count=0 kept=013762026/11/01 17:35:02 WARN Force mode enabled - objects will be deleted immediately without grace period1377--- PASS: TestPushWaitsForSweepHoldingRow (9.24s)1378=== CONT TestLeadElectsOneAndHandsOver13792026/11/01 17:35:02 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=013802026/11/01 17:35:02 INFO Vacuumed table table=pending_closures13812026/11/01 17:35:02 INFO Vacuumed table table=pending_objects13822026/11/01 17:35:02 INFO Vacuumed table table=multipart_uploads13832026/11/01 17:35:02 INFO Vacuumed table table=closures13842026/11/01 17:35:02 INFO Vacuumed table table=objects1385--- PASS: TestSweepRechecksPendingAfterLocking (8.75s)1386=== CONT TestConnectWaitsForAPeerMigration1387--- PASS: TestGetExistingObjectsLocksRows (8.50s)1388=== CONT TestResolveDBConnectionString1389=== RUN TestResolveDBConnectionString/flag_wins1390=== PAUSE TestResolveDBConnectionString/flag_wins1391=== RUN TestResolveDBConnectionString/file_when_flag_empty1392=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1393=== RUN TestResolveDBConnectionString/missing_file_is_an_error1394=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1395=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1396=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1397=== RUN TestResolveDBConnectionString/nothing_configured1398=== PAUSE TestResolveDBConnectionString/nothing_configured1399=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1400--- PASS: TestRegisterCompletedObjectNeedsPendingRow (7.74s)1401=== CONT TestService_AuthMiddleware_MTLSProxyHeader1402=== NAME TestOrphanedObjectsGCStressTest1403 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1404 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion14052026/11/01 17:35:02 INFO Aborted multipart uploads count=0 kept=014062026/11/01 17:35:02 WARN Force mode enabled - objects will be deleted immediately without grace period14072026/11/01 17:35:02 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=014082026/11/01 17:35:02 INFO Vacuumed table table=pending_closures14092026/11/01 17:35:02 INFO Vacuumed table table=pending_objects14102026/11/01 17:35:02 INFO Vacuumed table table=multipart_uploads14112026/11/01 17:35:02 INFO Vacuumed table table=closures14122026/11/01 17:35:03 INFO Vacuumed table table=objects14132026/11/01 17:35:03 INFO Aborted multipart uploads count=0 kept=014142026/11/01 17:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period14152026/11/01 17:35:03 INFO Received uploads request method=POST path=/api/pending_closures14162026/11/01 17:35:03 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=014172026/11/01 17:35:03 INFO Vacuumed table table=pending_closures14182026/11/01 17:35:03 INFO Vacuumed table table=pending_objects14192026/11/01 17:35:03 INFO Vacuumed table table=multipart_uploads14202026/11/01 17:35:03 INFO Vacuumed table table=closures14212026/11/01 17:35:03 INFO Vacuumed table table=objects1422--- PASS: TestSweepSkipsRowsLockedByPush (7.99s)1423=== CONT TestClientSharedPathCommittedMidPush14242026/11/01 17:35:03 INFO Aborted multipart uploads count=0 kept=014252026/11/01 17:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period14262026/11/01 17:35:03 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14272026/11/01 17:35:03 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1428--- PASS: TestFailedS3DeleteKeepsTombstone (8.08s)1429=== CONT TestClientWithDependencies14302026/11/01 17:35:03 INFO Received uploads request method=POST path=/api/pending_closures14312026/11/01 17:35:03 INFO Aborted multipart uploads count=0 kept=014322026/11/01 17:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/11/01 17:35:03 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=014342026/11/01 17:35:03 INFO Vacuumed table table=pending_closures14352026/11/01 17:35:03 INFO Vacuumed table table=pending_objects14362026/11/01 17:35:03 INFO Vacuumed table table=multipart_uploads14372026/11/01 17:35:03 INFO Vacuumed table table=closures14382026/11/01 17:35:03 INFO Vacuumed table table=objects1439--- PASS: TestGCSweepSkipsPendingObjects (8.32s)1440=== CONT TestClientFallsBackToClosures14412026/11/01 17:35:03 INFO Aborted multipart uploads count=0 kept=014422026/11/01 17:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period14432026/11/01 17:35:03 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=014442026/11/01 17:35:03 INFO Vacuumed table table=pending_closures14452026/11/01 17:35:03 INFO Vacuumed table table=pending_objects14462026/11/01 17:35:03 INFO Vacuumed table table=multipart_uploads14472026/11/01 17:35:03 INFO Vacuumed table table=closures14482026/11/01 17:35:03 INFO Vacuumed table table=objects1449--- PASS: TestGCMetrics (7.98s)1450=== CONT TestDeleteClosuresRacingPins1451--- PASS: TestGCBugBareHashReferences (7.60s)1452=== CONT TestClientPushesUseOnePush14532026/11/01 17:35:04 INFO Received uploads request method=POST path=/api/pending_closures1454--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.55s)1455=== CONT TestPinProtectsFromGC14562026/11/01 17:35:04 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld2 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1457--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.17s)1458=== CONT TestPendingClosureWriteTimeout/empty1459=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14602026/11/01 17:35:05 INFO Received uploads request method=POST path=/api/pending_closures14612026/11/01 17:35:05 INFO Received push request method=POST path=/api/pushes14622026/11/01 17:35:05 INFO Aborted multipart uploads count=0 kept=014632026/11/01 17:35:05 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=014642026/11/01 17:35:05 INFO Vacuumed table table=pending_closures14652026/11/01 17:35:05 INFO Vacuumed table table=pending_objects14662026/11/01 17:35:05 INFO Vacuumed table table=multipart_uploads14672026-11-01 17:35:05.928 UTC [12055] ERROR: could not obtain lock on row in relation "closures"14682026-11-01 17:35:05.928 UTC [12055] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14692026-11-01 17:35:05.945 UTC [12055] ERROR: could not obtain lock on row in relation "closures"14702026-11-01 17:35:05.945 UTC [12055] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14712026-11-01 17:35:05.946 UTC [12055] ERROR: could not obtain lock on row in relation "closures"14722026-11-01 17:35:05.946 UTC [12055] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14732026-11-01 17:35:05.951 UTC [12055] ERROR: could not obtain lock on row in relation "closures"14742026-11-01 17:35:05.951 UTC [12055] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14752026-11-01 17:35:05.952 UTC [12055] ERROR: could not obtain lock on row in relation "closures"14762026-11-01 17:35:05.952 UTC [12055] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14772026/11/01 17:35:05 INFO Vacuumed table table=closures1478--- PASS: TestPush_RootsAreLockedInByteOrder (7.87s)1479=== CONT TestPendingClosureWriteTimeout/670k_objects14802026/11/01 17:35:06 INFO Vacuumed table table=objects1481=== CONT TestPendingClosureWriteTimeout/400_objects1482=== CONT TestProxyWriteTimeout/narinfo1483=== CONT TestProxyWriteTimeout/10_GiB_nar1484=== CONT TestProxyWriteTimeout/unknown_size1485=== CONT TestProxyWriteTimeout/1_GiB_nar1486--- PASS: TestProxyWriteTimeout (0.00s)1487 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1488 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1489 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1490 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1491=== CONT TestIsValidUploadKey/narinfo1492=== CONT TestIsValidUploadKey/build_log_plus_in_name14932026/11/01 17:35:06 INFO Aborted multipart uploads count=0 kept=01494=== CONT TestIsValidUploadKey/nix-cache-info1495=== CONT TestIsValidUploadKey/realisation_plus_in_output1496=== CONT TestIsValidUploadKey/realisation1497=== CONT TestIsValidUploadKey/build_log_equals1498=== CONT TestIsValidUploadKey/build_log_question_mark1499=== CONT TestIsValidUploadKey/listing15002026/11/01 17:35:06 WARN Force mode enabled - objects will be deleted immediately without grace period1501=== CONT TestIsValidUploadKey/build_log_home-manager_file15022026/11/01 17:35:06 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=01503=== CONT TestIsValidUploadKey/build_log1504=== CONT TestIsValidUploadKey/absolute1505=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1506=== CONT TestIsValidUploadKey/traversal_nar1507=== CONT TestIsValidUploadKey/traversal1508=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1509=== CONT TestIsValidUploadKey/index.html1510=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1511=== CONT TestIsValidUploadKey/nar_xz1512=== CONT TestIsValidUploadKey/nar_plain1513=== CONT TestIsValidUploadKey/nar_zst1514=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15152026/11/01 17:35:06 INFO Received uploads request method=POST path=/1516=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15172026/11/01 17:35:06 INFO Received request for more parts method=POST path=/1518=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15192026/11/01 17:35:06 INFO Received complete multipart upload request method=POST path=/1520=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15212026/11/01 17:35:06 INFO Vacuumed table table=pending_closures15222026/11/01 17:35:06 INFO Received uploads request method=POST path=/1523--- PASS: TestUploadHandlersRejectInvalidKeys (0.05s)1524 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1525 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1526 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1527 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1528=== CONT TestIsValidUploadKey/unknown_type1529=== CONT TestIsValidUploadKey/empty_key1530--- PASS: TestIsValidUploadKey (0.05s)1531 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1532 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1533 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1534 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1535 --- PASS: TestIsValidUploadKey/realisation (0.00s)1536 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1537 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1538 --- PASS: TestIsValidUploadKey/listing (0.00s)1539 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1540 --- PASS: TestIsValidUploadKey/build_log (0.00s)1541 --- PASS: TestIsValidUploadKey/absolute (0.00s)1542 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1543 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1544 --- PASS: TestIsValidUploadKey/traversal (0.00s)1545 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1546 --- PASS: TestIsValidUploadKey/index.html (0.00s)1547 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1548 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1549 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1550 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1551 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1552 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1553=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15542026/11/01 17:35:06 INFO Received uploads request method=POST path=/15552026/11/01 17:35:06 INFO Vacuumed table table=pending_objects15562026/11/01 17:35:06 INFO Vacuumed table table=multipart_uploads15572026/11/01 17:35:06 INFO Vacuumed table table=closures15582026/11/01 17:35:06 INFO Vacuumed table table=objects1559--- PASS: TestService_ReadScope_PublicByDefault (7.59s)1560--- PASS: TestPushDedupSurvivesConcurrentGC (8.53s)1561=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1562=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15632026/11/01 17:35:06 INFO Received complete multipart upload request method=POST path=/15642026/11/01 17:35:06 INFO Received request for more parts method=POST path=/1565=== CONT TestPush_RejectsBadRequests/no_roots15662026/11/01 17:35:06 INFO Received push request method=POST path=/api/pushes1567=== CONT TestPush_RejectsBadRequests/bad_root1568=== CONT TestPush_RejectsBadRequests/root_not_in_objects15692026/11/01 17:35:06 INFO Received push request method=POST path=/api/pushes15702026/11/01 17:35:06 INFO Received push request method=POST path=/api/pushes1571=== CONT TestPush_RejectsBadRequests/no_objects15722026/11/01 17:35:06 INFO Received push request method=POST path=/api/pushes1573=== CONT TestServerTLSConfig/not_a_PEM_file1574=== CONT TestServerTLSConfig/no_client_CA1575=== CONT TestServerTLSConfig/missing_CA_file1576--- PASS: TestPush_RejectsBadRequests (3.16s)1577 --- PASS: TestPush_RejectsBadRequests/no_roots (0.03s)1578 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1579 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1580 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1581=== CONT TestIsValidCachePath/narinfo1582=== CONT TestIsValidCachePath/index.html1583=== CONT TestIsValidCachePath/short_hash1584=== CONT TestIsValidCachePath/leading_slash1585=== CONT TestIsValidCachePath/empty1586--- PASS: TestServerTLSConfig (0.00s)1587 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1588 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1589 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.17s)1590=== CONT TestIsValidCachePath/wrong_extension1591=== CONT TestIsValidCachePath/random_path1592=== CONT TestIsValidCachePath/invalid_char_u1593=== CONT TestIsValidCachePath/invalid_char_e1594=== CONT TestIsValidCachePath/traversal_in_middle1595=== CONT TestIsValidCachePath/traversal_parent1596=== CONT TestIsValidCachePath/nar_uncompressed1597=== CONT TestIsValidCachePath/nix-cache-info1598=== CONT TestIsValidCachePath/realisation1599=== CONT TestIsValidCachePath/log1600=== CONT TestIsValidCachePath/ls1601=== CONT TestIsValidCachePath/nar_xz1602=== CONT TestIsValidCachePath/nar_bz21603=== CONT TestIsValidCachePath/nar_zst1604=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1605=== CONT TestParseSingleRange/none1606=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1607--- PASS: TestIsValidCachePath (0.07s)1608 --- PASS: TestIsValidCachePath/narinfo (0.00s)1609 --- PASS: TestIsValidCachePath/index.html (0.00s)1610 --- PASS: TestIsValidCachePath/short_hash (0.00s)1611 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1612 --- PASS: TestIsValidCachePath/empty (0.00s)1613 --- PASS: TestIsValidCachePath/random_path (0.00s)1614 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1615 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1616 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1617 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1618 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1619 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1620 --- PASS: TestIsValidCachePath/realisation (0.00s)1621 --- PASS: TestIsValidCachePath/log (0.00s)1622 --- PASS: TestIsValidCachePath/ls (0.00s)1623 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1624 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1625 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1626 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1627 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1628=== CONT TestParseSingleRange/start_far_past_EOF1629=== CONT TestParseSingleRange/start_past_EOF1630=== CONT TestParseSingleRange/single_byte1631=== CONT TestParseSingleRange/suffix_exceeds_size1632=== CONT TestParseSingleRange/suffix1633=== CONT TestParseSingleRange/end_clamped_to_size1634=== CONT TestParseSingleRange/open-ended1635=== CONT TestParseSingleRange/closed1636=== CONT TestParseSingleRange/malformed_end_before_start1637=== CONT TestParseSingleRange/malformed_both_empty1638=== CONT TestParseSingleRange/malformed_no_dash1639=== CONT TestParseSingleRange/multi-range_ignored1640=== CONT TestParseSingleRange/unknown_unit1641--- PASS: TestParseSingleRange (0.04s)1642 --- PASS: TestParseSingleRange/none (0.00s)1643 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1644 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1645 --- PASS: TestParseSingleRange/single_byte (0.00s)1646 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1647 --- PASS: TestParseSingleRange/suffix (0.00s)1648 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1649 --- PASS: TestParseSingleRange/open-ended (0.00s)1650 --- PASS: TestParseSingleRange/closed (0.00s)1651 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1652 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1653 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1654 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1655 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1656=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1657--- PASS: TestUploadHandlersRejectOversizedBody (0.15s)1658 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1659 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)1660 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.84s)1661=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1662=== NAME TestClientMultipleUploads1663 client_integration_test.go:405: Created store path 0: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientMultipleUploads2704586156/001/store/jjsikzxazbg81a24zhgz0h24klgd3fsq-test-file-0.txt1664 client_integration_test.go:405: Created store path 1: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientMultipleUploads2704586156/001/store/4s0bbw2wfjpw4vg8rr8wy56hwxnqfsyj-test-file-1.txt1665 client_integration_test.go:405: Created store path 2: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientMultipleUploads2704586156/001/store/3z49v6xhqg5dlgifvisyis3fk9vqs886-test-file-2.txt1666=== NAME TestClientIntegration1667 client_integration_test.go:291: Created store path: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientIntegration3642738497/002/store/m45ihavmkc1w0v4lnlwr82vyfz41hb0f-test-file.txt16682026/11/01 17:35:08 INFO lead: acquired remote=192.0.2.1:123416692026/11/01 17:35:08 INFO lead: released remote=192.0.2.1:12341670--- PASS: TestLeadIncumbentAnnouncesAtOnce (9.04s)1671=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16722026/11/01 17:35:08 INFO Received push request method=POST path=/api/pushes16732026/11/01 17:35:08 INFO Received push request method=POST path=/api/pushes16742026/11/01 17:35:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16752026/11/01 17:35:08 INFO Uploading m45ihavmkc1w0v4lnlwr82vyfz41hb0f-test-file.txt (152B)16762026/11/01 17:35:08 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16772026/11/01 17:35:08 INFO Uploading jjsikzxazbg81a24zhgz0h24klgd3fsq-test-file-0.txt (160B)16782026/11/01 17:35:08 INFO Uploading 3z49v6xhqg5dlgifvisyis3fk9vqs886-test-file-2.txt (160B)16792026/11/01 17:35:08 INFO Uploading 4s0bbw2wfjpw4vg8rr8wy56hwxnqfsyj-test-file-1.txt (160B)16802026/11/01 17:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16812026/11/01 17:35:08 WARN Failed to register uploaded object key=m45ihavmkc1w0v4lnlwr82vyfz41hb0f.ls error="server returned 404: 404 page not found\n"16822026/11/01 17:35:08 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16832026/11/01 17:35:08 INFO Signed narinfos id=1 count=116842026/11/01 17:35:08 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16852026/11/01 17:35:08 INFO Uploading 1 narinfos16862026/11/01 17:35:08 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16872026/11/01 17:35:08 WARN Failed to register uploaded object key=jjsikzxazbg81a24zhgz0h24klgd3fsq.ls error="server returned 404: 404 page not found\n"16882026/11/01 17:35:08 WARN Failed to register uploaded object key=4s0bbw2wfjpw4vg8rr8wy56hwxnqfsyj.ls error="server returned 404: 404 page not found\n"16892026/11/01 17:35:08 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16902026/11/01 17:35:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16912026/11/01 17:35:08 WARN Failed to register uploaded object key=3z49v6xhqg5dlgifvisyis3fk9vqs886.ls error="server returned 404: 404 page not found\n"16922026/11/01 17:35:08 INFO Signed narinfos id=1 count=316932026/11/01 17:35:08 INFO Uploading 3 narinfos16942026/11/01 17:35:08 INFO Received complete push request method=POST path=/api/pushes/1/complete16952026/11/01 17:35:08 WARN Failed to register uploaded object key=m45ihavmkc1w0v4lnlwr82vyfz41hb0f.narinfo error="server returned 404: 404 page not found\n"16962026/11/01 17:35:08 WARN Failed to register uploaded object key=4s0bbw2wfjpw4vg8rr8wy56hwxnqfsyj.narinfo error="server returned 404: 404 page not found\n"16972026/11/01 17:35:08 INFO Completed push id=1 objects=3 duration=62.448375ms16982026/11/01 17:35:08 INFO Received complete push request method=POST path=/api/pushes/1/complete16992026/11/01 17:35:08 WARN Failed to register uploaded object key=3z49v6xhqg5dlgifvisyis3fk9vqs886.narinfo error="server returned 404: 404 page not found\n"17002026/11/01 17:35:08 WARN Failed to register uploaded object key=jjsikzxazbg81a24zhgz0h24klgd3fsq.narinfo error="server returned 404: 404 page not found\n"17012026/11/01 17:35:08 INFO Upload complete. (797ms)17022026/11/01 17:35:08 INFO Completed push id=1 objects=9 duration=42.691583ms17032026/11/01 17:35:08 INFO Upload complete. (862ms)1704=== NAME TestClientMultipleUploads1705 client_integration_test.go:416: Uploaded 3 paths in 928.795ms17062026/11/01 17:35:08 INFO All 1 paths already cached1707=== NAME TestClientIntegration1708 client_integration_test.go:317: Retrieved narinfo from S3:1709 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientIntegration3642738497/002/store/m45ihavmkc1w0v4lnlwr82vyfz41hb0f-test-file.txt1710 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1711 Compression: zstd1712 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11713 NarSize: 1521714 References: 1715 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11716 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1717 client_integration_test.go:318: Decompressed .ls content (64 bytes):1718 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1719--- PASS: TestClientMultipleUploads (10.76s)1720=== CONT TestGCEndsOnShutdown/before_the_run1721--- PASS: TestCacheStatsHandler (9.11s)1722=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17232026/11/01 17:35:09 INFO Received push request method=POST path=/api/pushes17242026/11/01 17:35:09 INFO Object in database but missing from S3 key=m45ihavmkc1w0v4lnlwr82vyfz41hb0f.ls17252026/11/01 17:35:09 WARN Found objects in DB but missing from S3, will re-upload count=117262026/11/01 17:35:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1727=== NAME TestClientCADerivations1728 client_ca_test.go:136: Built CA derivation: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientCADerivations3681144609/001/store/wizba1p4k4wkv3fv6ghxcd2dsm94px8m-ca-test17292026/11/01 17:35:09 INFO Received complete push request method=POST path=/api/pushes/2/complete17302026/11/01 17:35:09 WARN Failed to register uploaded object key=m45ihavmkc1w0v4lnlwr82vyfz41hb0f.ls error="server returned 404: 404 page not found\n"17312026/11/01 17:35:09 INFO Completed push id=2 objects=3 duration=1.029375ms17322026/11/01 17:35:09 INFO Upload complete. (247ms)1733=== NAME TestClientIntegration1734 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1735 client_integration_test.go:335: Decompressed .ls content (49 bytes):1736 {"version":1,"root":{"type":"regular","size":39}}1737--- PASS: TestService_ReadAuthMiddleware (9.02s)1738=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1739=== NAME TestClientCADerivations1740 client_ca_test.go:139: Found 1 dependencies (including self)17412026/11/01 17:35:10 INFO Received push request method=POST path=/api/pushes17422026/11/01 17:35:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17432026/11/01 17:35:10 INFO Uploading wizba1p4k4wkv3fv6ghxcd2dsm94px8m-ca-test (144B)17442026/11/01 17:35:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17452026/11/01 17:35:10 WARN Failed to register uploaded object key=wizba1p4k4wkv3fv6ghxcd2dsm94px8m.ls error="server returned 404: 404 page not found\n"17462026/11/01 17:35:10 WARN mTLS auth: bound subjects configured but subject DN unavailable17472026/11/01 17:35:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1748--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (8.97s)1749=== CONT TestClientErrorHandling/InvalidStorePath17502026/11/01 17:35:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17512026/11/01 17:35:10 WARN Failed to register uploaded object key=log/2pbj2y8id31rx62fbyyap5inggn23rm5-ca-test.drv error="server returned 404: 404 page not found\n"17522026/11/01 17:35:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17532026/11/01 17:35:10 INFO Signed narinfos id=1 count=117542026/11/01 17:35:10 INFO Uploading 1 narinfos1755--- PASS: TestConnectWaitsForAPeerMigration (8.10s)1756=== CONT TestClientErrorHandling/ServerNotAvailable17572026/11/01 17:35:10 INFO Received push request method=POST path=/api/pushes17582026/11/01 17:35:10 INFO Received complete push request method=POST path=/api/pushes/1/complete17592026/11/01 17:35:10 WARN Failed to register uploaded object key=wizba1p4k4wkv3fv6ghxcd2dsm94px8m.narinfo error="server returned 404: 404 page not found\n"17602026/11/01 17:35:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17612026/11/01 17:35:10 INFO Completed push id=1 objects=4 duration=47.988417ms17622026/11/01 17:35:10 INFO Upload complete. (714ms)1763=== NAME TestClientCADerivations1764 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientCADerivations3681144609/001/store/wizba1p4k4wkv3fv6ghxcd2dsm94px8m-ca-test1765 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1766 Compression: zstd1767 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1768 NarSize: 1441769 References: 1770 Deriver: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientCADerivations3681144609/001/store/2pbj2y8id31rx62fbyyap5inggn23rm5-ca-test.drv1771 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1772 client_ca_test.go:185: Checking for realisation files in S3...1773 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1774 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17752026/11/01 17:35:10 INFO Received complete push request method=POST path=/api/pushes/3/complete17762026/11/01 17:35:10 WARN Failed to register uploaded object key=m45ihavmkc1w0v4lnlwr82vyfz41hb0f.ls error="server returned 404: 404 page not found\n"17772026/11/01 17:35:10 INFO Completed push id=3 objects=3 duration=1.274916ms17782026/11/01 17:35:10 INFO Upload complete. (417ms)1779=== NAME TestClientIntegration1780 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1781 client_integration_test.go:352: Decompressed .ls content (49 bytes):1782 {"version":1,"root":{"type":"regular","size":39}}1783 client_integration_test.go:363: Testing garbage collection...17842026/11/01 17:35:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures17852026/11/01 17:35:10 INFO Garbage collection started1786=== NAME TestClientCADerivations1787 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket76?endpoint=http://localhost:53649®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/2/scratch/8135d018037c16fe/build/TestClientCADerivations3681144609/001/store'1788 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117892026/11/01 17:35:10 INFO Aborted multipart uploads count=0 kept=01790--- PASS: TestClientCADerivations (11.68s)1791=== CONT TestClientErrorHandling/InvalidAuthToken17922026/11/01 17:35:10 WARN Force mode enabled - objects will be deleted immediately without grace period1793=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1794=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1795=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1796=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1797=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1798=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1799=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1800=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1801=== CONT TestCacheConfigHandler/full_config,_no_issuer1802=== CONT TestCacheConfigHandler/no_signing_keys1803=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1804=== CONT TestCacheConfigHandler/no_cache_url_configured1805--- PASS: TestCacheConfigHandler (0.02s)1806 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1807 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1808 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1809 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1810=== CONT TestResolveDBConnectionString/flag_wins1811=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1812=== CONT TestResolveDBConnectionString/nothing_configured1813=== CONT TestResolveDBConnectionString/missing_file_is_an_error1814=== CONT TestResolveDBConnectionString/file_when_flag_empty1815=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1816--- PASS: TestResolveDBConnectionString (0.01s)1817 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1818 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1819 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1820 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1821 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1822=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18232026/11/01 17:35:11 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]1824=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1825=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18262026/11/01 17:35:11 WARN Authentication failed token_preview=eyJhbGciOi...b7MOz0UEYA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1827--- PASS: TestService_AuthMiddleware_OIDC (9.71s)1828 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1829 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)1830 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1831 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)18322026/11/01 17:35:11 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/present18332026/11/01 17:35:11 WARN Request failed, retrying attempt=2 backoff=214.115984ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18342026/11/01 17:35:11 WARN Request failed, retrying attempt=3 backoff=407.635407ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18352026/11/01 17:35:11 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=01836=== RUN TestService_RequireScope_OIDC/builder_may_write1837=== PAUSE TestService_RequireScope_OIDC/builder_may_write1838=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1839=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1840=== RUN TestService_RequireScope_OIDC/ops_may_admin1841=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1842=== RUN TestService_RequireScope_OIDC/ops_may_not_write1843=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1844=== RUN TestService_RequireScope_OIDC/reader_may_not_write1845=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1846=== RUN TestService_RequireScope_OIDC/static_token_may_admin1847=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1848=== RUN TestService_RequireScope_OIDC/static_token_may_write1849=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1850=== RUN TestService_RequireScope_OIDC/reader_may_read1851=== PAUSE TestService_RequireScope_OIDC/reader_may_read1852=== RUN TestService_RequireScope_OIDC/writer_implies_read1853=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1854=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1855=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1856=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1857=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1858=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1859=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1860=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1861=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1862=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1863=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1864=== CONT TestService_RequireScope_OIDC/builder_may_write1865=== CONT TestService_RequireScope_OIDC/reader_may_read1866=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1867=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1868=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18692026/11/01 17:35:11 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]1870=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1871=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1872=== CONT TestService_RequireScope_OIDC/reader_may_not_write1873=== CONT TestService_RequireScope_OIDC/static_token_may_write1874=== CONT TestService_RequireScope_OIDC/ops_may_admin1875=== CONT TestService_RequireScope_OIDC/ops_may_not_write1876=== CONT TestService_RequireScope_OIDC/static_token_may_admin1877=== CONT TestService_RequireScope_OIDC/writer_implies_read1878=== CONT TestService_RequireScope_OIDC/builder_may_not_admin18792026/11/01 17:35:11 INFO Vacuumed table table=pending_closures1880--- PASS: TestService_RequireScope_OIDC (10.27s)1881 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1882 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1883 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1884 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1885 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1886 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1887 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)18952026/11/01 17:35:11 INFO Vacuumed table table=pending_objects18962026/11/01 17:35:11 INFO Vacuumed table table=multipart_uploads18972026/11/01 17:35:11 INFO Vacuumed table table=closures18982026/11/01 17:35:11 INFO Vacuumed table table=objects18992026/11/01 17:35:11 WARN Request failed, retrying attempt=4 backoff=807.861268ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19002026/11/01 17:35:11 INFO lead: acquired remote=192.0.2.1:12341901--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (9.89s)19022026/11/01 17:35:12 WARN Request failed, retrying attempt=5 backoff=1.578708325s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19032026/11/01 17:35:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01904=== NAME TestClientIntegration1905 client_integration_test.go:370: Objects in database after GC:1906 client_integration_test.go:370: Successfully deleted all objects with GC --force1907--- PASS: TestClientIntegration (14.14s)19082026/11/01 17:35:13 INFO lead: released remote=192.0.2.1:123419092026/11/01 17:35:13 INFO lead: acquired remote=192.0.2.1:123419102026/11/01 17:35:13 INFO Received push request method=POST path=/api/pushes1911--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (11.17s)19122026/11/01 17:35:13 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19132026/11/01 17:35:13 INFO Uploading 2073hvrqgpwfg435xv5inhwa10gqpppa-top (264B)19142026/11/01 17:35:13 INFO Uploading dsil8x9ans9mg7b59g2fk8mracls7pmf-shared-dep (136B)19152026/11/01 17:35:13 WARN Failed to register uploaded object key=nar/1mjs722y30jyi26hsp1ixsq8wbqah6m170j24fvnh1ar7zv5gpsc.nar.zst error="server returned 404: 404 page not found\n"19162026/11/01 17:35:13 WARN Failed to register uploaded object key=2073hvrqgpwfg435xv5inhwa10gqpppa.ls error="server returned 404: 404 page not found\n"19172026/11/01 17:35:13 WARN Failed to register uploaded object key=dsil8x9ans9mg7b59g2fk8mracls7pmf.ls error="server returned 404: 404 page not found\n"19182026/11/01 17:35:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19192026/11/01 17:35:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19202026/11/01 17:35:13 INFO Signed narinfos id=1 count=219212026/11/01 17:35:13 INFO Uploading 2 narinfos19222026/11/01 17:35:13 INFO Received complete push request method=POST path=/api/pushes/1/complete19232026/11/01 17:35:13 WARN Failed to register uploaded object key=dsil8x9ans9mg7b59g2fk8mracls7pmf.narinfo error="server returned 404: 404 page not found\n"19242026/11/01 17:35:13 WARN Failed to register uploaded object key=2073hvrqgpwfg435xv5inhwa10gqpppa.narinfo error="server returned 404: 404 page not found\n"19252026/11/01 17:35:13 INFO Completed push id=1 objects=6 duration=46.315625ms19262026/11/01 17:35:14 INFO Upload complete. (570ms)1927=== NAME TestClientSharedPathCommittedMidPush1928 client_integration_test.go:727: Retrieved narinfo from S3:1929 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientSharedPathCommittedMidPush1565735835/001/store/dsil8x9ans9mg7b59g2fk8mracls7pmf-shared-dep1930 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1931 Compression: zstd1932 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821933 NarSize: 1361934 References: 1935 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1936 client_integration_test.go:727: Retrieved narinfo from S3:1937 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientSharedPathCommittedMidPush1565735835/001/store/2073hvrqgpwfg435xv5inhwa10gqpppa-top1938 URL: nar/1mjs722y30jyi26hsp1ixsq8wbqah6m170j24fvnh1ar7zv5gpsc.nar.zst1939 Compression: zstd1940 NarHash: sha256:1mjs722y30jyi26hsp1ixsq8wbqah6m170j24fvnh1ar7zv5gpsc1941 NarSize: 2641942 References: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientSharedPathCommittedMidPush1565735835/001/store/dsil8x9ans9mg7b59g2fk8mracls7pmf-shared-dep1943 CA: text:sha256:0ihbj2rvjpngx6mjz058zziyq5rp61d2r1l953jwimv8a98wmmvc1944=== NAME TestClientWithDependencies1945 client_integration_test.go:660: Built derivation: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientWithDependencies3528337913/001/store/0q81zy8afrdsiflzw3nw415613plsw0w-test-script1946--- PASS: TestClientSharedPathCommittedMidPush (10.76s)1947=== NAME TestClientWithDependencies1948 client_integration_test.go:662: Found 1 dependencies (including self)19492026/11/01 17:35:14 INFO lead: released remote=192.0.2.1:12341950--- PASS: TestLeadElectsOneAndHandsOver (12.00s)19512026/11/01 17:35:14 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-config19522026/11/01 17:35:14 INFO Received push request method=POST path=/api/pushes19532026/11/01 17:35:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19542026/11/01 17:35:14 INFO Uploading 0q81zy8afrdsiflzw3nw415613plsw0w-test-script (136B)19552026/11/01 17:35:14 WARN Request failed, retrying attempt=2 backoff=181.977823ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19562026/11/01 17:35:14 WARN Failed to register uploaded object key=0q81zy8afrdsiflzw3nw415613plsw0w.ls error="server returned 404: 404 page not found\n"19572026/11/01 17:35:14 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19582026/11/01 17:35:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19592026/11/01 17:35:14 WARN Failed to register uploaded object key=log/lis6cwnsr80aydvk5ghbyc96jmk3g4fg-test-script.drv error="server returned 404: 404 page not found\n"19602026/11/01 17:35:14 INFO Signed narinfos id=1 count=119612026/11/01 17:35:14 INFO Uploading 1 narinfos19622026/11/01 17:35:14 INFO Received uploads request method=POST path=/api/pending_closures19632026/11/01 17:35:14 INFO Received uploads request method=POST path=/api/pending_closures19642026/11/01 17:35:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19652026/11/01 17:35:14 INFO Uploading b61rvw9fcidr00k307dh9wbzyzi3ws81-shared-dep (136B)19662026/11/01 17:35:14 INFO Uploading fgv7664jl37q5zh6bhbaaw9m22szz5lj-b (256B)19672026/11/01 17:35:14 INFO Received complete push request method=POST path=/api/pushes/1/complete19682026/11/01 17:35:14 WARN Failed to register uploaded object key=0q81zy8afrdsiflzw3nw415613plsw0w.narinfo error="server returned 404: 404 page not found\n"19692026/11/01 17:35:14 INFO Completed push id=1 objects=4 duration=38.60575ms19702026/11/01 17:35:14 INFO Upload complete. (361ms)19712026/11/01 17:35:14 WARN Request failed, retrying attempt=3 backoff=436.339574ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1972=== NAME TestClientWithDependencies1973 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/2/scratch/8135d018037c16fe/build/TestClientWithDependencies3528337913/001/store) requires matching store prefix19742026/11/01 17:35:14 WARN Failed to register uploaded object key=dfs25hsxmgmc2x1i5dsgj5arbv1w3cm8.ls error="server returned 404: 404 page not found\n"19752026/11/01 17:35:14 WARN Failed to register uploaded object key=fgv7664jl37q5zh6bhbaaw9m22szz5lj.ls error="server returned 404: 404 page not found\n"19762026/11/01 17:35:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19772026/11/01 17:35:14 WARN Failed to register uploaded object key=nar/08g5hn5dsyzn5y1wpnpk4chi0hhbzhpaspp3hpjzqfgci50ag91b.nar.zst error="server returned 404: 404 page not found\n"19782026/11/01 17:35:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign19792026/11/01 17:35:14 WARN Failed to register uploaded object key=b61rvw9fcidr00k307dh9wbzyzi3ws81.ls error="server returned 404: 404 page not found\n"19802026/11/01 17:35:14 INFO Signed narinfos id=1 count=219812026/11/01 17:35:14 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign19822026/11/01 17:35:14 INFO Signed narinfos id=2 count=219832026/11/01 17:35:14 INFO Uploading 4 narinfos19842026/11/01 17:35:14 WARN Failed to register uploaded object key=fgv7664jl37q5zh6bhbaaw9m22szz5lj.narinfo error="server returned 404: 404 page not found\n"19852026/11/01 17:35:14 WARN Failed to register uploaded object key=b61rvw9fcidr00k307dh9wbzyzi3ws81.narinfo error="server returned 404: 404 page not found\n"1986--- PASS: TestClientWithDependencies (11.31s)19872026/11/01 17:35:14 WARN Failed to register uploaded object key=dfs25hsxmgmc2x1i5dsgj5arbv1w3cm8.narinfo error="server returned 404: 404 page not found\n"19882026/11/01 17:35:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19892026/11/01 17:35:14 WARN Failed to register uploaded object key=b61rvw9fcidr00k307dh9wbzyzi3ws81.narinfo error="server returned 404: 404 page not found\n"19902026/11/01 17:35:14 INFO Completed upload id=1 objects=6 duration=7.333666ms19912026/11/01 17:35:14 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete19922026/11/01 17:35:14 INFO Completed upload id=2 objects=6 duration=1.124084ms19932026/11/01 17:35:14 INFO Upload complete. (424ms)1994=== NAME TestClientFallsBackToClosures1995 client_pushes_test.go:112: Retrieved narinfo from S3:1996 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientFallsBackToClosures2101213991/001/store/b61rvw9fcidr00k307dh9wbzyzi3ws81-shared-dep1997 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1998 Compression: zstd1999 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822000 NarSize: 1362001 References: 2002 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2003 client_pushes_test.go:112: Retrieved narinfo from S3:2004 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientFallsBackToClosures2101213991/001/store/dfs25hsxmgmc2x1i5dsgj5arbv1w3cm8-a2005 URL: nar/08g5hn5dsyzn5y1wpnpk4chi0hhbzhpaspp3hpjzqfgci50ag91b.nar.zst2006 Compression: zstd2007 NarHash: sha256:08g5hn5dsyzn5y1wpnpk4chi0hhbzhpaspp3hpjzqfgci50ag91b2008 NarSize: 2562009 References: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientFallsBackToClosures2101213991/001/store/b61rvw9fcidr00k307dh9wbzyzi3ws81-shared-dep2010 CA: text:sha256:1j8c4h9igl3mpdxa4mfgspk9dn3kdb42qxsvsay64il8cq92vxr12011 client_pushes_test.go:112: Retrieved narinfo from S3:2012 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientFallsBackToClosures2101213991/001/store/fgv7664jl37q5zh6bhbaaw9m22szz5lj-b2013 URL: nar/08g5hn5dsyzn5y1wpnpk4chi0hhbzhpaspp3hpjzqfgci50ag91b.nar.zst2014 Compression: zstd2015 NarHash: sha256:08g5hn5dsyzn5y1wpnpk4chi0hhbzhpaspp3hpjzqfgci50ag91b2016 NarSize: 2562017 References: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientFallsBackToClosures2101213991/001/store/b61rvw9fcidr00k307dh9wbzyzi3ws81-shared-dep2018 CA: text:sha256:1j8c4h9igl3mpdxa4mfgspk9dn3kdb42qxsvsay64il8cq92vxr12019--- PASS: TestClientFallsBackToClosures (11.09s)20202026/11/01 17:35:15 WARN Request failed, retrying attempt=4 backoff=832.575591ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2021=== NAME TestPinProtectsFromGC2022 client_integration_test.go:778: Pinned store path: /private/var/tb/2/scratch/8135d018037c16fe/build/TestPinProtectsFromGC1578185186/001/store/gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p-pinned-file.txt2023 client_integration_test.go:779: Unpinned store path: /private/var/tb/2/scratch/8135d018037c16fe/build/TestPinProtectsFromGC1578185186/001/store/18i3zw1svp4dabkzbl5x9grgv9hsiprd-unpinned-file.txt20242026/11/01 17:35:15 INFO Received push request method=POST path=/api/pushes20252026/11/01 17:35:15 INFO Received uploads request method=POST path=/api/pending_closures20262026/11/01 17:35:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20272026/11/01 17:35:15 INFO Uploading gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p-pinned-file.txt (128B)20282026/11/01 17:35:15 WARN Failed to register uploaded object key=gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p.ls error="server returned 404: 404 page not found\n"20292026/11/01 17:35:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20302026/11/01 17:35:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20312026/11/01 17:35:15 INFO Signed narinfos id=1 count=120322026/11/01 17:35:15 INFO Uploading 1 narinfos20332026/11/01 17:35:15 INFO Received complete push request method=POST path=/api/pushes/1/complete20342026/11/01 17:35:15 WARN Failed to register uploaded object key=gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p.narinfo error="server returned 404: 404 page not found\n"20352026/11/01 17:35:15 INFO Completed push id=1 objects=3 duration=17.662292ms20362026/11/01 17:35:15 INFO Upload complete. (324ms)20372026/11/01 17:35:15 INFO Received push request method=POST path=/api/pushes20382026/11/01 17:35:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20392026/11/01 17:35:15 INFO Uploading 18i3zw1svp4dabkzbl5x9grgv9hsiprd-unpinned-file.txt (128B)20402026/11/01 17:35:15 INFO Received push request method=POST path=/api/pushes20412026/11/01 17:35:15 WARN Failed to register uploaded object key=18i3zw1svp4dabkzbl5x9grgv9hsiprd.ls error="server returned 404: 404 page not found\n"20422026/11/01 17:35:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20432026/11/01 17:35:15 INFO Uploading l19nfggr1b6w7rhmsg614qvlbiyzanrg-shared-dep (136B)20442026/11/01 17:35:15 INFO Uploading jvmpvjc9ak6qpgd7xdywjqbma20fs7hn-b (256B)20452026/11/01 17:35:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20462026/11/01 17:35:15 INFO Signed narinfos id=2 count=120472026/11/01 17:35:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20482026/11/01 17:35:15 INFO Uploading 1 narinfos20492026/11/01 17:35:15 WARN Failed to register uploaded object key=l19nfggr1b6w7rhmsg614qvlbiyzanrg.ls error="server returned 404: 404 page not found\n"20502026/11/01 17:35:15 INFO Received complete push request method=POST path=/api/pushes/2/complete20512026/11/01 17:35:15 WARN Failed to register uploaded object key=18i3zw1svp4dabkzbl5x9grgv9hsiprd.narinfo error="server returned 404: 404 page not found\n"20522026/11/01 17:35:15 WARN Failed to register uploaded object key=nar/0yqfn86xg7czsj5x23yh10iwzxr0wycv5kcxjkkmw23cdsm5avas.nar.zst error="server returned 404: 404 page not found\n"20532026/11/01 17:35:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20542026/11/01 17:35:15 WARN Failed to register uploaded object key=jvmpvjc9ak6qpgd7xdywjqbma20fs7hn.ls error="server returned 404: 404 page not found\n"20552026/11/01 17:35:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20562026/11/01 17:35:15 WARN Failed to register uploaded object key=1vpw2w37rvs6hgzsv3np4fbw165mbbm5.ls error="server returned 404: 404 page not found\n"20572026/11/01 17:35:15 INFO Completed push id=2 objects=3 duration=4.34325ms20582026/11/01 17:35:15 INFO Signed narinfos id=1 count=320592026/11/01 17:35:15 INFO Upload complete. (292ms)20602026/11/01 17:35:15 INFO Uploading 3 narinfos20612026/11/01 17:35:15 WARN Request failed, retrying attempt=5 backoff=1.582011543s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20622026/11/01 17:35:16 WARN Failed to register uploaded object key=1vpw2w37rvs6hgzsv3np4fbw165mbbm5.narinfo error="server returned 404: 404 page not found\n"20632026/11/01 17:35:16 INFO Received complete push request method=POST path=/api/pushes/1/complete20642026/11/01 17:35:16 WARN Failed to register uploaded object key=jvmpvjc9ak6qpgd7xdywjqbma20fs7hn.narinfo error="server returned 404: 404 page not found\n"20652026/11/01 17:35:16 WARN Failed to register uploaded object key=l19nfggr1b6w7rhmsg614qvlbiyzanrg.narinfo error="server returned 404: 404 page not found\n"20662026/11/01 17:35:16 INFO Completed push id=1 objects=8 duration=16.074833ms20672026/11/01 17:35:16 INFO Upload complete. (409ms)2068=== NAME TestClientPushesUseOnePush2069 client_pushes_test.go:97: Retrieved narinfo from S3:2070 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientPushesUseOnePush2474173300/001/store/l19nfggr1b6w7rhmsg614qvlbiyzanrg-shared-dep2071 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2072 Compression: zstd2073 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822074 NarSize: 1362075 References: 2076 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n20772026/11/01 17:35:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures20782026/11/01 17:35:16 INFO Garbage collection started2079 client_pushes_test.go:97: Retrieved narinfo from S3:2080 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientPushesUseOnePush2474173300/001/store/1vpw2w37rvs6hgzsv3np4fbw165mbbm5-a2081 URL: nar/0yqfn86xg7czsj5x23yh10iwzxr0wycv5kcxjkkmw23cdsm5avas.nar.zst2082 Compression: zstd2083 NarHash: sha256:0yqfn86xg7czsj5x23yh10iwzxr0wycv5kcxjkkmw23cdsm5avas2084 NarSize: 2562085 References: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientPushesUseOnePush2474173300/001/store/l19nfggr1b6w7rhmsg614qvlbiyzanrg-shared-dep2086 CA: text:sha256:0sqnalzcrbj95k9qxrw6imsjhv88gp8qrfl09jjhanpw75rwh6l82087 client_pushes_test.go:97: Retrieved narinfo from S3:2088 StorePath: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientPushesUseOnePush2474173300/001/store/jvmpvjc9ak6qpgd7xdywjqbma20fs7hn-b2089 URL: nar/0yqfn86xg7czsj5x23yh10iwzxr0wycv5kcxjkkmw23cdsm5avas.nar.zst2090 Compression: zstd2091 NarHash: sha256:0yqfn86xg7czsj5x23yh10iwzxr0wycv5kcxjkkmw23cdsm5avas2092 NarSize: 2562093 References: /private/var/tb/2/scratch/8135d018037c16fe/build/TestClientPushesUseOnePush2474173300/001/store/l19nfggr1b6w7rhmsg614qvlbiyzanrg-shared-dep2094 CA: text:sha256:0sqnalzcrbj95k9qxrw6imsjhv88gp8qrfl09jjhanpw75rwh6l820952026/11/01 17:35:16 INFO Aborted multipart uploads count=0 kept=02096--- PASS: TestClientPushesUseOnePush (11.58s)20972026/11/01 17:35:16 WARN Force mode enabled - objects will be deleted immediately without grace period2098--- PASS: TestPendingClosureWriteTimeout (0.00s)2099 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2100 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2101 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2102 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (11.28s)21032026/11/01 17:35:16 INFO Received uploads request method=POST path=/api/pending_closures21042026/11/01 17:35:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=021052026/11/01 17:35:16 INFO Aborted multipart uploads count=0 kept=021062026/11/01 17:35:16 WARN Force mode enabled - objects will be deleted immediately without grace period21072026/11/01 17:35:16 INFO Vacuumed table table=pending_closures21082026/11/01 17:35:16 INFO Vacuumed table table=pending_objects21092026/11/01 17:35:16 INFO Vacuumed table table=multipart_uploads21102026/11/01 17:35:16 INFO Vacuumed table table=closures21112026/11/01 17:35:16 INFO Vacuumed table table=objects2112--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2113 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (9.81s)2114 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (10.01s)21152026/11/01 17:35:16 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=021162026/11/01 17:35:16 INFO Vacuumed table table=pending_closures21172026/11/01 17:35:16 INFO Vacuumed table table=pending_objects21182026/11/01 17:35:16 INFO Vacuumed table table=multipart_uploads21192026/11/01 17:35:16 INFO Vacuumed table table=closures21202026/11/01 17:35:16 INFO Vacuumed table table=objects21212026/11/01 17:35:16 INFO Received uploads request method=POST path=/api/pending_closures21222026/11/01 17:35:16 INFO Aborted multipart uploads count=0 kept=021232026/11/01 17:35:16 WARN Force mode enabled - objects will be deleted immediately without grace period21242026/11/01 17:35:16 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021252026/11/01 17:35:16 INFO Vacuumed table table=pending_closures21262026/11/01 17:35:16 INFO Vacuumed table table=pending_objects21272026/11/01 17:35:16 INFO Vacuumed table table=multipart_uploads21282026/11/01 17:35:16 INFO Vacuumed table table=closures21292026/11/01 17:35:16 INFO Vacuumed table table=objects2130--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2131 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (9.92s)2132 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (8.88s)21332026/11/01 17:35:17 INFO Aborted multipart uploads count=0 kept=021342026/11/01 17:35:17 WARN Force mode enabled - objects will be deleted immediately without grace period21352026-11-01 17:35:17.232 UTC [12431] ERROR: canceling statement due to user request21362026-11-01 17:35:17.232 UTC [12431] CONTEXT: PL/pgSQL function object_stats_update() line 2 at statement block21372026-11-01 17:35:17.232 UTC [12431] STATEMENT: -- name: MarkStaleObjects :execrows2138 WITH RECURSIVE ct AS (2139 SELECT timezone('UTC', now()) AS now2140 ),2141 closure_reach AS (2142 -- Start with all closure keys2143 SELECT o.key, o.refs2144 FROM objects o2145 INNER JOIN closures c ON o.key = c.key2146 UNION2147 -- Recursively add all referenced objects2148 SELECT o.key, o.refs2149 FROM objects o2150 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2151 ),2152 reachable_objects AS (2153 SELECT DISTINCT key FROM closure_reach2154 ),2155 stale_objects AS (2156 SELECT o.key2157 FROM objects AS o, ct2158 WHERE2159 NOT EXISTS (2160 SELECT 12161 FROM reachable_objects ro2162 WHERE ro.key = o.key2163 )2164 AND NOT EXISTS (2165 SELECT 12166 FROM pending_objects AS po2167 WHERE po.key = o.key2168 )2169 AND o.deleted_at IS NULL -- Only mark fresh objects2170 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2171 FOR UPDATE2172 )2173 UPDATE objects2174 SET2175 deleted_at = ct.now,2176 first_deleted_at = COALESCE(first_deleted_at, ct.now)2177 FROM stale_objects, ct2178 WHERE objects.key = stale_objects.key2179 2180--- PASS: TestDeleteClosuresRacingPins (13.30s)21812026/11/01 17:35:17 INFO Aborted multipart uploads count=0 kept=021822026/11/01 17:35:17 WARN Force mode enabled - objects will be deleted immediately without grace period21832026/11/01 17:35:17 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:53649/bucket98/?delete=\": context canceled"2184--- PASS: TestGCEndsOnShutdown (0.00s)2185 --- PASS: TestGCEndsOnShutdown/before_the_run (7.91s)2186 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.81s)2187 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.60s)21882026/11/01 17:35:17 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"21892026/11/01 17:35:17 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-config21902026/11/01 17:35:17 WARN Request failed, retrying attempt=2 backoff=192.589849ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21912026/11/01 17:35:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21922026/11/01 17:35:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21932026/11/01 17:35:17 WARN Request failed, retrying attempt=3 backoff=436.021214ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21942026/11/01 17:35:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021952026/11/01 17:35:18 INFO Received create pin request method=POST path=/api/pins/myapp21962026/11/01 17:35:18 INFO Created/updated pin name=myapp store_path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestPinProtectsFromGC1578185186/001/store/gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p-pinned-file.txt narinfo_key=gvv7ah80s8cdrz9x4cl3kv1vdfv0h06p.narinfo21972026/11/01 17:35:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures21982026/11/01 17:35:18 INFO Garbage collection started21992026/11/01 17:35:18 INFO Aborted multipart uploads count=0 kept=022002026/11/01 17:35:18 WARN Force mode enabled - objects will be deleted immediately without grace period22012026/11/01 17:35:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022022026/11/01 17:35:18 INFO Vacuumed table table=pending_closures22032026/11/01 17:35:18 INFO Vacuumed table table=pending_objects22042026/11/01 17:35:18 INFO Vacuumed table table=multipart_uploads22052026/11/01 17:35:18 INFO Vacuumed table table=closures22062026/11/01 17:35:18 INFO Vacuumed table table=objects22072026/11/01 17:35:18 WARN Request failed, retrying attempt=4 backoff=739.740872ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/11/01 17:35:19 WARN Request failed, retrying attempt=5 backoff=1.642163777s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2209=== NAME TestPinProtectsFromGC2210 client_integration_test.go:887: Pin successfully protected closure from garbage collection2211--- PASS: TestPinProtectsFromGC (15.71s)22122026/11/01 17:35:20 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_closures22132026/11/01 17:35:20 WARN Request failed, retrying attempt=2 backoff=201.404058ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22142026/11/01 17:35:20 WARN Request failed, retrying attempt=3 backoff=386.253583ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22152026/11/01 17:35:21 WARN Request failed, retrying attempt=4 backoff=879.040157ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22162026/11/01 17:35:22 WARN Request failed, retrying attempt=5 backoff=1.578560824s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2217=== NAME TestOrphanedObjectsGCStressTest2218 orphaned_objects_gc_test.go:503: Stress test completed successfully:2219 orphaned_objects_gc_test.go:504: - Active objects preserved: 202220 orphaned_objects_gc_test.go:505: - Objects deleted: 2102221 orphaned_objects_gc_test.go:506: - Total GC'd: 2102222--- PASS: TestOrphanedObjectsGCStressTest (42.66s)2223--- PASS: TestClientErrorHandling (0.00s)2224 --- PASS: TestClientErrorHandling/InvalidStorePath (3.93s)2225 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.88s)2226 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.44s)2227PASS2228{"timestamp":"2026-11-01T17:35:23.897509Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53709","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}22292026-11-01 17:35:24.010 UTC [11332] LOG: received smart shutdown request22302026-11-01 17:35:24.012 UTC [11332] LOG: background worker "logical replication launcher" (PID 11343) exited with exit code 122312026-11-01 17:35:24.028 UTC [11337] LOG: shutting down22322026-11-01 17:35:24.028 UTC [11337] LOG: checkpoint starting: shutdown immediate22332026-11-01 17:35:26.446 UTC [11337] LOG: checkpoint complete: wrote 11866 buffers (72.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=1.202 s, sync=1.196 s, total=2.419 s; sync files=34045, longest=0.009 s, average=0.001 s; distance=502028 kB, estimate=502028 kB; lsn=0/201D0118, redo lsn=0/201D011822342026-11-01 17:35:26.468 UTC [11332] LOG: database system is shut down2235Running OIDC tests...2236=== RUN TestAudienceForIssuer2237=== PAUSE TestAudienceForIssuer2238=== RUN TestGlobMatch2239=== PAUSE TestGlobMatch2240=== RUN TestValidateToken_ValidToken2241=== PAUSE TestValidateToken_ValidToken2242=== RUN TestValidateToken_WrongAudience2243=== PAUSE TestValidateToken_WrongAudience2244=== RUN TestValidateToken_Expired2245=== PAUSE TestValidateToken_Expired2246=== RUN TestValidateToken_BoundClaimsMismatch2247=== PAUSE TestValidateToken_BoundClaimsMismatch2248=== RUN TestValidateToken_BoundSubjectMismatch2249=== PAUSE TestValidateToken_BoundSubjectMismatch2250=== RUN TestValidateToken_MultipleProviders2251=== PAUSE TestValidateToken_MultipleProviders2252=== RUN TestValidateToken_NoMatchingProvider2253=== PAUSE TestValidateToken_NoMatchingProvider2254=== RUN TestValidateToken_KubernetesServiceAccount2255=== PAUSE TestValidateToken_KubernetesServiceAccount2256=== RUN TestNewValidator_KubernetesRequiresCA2257=== PAUSE TestNewValidator_KubernetesRequiresCA2258=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2259=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2260=== RUN TestPins_ReservedForMatchingRule2261=== PAUSE TestPins_ReservedForMatchingRule2262=== RUN TestPins_TopLevelShorthand2263=== PAUSE TestPins_TopLevelShorthand2264=== RUN TestPins_ConfigValidation2265=== PAUSE TestPins_ConfigValidation2266=== RUN TestScopes_LegacyProviderDefaultsToWrite2267=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2268=== RUN TestScopes_Rules2269=== PAUSE TestScopes_Rules2270=== RUN TestScopes_ConfigValidation2271=== PAUSE TestScopes_ConfigValidation2272=== CONT TestAudienceForIssuer2273=== CONT TestValidateToken_KubernetesServiceAccount2274--- PASS: TestAudienceForIssuer (0.00s)2275=== CONT TestValidateToken_NoMatchingProvider2276=== CONT TestValidateToken_MultipleProviders2277=== CONT TestValidateToken_BoundSubjectMismatch2278=== CONT TestValidateToken_BoundClaimsMismatch2279=== CONT TestValidateToken_Expired2280=== CONT TestValidateToken_WrongAudience2281=== CONT TestValidateToken_ValidToken2282=== CONT TestGlobMatch2283=== RUN TestGlobMatch/foo_foo2284=== PAUSE TestGlobMatch/foo_foo2285=== RUN TestGlobMatch/foo_bar2286=== PAUSE TestGlobMatch/foo_bar2287=== RUN TestGlobMatch/*_2288=== PAUSE TestGlobMatch/*_2289=== RUN TestGlobMatch/*_anything2290=== PAUSE TestGlobMatch/*_anything2291=== RUN TestGlobMatch/foo*_foo2292=== PAUSE TestGlobMatch/foo*_foo2293=== RUN TestGlobMatch/foo*_foobar2294=== PAUSE TestGlobMatch/foo*_foobar2295=== RUN TestGlobMatch/foo*_bar2296=== PAUSE TestGlobMatch/foo*_bar2297=== RUN TestGlobMatch/*bar_bar2298=== PAUSE TestGlobMatch/*bar_bar2299=== RUN TestGlobMatch/*bar_foobar2300=== PAUSE TestGlobMatch/*bar_foobar2301=== RUN TestGlobMatch/*bar_foo2302=== PAUSE TestGlobMatch/*bar_foo2303=== RUN TestGlobMatch/foo*bar_foobar2304=== PAUSE TestGlobMatch/foo*bar_foobar2305=== RUN TestGlobMatch/foo*bar_foo123bar2306=== PAUSE TestGlobMatch/foo*bar_foo123bar2307=== RUN TestGlobMatch/foo*bar_foobarbaz2308=== PAUSE TestGlobMatch/foo*bar_foobarbaz2309=== RUN TestGlobMatch/*/*_foo/bar2310=== PAUSE TestGlobMatch/*/*_foo/bar2311=== RUN TestGlobMatch/*/*_foo2312=== PAUSE TestGlobMatch/*/*_foo2313=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2314=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2315=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02316=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02317=== RUN TestGlobMatch/refs/*/main_refs/heads/main2318=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2319=== RUN TestGlobMatch/fo?_foo2320=== PAUSE TestGlobMatch/fo?_foo2321=== RUN TestGlobMatch/fo?_fo2322=== PAUSE TestGlobMatch/fo?_fo2323=== RUN TestGlobMatch/fo?_fooo2324=== PAUSE TestGlobMatch/fo?_fooo2325=== RUN TestGlobMatch/?oo_foo2326=== PAUSE TestGlobMatch/?oo_foo2327=== RUN TestGlobMatch/?oo_boo2328=== PAUSE TestGlobMatch/?oo_boo2329=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2330=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2331=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2332=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2333=== CONT TestGlobMatch/foo_foo2334=== CONT TestPins_ReservedForMatchingRule2335=== CONT TestGlobMatch/*/*_foo/bar2336=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2337=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2338=== CONT TestGlobMatch/?oo_boo2339=== CONT TestGlobMatch/?oo_foo2340=== CONT TestGlobMatch/fo?_fooo2341=== CONT TestGlobMatch/fo?_fo2342=== CONT TestGlobMatch/fo?_foo2343=== CONT TestGlobMatch/refs/*/main_refs/heads/main2344=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02345=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2346=== CONT TestGlobMatch/*/*_foo2347=== CONT TestGlobMatch/*bar_bar2348=== CONT TestGlobMatch/foo*bar_foobarbaz2349=== CONT TestGlobMatch/foo*bar_foo123bar2350=== CONT TestGlobMatch/foo*bar_foobar2351=== CONT TestGlobMatch/*bar_foo2352=== CONT TestGlobMatch/*bar_foobar2353=== CONT TestGlobMatch/foo*_foo2354=== CONT TestGlobMatch/foo*_bar2355=== CONT TestGlobMatch/foo*_foobar2356=== CONT TestGlobMatch/*_2357=== CONT TestGlobMatch/*_anything2358=== CONT TestGlobMatch/foo_bar2359--- PASS: TestGlobMatch (0.00s)2360 --- PASS: TestGlobMatch/foo_foo (0.00s)2361 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2362 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2363 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2364 --- PASS: TestGlobMatch/?oo_boo (0.00s)2365 --- PASS: TestGlobMatch/?oo_foo (0.00s)2366 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2367 --- PASS: TestGlobMatch/fo?_fo (0.00s)2368 --- PASS: TestGlobMatch/fo?_foo (0.00s)2369 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2370 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2371 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/*/*_foo (0.00s)2373 --- PASS: TestGlobMatch/*bar_bar (0.00s)2374 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2375 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2376 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2377 --- PASS: TestGlobMatch/*bar_foo (0.00s)2378 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2379 --- PASS: TestGlobMatch/foo*_foo (0.00s)2380 --- PASS: TestGlobMatch/foo*_bar (0.00s)2381 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2382 --- PASS: TestGlobMatch/*_ (0.00s)2383 --- PASS: TestGlobMatch/*_anything (0.00s)2384 --- PASS: TestGlobMatch/foo_bar (0.00s)2385=== CONT TestPins_TopLevelShorthand2386=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2387=== CONT TestScopes_Rules2388=== CONT TestScopes_ConfigValidation23892026/11/01 17:35:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54152/oidc2390=== CONT TestScopes_LegacyProviderDefaultsToWrite2391=== CONT TestNewValidator_KubernetesRequiresCA2392--- PASS: TestScopes_ConfigValidation (0.00s)2393=== CONT TestPins_ConfigValidation2394--- PASS: TestPins_ConfigValidation (0.00s)2395--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)23962026/11/01 17:35:28 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54154/oidc2397--- PASS: TestValidateToken_NoMatchingProvider (0.10s)23982026/11/01 17:35:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54158/oidc23992026/11/01 17:35:28 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324002026/11/01 17:35:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54160/oidc2401--- PASS: TestValidateToken_ValidToken (0.24s)24022026/11/01 17:35:29 http: TLS handshake error from 127.0.0.1:54166: read tcp 127.0.0.1:54164->127.0.0.1:54166: use of closed network connection2403--- PASS: TestNewValidator_KubernetesRequiresCA (0.23s)24042026/11/01 17:35:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54155/oidc24052026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54162/oidc2406--- PASS: TestValidateToken_WrongAudience (0.29s)2407--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.28s)24082026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54168/oidc24092026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54172/oidc24102026/11/01 17:35:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54169/oidc2411--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.29s)2412--- PASS: TestPins_ReservedForMatchingRule (0.31s)2413--- PASS: TestValidateToken_MultipleProviders (0.33s)2414--- PASS: TestValidateToken_Expired (0.33s)24152026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54180/oidc2416--- PASS: TestValidateToken_BoundSubjectMismatch (0.35s)24172026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54182/oidc2418--- PASS: TestPins_TopLevelShorthand (0.36s)24192026/11/01 17:35:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54184/oidc2420--- PASS: TestScopes_Rules (0.37s)24212026/11/01 17:35:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:541862422--- PASS: TestValidateToken_KubernetesServiceAccount (0.44s)2423PASS2424Running hook tests...2425=== RUN TestSendPathsEmpty2426=== PAUSE TestSendPathsEmpty2427=== RUN TestQueueEnqueueAndFetch2428=== PAUSE TestQueueEnqueueAndFetch2429=== RUN TestQueueDeduplication2430=== PAUSE TestQueueDeduplication2431=== RUN TestQueueRemove2432=== PAUSE TestQueueRemove2433=== RUN TestQueueFetchBatchLimit2434=== PAUSE TestQueueFetchBatchLimit2435=== RUN TestQueueRetryMovesToBack2436=== PAUSE TestQueueRetryMovesToBack2437=== RUN TestQueueFetchRemoveLifecycle2438=== PAUSE TestQueueFetchRemoveLifecycle2439=== RUN TestQueueConcurrentWriters2440=== PAUSE TestQueueConcurrentWriters2441=== RUN TestQueueRemoveLargeClosure2442=== PAUSE TestQueueRemoveLargeClosure2443=== RUN TestServerClientIntegration2444--- PASS: TestServerClientIntegration (0.00s)2445=== RUN TestServerQueueError24462026/11/01 17:35:29 ERROR Failed to queue paths error="permission denied" count=12447--- PASS: TestServerQueueError (0.00s)2448=== RUN TestGetListenerSocketActivation2449 server_test.go:145: systemd socket activation does not exist on darwin2450--- SKIP: TestGetListenerSocketActivation (0.00s)2451=== RUN TestServerStalledClientDoesNotBlockShutdown2452=== PAUSE TestServerStalledClientDoesNotBlockShutdown2453=== RUN TestServerBacksOffOnAcceptErrors2454=== PAUSE TestServerBacksOffOnAcceptErrors2455=== RUN TestDrainIsolatesPoisonPath2456=== PAUSE TestDrainIsolatesPoisonPath2457=== RUN TestRunNotBlockedByPoisonHead2458=== PAUSE TestRunNotBlockedByPoisonHead2459=== RUN TestDrainGivesUpWhenServerDown2460=== PAUSE TestDrainGivesUpWhenServerDown2461=== RUN TestFailedPathPrunedByLaterClosure2462=== PAUSE TestFailedPathPrunedByLaterClosure2463=== RUN TestWorkerUploadsAndRemoves2464=== PAUSE TestWorkerUploadsAndRemoves2465=== RUN TestWorkerSkipsGCdPaths2466=== PAUSE TestWorkerSkipsGCdPaths2467=== RUN TestWorkerPrunesClosureDeps2468=== PAUSE TestWorkerPrunesClosureDeps2469=== RUN TestDrainTimeout2470=== PAUSE TestDrainTimeout2471=== RUN TestWorkerRemoveFailureIsNotProgress2472=== PAUSE TestWorkerRemoveFailureIsNotProgress2473=== RUN TestWorkerKeepsPathItCannotStat2474=== PAUSE TestWorkerKeepsPathItCannotStat2475=== CONT TestSendPathsEmpty2476--- PASS: TestSendPathsEmpty (0.00s)2477=== CONT TestDrainIsolatesPoisonPath2478=== CONT TestWorkerKeepsPathItCannotStat2479=== CONT TestWorkerRemoveFailureIsNotProgress2480=== CONT TestDrainTimeout2481=== CONT TestWorkerPrunesClosureDeps2482=== CONT TestWorkerSkipsGCdPaths2483=== CONT TestWorkerUploadsAndRemoves2484=== CONT TestFailedPathPrunedByLaterClosure2485=== CONT TestDrainGivesUpWhenServerDown2486=== CONT TestRunNotBlockedByPoisonHead2487=== CONT TestQueueFetchRemoveLifecycle2488=== CONT TestServerBacksOffOnAcceptErrors24892026/11/01 17:35:29 ERROR Accept failed error="too many open files"2490=== CONT TestServerStalledClientDoesNotBlockShutdown2491=== CONT TestQueueRemoveLargeClosure2492=== CONT TestQueueRemove2493=== CONT TestQueueConcurrentWriters2494=== CONT TestQueueRetryMovesToBack2495=== CONT TestQueueFetchBatchLimit2496=== CONT TestQueueDeduplication2497=== CONT TestQueueEnqueueAndFetch24982026/11/01 17:35:29 ERROR Accept failed error="too many open files"24992026/11/01 17:35:29 ERROR Accept failed error="too many open files"25002026/11/01 17:35:29 INFO Uploading batch count=125012026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=125022026/11/01 17:35:29 INFO Uploading batch count=125032026/11/01 17:35:29 INFO Upload queue status pending=325042026/11/01 17:35:29 INFO Uploading batch count=125052026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=125062026/11/01 17:35:29 INFO Uploading batch count=425072026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=425082026/11/01 17:35:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerRemoveFailureIsNotProgress214018364/002/nonexistent25092026/11/01 17:35:29 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125102026/11/01 17:35:29 INFO Upload queue status pending=225112026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainIsolatesPoisonPath144668691/002/bbb25122026/11/01 17:35:29 INFO Uploading batch count=225132026/11/01 17:35:29 INFO Upload queue status pending=225142026/11/01 17:35:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerSkipsGCdPaths4108023621/002/nonexistent25152026/11/01 17:35:29 INFO Uploading batch count=125162026/11/01 17:35:29 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa error="stat /private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa: permission denied"25172026/11/01 17:35:29 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa error="stat /private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa: permission denied"25182026/11/01 17:35:29 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa error="stat /private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerKeepsPathItCannotStat371306207/002/locked/aaa: permission denied"25192026/11/01 17:35:29 INFO Upload queue status pending=225202026/11/01 17:35:29 INFO Uploading batch count=125212026/11/01 17:35:29 INFO Uploading batch count=125222026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=125232026/11/01 17:35:29 INFO Uploading batch count=125242026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=125252026/11/01 17:35:29 ERROR Drain finished with paths left in queue remaining=12526--- PASS: TestQueueEnqueueAndFetch (0.02s)25272026/11/01 17:35:29 INFO Uploading batch count=125282026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=125292026/11/01 17:35:29 ERROR Drain finished with paths left in queue remaining=125302026/11/01 17:35:29 INFO Uploading batch count=225312026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=225322026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/a25332026/11/01 17:35:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerRemoveFailureIsNotProgress214018364/002/nonexistent25342026/11/01 17:35:29 INFO Uploading batch count=225352026/11/01 17:35:29 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125362026/11/01 17:35:29 INFO Uploading batch count=125372026/11/01 17:35:29 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestWorkerRemoveFailureIsNotProgress214018364/002/nonexistent25382026/11/01 17:35:29 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125392026/11/01 17:35:29 ERROR Drain finished with paths left in queue remaining=12540--- PASS: TestQueueDeduplication (0.02s)25412026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/b2542--- PASS: TestDrainIsolatesPoisonPath (0.03s)2543--- PASS: TestWorkerRemoveFailureIsNotProgress (0.03s)2544--- PASS: TestFailedPathPrunedByLaterClosure (0.03s)2545--- PASS: TestQueueRemove (0.02s)25462026/11/01 17:35:29 INFO Uploading batch count=225472026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=225482026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/c25492026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/d2550--- PASS: TestWorkerKeepsPathItCannotStat (0.03s)2551--- PASS: TestQueueFetchRemoveLifecycle (0.03s)25522026/11/01 17:35:29 INFO Uploading batch count=225532026/11/01 17:35:29 ERROR Upload failed error="upload failed" count=225542026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/e2555--- PASS: TestQueueFetchBatchLimit (0.02s)25562026/11/01 17:35:29 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/8135d018037c16fe/build/TestDrainGivesUpWhenServerDown1724811997/002/f25572026/11/01 17:35:29 ERROR Drain finished with paths left in queue remaining=102558--- PASS: TestQueueRetryMovesToBack (0.03s)2559--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2560--- PASS: TestWorkerPrunesClosureDeps (0.03s)25612026/11/01 17:35:29 ERROR Accept failed error="too many open files"2562--- PASS: TestWorkerUploadsAndRemoves (0.04s)2563--- PASS: TestWorkerSkipsGCdPaths (0.04s)2564--- PASS: TestQueueConcurrentWriters (0.06s)2565--- PASS: TestQueueRemoveLargeClosure (0.07s)25662026/11/01 17:35:29 ERROR Accept failed error="too many open files"25672026/11/01 17:35:29 ERROR Accept failed error="too many open files"25682026/11/01 17:35:29 ERROR Failed to decode request error="read unix /private/var/tb/2/scratch/8135d018037c16fe/build/hook2457515307/test.sock->: i/o timeout"25692026/11/01 17:35:29 ERROR Failed to write response error="write unix /private/var/tb/2/scratch/8135d018037c16fe/build/hook2457515307/test.sock->: i/o timeout"2570--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25712026/11/01 17:35:29 ERROR Upload failed error="context deadline exceeded" count=225722026/11/01 17:35:29 ERROR Drain finished with paths left in queue remaining=42573--- PASS: TestDrainTimeout (0.23s)25742026/11/01 17:35:29 ERROR Accept failed error="too many open files"25752026/11/01 17:35:30 ERROR Accept failed error="too many open files"2576--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25772026/11/01 17:35:30 INFO Uploading batch count=125782026/11/01 17:35:30 INFO Uploading batch count=125792026/11/01 17:35:30 INFO Uploading batch count=125802026/11/01 17:35:30 ERROR Upload failed error="upload failed" count=125812026/11/01 17:35:30 INFO Uploading batch count=125822026/11/01 17:35:30 ERROR Upload failed error="upload failed" count=125832026/11/01 17:35:30 INFO Uploading batch count=125842026/11/01 17:35:30 ERROR Upload failed error="upload failed" count=125852026/11/01 17:35:30 INFO Uploading batch count=125862026/11/01 17:35:30 ERROR Upload failed error="upload failed" count=125872026/11/01 17:35:30 ERROR Drain finished with paths left in queue remaining=12588--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2589PASS2590Running signing tests...2591=== RUN TestExternalSigner2592=== PAUSE TestExternalSigner2593=== RUN TestExternalSignerWrongPublicKey2594=== PAUSE TestExternalSignerWrongPublicKey2595=== RUN TestExternalSignerErrors2596=== PAUSE TestExternalSignerErrors2597=== RUN TestExternalSignerRestartsAfterCrash2598=== PAUSE TestExternalSignerRestartsAfterCrash2599=== RUN TestExternalSignerProgramErrorKeepsProcess2600=== PAUSE TestExternalSignerProgramErrorKeepsProcess2601=== RUN TestExternalSignerClose2602=== PAUSE TestExternalSignerClose2603=== RUN TestExternalSignerRejectsInvalidPublicKey2604=== PAUSE TestExternalSignerRejectsInvalidPublicKey2605=== RUN TestExternalSignerCancellation2606=== PAUSE TestExternalSignerCancellation2607=== RUN TestGenerateFingerprint2608=== PAUSE TestGenerateFingerprint2609=== RUN TestParseSigningKey2610=== PAUSE TestParseSigningKey2611=== RUN TestSign2612=== PAUSE TestSign2613=== RUN TestSignBatch2614=== PAUSE TestSignBatch2615=== RUN TestNilKeyPublicKey2616=== PAUSE TestNilKeyPublicKey2617=== RUN TestSignErrors2618=== PAUSE TestSignErrors2619=== CONT TestExternalSigner2620=== CONT TestSignBatch2621=== CONT TestExternalSignerCancellation2622=== CONT TestExternalSignerProgramErrorKeepsProcess2623=== CONT TestSignErrors2624=== CONT TestNilKeyPublicKey2625--- PASS: TestNilKeyPublicKey (0.00s)2626=== CONT TestExternalSignerErrors2627=== RUN TestExternalSignerErrors/wrong_signature_length2628=== PAUSE TestExternalSignerErrors/wrong_signature_length2629=== RUN TestExternalSignerErrors/exit_on_request2630=== PAUSE TestExternalSignerErrors/exit_on_request2631=== RUN TestExternalSignerErrors/invalid_JSON2632=== CONT TestParseSigningKey2633=== RUN TestParseSigningKey/valid_32-byte_key2634=== PAUSE TestParseSigningKey/valid_32-byte_key2635=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2636=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2637=== PAUSE TestExternalSignerErrors/invalid_JSON2638=== RUN TestExternalSignerErrors/too_few_signatures2639=== PAUSE TestExternalSignerErrors/too_few_signatures2640=== RUN TestExternalSignerErrors/unrequested_key2641=== PAUSE TestExternalSignerErrors/unrequested_key2642=== RUN TestExternalSignerErrors/missing_signature_name2643=== CONT TestExternalSignerRestartsAfterCrash2644=== CONT TestExternalSignerRejectsInvalidPublicKey2645=== RUN TestExternalSignerRejectsInvalidPublicKey/#002646=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002647=== CONT TestExternalSignerClose2648=== CONT TestExternalSignerWrongPublicKey2649=== CONT TestGenerateFingerprint2650=== RUN TestGenerateFingerprint/basic_with_references2651=== PAUSE TestGenerateFingerprint/basic_with_references2652=== CONT TestSign2653=== RUN TestParseSigningKey/no_colon2654=== PAUSE TestParseSigningKey/no_colon2655=== PAUSE TestExternalSignerErrors/missing_signature_name2656=== RUN TestExternalSignerErrors/wrong_shape2657=== PAUSE TestExternalSignerErrors/wrong_shape2658=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2659=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2660=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2661=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2662=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2663=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2664=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2665=== RUN TestGenerateFingerprint/no_references2666=== PAUSE TestGenerateFingerprint/no_references2667=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2668=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2669=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2670=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2671=== RUN TestGenerateFingerprint/invalid_nar_hash_length2672=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2673=== RUN TestGenerateFingerprint/invalid_store_path_prefix2674=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2675=== RUN TestSignErrors/nil_key2676=== RUN TestGenerateFingerprint/invalid_reference_prefix2677=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2678=== CONT TestGenerateFingerprint/basic_with_references2679=== RUN TestExternalSignerErrors/null_signatures2680=== PAUSE TestExternalSignerErrors/null_signatures2681=== RUN TestExternalSignerErrors/wrong_signatures_shape2682=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2683--- PASS: TestSign (0.00s)2684=== PAUSE TestSignErrors/nil_key2685=== RUN TestSignErrors/nil_narinfo2686=== PAUSE TestSignErrors/nil_narinfo2687=== RUN TestSignErrors/invalid_narinfo2688=== PAUSE TestSignErrors/invalid_narinfo2689=== RUN TestSignErrors/canceled2690=== PAUSE TestSignErrors/canceled2691=== CONT TestSignErrors/nil_key2692=== RUN TestExternalSignerErrors/wrong_signature_name2693=== CONT TestSignErrors/canceled2694=== PAUSE TestExternalSignerErrors/wrong_signature_name2695=== RUN TestExternalSignerErrors/program_error2696=== PAUSE TestExternalSignerErrors/program_error2697=== RUN TestExternalSignerErrors/exit_at_startup2698=== PAUSE TestExternalSignerErrors/exit_at_startup2699=== RUN TestExternalSignerErrors/wrong_id2700=== PAUSE TestExternalSignerErrors/wrong_id2701=== RUN TestExternalSignerErrors/missing_signatures2702=== PAUSE TestExternalSignerErrors/missing_signatures2703=== RUN TestExternalSignerErrors/invalid_signature_base642704=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2705=== CONT TestExternalSignerRejectsInvalidPublicKey/#002706--- PASS: TestSignBatch (0.00s)2707=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2708=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2709=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2710=== CONT TestGenerateFingerprint/invalid_reference_prefix2711=== CONT TestGenerateFingerprint/invalid_store_path_prefix2712=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2713=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2714=== CONT TestGenerateFingerprint/no_references2715=== CONT TestSignErrors/invalid_narinfo2716=== CONT TestSignErrors/nil_narinfo2717--- PASS: TestSignErrors (0.00s)2718 --- PASS: TestSignErrors/nil_key (0.00s)2719 --- PASS: TestSignErrors/canceled (0.00s)2720 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2721 --- PASS: TestSignErrors/nil_narinfo (0.00s)2722=== RUN TestParseSigningKey/empty_name2723=== PAUSE TestExternalSignerErrors/invalid_signature_base642724=== PAUSE TestParseSigningKey/empty_name2725=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2726--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2727 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2728 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2729 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2730 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2731 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2732=== CONT TestGenerateFingerprint/invalid_nar_hash_length2733--- PASS: TestGenerateFingerprint (0.00s)2734 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2735 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2736 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2737 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2738 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2739 --- PASS: TestGenerateFingerprint/no_references (0.00s)2740 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2741=== RUN TestExternalSignerErrors/null2742=== PAUSE TestExternalSignerErrors/null2743=== CONT TestExternalSignerErrors/wrong_signature_length2744=== RUN TestParseSigningKey/invalid_base642745=== PAUSE TestParseSigningKey/invalid_base642746=== RUN TestParseSigningKey/wrong_length2747=== PAUSE TestParseSigningKey/wrong_length2748=== CONT TestParseSigningKey/valid_32-byte_key2749=== CONT TestExternalSignerErrors/null2750=== CONT TestExternalSignerErrors/program_error2751=== CONT TestExternalSignerErrors/missing_signature_name2752=== CONT TestExternalSignerErrors/wrong_signature_name2753=== CONT TestExternalSignerErrors/invalid_signature_base642754=== CONT TestExternalSignerErrors/wrong_id2755=== CONT TestExternalSignerErrors/wrong_signatures_shape2756=== CONT TestExternalSignerErrors/exit_at_startup2757=== CONT TestExternalSignerErrors/unrequested_key2758=== CONT TestExternalSignerErrors/invalid_JSON2759=== CONT TestExternalSignerErrors/missing_signatures2760=== CONT TestExternalSignerErrors/exit_on_request2761=== CONT TestParseSigningKey/empty_name2762=== CONT TestParseSigningKey/wrong_length2763=== CONT TestParseSigningKey/invalid_base642764=== CONT TestParseSigningKey/no_colon2765=== CONT TestExternalSignerErrors/too_few_signatures2766=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2767--- PASS: TestParseSigningKey (0.00s)2768 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2769 --- PASS: TestParseSigningKey/empty_name (0.00s)2770 --- PASS: TestParseSigningKey/wrong_length (0.00s)2771 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2772 --- PASS: TestParseSigningKey/no_colon (0.00s)2773 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2774=== CONT TestExternalSignerErrors/null_signatures2775=== CONT TestExternalSignerErrors/wrong_shape2776--- PASS: TestExternalSignerCancellation (0.25s)2777--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.43s)2778--- PASS: TestExternalSignerRestartsAfterCrash (0.65s)2779/private/var/tb/2/scratch/8135d018037c16fe/build/TestExternalSignerRestartsAfterCrash927447218/001/sign program: line 7: /private/var/tb/2/scratch/8135d018037c16fe/build/TestExternalSignerRestartsAfterCrash927447218/001/sign program.starts: No such file or directory2780--- PASS: TestExternalSignerClose (1.83s)2781--- PASS: TestExternalSigner (2.85s)2782--- PASS: TestExternalSignerWrongPublicKey (3.23s)2783--- PASS: TestExternalSignerErrors (0.00s)2784 --- PASS: TestExternalSignerErrors/program_error (0.81s)2785 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.03s)2786 --- PASS: TestExternalSignerErrors/missing_signatures (1.23s)2787 --- PASS: TestExternalSignerErrors/exit_on_request (1.43s)2788 --- PASS: TestExternalSignerErrors/invalid_JSON (1.63s)2789 --- PASS: TestExternalSignerErrors/exit_at_startup (2.03s)2790 --- PASS: TestExternalSignerErrors/missing_signature_name (2.22s)2791 --- PASS: TestExternalSignerErrors/null_signatures (2.43s)2792 --- PASS: TestExternalSignerErrors/wrong_id (2.63s)2793 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (3.03s)2794 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.44s)2795 --- PASS: TestExternalSignerErrors/unrequested_key (3.65s)2796 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.84s)2797 --- PASS: TestExternalSignerErrors/null (4.04s)2798 --- PASS: TestExternalSignerErrors/too_few_signatures (4.23s)2799 --- PASS: TestExternalSignerErrors/wrong_shape (4.44s)2800PASS2801Running OpenBao signer tests...2802=== RUN TestSign2803=== PAUSE TestSign2804=== RUN TestSignErrors2805=== PAUSE TestSignErrors2806=== RUN TestServe2807=== PAUSE TestServe2808=== RUN TestServeRejectsGarbage2809=== PAUSE TestServeRejectsGarbage2810=== CONT TestSign2811=== CONT TestSignErrors2812=== CONT TestServe2813=== RUN TestSignErrors/invalid_json2814=== PAUSE TestSignErrors/invalid_json2815=== RUN TestSignErrors/no_prefix2816=== PAUSE TestSignErrors/no_prefix2817=== RUN TestSignErrors/invalid_base642818=== PAUSE TestSignErrors/invalid_base642819=== RUN TestSignErrors/http_error2820=== PAUSE TestSignErrors/http_error2821=== CONT TestSignErrors/invalid_json2822=== CONT TestServeRejectsGarbage2823--- PASS: TestServeRejectsGarbage (0.00s)2824=== CONT TestSignErrors/invalid_base642825--- PASS: TestServe (0.00s)2826=== CONT TestSignErrors/http_error2827=== CONT TestSignErrors/no_prefix2828--- PASS: TestSign (0.00s)2829--- PASS: TestSignErrors (0.00s)2830 --- PASS: TestSignErrors/http_error (0.00s)2831 --- PASS: TestSignErrors/no_prefix (0.00s)2832 --- PASS: TestSignErrors/invalid_base64 (0.00s)2833 --- PASS: TestSignErrors/invalid_json (0.00s)2834PASS