niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #435
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestDoWithRetry_BodyReplayedViaGetBody117=== CONT TestSetClientTLS118=== CONT TestDumpPathWriterError119=== CONT TestResolveStorePath120--- PASS: TestResolveStorePath (0.00s)121=== CONT TestScriptTokenNoExpiryRerunsEveryCall122=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer123=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess124=== CONT TestRateLimiterFeedback125=== CONT TestPathInfoCACompatibility126=== CONT TestParsePathInfoJSONMultiplePaths127=== CONT TestParsePathInfoJSON128=== CONT TestPathInfoHashCompatibility129=== CONT TestGetStorePathHash130=== CONT TestConvertHashToNix32131=== CONT TestEncodeNixBase32WithRealHash132--- PASS: TestEncodeNixBase32WithRealHash (0.00s)133=== CONT TestEncodeNixBase321342026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=server-test rate=5135=== CONT TestUploadMultipart_PartsInParallel136=== CONT TestDumpPathSingleFile137=== CONT TestDumpPathMatchesNix138=== CONT TestSupersededNARStillUploadsListing139=== CONT TestUploadMultipart_SupersededByPeer140=== CONT TestPartSizeForNAR141=== CONT TestUploadMultipart_FailedPartBufferNotReused142=== CONT TestStreamPushIsolatesFailures143=== RUN TestRateLimiterFeedback/429_enables_limiter144=== PAUSE TestRateLimiterFeedback/429_enables_limiter145=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== RUN TestParsePathInfoJSON/Nix_format147=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== RUN TestGetStorePathHash/valid_store_path149=== RUN TestConvertHashToNix32/SRI_format_to_Nix32150=== CONT TestStreamPushStopsWhenCanceled151=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths152=== RUN TestPathInfoCACompatibility/null_ca_field153=== RUN TestEncodeNixBase32/test_string_hash154=== RUN TestUploadMultipart_SupersededByPeer/exists155=== PAUSE TestUploadMultipart_SupersededByPeer/exists156=== PAUSE TestEncodeNixBase32/test_string_hash157=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158=== RUN TestSetClientTLS/rejects_connection_without_client_cert159=== PAUSE TestPathInfoCACompatibility/null_ca_field160=== RUN TestPathInfoCACompatibility/old_string_format_-_text161=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text162=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive163=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths164=== PAUSE TestGetStorePathHash/valid_store_path165=== PAUSE TestParsePathInfoJSON/Nix_format166=== RUN TestRateLimiterFeedback/503_enables_limiter167=== CONT TestClientSignaturesByStorePath168=== RUN TestUploadMultipart_SupersededByPeer/missing1692026/10/25 19:40:01 ERROR Upload failed error="bad path" count=3170=== RUN TestSupersededNARStillUploadsListing/small_NAR171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172=== RUN TestEncodeNixBase32/empty_input173=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert174=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive175=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)176=== CONT TestScriptTokenEmptyCommand177=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32178=== RUN TestGetStorePathHash/basename_without_hyphen_should_error179--- PASS: TestStreamPushStopsWhenCanceled (0.00s)180=== RUN TestParsePathInfoJSON/Lix_format181=== CONT TestStreamPushReportsSkippedPaths182--- PASS: TestClientSignaturesByStorePath (0.00s)1832026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=server-test rate=5184=== PAUSE TestParsePathInfoJSON/Lix_format1852026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:43543186=== RUN TestParsePathInfoJSON/empty_input187=== PAUSE TestParsePathInfoJSON/empty_input188=== RUN TestParsePathInfoJSON/whitespace_only189=== PAUSE TestUploadMultipart_SupersededByPeer/missing190=== PAUSE TestRateLimiterFeedback/503_enables_limiter191=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter192=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter193=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter194=== CONT TestScriptTokenScriptFails195=== PAUSE TestEncodeNixBase32/empty_input1962026/10/25 19:40:01 WARN Rate limiter backed off name=server-test rate=5197=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter1982026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:43543199=== RUN TestPathInfoCACompatibility/new_structured_format_-_text200=== CONT TestScriptTokenEmptyToken201=== CONT TestFileTokenReadsAndCaches202=== CONT TestStreamPushGivesUpOnDeadServer203=== PAUSE TestSupersededNARStillUploadsListing/small_NAR2042026/10/25 19:40:01 ERROR Upload failed error="connection refused" count=20205=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error2062026/10/25 19:40:01 ERROR Server seems unavailable, giving up on batch untried=17207=== RUN TestSupersededNARStillUploadsListing/dump_cut_short208=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short209=== PAUSE TestParsePathInfoJSON/whitespace_only210=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails211=== RUN TestParsePathInfoJSON/invalid_JSON212=== PAUSE TestParsePathInfoJSON/invalid_JSON213=== CONT TestScriptTokenCachesUntilRefresh214=== CONT TestStreamPushReportsSignatures215=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum216=== CONT TestStreamPushRequestLine217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA219=== RUN TestSetClientTLS/preserves_debug_logging_transport220=== PAUSE TestSetClientTLS/preserves_debug_logging_transport221=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun222=== CONT TestScriptTokenBadJSON2232026/10/25 19:40:01 ERROR Upload failed error=boom count=1224=== CONT TestRegisterUploadedObjectReusesConnections225=== RUN TestConvertHashToNix32/already_Nix32_format226=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon227=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon228=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text2292026/10/25 19:40:01 ERROR Upload failed error=boom count=1230=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method231=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method232=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error233=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error234=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error235=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error236=== CONT TestCaseHackSuffix237--- PASS: TestStreamPushReportsSkippedPaths (0.00s)238--- PASS: TestStreamPushIsolatesFailures (0.06s)239--- PASS: TestScriptTokenEmptyCommand (0.00s)240--- PASS: TestDoServerRequestAttachesToken (0.07s)241=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails242--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)243--- PASS: TestFileTokenReadsAndCaches (0.00s)244--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.07s)245--- PASS: TestStreamPushReportsSignatures (0.00s)246=== CONT TestFileTokenEmpty247--- PASS: TestFileTokenEmpty (0.00s)248=== CONT TestStaticToken249--- PASS: TestStaticToken (0.00s)250=== CONT TestShellSplitErrors251--- PASS: TestShellSplitErrors (0.00s)252=== CONT TestStreamPushBatchesUnderLoad253=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2542026/10/25 19:40:01 INFO Garbage collection started255=== CONT TestSetClientTLSErrors256--- PASS: TestScriptTokenScriptFails (0.01s)257=== RUN TestPartSizeForNAR/small_stays_at_minimum258=== CONT TestFileTokenMissing259=== CONT TestFilterOversizedClosures260=== PAUSE TestConvertHashToNix32/already_Nix32_format261=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI262=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI263=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512264=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512265=== CONT TestStreamPushReportsEveryPath266=== PAUSE TestPartSizeForNAR/small_stays_at_minimum267=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum268=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum269=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts270=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts271=== RUN TestPartSizeForNAR/1_TiB272=== PAUSE TestPartSizeForNAR/1_TiB273=== RUN TestPartSizeForNAR/5_TiB_S3_max_object274=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object275=== RUN TestPartSizeForNAR/capped_at_5_GiB276=== PAUSE TestPartSizeForNAR/capped_at_5_GiB277--- PASS: TestScriptTokenEmptyToken (0.01s)278=== CONT TestRetryTimeoutOutlastsMaxRetries279=== RUN TestSetClientTLSErrors/missing_cert_file280=== PAUSE TestSetClientTLSErrors/missing_cert_file281=== RUN TestSetClientTLSErrors/missing_key_file282=== PAUSE TestSetClientTLSErrors/missing_key_file283=== RUN TestSetClientTLSErrors/missing_ca_file284=== PAUSE TestSetClientTLSErrors/missing_ca_file285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== PAUSE TestSetClientTLSErrors/invalid_ca_file287=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths288=== CONT TestUploadMultipart_SupersededByPeer/exists289=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2902026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41541291=== CONT TestUploadMultipart_SupersededByPeer/missing2922026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=s3-test rate=52932026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39355294--- PASS: TestFileTokenMissing (0.00s)295--- PASS: TestStreamPushReportsEveryPath (0.00s)296--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)297--- PASS: TestScriptTokenBadJSON (0.01s)298=== CONT TestDoWithRetry_FinalResponseBodyReadable299=== RUN TestConvertHashToNix32/invalid_format300=== PAUSE TestConvertHashToNix32/invalid_format301=== CONT TestSetClientTLSDoesNotMutateDefaultTransport302--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)303=== CONT TestRateLimiterFeedback/429_enables_limiter304=== CONT TestEncodeNixBase32/test_string_hash305=== CONT TestShellSplit306--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.07s)307--- PASS: TestShellSplit (0.00s)3082026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=server-test rate=5309=== CONT TestRateLimiterFeedback/503_enables_limiter3102026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:379753112026/10/25 19:40:01 WARN Rate limiter backed off name=server-test rate=5312=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter3132026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=server-test rate=5314--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)3152026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:46043316=== CONT TestEncodeNixBase32/empty_input3172026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41541318--- PASS: TestEncodeNixBase32 (0.06s)319 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)320 --- PASS: TestEncodeNixBase32/empty_input (0.00s)321=== RUN TestFilterOversizedClosures/no_limit_keeps_everything3222026/10/25 19:40:01 WARN Rate limiter backed off name=server-test rate=5323=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter324=== CONT TestParsePathInfoJSON/whitespace_only325=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths326=== CONT TestParsePathInfoJSON/Nix_format327=== CONT TestParsePathInfoJSON/invalid_JSON328=== CONT TestSetClientTLS/preserves_debug_logging_transport329=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA330=== CONT TestParsePathInfoJSON/empty_input331=== CONT TestGetStorePathHash/valid_store_path332--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)335=== CONT TestParsePathInfoJSON/Lix_format336--- PASS: TestParsePathInfoJSON (0.07s)337 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)338 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)339 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)340 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)341 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)342=== CONT TestSetClientTLS/rejects_connection_without_client_cert3432026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:41541344=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything345=== CONT TestPathInfoCACompatibility/null_ca_field346=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped347=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped348=== RUN TestFilterOversizedClosures/all_closures_skipped349=== CONT TestPathInfoCACompatibility/new_structured_format_-_text350=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method351=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive352=== CONT TestPathInfoCACompatibility/old_string_format_-_text3532026/10/25 19:40:01 INFO Garbage collection started354=== CONT TestSupersededNARStillUploadsListing/small_NAR3552026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:41541356=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3572026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=server-test rate=53582026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:370273592026/10/25 19:40:01 WARN Rate limiter backed off name=server-test rate=5360=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error361=== CONT TestGetStorePathHash/basename_without_hyphen_should_error3622026/10/25 19:40:01 INFO Uploading abc-hello (1.0GB)363=== PAUSE TestFilterOversizedClosures/all_closures_skipped364=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3652026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:41541366--- PASS: TestPathInfoCACompatibility (0.07s)367 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)369 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)371 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)372=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error373=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)374=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512375=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon376--- PASS: TestUploadMultipart_SupersededByPeer (0.06s)377 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)378 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)3792026/10/25 19:40:01 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=03802026/10/25 19:40:01 INFO Uploading abc-hello (1.0GB)381=== CONT TestPartSizeForNAR/1_TiB382=== CONT TestPartSizeForNAR/small_stays_at_minimum3832026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:41541384=== CONT TestSetClientTLSErrors/missing_cert_file385=== CONT TestConvertHashToNix32/SRI_format_to_Nix32386=== CONT TestConvertHashToNix32/already_Nix32_format387=== CONT TestSetClientTLSErrors/missing_ca_file388=== CONT TestSetClientTLSErrors/missing_key_file389=== CONT TestFilterOversizedClosures/no_limit_keeps_everything390=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI391=== CONT TestPartSizeForNAR/capped_at_5_GiB392=== CONT TestPartSizeForNAR/5_TiB_S3_max_object393=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts394=== CONT TestFilterOversizedClosures/all_closures_skipped3952026/10/25 19:40:01 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50396=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3972026/10/25 19:40:01 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000398--- PASS: TestGetStorePathHash (0.07s)399 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)400 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)401 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)402 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)403--- PASS: TestDumpPathSingleFile (0.21s)404--- PASS: TestCaseHackSuffix (0.15s)405--- PASS: TestRateLimiterFeedback (0.07s)406 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)407 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)408 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)409 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)410=== CONT TestConvertHashToNix32/invalid_format411=== CONT TestSetClientTLSErrors/invalid_ca_file412--- PASS: TestPathInfoHashCompatibility (0.07s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)415 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)416 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)4172026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:41541418=== CONT TestPartSizeForNAR/zero_stays_at_minimum419=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum420--- PASS: TestConvertHashToNix32 (0.07s)421 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)422 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)423 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)424--- PASS: TestSetClientTLSErrors (0.00s)425 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)426 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)427 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)428 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)429--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)430--- PASS: TestScriptTokenCachesUntilRefresh (0.15s)431--- PASS: TestPartSizeForNAR (0.07s)432 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)433 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)434 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)435 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)436 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)437 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)438 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)439--- PASS: TestFilterOversizedClosures (0.01s)440 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)441 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)442 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)4432026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:415414442026/10/25 19:40:01 WARN Garbage collection finished on another replica. Its statistics are not available here445--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.14s)4462026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:415414472026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:415414482026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:415414492026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:415414502026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:415414512026/10/25 19:40:01 http: TLS handshake error from 127.0.0.1:56538: remote error: tls: bad certificate452--- PASS: TestSetClientTLS (0.07s)453 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.14s)454 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.14s)455 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.15s)4562026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:41541457--- PASS: TestStreamPushRequestLine (0.16s)4582026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:415414592026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:41541460--- PASS: TestRegisterUploadedObjectReusesConnections (0.16s)461--- PASS: TestDumpPathWriterError (0.23s)4622026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:415414632026/10/25 19:40:01 WARN Rate limiter enabled after throttle name=s3-test rate=54642026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:415414652026/10/25 19:40:01 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:41541466--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.16s)4672026/10/25 19:40:01 INFO Uploading abc-hello (1.0GB)468--- PASS: TestStreamPushBatchesUnderLoad (0.19s)4692026/10/25 19:40:01 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:44895/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:44895/part/24702026/10/25 19:40:01 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"471--- PASS: TestDumpPathMatchesNix (0.26s)472--- PASS: TestSupersededNARStillUploadsListing (0.07s)473 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.00s)474 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.14s)475 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.68s)476--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.78s)477--- PASS: TestUploadMultipart_PartsInParallel (0.78s)4782026/10/25 19:40:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45295/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45295/api/uploads/complete4792026/10/25 19:40:02 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4802026/10/25 19:40:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45295/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45295/api/uploads/complete4812026/10/25 19:40:02 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"482--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4832026/10/25 19:40:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:45295/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:45295/api/uploads/complete4842026/10/25 19:40:02 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"485--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.03s)486PASS487Running server tests...488The files belonging to this database system will be owned by user "nixbld".489This user must also own the server process.490491The database cluster will be initialized with locale "C".492The default database encoding has accordingly been set to "SQL_ASCII".493The default text search configuration will be set to "english".494495Data page checksums are enabled.496497creating directory /build/postgres3406977930/data ... ok498creating subdirectories ... ok499selecting dynamic shared memory implementation ... posix500selecting default "max_connections" ... 100501selecting default "shared_buffers" ... 128MB502selecting default time zone ... UTC503creating configuration files ... ok504running bootstrap script ... ok505performing post-bootstrap initialization ... ok506syncing data to disk ... ok507508initdb: warning: enabling "trust" authentication for local connections509initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.510511Success. You can now start the database server using:512513 pg_ctl -D /build/postgres3406977930/data -l logfile start514515/build/postgres3406977930:5432 - no response5162026-10-25 19:40:03.927 UTC [128] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5172026-10-25 19:40:03.927 UTC [128] LOG: listening on Unix socket "/build/postgres3406977930/.s.PGSQL.5432"5182026-10-25 19:40:03.931 UTC [135] LOG: database system was shut down at 2026-10-25 19:40:03 UTC5192026-10-25 19:40:03.936 UTC [128] LOG: database system is ready to accept connections520/build/postgres3406977930:5432 - accepting connections521{"timestamp":"2026-10-25T19:40:04.433346801Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"41c122f7-faca-4325-a83d-4c5d38d5fd8e","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(133)"}522=== RUN TestService_AuthMiddleware523=== PAUSE TestService_AuthMiddleware524=== RUN TestService_AuthMiddleware_MTLSProxyHeader525=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader526=== RUN TestService_AuthMiddleware_MTLSBoundSubjects527=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects528=== RUN TestService_ReadAuthMiddleware529=== PAUSE TestService_ReadAuthMiddleware530=== RUN TestService_AuthMiddleware_OIDC531=== PAUSE TestService_AuthMiddleware_OIDC532=== RUN TestService_RequireScope_OIDC533=== PAUSE TestService_RequireScope_OIDC534=== RUN TestService_ReadScope_PublicByDefault535=== PAUSE TestService_ReadScope_PublicByDefault536=== RUN TestCacheConfigHandler537=== PAUSE TestCacheConfigHandler538=== RUN TestCacheStatsHandler539=== PAUSE TestCacheStatsHandler540=== RUN TestClientCADerivations541=== PAUSE TestClientCADerivations542=== RUN TestClientErrorHandling543=== PAUSE TestClientErrorHandling544=== RUN TestClientIntegration545=== PAUSE TestClientIntegration546=== RUN TestClientMultipleUploads547=== PAUSE TestClientMultipleUploads548=== RUN TestClientWithDependencies549=== PAUSE TestClientWithDependencies550=== RUN TestClientSharedPathCommittedMidPush551=== PAUSE TestClientSharedPathCommittedMidPush552=== RUN TestPinProtectsFromGC553=== PAUSE TestPinProtectsFromGC554=== RUN TestClientPushesUseOnePush555=== PAUSE TestClientPushesUseOnePush556=== RUN TestClientFallsBackToClosures557=== PAUSE TestClientFallsBackToClosures558=== RUN TestDeleteClosuresRacingPins559=== PAUSE TestDeleteClosuresRacingPins560=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock561=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock562=== RUN TestResolveDBConnectionString563=== PAUSE TestResolveDBConnectionString564=== RUN TestConnectWaitsForAPeerMigration565=== PAUSE TestConnectWaitsForAPeerMigration566=== RUN TestLeadElectsOneAndHandsOver567=== PAUSE TestLeadElectsOneAndHandsOver568=== RUN TestLeadIncumbentWinsAfterRestart5692026/10/25 19:40:04 INFO lead: acquired remote=192.0.2.1:12345702026/10/25 19:40:05 INFO lead: released remote=192.0.2.1:12345712026/10/25 19:40:05 INFO lead: acquired remote=192.0.2.1:12345722026/10/25 19:40:06 INFO lead: released remote=192.0.2.1:1234573--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)574=== RUN TestLeadIncumbentAnnouncesAtOnce575=== PAUSE TestLeadIncumbentAnnouncesAtOnce576=== RUN TestLeadEndsOnShutdown577=== PAUSE TestLeadEndsOnShutdown578=== RUN TestLeadEndsWhenItsConnectionHangs5792026/10/25 19:40:06 INFO lead: acquired remote=192.0.2.1:12345802026-10-25 19:40:08.033 UTC [316] FATAL: terminating connection due to administrator command5812026/10/25 19:40:08 INFO lead: acquired remote=192.0.2.1:12345822026/10/25 19:40:09 WARN lead: lock connection lost error="timeout: context deadline exceeded"5832026/10/25 19:40:09 INFO lead: released remote=192.0.2.1:12345842026/10/25 19:40:09 INFO lead: released remote=192.0.2.1:1234585--- PASS: TestLeadEndsWhenItsConnectionHangs (3.27s)586=== RUN TestGCAdvisoryLockBlocksConcurrentRun587=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun588=== RUN TestGCBugBareHashReferences589=== PAUSE TestGCBugBareHashReferences590=== RUN TestGCMetrics591=== PAUSE TestGCMetrics592=== RUN TestPushDedupSurvivesConcurrentGC593=== PAUSE TestPushDedupSurvivesConcurrentGC594=== RUN TestDeduplicatedObjectsRecordedAsPending595=== PAUSE TestDeduplicatedObjectsRecordedAsPending596=== RUN TestGCSweepSkipsPendingObjects597=== PAUSE TestGCSweepSkipsPendingObjects598=== RUN TestTombstonedObjectOfferedWithoutWaiting599=== PAUSE TestTombstonedObjectOfferedWithoutWaiting600=== RUN TestGCSweepDeliversEachKeyOnce601=== PAUSE TestGCSweepDeliversEachKeyOnce602=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection603=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection604=== RUN TestForceGCDuringPushOffersSweptObject605=== PAUSE TestForceGCDuringPushOffersSweptObject606=== RUN TestFailedS3DeleteKeepsTombstone607=== PAUSE TestFailedS3DeleteKeepsTombstone608=== RUN TestSweepSkipsRowsLockedByPush609=== PAUSE TestSweepSkipsRowsLockedByPush610=== RUN TestRegisterCompletedObjectNeedsPendingRow611=== PAUSE TestRegisterCompletedObjectNeedsPendingRow612=== RUN TestGetExistingObjectsLocksRows613=== PAUSE TestGetExistingObjectsLocksRows614=== RUN TestSweepRechecksPendingAfterLocking615=== PAUSE TestSweepRechecksPendingAfterLocking616=== RUN TestPushWaitsForSweepHoldingRow617=== PAUSE TestPushWaitsForSweepHoldingRow618=== RUN TestCommitRacingPendingCleanupKeepsObjects619=== PAUSE TestCommitRacingPendingCleanupKeepsObjects620=== RUN TestGCEndsOnShutdown621=== PAUSE TestGCEndsOnShutdown622=== RUN TestGCTaskStore_StartNew623=== PAUSE TestGCTaskStore_StartNew624=== RUN TestGCTaskStore_DeduplicateSameParams625=== PAUSE TestGCTaskStore_DeduplicateSameParams626=== RUN TestGCTaskStore_ConflictDifferentParams627=== PAUSE TestGCTaskStore_ConflictDifferentParams628=== RUN TestGCTaskStore_GetEmpty629=== PAUSE TestGCTaskStore_GetEmpty630=== RUN TestGCTaskStore_GetReturnsLatest631=== PAUSE TestGCTaskStore_GetReturnsLatest632=== RUN TestGCTaskStore_CompletedAllowsNewTask633=== PAUSE TestGCTaskStore_CompletedAllowsNewTask634=== RUN TestGCTaskStore_PhaseUpdates635=== PAUSE TestGCTaskStore_PhaseUpdates636=== RUN TestGCTaskStore_Fail637=== PAUSE TestGCTaskStore_Fail638=== RUN TestGracefulShutdownDrainsInflight639=== PAUSE TestGracefulShutdownDrainsInflight640=== RUN TestService_healthCheckHandler641=== PAUSE TestService_healthCheckHandler642=== RUN TestService_readinessHandler643=== PAUSE TestService_readinessHandler644=== RUN TestGenerateLandingPage645=== PAUSE TestGenerateLandingPage646=== RUN TestCacheConfigHandlerMaxNarSize647=== PAUSE TestCacheConfigHandlerMaxNarSize648=== RUN TestCreatePendingClosureRejectsOversizedNAR649=== PAUSE TestCreatePendingClosureRejectsOversizedNAR650=== RUN TestNARDeduplicationMetadataUploadBug651=== PAUSE TestNARDeduplicationMetadataUploadBug652=== RUN TestMetricsInventory653=== PAUSE TestMetricsInventory654=== RUN TestMetricsCommit655=== PAUSE TestMetricsCommit656=== RUN TestService_NativeMTLS657=== PAUSE TestService_NativeMTLS658=== RUN TestServerTLSConfig659=== PAUSE TestServerTLSConfig660=== RUN TestMultipartCleanup661=== PAUSE TestMultipartCleanup662=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded663=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded664=== RUN TestPendingCleanupUsesOneCutoff665=== PAUSE TestPendingCleanupUsesOneCutoff666=== RUN TestObjectStatsTrigger667=== PAUSE TestObjectStatsTrigger668=== RUN TestObjectStatsUpdatedOncePerCommit669=== PAUSE TestObjectStatsUpdatedOncePerCommit670=== RUN TestOrphanedObjectsGC671=== PAUSE TestOrphanedObjectsGC672=== RUN TestOrphanedObjectsGCStressTest673=== PAUSE TestOrphanedObjectsGCStressTest674=== RUN TestCreatePin_ReservedPins675=== PAUSE TestCreatePin_ReservedPins676=== RUN TestPresentReportsOnlyClosureRoots677=== PAUSE TestPresentReportsOnlyClosureRoots678=== RUN TestPresentRefreshesOnlyStaleClosures679=== PAUSE TestPresentRefreshesOnlyStaleClosures680=== RUN TestPresentNotReportedWhileGCDeletesClosure681=== PAUSE TestPresentNotReportedWhileGCDeletesClosure682=== RUN TestParseSingleRange683=== PAUSE TestParseSingleRange684=== RUN TestProxyHeadersOnlyTrustedOnSocket6852026/10/25 19:40:09 INFO Starting HTTP server address=127.0.0.1:332396862026/10/25 19:40:09 INFO Starting HTTP server address=proxy.sock6872026/10/25 19:40:09 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6882026/10/25 19:40:09 INFO Shutdown signal received, draining in-flight requests timeout=10s689--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)690=== RUN TestIsValidCachePath691=== PAUSE TestIsValidCachePath692=== RUN TestReadProxyNarinfo693=== PAUSE TestReadProxyNarinfo694=== RUN TestReadProxyNarinfoAlreadyDecompressed695=== PAUSE TestReadProxyNarinfoAlreadyDecompressed696=== RUN TestReadProxyContentNegotiation697=== PAUSE TestReadProxyContentNegotiation698=== RUN TestReadProxyNarStreaming699=== PAUSE TestReadProxyNarStreaming700=== RUN TestReadProxy404701=== PAUSE TestReadProxy404702=== RUN TestReadProxyInvalidPath703=== PAUSE TestReadProxyInvalidPath704=== RUN TestReadProxyHead705=== PAUSE TestReadProxyHead706=== RUN TestReadProxyOutlastsServerWriteTimeout707=== PAUSE TestReadProxyOutlastsServerWriteTimeout708=== RUN TestReadProxyConditionalGet709=== PAUSE TestReadProxyConditionalGet710=== RUN TestReadProxyRootRedirectsToIndexHTML711=== PAUSE TestReadProxyRootRedirectsToIndexHTML712=== RUN TestReadProxyDisabled713=== PAUSE TestReadProxyDisabled714=== RUN TestReadRedirectNar715=== PAUSE TestReadRedirectNar716=== RUN TestReadRedirectKeepsNarinfoProxied717=== PAUSE TestReadRedirectKeepsNarinfoProxied718=== RUN TestReadProxyRangeRequest719=== PAUSE TestReadProxyRangeRequest720=== RUN TestReadRedirectUsesPublicS3URL721=== PAUSE TestReadRedirectUsesPublicS3URL722=== RUN TestPush_OverlappingRootsStoreOneRowPerKey723=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey724=== RUN TestPush_CompleteCommitsEveryRoot725=== PAUSE TestPush_CompleteCommitsEveryRoot726=== RUN TestPush_RepeatedRootCommitsOnce727=== PAUSE TestPush_RepeatedRootCommitsOnce728=== RUN TestPush_CompleteWaitsForCleanupOfThePush729=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush730=== RUN TestPush_RootsAreLockedInByteOrder731=== PAUSE TestPush_RootsAreLockedInByteOrder732=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit733=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit734=== RUN TestPush_RejectsBadRequests735=== PAUSE TestPush_RejectsBadRequests736=== RUN TestPush_SignsNarinfosOfItsPendingObjects737=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects738=== RUN TestRedundantMultipartUpload739=== PAUSE TestRedundantMultipartUpload740=== RUN TestCompleteMultipartUpload_ErrorButObjectExists741=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists742=== RUN TestCompletedNarNotReofferedAcrossClosures743=== PAUSE TestCompletedNarNotReofferedAcrossClosures744=== RUN TestPresignedUploadRegisteredBeforeCommit745=== PAUSE TestPresignedUploadRegisteredBeforeCommit746=== RUN TestService_Rustfstest747=== PAUSE TestService_Rustfstest748=== RUN TestParseSize749=== PAUSE TestParseSize750=== RUN TestSkippedUploadsHandler751=== PAUSE TestSkippedUploadsHandler752=== RUN TestSystemdListenerNotActivated753--- PASS: TestSystemdListenerNotActivated (0.00s)754=== RUN TestWatchdogBeatsWhenHealthy755--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)756=== RUN TestWatchdogSkipsWhenUnhealthy7572026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7582026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7592026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7602026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7612026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7622026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7632026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7642026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 19:40:09 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"767--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)768=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle769=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle770=== RUN TestProxyWriteTimeout771=== PAUSE TestProxyWriteTimeout772=== RUN TestPendingClosureWriteTimeout773=== PAUSE TestPendingClosureWriteTimeout774=== RUN TestIsValidUploadKey775=== PAUSE TestIsValidUploadKey776=== RUN TestUploadHandlersRejectInvalidKeys777=== PAUSE TestUploadHandlersRejectInvalidKeys778=== RUN TestUploadHandlersRejectOversizedBody779=== PAUSE TestUploadHandlersRejectOversizedBody780=== RUN TestService_cleanupPendingClosuresHandler781=== PAUSE TestService_cleanupPendingClosuresHandler782=== RUN TestService_createPendingClosureHandler783=== PAUSE TestService_createPendingClosureHandler784=== RUN TestService_verifyS3Integrity785=== PAUSE TestService_verifyS3Integrity786=== RUN TestCompleteMultipartUnregistered787=== PAUSE TestCompleteMultipartUnregistered788=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT789=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT790=== CONT TestService_AuthMiddleware791=== CONT TestPush_RejectsBadRequests792=== CONT TestReadProxyConditionalGet793=== CONT TestPush_OverlappingRootsStoreOneRowPerKey794=== CONT TestCompleteMultipartUnregistered795=== CONT TestService_verifyS3Integrity796=== CONT TestService_createPendingClosureHandler797=== CONT TestService_cleanupPendingClosuresHandler798=== CONT TestUploadHandlersRejectOversizedBody799=== CONT TestUploadHandlersRejectInvalidKeys800=== CONT TestIsValidUploadKey801=== CONT TestPendingClosureWriteTimeout802=== RUN TestIsValidUploadKey/narinfo803=== CONT TestProxyWriteTimeout804=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle805=== CONT TestSkippedUploadsHandler806=== CONT TestParseSize807=== CONT TestService_Rustfstest808=== CONT TestPresignedUploadRegisteredBeforeCommit809=== CONT TestCompletedNarNotReofferedAcrossClosures810=== CONT TestCompleteMultipartUpload_ErrorButObjectExists811=== CONT TestRedundantMultipartUpload812=== CONT TestPush_SignsNarinfosOfItsPendingObjects813=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit814=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT815=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info816=== CONT TestPush_RootsAreLockedInByteOrder817=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info818=== RUN TestPendingClosureWriteTimeout/empty819=== PAUSE TestPendingClosureWriteTimeout/empty820=== RUN TestPendingClosureWriteTimeout/400_objects821=== PAUSE TestPendingClosureWriteTimeout/400_objects822=== RUN TestPendingClosureWriteTimeout/670k_objects823=== PAUSE TestPendingClosureWriteTimeout/670k_objects824=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline825=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline826=== PAUSE TestIsValidUploadKey/narinfo827=== RUN TestIsValidUploadKey/nar_zst828=== PAUSE TestIsValidUploadKey/nar_zst829=== RUN TestIsValidUploadKey/nar_xz830=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal831=== RUN TestProxyWriteTimeout/narinfo832--- PASS: TestParseSize (0.00s)8332026/10/25 19:40:09 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000834=== PAUSE TestIsValidUploadKey/nar_xz835=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal836=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key837=== CONT TestPush_CompleteWaitsForCleanupOfThePush838=== PAUSE TestProxyWriteTimeout/narinfo839=== RUN TestIsValidUploadKey/nar_plain840=== PAUSE TestIsValidUploadKey/nar_plain841=== RUN TestIsValidUploadKey/listing842=== PAUSE TestIsValidUploadKey/listing843=== RUN TestIsValidUploadKey/build_log844=== PAUSE TestIsValidUploadKey/build_log845=== RUN TestIsValidUploadKey/build_log_home-manager_file846=== PAUSE TestIsValidUploadKey/build_log_home-manager_file847=== RUN TestIsValidUploadKey/build_log_plus_in_name848=== PAUSE TestIsValidUploadKey/build_log_plus_in_name849=== RUN TestIsValidUploadKey/build_log_question_mark850=== PAUSE TestIsValidUploadKey/build_log_question_mark851=== RUN TestIsValidUploadKey/build_log_equals852=== PAUSE TestIsValidUploadKey/build_log_equals853=== RUN TestIsValidUploadKey/realisation854=== PAUSE TestIsValidUploadKey/realisation855=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key856=== RUN TestProxyWriteTimeout/1_GiB_nar857=== PAUSE TestProxyWriteTimeout/1_GiB_nar858=== RUN TestProxyWriteTimeout/10_GiB_nar859=== PAUSE TestProxyWriteTimeout/10_GiB_nar860=== RUN TestProxyWriteTimeout/unknown_size861=== PAUSE TestProxyWriteTimeout/unknown_size862=== RUN TestIsValidUploadKey/realisation_plus_in_output863=== PAUSE TestIsValidUploadKey/realisation_plus_in_output864=== RUN TestIsValidUploadKey/nix-cache-info865=== PAUSE TestIsValidUploadKey/nix-cache-info866=== RUN TestIsValidUploadKey/index.html867=== PAUSE TestIsValidUploadKey/index.html868=== RUN TestIsValidUploadKey/narinfo_key,_nar_type869=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type870=== RUN TestIsValidUploadKey/nar_key,_narinfo_type871=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type872=== RUN TestIsValidUploadKey/listing_key,_narinfo_type873=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type874=== RUN TestIsValidUploadKey/traversal875=== PAUSE TestIsValidUploadKey/traversal876=== RUN TestIsValidUploadKey/traversal_nar877=== PAUSE TestIsValidUploadKey/traversal_nar878=== RUN TestIsValidUploadKey/absolute879=== PAUSE TestIsValidUploadKey/absolute880=== RUN TestIsValidUploadKey/empty_key881=== PAUSE TestIsValidUploadKey/empty_key882=== RUN TestIsValidUploadKey/unknown_type883=== PAUSE TestIsValidUploadKey/unknown_type884=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key885=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key886=== CONT TestReadRedirectKeepsNarinfoProxied887=== CONT TestPush_RepeatedRootCommitsOnce888=== CONT TestPush_CompleteCommitsEveryRoot889--- PASS: TestSkippedUploadsHandler (0.08s)890=== CONT TestReadRedirectUsesPublicS3URL891=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart892=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart893=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts894=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts895=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure896=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure897=== CONT TestReadProxyRangeRequest8982026/10/25 19:40:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8992026/10/25 19:40:10 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst900--- PASS: TestCompleteMultipartUnregistered (0.96s)901=== CONT TestReadProxyDisabled9022026/10/25 19:40:10 INFO Received cleanup request method=DELETE path=/api/pending_closures9032026/10/25 19:40:10 INFO Aborted multipart uploads count=0 kept=09042026/10/25 19:40:10 INFO Received uploads request method=POST path=/api/pending_closures9052026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9062026/10/25 19:40:11 INFO Received cleanup request method=DELETE path=/api/pending_closures9072026/10/25 19:40:11 INFO Aborted multipart uploads count=1 kept=09082026/10/25 19:40:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9092026-10-25 19:40:11.057 UTC [390] ERROR: Closure does not exist: id=19102026-10-25 19:40:11.057 UTC [390] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9112026-10-25 19:40:11.057 UTC [390] STATEMENT: -- name: CommitPendingClosure :one912 SELECT commit_pending_closure($1::bigint)::bigint913 914--- PASS: TestService_cleanupPendingClosuresHandler (1.10s)915=== CONT TestReadRedirectNar9162026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes9172026/10/25 19:40:11 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"918--- PASS: TestService_AuthMiddleware (1.14s)919=== CONT TestGCEndsOnShutdown920=== RUN TestGCEndsOnShutdown/before_the_run921=== PAUSE TestGCEndsOnShutdown/before_the_run922=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete923=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete924=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark925=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark926=== CONT TestReadProxyOutlastsServerWriteTimeout927--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.14s)928=== CONT TestReadProxyHead929=== RUN TestPush_RejectsBadRequests/no_roots930=== PAUSE TestPush_RejectsBadRequests/no_roots931=== RUN TestPush_RejectsBadRequests/no_objects932=== PAUSE TestPush_RejectsBadRequests/no_objects933=== RUN TestPush_RejectsBadRequests/bad_root934=== PAUSE TestPush_RejectsBadRequests/bad_root935=== RUN TestPush_RejectsBadRequests/root_not_in_objects936=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects937=== CONT TestReadProxyInvalidPath9382026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9432026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes9442026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9452026/10/25 19:40:11 INFO Received complete push request method=POST path=/api/pushes/1/complete9462026/10/25 19:40:11 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjhkNGNkNWUzLWU1OTItNGZkOC1hYWUyLTY1ZGY0N2FiNjRjNngxNzkyOTU3MjExMTg2NTg3NTg19472026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes9482026/10/25 19:40:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjhkNGNkNWUzLWU1OTItNGZkOC1hYWUyLTY1ZGY0N2FiNjRjNngxNzkyOTU3MjExMTg2NTg3NTg1 parts=19492026/10/25 19:40:11 INFO Completed push id=1 objects=4 duration=8.237017ms9502026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes951--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.26s)952=== CONT TestReadProxy4049532026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9542026/10/25 19:40:11 INFO Signed narinfos id=1 count=19552026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9562026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9572026/10/25 19:40:11 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9582026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9592026/10/25 19:40:11 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9602026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9612026/10/25 19:40:11 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19622026/10/25 19:40:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9632026/10/25 19:40:11 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo964--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.26s)965=== CONT TestReadProxyNarStreaming966--- PASS: TestService_Rustfstest (1.27s)967=== CONT TestReadProxyContentNegotiation9682026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9692026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/25 19:40:11 INFO Aborted multipart uploads count=0 kept=09722026/10/25 19:40:11 WARN Force mode enabled - objects will be deleted immediately without grace period973--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.32s)974=== CONT TestReadProxyNarinfoAlreadyDecompressed9752026/10/25 19:40:11 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=09762026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes9772026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/25 19:40:11 INFO Vacuumed table table=pending_closures9792026/10/25 19:40:11 INFO Vacuumed table table=pending_objects9802026/10/25 19:40:11 INFO Vacuumed table table=multipart_uploads9812026/10/25 19:40:11 INFO Vacuumed table table=closures9822026/10/25 19:40:11 INFO Vacuumed table table=objects9832026/10/25 19:40:11 INFO Received complete push request method=POST path=/api/pushes/2/complete9842026/10/25 19:40:11 INFO Completed push id=2 objects=4 duration=3.272539ms985--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.37s)986=== CONT TestReadProxyNarinfo9872026/10/25 19:40:11 INFO Received complete push request method=POST path=/api/pushes/1/complete9882026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/25 19:40:11 INFO Completed push id=1 objects=6 duration=8.896796ms990--- PASS: TestPush_CompleteCommitsEveryRoot (1.30s)991=== CONT TestIsValidCachePath992=== RUN TestIsValidCachePath/narinfo993=== PAUSE TestIsValidCachePath/narinfo994=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars995=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars996=== RUN TestIsValidCachePath/nar_zst997=== PAUSE TestIsValidCachePath/nar_zst998=== RUN TestIsValidCachePath/nar_xz999=== PAUSE TestIsValidCachePath/nar_xz1000=== RUN TestIsValidCachePath/nar_bz21001=== PAUSE TestIsValidCachePath/nar_bz21002=== RUN TestIsValidCachePath/nar_uncompressed1003=== PAUSE TestIsValidCachePath/nar_uncompressed1004=== RUN TestIsValidCachePath/ls1005=== PAUSE TestIsValidCachePath/ls1006=== RUN TestIsValidCachePath/log1007=== PAUSE TestIsValidCachePath/log1008=== RUN TestIsValidCachePath/realisation1009=== PAUSE TestIsValidCachePath/realisation1010=== RUN TestIsValidCachePath/nix-cache-info1011=== PAUSE TestIsValidCachePath/nix-cache-info1012=== RUN TestIsValidCachePath/index.html1013=== PAUSE TestIsValidCachePath/index.html1014=== RUN TestIsValidCachePath/traversal_parent1015=== PAUSE TestIsValidCachePath/traversal_parent1016=== RUN TestIsValidCachePath/traversal_in_middle1017=== PAUSE TestIsValidCachePath/traversal_in_middle1018=== RUN TestIsValidCachePath/invalid_char_e1019=== PAUSE TestIsValidCachePath/invalid_char_e1020=== RUN TestIsValidCachePath/invalid_char_u1021=== PAUSE TestIsValidCachePath/invalid_char_u1022=== RUN TestIsValidCachePath/random_path1023=== PAUSE TestIsValidCachePath/random_path1024=== RUN TestIsValidCachePath/empty1025=== PAUSE TestIsValidCachePath/empty1026=== RUN TestIsValidCachePath/leading_slash1027=== PAUSE TestIsValidCachePath/leading_slash1028=== RUN TestIsValidCachePath/wrong_extension1029=== PAUSE TestIsValidCachePath/wrong_extension1030=== RUN TestIsValidCachePath/short_hash1031=== PAUSE TestIsValidCachePath/short_hash1032=== CONT TestParseSingleRange1033=== RUN TestParseSingleRange/none1034=== PAUSE TestParseSingleRange/none1035=== RUN TestParseSingleRange/unknown_unit1036=== PAUSE TestParseSingleRange/unknown_unit1037=== RUN TestParseSingleRange/multi-range_ignored1038=== PAUSE TestParseSingleRange/multi-range_ignored1039=== RUN TestParseSingleRange/malformed_no_dash1040=== PAUSE TestParseSingleRange/malformed_no_dash1041=== RUN TestParseSingleRange/malformed_both_empty1042=== PAUSE TestParseSingleRange/malformed_both_empty1043=== RUN TestParseSingleRange/malformed_end_before_start1044=== PAUSE TestParseSingleRange/malformed_end_before_start1045=== RUN TestParseSingleRange/closed1046=== PAUSE TestParseSingleRange/closed1047=== RUN TestParseSingleRange/open-ended1048=== PAUSE TestParseSingleRange/open-ended1049=== RUN TestParseSingleRange/end_clamped_to_size1050=== PAUSE TestParseSingleRange/end_clamped_to_size1051=== RUN TestParseSingleRange/suffix1052=== PAUSE TestParseSingleRange/suffix1053=== RUN TestParseSingleRange/suffix_exceeds_size1054=== PAUSE TestParseSingleRange/suffix_exceeds_size1055=== RUN TestParseSingleRange/single_byte1056=== PAUSE TestParseSingleRange/single_byte1057=== RUN TestParseSingleRange/start_past_EOF1058=== PAUSE TestParseSingleRange/start_past_EOF1059=== RUN TestParseSingleRange/start_far_past_EOF1060=== PAUSE TestParseSingleRange/start_far_past_EOF1061=== CONT TestPresentNotReportedWhileGCDeletesClosure1062=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1063=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1064=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1065=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1066=== CONT TestPresentRefreshesOnlyStaleClosures10672026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10682026/10/25 19:40:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10692026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures1070--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.39s)1071=== CONT TestPresentReportsOnlyClosureRoots10722026/10/25 19:40:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjc2ZmNhZGUyLWI5ZjAtNGU4NS04M2VlLTQ5NmI3YjExZTA1OHgxNzkyOTU3MjExMDU3NzkyNzI3 parts=1010732026/10/25 19:40:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10742026/10/25 19:40:11 INFO Completed upload id=1 objects=2 duration=2.994869ms10752026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures10762026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures1077--- PASS: TestReadRedirectUsesPublicS3URL (1.34s)10782026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1079=== CONT TestCreatePin_ReservedPins10802026/10/25 19:40:11 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10812026/10/25 19:40:11 WARN Found objects in DB but missing from S3, will re-upload count=11082--- PASS: TestService_verifyS3Integrity (1.42s)1083=== CONT TestOrphanedObjectsGCStressTest10842026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes10852026/10/25 19:40:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38677/oidc10862026/10/25 19:40:11 INFO Received complete push request method=POST path=/api/pushes/1/complete1087--- PASS: TestReadProxyConditionalGet (1.48s)1088=== CONT TestOrphanedObjectsGC10892026/10/25 19:40:11 INFO Completed push id=1 objects=4 duration=54.000128ms1090--- PASS: TestPush_RepeatedRootCommitsOnce (1.42s)1091=== CONT TestObjectStatsUpdatedOncePerCommit10922026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10932026/10/25 19:40:11 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjgwY2MwMTQ1LWQ0MjItNDBjYi05ZjM2LWJmMTBhZjhjYWZmY3gxNzkyOTU3MjExMTQ3MzQ5OTMw parts=1010942026/10/25 19:40:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10952026/10/25 19:40:11 INFO Completed upload id=1 objects=2 duration=3.879659ms10962026/10/25 19:40:11 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010972026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures1098--- PASS: TestReadRedirectKeepsNarinfoProxied (1.57s)1099=== CONT TestObjectStatsTrigger11002026/10/25 19:40:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures11012026/10/25 19:40:11 INFO Aborted multipart uploads count=0 kept=011022026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes11032026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11042026/10/25 19:40:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011052026/10/25 19:40:11 INFO Received push request method=POST path=/api/pushes11062026/10/25 19:40:11 INFO Vacuumed table table=pending_closures11072026/10/25 19:40:11 INFO Vacuumed table table=pending_objects11082026/10/25 19:40:11 INFO Vacuumed table table=multipart_uploads11092026/10/25 19:40:11 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjdkMTM1NjQ1LTZmY2UtNGRhZS1iZmIxLTc5ZmZiNTkwYzRkOXgxNzkyOTU3MjExMTc4Njg3NTk4 parts=1211102026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/25 19:40:11 INFO Vacuumed table table=closures11122026/10/25 19:40:11 INFO Vacuumed table table=objects1113--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.70s)1114=== CONT TestPendingCleanupUsesOneCutoff1115--- PASS: TestReadProxyRangeRequest (1.57s)1116=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11172026-10-25 19:40:11.695 UTC [495] ERROR: could not obtain lock on row in relation "closures"11182026-10-25 19:40:11.695 UTC [495] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11192026-10-25 19:40:11.695 UTC [495] ERROR: could not obtain lock on row in relation "closures"11202026-10-25 19:40:11.695 UTC [495] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11212026-10-25 19:40:11.695 UTC [495] ERROR: could not obtain lock on row in relation "closures"11222026-10-25 19:40:11.695 UTC [495] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11232026-10-25 19:40:11.696 UTC [495] ERROR: could not obtain lock on row in relation "closures"11242026-10-25 19:40:11.696 UTC [495] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11252026-10-25 19:40:11.696 UTC [495] ERROR: could not obtain lock on row in relation "closures"11262026-10-25 19:40:11.696 UTC [495] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1127--- PASS: TestReadProxyDisabled (0.77s)1128=== CONT TestMultipartCleanup1129--- PASS: TestPush_RootsAreLockedInByteOrder (1.74s)1130=== CONT TestServerTLSConfig1131=== RUN TestServerTLSConfig/no_client_CA1132=== PAUSE TestServerTLSConfig/no_client_CA1133=== RUN TestServerTLSConfig/missing_CA_file1134=== PAUSE TestServerTLSConfig/missing_CA_file1135=== RUN TestServerTLSConfig/not_a_PEM_file1136=== PAUSE TestServerTLSConfig/not_a_PEM_file1137=== CONT TestService_NativeMTLS11382026/10/25 19:40:11 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001139--- PASS: TestService_createPendingClosureHandler (1.76s)1140=== CONT TestMetricsCommit1141--- PASS: TestReadRedirectNar (0.67s)1142=== CONT TestMetricsInventory11432026/10/25 19:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1144--- PASS: TestReadProxyHead (0.67s)1145=== CONT TestNARDeduplicationMetadataUploadBug1146--- PASS: TestReadProxyInvalidPath (0.66s)1147=== CONT TestCreatePendingClosureRejectsOversizedNAR11482026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures1149--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1150=== CONT TestCacheConfigHandlerMaxNarSize1151--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1152=== CONT TestGenerateLandingPage11532026/10/25 19:40:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjQ4MGNkODgxLTVlMzItNDI0Yy1iMmNmLTM1ZjlmZWQyMjFjY3gxNzkyOTU3MjExMjY2NTU2ODcy parts=121154--- PASS: TestGenerateLandingPage (0.00s)1155=== CONT TestService_readinessHandler11562026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/25 19:40:11 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestReadProxyNarStreaming (0.60s)1159=== CONT TestService_healthCheckHandler1160--- PASS: TestReadProxy404 (0.63s)1161=== CONT TestGracefulShutdownDrainsInflight11622026/10/25 19:40:11 INFO Starting HTTP server address=127.0.0.1:4392311632026/10/25 19:40:11 INFO Shutdown signal received, draining in-flight requests timeout=10s1164--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.58s)1165=== CONT TestGCTaskStore_Fail1166--- PASS: TestGCTaskStore_Fail (0.00s)1167=== CONT TestGCTaskStore_PhaseUpdates1168--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1169=== CONT TestGCTaskStore_CompletedAllowsNewTask1170--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1171=== CONT TestGCTaskStore_GetReturnsLatest1172--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1173=== CONT TestGCTaskStore_GetEmpty1174--- PASS: TestGCTaskStore_GetEmpty (0.00s)1175=== CONT TestGCTaskStore_ConflictDifferentParams1176--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1177=== CONT TestGCTaskStore_DeduplicateSameParams1178--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1179=== CONT TestGCTaskStore_StartNew1180--- PASS: TestGCTaskStore_StartNew (0.00s)1181=== CONT TestConnectWaitsForAPeerMigration1182--- PASS: TestReadProxyContentNegotiation (0.65s)1183=== CONT TestCommitRacingPendingCleanupKeepsObjects1184--- PASS: TestPresentRefreshesOnlyStaleClosures (0.55s)1185=== CONT TestPushWaitsForSweepHoldingRow1186--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1187=== CONT TestSweepRechecksPendingAfterLocking11882026/10/25 19:40:11 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1189--- PASS: TestReadProxyNarinfo (0.65s)1190=== CONT TestGetExistingObjectsLocksRows11912026-10-25 19:40:12.016 UTC [487] ERROR: Push does not exist: id=111922026-10-25 19:40:12.016 UTC [487] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11932026-10-25 19:40:12.016 UTC [487] STATEMENT: SELECT commit_push($1)1194--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.98s)1195=== CONT TestRegisterCompletedObjectNeedsPendingRow1196--- PASS: TestPresentReportsOnlyClosureRoots (0.79s)1197=== CONT TestSweepSkipsRowsLockedByPush11982026/10/25 19:40:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11992026/10/25 19:40:12 WARN Refused reserved pin name=worker-x86_64-linux12002026/10/25 19:40:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12012026/10/25 19:40:12 INFO Received create pin request method=POST path=/api/pins/my-app12022026/10/25 19:40:12 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1203--- PASS: TestCreatePin_ReservedPins (0.80s)1204=== CONT TestFailedS3DeleteKeepsTombstone1205--- PASS: TestObjectStatsUpdatedOncePerCommit (0.82s)1206=== CONT TestForceGCDuringPushOffersSweptObject1207=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1208=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1209=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1210=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1211=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12122026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures1213--- PASS: TestObjectStatsTrigger (0.74s)1214=== CONT TestGCSweepDeliversEachKeyOnce12152026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures12162026/10/25 19:40:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12172026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures1218--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.70s)1219=== CONT TestTombstonedObjectOfferedWithoutWaiting12202026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/25 19:40:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12222026/10/25 19:40:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12232026/10/25 19:40:12 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1224--- PASS: TestService_NativeMTLS (0.71s)1225=== CONT TestGCSweepSkipsPendingObjects12262026/10/25 19:40:12 INFO Received push request method=POST path=/api/pushes12272026/10/25 19:40:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjViYWYyYjdjLTE1ZDctNDg0Yy05MzMxLWRlYzNhYmI0MmVmMHgxNzkyOTU3MjExODA3NDg1MjE1 error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12282026/10/25 19:40:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=Y2NkZTVhZjYtMjU5MC00ZmNkLTg2NjItNWRlM2U4N2IxMmJmLjMyNzdhYjlmLWJmZWUtNGI4YS1hMDQzLTNmZjk3ZjgwYmFkNXgxNzkyOTU3MjExNzk5NjgyOTM4 parts=1212292026/10/25 19:40:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12302026/10/25 19:40:12 INFO Aborted multipart uploads count=1 kept=01231--- PASS: TestRedundantMultipartUpload (2.48s)1232=== CONT TestDeduplicatedObjectsRecordedAsPending12332026/10/25 19:40:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12342026/10/25 19:40:12 INFO Completed push id=1 objects=4 duration=8.979256ms12352026/10/25 19:40:12 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12362026/10/25 19:40:12 INFO Completed upload id=2 objects=2 duration=1.128989ms1237--- PASS: TestMetricsInventory (0.74s)1238=== CONT TestPushDedupSurvivesConcurrentGC1239--- PASS: TestMetricsCommit (0.75s)1240=== CONT TestGCMetrics12412026/10/25 19:40:12 WARN readiness check failed error="closed pool"1242--- PASS: TestService_readinessHandler (0.71s)1243=== CONT TestGCBugBareHashReferences12442026/10/25 19:40:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12452026/10/25 19:40:12 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12462026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=11247--- PASS: TestService_healthCheckHandler (0.68s)1248=== CONT TestGCAdvisoryLockBlocksConcurrentRun1249=== NAME TestNARDeduplicationMetadataUploadBug1250 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1202718827/001/store/113mfnkfbr1l7zc95hqvq4wprbqdd1ns-file1.txt12512026/10/25 19:40:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12522026/10/25 19:40:12 INFO Aborted multipart uploads count=1 kept=01253--- PASS: TestMultipartCleanup (0.83s)1254=== CONT TestLeadEndsOnShutdown12552026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=012562026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period12572026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures12582026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012592026/10/25 19:40:12 INFO Vacuumed table table=pending_closures12602026/10/25 19:40:12 INFO Vacuumed table table=pending_objects12612026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads12622026/10/25 19:40:12 INFO Vacuumed table table=closures12632026/10/25 19:40:12 INFO Vacuumed table table=objects1264--- PASS: TestSweepRechecksPendingAfterLocking (0.66s)1265=== CONT TestLeadIncumbentAnnouncesAtOnce12662026/10/25 19:40:12 INFO Received push request method=POST path=/api/pushes12672026/10/25 19:40:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12682026/10/25 19:40:12 INFO Uploading 113mfnkfbr1l7zc95hqvq4wprbqdd1ns-file1.txt (160B)1269--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.59s)1270=== CONT TestLeadElectsOneAndHandsOver12712026/10/25 19:40:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12722026/10/25 19:40:12 WARN Failed to register uploaded object key=113mfnkfbr1l7zc95hqvq4wprbqdd1ns.ls error="server returned 404: 404 page not found\n"12732026/10/25 19:40:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12742026/10/25 19:40:12 INFO Signed narinfos id=1 count=112752026/10/25 19:40:12 INFO Uploading 1 narinfos1276--- PASS: TestGetExistingObjectsLocksRows (0.64s)1277=== CONT TestClientIntegration12782026/10/25 19:40:12 INFO Received complete push request method=POST path=/api/pushes/1/complete12792026/10/25 19:40:12 WARN Failed to register uploaded object key=113mfnkfbr1l7zc95hqvq4wprbqdd1ns.narinfo error="server returned 404: 404 page not found\n"12802026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=012812026/10/25 19:40:12 INFO Completed push id=1 objects=3 duration=7.220537ms12822026/10/25 19:40:12 INFO Upload complete. (86ms)12832026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period1284=== NAME TestNARDeduplicationMetadataUploadBug1285 metadata_upload_test.go:54: Retrieved narinfo from S3:1286 StorePath: /build/TestNARDeduplicationMetadataUploadBug1202718827/001/store/113mfnkfbr1l7zc95hqvq4wprbqdd1ns-file1.txt1287 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1288 Compression: zstd1289 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1290 NarSize: 1601291 References: 1292 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1293 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1294 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1295 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12962026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012972026/10/25 19:40:12 INFO Vacuumed table table=pending_closures12982026/10/25 19:40:12 INFO Vacuumed table table=pending_objects12992026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads13002026/10/25 19:40:12 INFO Vacuumed table table=closures13012026/10/25 19:40:12 INFO Vacuumed table table=objects13022026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures13032026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=013042026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period1305--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.77s)1306=== CONT TestResolveDBConnectionString1307=== RUN TestResolveDBConnectionString/flag_wins1308=== PAUSE TestResolveDBConnectionString/flag_wins1309=== RUN TestResolveDBConnectionString/file_when_flag_empty1310=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1311=== RUN TestResolveDBConnectionString/missing_file_is_an_error1312=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1313=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1314=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1315=== RUN TestResolveDBConnectionString/nothing_configured1316=== PAUSE TestResolveDBConnectionString/nothing_configured1317=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13182026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013192026/10/25 19:40:12 INFO Vacuumed table table=pending_closures13202026/10/25 19:40:12 INFO Vacuumed table table=pending_objects13212026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads13222026/10/25 19:40:12 INFO Vacuumed table table=closures13232026/10/25 19:40:12 INFO Vacuumed table table=objects13242026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=01325=== NAME TestNARDeduplicationMetadataUploadBug1326 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1202718827/001/store/ib3c8ririnxgqmwj4kv0cmxpil05x3li-file2.txt13272026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period13282026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures13292026/10/25 19:40:12 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=013302026/10/25 19:40:12 INFO Vacuumed table table=pending_closures13312026/10/25 19:40:12 INFO Vacuumed table table=pending_objects13322026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads13332026/10/25 19:40:12 INFO Vacuumed table table=closures13342026/10/25 19:40:12 INFO Vacuumed table table=objects1335--- PASS: TestSweepSkipsRowsLockedByPush (0.56s)1336=== CONT TestDeleteClosuresRacingPins1337=== NAME TestOrphanedObjectsGC1338 orphaned_objects_gc_test.go:287: GC Test Summary:1339 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1340 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1341 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1342 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1343 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1344--- PASS: TestOrphanedObjectsGC (1.27s)1345=== CONT TestClientFallsBackToClosures13462026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures1347--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.32s)1348=== CONT TestClientPushesUseOnePush13492026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=013502026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=013512026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period13522026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period13532026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures13542026/10/25 19:40:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13552026/10/25 19:40:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13562026/10/25 19:40:12 INFO Received push request method=POST path=/api/pushes1357--- PASS: TestFailedS3DeleteKeepsTombstone (0.56s)1358=== CONT TestPinProtectsFromGC13592026/10/25 19:40:12 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13602026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=013612026/10/25 19:40:12 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13622026/10/25 19:40:12 WARN Failed to register uploaded object key=ib3c8ririnxgqmwj4kv0cmxpil05x3li.ls error="server returned 404: 404 page not found\n"13632026/10/25 19:40:12 INFO Signed narinfos id=2 count=113642026/10/25 19:40:12 INFO Uploading 1 narinfos13652026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period13662026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures13672026/10/25 19:40:12 INFO Received complete push request method=POST path=/api/pushes/2/complete13682026/10/25 19:40:12 WARN Failed to register uploaded object key=ib3c8ririnxgqmwj4kv0cmxpil05x3li.narinfo error="server returned 404: 404 page not found\n"13692026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013702026/10/25 19:40:12 INFO Completed push id=2 objects=3 duration=2.597829ms13712026/10/25 19:40:12 INFO Upload complete. (57ms)1372=== NAME TestNARDeduplicationMetadataUploadBug1373 metadata_upload_test.go:76: Retrieved narinfo from S3:1374 StorePath: /build/TestNARDeduplicationMetadataUploadBug1202718827/001/store/ib3c8ririnxgqmwj4kv0cmxpil05x3li-file2.txt1375 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1376 Compression: zstd1377 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1378 NarSize: 1601379 References: 1380 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13812026/10/25 19:40:12 INFO Vacuumed table table=pending_closures1382--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.31s)1383=== CONT TestClientSharedPathCommittedMidPush1384=== NAME TestNARDeduplicationMetadataUploadBug1385 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1386 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1387 {"version":1,"root":{"type":"regular","size":44}}13882026/10/25 19:40:12 INFO Vacuumed table table=pending_objects13892026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads13902026/10/25 19:40:12 INFO Vacuumed table table=closures13912026/10/25 19:40:12 INFO Vacuumed table table=objects13922026/10/25 19:40:12 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=01393--- PASS: TestNARDeduplicationMetadataUploadBug (1.00s)1394=== CONT TestClientWithDependencies13952026/10/25 19:40:12 INFO Vacuumed table table=pending_closures13962026/10/25 19:40:12 INFO Vacuumed table table=pending_objects13972026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads13982026/10/25 19:40:12 INFO Vacuumed table table=closures1399--- PASS: TestGCSweepSkipsPendingObjects (0.37s)1400=== CONT TestClientMultipleUploads14012026/10/25 19:40:12 INFO Vacuumed table table=objects1402--- PASS: TestGCSweepDeliversEachKeyOnce (0.44s)1403=== CONT TestService_ReadScope_PublicByDefault14042026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=014052026/10/25 19:40:12 INFO Received uploads request method=POST path=/api/pending_closures14062026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period14072026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014082026/10/25 19:40:12 INFO Vacuumed table table=pending_closures14092026/10/25 19:40:12 INFO Vacuumed table table=pending_objects14102026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads14112026/10/25 19:40:12 INFO Vacuumed table table=closures14122026/10/25 19:40:12 INFO Vacuumed table table=objects1413--- PASS: TestGCMetrics (0.36s)1414=== CONT TestClientErrorHandling1415=== RUN TestClientErrorHandling/InvalidStorePath1416=== PAUSE TestClientErrorHandling/InvalidStorePath1417=== RUN TestClientErrorHandling/InvalidAuthToken1418=== PAUSE TestClientErrorHandling/InvalidAuthToken1419=== RUN TestClientErrorHandling/ServerNotAvailable1420=== PAUSE TestClientErrorHandling/ServerNotAvailable1421=== CONT TestClientCADerivations14222026/10/25 19:40:12 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1423--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.34s)1424=== CONT TestCacheStatsHandler14252026/10/25 19:40:12 INFO lead: acquired remote=192.0.2.1:123414262026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=014272026/10/25 19:40:12 INFO lead: acquired remote=192.0.2.1:123414282026/10/25 19:40:12 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=014292026/10/25 19:40:12 INFO Vacuumed table table=pending_closures1430--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.62s)1431=== CONT TestCacheConfigHandler1432=== RUN TestCacheConfigHandler/full_config,_no_issuer1433=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1434=== RUN TestCacheConfigHandler/no_cache_url_configured1435=== PAUSE TestCacheConfigHandler/no_cache_url_configured1436=== RUN TestCacheConfigHandler/no_signing_keys1437=== PAUSE TestCacheConfigHandler/no_signing_keys1438=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1439=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1440=== CONT TestService_ReadAuthMiddleware14412026/10/25 19:40:12 INFO Vacuumed table table=pending_objects14422026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads14432026/10/25 19:40:12 INFO Vacuumed table table=closures14442026/10/25 19:40:12 INFO Vacuumed table table=objects14452026/10/25 19:40:12 INFO lead: acquired remote=192.0.2.1:123414462026/10/25 19:40:12 INFO lead: released remote=192.0.2.1:12341447--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.34s)1448=== CONT TestService_RequireScope_OIDC14492026/10/25 19:40:12 INFO Aborted multipart uploads count=0 kept=014502026/10/25 19:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period14512026/10/25 19:40:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014522026/10/25 19:40:12 INFO Vacuumed table table=pending_closures14532026/10/25 19:40:12 INFO Vacuumed table table=pending_objects14542026/10/25 19:40:12 INFO Vacuumed table table=multipart_uploads14552026/10/25 19:40:13 INFO Vacuumed table table=closures14562026/10/25 19:40:13 INFO Vacuumed table table=objects1457--- PASS: TestPushDedupSurvivesConcurrentGC (0.59s)1458=== CONT TestService_AuthMiddleware_OIDC14592026/10/25 19:40:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38197/oidc14602026/10/25 19:40:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36117/oidc1461--- PASS: TestPushWaitsForSweepHoldingRow (1.21s)1462=== CONT TestReadProxyRootRedirectsToIndexHTML1463=== NAME TestClientIntegration1464 client_integration_test.go:291: Created store path: /build/TestClientIntegration3504837079/002/store/5b4dz73pg328kh2r45abh8vcwvcys6xk-test-file.txt1465--- PASS: TestGCBugBareHashReferences (0.65s)1466=== CONT TestService_AuthMiddleware_MTLSProxyHeader14672026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes14682026/10/25 19:40:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14692026/10/25 19:40:13 INFO Uploading 5b4dz73pg328kh2r45abh8vcwvcys6xk-test-file.txt (152B)14702026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14712026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14722026/10/25 19:40:13 WARN Failed to register uploaded object key=5b4dz73pg328kh2r45abh8vcwvcys6xk.ls error="server returned 404: 404 page not found\n"14732026/10/25 19:40:13 INFO Signed narinfos id=1 count=114742026/10/25 19:40:13 INFO Uploading 1 narinfos14752026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14762026/10/25 19:40:13 WARN Failed to register uploaded object key=5b4dz73pg328kh2r45abh8vcwvcys6xk.narinfo error="server returned 404: 404 page not found\n"14772026/10/25 19:40:13 INFO Completed push id=1 objects=3 duration=10.512515ms14782026/10/25 19:40:13 INFO Upload complete. (106ms)14792026/10/25 19:40:13 INFO All 1 paths already cached1480=== NAME TestClientIntegration1481 client_integration_test.go:317: Retrieved narinfo from S3:1482 StorePath: /build/TestClientIntegration3504837079/002/store/5b4dz73pg328kh2r45abh8vcwvcys6xk-test-file.txt1483 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1484 Compression: zstd1485 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11486 NarSize: 1521487 References: 1488 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11489 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1490 client_integration_test.go:318: Decompressed .ls content (64 bytes):1491 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}14922026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes14932026/10/25 19:40:13 INFO Object in database but missing from S3 key=5b4dz73pg328kh2r45abh8vcwvcys6xk.ls14942026/10/25 19:40:13 WARN Found objects in DB but missing from S3, will re-upload count=114952026/10/25 19:40:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14962026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/2/complete14972026/10/25 19:40:13 WARN Failed to register uploaded object key=5b4dz73pg328kh2r45abh8vcwvcys6xk.ls error="server returned 404: 404 page not found\n"14982026/10/25 19:40:13 INFO Completed push id=2 objects=3 duration=2.293519ms14992026/10/25 19:40:13 INFO Upload complete. (46ms)1500 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1501 client_integration_test.go:335: Decompressed .ls content (49 bytes):1502 {"version":1,"root":{"type":"regular","size":39}}1503=== NAME TestPinProtectsFromGC1504 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC2648889405/001/store/44vjpz6kqxhbapi566h11qbzczqnml7r-pinned-file.txt1505 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC2648889405/001/store/fcp6jf8dq197011yhg0q0wqr4pgq0kpk-unpinned-file.txt1506=== NAME TestClientMultipleUploads1507 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads89102177/001/store/1fgcz12rxgz01vnq1cj5s5hp47xmxjhs-test-file-0.txt1508--- PASS: TestService_ReadScope_PublicByDefault (0.65s)1509=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1510=== NAME TestClientMultipleUploads1511 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads89102177/001/store/vd51j8v9d5diw0a6y1bymnbapq9zi4md-test-file-1.txt15122026/10/25 19:40:13 INFO Received uploads request method=POST path=/api/pending_closures15132026/10/25 19:40:13 INFO Received uploads request method=POST path=/api/pending_closures15142026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes15152026/10/25 19:40:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15162026/10/25 19:40:13 INFO Uploading pivpsvjnc9dd43nch61sisca1fl9s8p9-shared-dep (136B)15172026/10/25 19:40:13 INFO Uploading wcq2vb1jvqhgpk88mxa097wrxrlsdf5k-a (216B)1518--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.83s)1519=== CONT TestPendingClosureWriteTimeout/empty1520=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline15212026/10/25 19:40:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15222026/10/25 19:40:13 INFO Uploading 44vjpz6kqxhbapi566h11qbzczqnml7r-pinned-file.txt (128B)15232026/10/25 19:40:13 WARN Failed to register uploaded object key=wi2wnriz2pwyr2asmqfrqmmqi275br70.ls error="server returned 404: 404 page not found\n"15242026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15252026/10/25 19:40:13 WARN Failed to register uploaded object key=pivpsvjnc9dd43nch61sisca1fl9s8p9.ls error="server returned 404: 404 page not found\n"15262026/10/25 19:40:13 WARN Failed to register uploaded object key=wcq2vb1jvqhgpk88mxa097wrxrlsdf5k.ls error="server returned 404: 404 page not found\n"15272026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1528--- PASS: TestCacheStatsHandler (0.64s)15292026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/17057snjvslrqby95gni1mbx2m19mrp14gyqfjylxca9zz575wsx.nar.zst error="server returned 404: 404 page not found\n"1530=== CONT TestPendingClosureWriteTimeout/670k_objects15312026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes1532=== CONT TestPendingClosureWriteTimeout/400_objects1533=== CONT TestProxyWriteTimeout/narinfo15342026/10/25 19:40:13 INFO Signed narinfos id=1 count=21535=== CONT TestProxyWriteTimeout/10_GiB_nar15362026/10/25 19:40:13 WARN Failed to register uploaded object key=44vjpz6kqxhbapi566h11qbzczqnml7r.ls error="server returned 404: 404 page not found\n"1537=== CONT TestProxyWriteTimeout/1_GiB_nar15382026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1539=== CONT TestProxyWriteTimeout/unknown_size1540--- PASS: TestProxyWriteTimeout (0.07s)1541 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1542 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1543 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1544 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)15452026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1546=== CONT TestIsValidUploadKey/narinfo15472026/10/25 19:40:13 INFO Signed narinfos id=2 count=21548=== CONT TestIsValidUploadKey/realisation_plus_in_output1549=== CONT TestIsValidUploadKey/realisation15502026/10/25 19:40:13 INFO Signed narinfos id=1 count=11551=== CONT TestIsValidUploadKey/build_log_equals15522026/10/25 19:40:13 INFO Uploading 4 narinfos1553=== CONT TestIsValidUploadKey/build_log_question_mark15542026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1555=== CONT TestIsValidUploadKey/build_log_plus_in_name15562026/10/25 19:40:13 INFO Uploading 1 narinfos1557=== CONT TestIsValidUploadKey/build_log_home-manager_file1558=== CONT TestIsValidUploadKey/build_log1559=== CONT TestIsValidUploadKey/listing1560=== CONT TestIsValidUploadKey/nar_plain1561=== CONT TestIsValidUploadKey/nix-cache-info1562=== CONT TestIsValidUploadKey/nar_xz1563=== CONT TestIsValidUploadKey/nar_zst1564=== CONT TestIsValidUploadKey/traversal_nar1565=== CONT TestIsValidUploadKey/unknown_type1566=== CONT TestIsValidUploadKey/empty_key1567=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1568=== CONT TestIsValidUploadKey/traversal1569=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1570=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1571=== CONT TestIsValidUploadKey/index.html1572=== CONT TestIsValidUploadKey/absolute1573--- PASS: TestIsValidUploadKey (0.08s)1574 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1575 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1576 --- PASS: TestIsValidUploadKey/realisation (0.00s)1577 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1578 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1579 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1580 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1581 --- PASS: TestIsValidUploadKey/build_log (0.00s)1582 --- PASS: TestIsValidUploadKey/listing (0.00s)1583 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1584 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1585 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1586 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1587 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1588 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1589 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1590 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1591 --- PASS: TestIsValidUploadKey/traversal (0.00s)1592 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1593 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1594 --- PASS: TestIsValidUploadKey/index.html (0.00s)1595 --- PASS: TestIsValidUploadKey/absolute (0.00s)1596=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15972026/10/25 19:40:13 INFO Received uploads request method=POST path=/1598=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15992026/10/25 19:40:13 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16002026/10/25 19:40:13 INFO Received complete multipart upload request method=POST path=/1601=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16022026/10/25 19:40:13 INFO Received request for more parts method=POST path=/1603=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16042026/10/25 19:40:13 INFO Received uploads request method=POST path=/1605--- PASS: TestUploadHandlersRejectInvalidKeys (0.08s)1606 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1607 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1608 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1609 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1610=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16112026/10/25 19:40:13 INFO Received complete multipart upload request method=POST path=/16122026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete16132026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes16142026/10/25 19:40:13 WARN Failed to register uploaded object key=wcq2vb1jvqhgpk88mxa097wrxrlsdf5k.narinfo error="server returned 404: 404 page not found\n"16152026/10/25 19:40:13 WARN Failed to register uploaded object key=44vjpz6kqxhbapi566h11qbzczqnml7r.narinfo error="server returned 404: 404 page not found\n"16162026/10/25 19:40:13 WARN Failed to register uploaded object key=pivpsvjnc9dd43nch61sisca1fl9s8p9.narinfo error="server returned 404: 404 page not found\n"16172026/10/25 19:40:13 WARN Failed to register uploaded object key=wi2wnriz2pwyr2asmqfrqmmqi275br70.narinfo error="server returned 404: 404 page not found\n"16182026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/3/complete1619=== NAME TestClientWithDependencies16202026/10/25 19:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1621 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies244315/001/store/39ich7gfdwi4f3ygni56nfywq99yqsph-test-script16222026/10/25 19:40:13 WARN Failed to register uploaded object key=5b4dz73pg328kh2r45abh8vcwvcys6xk.ls error="server returned 404: 404 page not found\n"16232026/10/25 19:40:13 WARN Failed to register uploaded object key=pivpsvjnc9dd43nch61sisca1fl9s8p9.narinfo error="server returned 404: 404 page not found\n"1624=== NAME TestClientMultipleUploads1625 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads89102177/001/store/v6fcx7215i99rzn7ad2n15s162r0986d-test-file-2.txt16262026/10/25 19:40:13 INFO Completed push id=3 objects=3 duration=2.018559ms16272026/10/25 19:40:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16282026/10/25 19:40:13 INFO Upload complete. (39ms)16292026/10/25 19:40:13 INFO Uploading fq6ff0k0jqrval6q5mzzbsqh6rnzr0qi-b (216B)16302026/10/25 19:40:13 INFO Uploading ymf8wyl16nx9bl6qd543pzq9hcra47m5-shared-dep (136B)16312026/10/25 19:40:13 INFO Completed push id=1 objects=3 duration=5.242628ms16322026/10/25 19:40:13 INFO Upload complete. (50ms)1633=== NAME TestClientIntegration1634 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1635 client_integration_test.go:352: Decompressed .ls content (49 bytes):1636 {"version":1,"root":{"type":"regular","size":39}}1637 client_integration_test.go:363: Testing garbage collection...16382026/10/25 19:40:13 INFO Completed upload id=1 objects=6 duration=4.844888ms16392026/10/25 19:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16402026/10/25 19:40:13 WARN Failed to register uploaded object key=bxhv5b3q8mzrjc0r41nqxhrqrqxahn47.ls error="server returned 404: 404 page not found\n"16412026/10/25 19:40:13 WARN Failed to register uploaded object key=ymf8wyl16nx9bl6qd543pzq9hcra47m5.ls error="server returned 404: 404 page not found\n"16422026/10/25 19:40:13 INFO Completed upload id=2 objects=6 duration=1.545079ms16432026/10/25 19:40:13 INFO Upload complete. (62ms)1644--- PASS: TestService_ReadAuthMiddleware (0.60s)1645=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16462026/10/25 19:40:13 INFO Received uploads request method=POST path=/16472026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1648=== NAME TestClientFallsBackToClosures1649 client_pushes_test.go:112: Retrieved narinfo from S3:16502026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1sk9w4bhcqwhjbinvll9rj905ri8y0hd8qy37pg2hbhq6aia1wrf.nar.zst error="server returned 404: 404 page not found\n"1651 StorePath: /build/TestClientFallsBackToClosures1114049316/001/store/pivpsvjnc9dd43nch61sisca1fl9s8p9-shared-dep1652 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1653 Compression: zstd1654 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821655 NarSize: 13616562026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1657 References: 1658 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16592026/10/25 19:40:13 WARN Failed to register uploaded object key=fq6ff0k0jqrval6q5mzzbsqh6rnzr0qi.ls error="server returned 404: 404 page not found\n"16602026/10/25 19:40:13 INFO Signed narinfos id=1 count=316612026/10/25 19:40:13 INFO Uploading 3 narinfos1662 client_pushes_test.go:112: Retrieved narinfo from S3:1663 StorePath: /build/TestClientFallsBackToClosures1114049316/001/store/wcq2vb1jvqhgpk88mxa097wrxrlsdf5k-a1664 URL: nar/17057snjvslrqby95gni1mbx2m19mrp14gyqfjylxca9zz575wsx.nar.zst1665 Compression: zstd1666 NarHash: sha256:17057snjvslrqby95gni1mbx2m19mrp14gyqfjylxca9zz575wsx1667 NarSize: 2161668 References: /build/TestClientFallsBackToClosures1114049316/001/store/pivpsvjnc9dd43nch61sisca1fl9s8p9-shared-dep1669 CA: text:sha256:0y4axn984w4d3sdj6zm50lilxzrlq840qrzzr1abknp9xsj2nswc16702026/10/25 19:40:13 WARN Failed to register uploaded object key=bxhv5b3q8mzrjc0r41nqxhrqrqxahn47.narinfo error="server returned 404: 404 page not found\n"16712026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes16722026/10/25 19:40:13 WARN Failed to register uploaded object key=ymf8wyl16nx9bl6qd543pzq9hcra47m5.narinfo error="server returned 404: 404 page not found\n"1673 client_pushes_test.go:112: Retrieved narinfo from S3:1674 StorePath: /build/TestClientFallsBackToClosures1114049316/001/store/wi2wnriz2pwyr2asmqfrqmmqi275br70-b1675 URL: nar/17057snjvslrqby95gni1mbx2m19mrp14gyqfjylxca9zz575wsx.nar.zst1676 Compression: zstd1677 NarHash: sha256:17057snjvslrqby95gni1mbx2m19mrp14gyqfjylxca9zz575wsx1678 NarSize: 2161679 References: /build/TestClientFallsBackToClosures1114049316/001/store/pivpsvjnc9dd43nch61sisca1fl9s8p9-shared-dep16802026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1681 CA: text:sha256:0y4axn984w4d3sdj6zm50lilxzrlq840qrzzr1abknp9xsj2nswc16822026/10/25 19:40:13 WARN Failed to register uploaded object key=fq6ff0k0jqrval6q5mzzbsqh6rnzr0qi.narinfo error="server returned 404: 404 page not found\n"1683--- PASS: TestClientFallsBackToClosures (0.81s)1684=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16852026/10/25 19:40:13 INFO Received request for more parts method=POST path=/16862026/10/25 19:40:13 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16872026/10/25 19:40:13 INFO Uploading sqzhj8fcb7p7d3fhnx7la7nkql827spw-shared-dep (136B)16882026/10/25 19:40:13 INFO Uploading rxnrldnzp5wcxikj6k06b578xkiw1lql-top (224B)16892026/10/25 19:40:13 INFO Completed push id=1 objects=8 duration=5.846067ms16902026/10/25 19:40:13 INFO Upload complete. (53ms)1691=== NAME TestClientPushesUseOnePush1692 client_pushes_test.go:97: Retrieved narinfo from S3:1693 StorePath: /build/TestClientPushesUseOnePush2135353434/001/store/ymf8wyl16nx9bl6qd543pzq9hcra47m5-shared-dep1694 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1695 Compression: zstd1696 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821697 NarSize: 1361698 References: 1699 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17002026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17012026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/083rzcqix7980xl4sbhngb39acdw1npz8550kyy7mi10aymqxvys.nar.zst error="server returned 404: 404 page not found\n"17022026/10/25 19:40:13 WARN Failed to register uploaded object key=rxnrldnzp5wcxikj6k06b578xkiw1lql.ls error="server returned 404: 404 page not found\n"17032026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1704 client_pushes_test.go:97: Retrieved narinfo from S3:1705 StorePath: /build/TestClientPushesUseOnePush2135353434/001/store/bxhv5b3q8mzrjc0r41nqxhrqrqxahn47-a1706 URL: nar/1sk9w4bhcqwhjbinvll9rj905ri8y0hd8qy37pg2hbhq6aia1wrf.nar.zst17072026/10/25 19:40:13 WARN Failed to register uploaded object key=sqzhj8fcb7p7d3fhnx7la7nkql827spw.ls error="server returned 404: 404 page not found\n"1708 Compression: zstd1709 NarHash: sha256:1sk9w4bhcqwhjbinvll9rj905ri8y0hd8qy37pg2hbhq6aia1wrf1710 NarSize: 2161711 References: /build/TestClientPushesUseOnePush2135353434/001/store/ymf8wyl16nx9bl6qd543pzq9hcra47m5-shared-dep1712 CA: text:sha256:154ia5x9xav6rsar66gyxgzih4q3mzgrrw5mj6km1dxxjj0klwqv17132026/10/25 19:40:13 INFO Signed narinfos id=1 count=217142026/10/25 19:40:13 INFO Uploading 2 narinfos1715 client_pushes_test.go:97: Retrieved narinfo from S3:1716 StorePath: /build/TestClientPushesUseOnePush2135353434/001/store/fq6ff0k0jqrval6q5mzzbsqh6rnzr0qi-b1717 URL: nar/1sk9w4bhcqwhjbinvll9rj905ri8y0hd8qy37pg2hbhq6aia1wrf.nar.zst1718 Compression: zstd1719 NarHash: sha256:1sk9w4bhcqwhjbinvll9rj905ri8y0hd8qy37pg2hbhq6aia1wrf1720 NarSize: 2161721 References: /build/TestClientPushesUseOnePush2135353434/001/store/ymf8wyl16nx9bl6qd543pzq9hcra47m5-shared-dep1722 CA: text:sha256:154ia5x9xav6rsar66gyxgzih4q3mzgrrw5mj6km1dxxjj0klwqv17232026/10/25 19:40:13 WARN Failed to register uploaded object key=sqzhj8fcb7p7d3fhnx7la7nkql827spw.narinfo error="server returned 404: 404 page not found\n"17242026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete17252026/10/25 19:40:13 WARN Failed to register uploaded object key=rxnrldnzp5wcxikj6k06b578xkiw1lql.narinfo error="server returned 404: 404 page not found\n"1726--- PASS: TestClientPushesUseOnePush (0.81s)1727=== CONT TestGCEndsOnShutdown/before_the_run1728=== NAME TestClientWithDependencies1729 client_integration_test.go:662: Found 1 dependencies (including self)1730=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17312026/10/25 19:40:13 INFO Completed push id=1 objects=6 duration=4.889728ms17322026/10/25 19:40:13 INFO Upload complete. (54ms)1733=== NAME TestClientSharedPathCommittedMidPush1734 client_integration_test.go:727: Retrieved narinfo from S3:1735 StorePath: /build/TestClientSharedPathCommittedMidPush3007454465/001/store/sqzhj8fcb7p7d3fhnx7la7nkql827spw-shared-dep1736 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1737 Compression: zstd1738 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821739 NarSize: 1361740 References: 1741 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17422026/10/25 19:40:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures17432026/10/25 19:40:13 INFO Garbage collection started1744 client_integration_test.go:727: Retrieved narinfo from S3:1745 StorePath: /build/TestClientSharedPathCommittedMidPush3007454465/001/store/rxnrldnzp5wcxikj6k06b578xkiw1lql-top1746 URL: nar/083rzcqix7980xl4sbhngb39acdw1npz8550kyy7mi10aymqxvys.nar.zst1747 Compression: zstd1748 NarHash: sha256:083rzcqix7980xl4sbhngb39acdw1npz8550kyy7mi10aymqxvys1749 NarSize: 2241750 References: /build/TestClientSharedPathCommittedMidPush3007454465/001/store/sqzhj8fcb7p7d3fhnx7la7nkql827spw-shared-dep1751 CA: text:sha256:11ybxi6hz98s0n0gd4587vy2yrfs1mxw60b80b4v8lql15w01ir11752=== RUN TestService_RequireScope_OIDC/builder_may_write1753=== PAUSE TestService_RequireScope_OIDC/builder_may_write1754=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1755=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1756=== RUN TestService_RequireScope_OIDC/ops_may_admin1757=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1758=== RUN TestService_RequireScope_OIDC/ops_may_not_write1759=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1760=== RUN TestService_RequireScope_OIDC/reader_may_not_write1761=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1762=== RUN TestService_RequireScope_OIDC/static_token_may_admin1763=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1764=== RUN TestService_RequireScope_OIDC/static_token_may_write1765=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1766=== RUN TestService_RequireScope_OIDC/reader_may_read1767=== PAUSE TestService_RequireScope_OIDC/reader_may_read1768=== RUN TestService_RequireScope_OIDC/writer_implies_read1769=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1770=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1771=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1772=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1773=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1774=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1775=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1776=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1777=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1778=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1779=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1780=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1781--- PASS: TestClientSharedPathCommittedMidPush (0.78s)1782=== CONT TestPush_RejectsBadRequests/no_roots17832026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes1784=== CONT TestPush_RejectsBadRequests/bad_root17852026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes1786=== CONT TestPush_RejectsBadRequests/root_not_in_objects17872026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes1788=== CONT TestPush_RejectsBadRequests/no_objects17892026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes1790=== CONT TestIsValidCachePath/narinfo1791=== CONT TestIsValidCachePath/traversal_parent1792=== CONT TestIsValidCachePath/index.html1793=== CONT TestIsValidCachePath/nix-cache-info1794=== CONT TestIsValidCachePath/realisation1795=== CONT TestIsValidCachePath/traversal_in_middle1796=== CONT TestIsValidCachePath/log1797=== CONT TestIsValidCachePath/ls1798=== CONT TestIsValidCachePath/nar_uncompressed1799=== CONT TestIsValidCachePath/nar_bz21800--- PASS: TestPush_RejectsBadRequests (1.16s)1801 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1802 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1803 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1804 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1805=== CONT TestIsValidCachePath/nar_xz1806=== CONT TestIsValidCachePath/nar_zst1807=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1808=== CONT TestIsValidCachePath/invalid_char_u1809=== CONT TestIsValidCachePath/random_path1810=== CONT TestIsValidCachePath/wrong_extension1811=== CONT TestIsValidCachePath/short_hash1812=== CONT TestIsValidCachePath/leading_slash1813=== CONT TestIsValidCachePath/empty1814=== CONT TestIsValidCachePath/invalid_char_e1815--- PASS: TestIsValidCachePath (0.00s)1816 --- PASS: TestIsValidCachePath/narinfo (0.00s)1817 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1818 --- PASS: TestIsValidCachePath/index.html (0.00s)1819 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1820 --- PASS: TestIsValidCachePath/realisation (0.00s)1821 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1822 --- PASS: TestIsValidCachePath/log (0.00s)1823 --- PASS: TestIsValidCachePath/ls (0.00s)1824 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1825 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1826 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1827 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1828 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1829 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1830 --- PASS: TestIsValidCachePath/random_path (0.00s)1831 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1832 --- PASS: TestIsValidCachePath/short_hash (0.00s)1833 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1834 --- PASS: TestIsValidCachePath/empty (0.00s)1835 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1836=== CONT TestParseSingleRange/none1837=== CONT TestParseSingleRange/open-ended1838=== CONT TestParseSingleRange/closed1839=== CONT TestParseSingleRange/malformed_end_before_start1840=== CONT TestParseSingleRange/malformed_both_empty1841=== CONT TestParseSingleRange/malformed_no_dash1842=== CONT TestParseSingleRange/multi-range_ignored1843=== CONT TestParseSingleRange/unknown_unit1844=== CONT TestParseSingleRange/start_past_EOF1845=== CONT TestParseSingleRange/end_clamped_to_size1846=== CONT TestParseSingleRange/single_byte1847=== CONT TestParseSingleRange/suffix_exceeds_size1848=== CONT TestParseSingleRange/suffix1849=== CONT TestParseSingleRange/start_far_past_EOF1850--- PASS: TestParseSingleRange (0.00s)1851 --- PASS: TestParseSingleRange/none (0.00s)1852 --- PASS: TestParseSingleRange/open-ended (0.00s)1853 --- PASS: TestParseSingleRange/closed (0.00s)1854 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1855 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1856 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1857 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1858 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1859 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1860 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1861 --- PASS: TestParseSingleRange/single_byte (0.00s)1862 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1863 --- PASS: TestParseSingleRange/suffix (0.00s)1864 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1865=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18662026/10/25 19:40:13 INFO Aborted multipart uploads count=0 kept=01867=== NAME TestClientCADerivations1868 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3443862486/001/store/ih26a22455gradiphv3gfq447hqfk31c-ca-test1869--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.43s)1870=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1871=== CONT TestServerTLSConfig/no_client_CA1872=== CONT TestServerTLSConfig/missing_CA_file1873=== CONT TestServerTLSConfig/not_a_PEM_file1874--- PASS: TestServerTLSConfig (0.00s)1875 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1876 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1877 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1878=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1879--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.42s)1880=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18812026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes18822026/10/25 19:40:13 WARN Force mode enabled - objects will be deleted immediately without grace period18832026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes18842026/10/25 19:40:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18852026/10/25 19:40:13 INFO Uploading fcp6jf8dq197011yhg0q0wqr4pgq0kpk-unpinned-file.txt (128B)18862026/10/25 19:40:13 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18872026/10/25 19:40:13 INFO Uploading 1fgcz12rxgz01vnq1cj5s5hp47xmxjhs-test-file-0.txt (160B)18882026/10/25 19:40:13 INFO Uploading v6fcx7215i99rzn7ad2n15s162r0986d-test-file-2.txt (160B)18892026/10/25 19:40:13 INFO Uploading vd51j8v9d5diw0a6y1bymnbapq9zi4md-test-file-1.txt (160B)18902026/10/25 19:40:13 WARN Failed to register uploaded object key=fcp6jf8dq197011yhg0q0wqr4pgq0kpk.ls error="server returned 404: 404 page not found\n"18912026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18922026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18932026/10/25 19:40:13 INFO Signed narinfos id=2 count=118942026/10/25 19:40:13 INFO Uploading 1 narinfos18952026/10/25 19:40:13 WARN Failed to register uploaded object key=v6fcx7215i99rzn7ad2n15s162r0986d.ls error="server returned 404: 404 page not found\n"18962026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18972026/10/25 19:40:13 WARN Failed to register uploaded object key=1fgcz12rxgz01vnq1cj5s5hp47xmxjhs.ls error="server returned 404: 404 page not found\n"18982026/10/25 19:40:13 WARN Failed to register uploaded object key=vd51j8v9d5diw0a6y1bymnbapq9zi4md.ls error="server returned 404: 404 page not found\n"18992026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19002026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19012026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19022026/10/25 19:40:13 INFO Signed narinfos id=1 count=319032026/10/25 19:40:13 INFO Uploading 3 narinfos1904=== NAME TestClientCADerivations1905 client_ca_test.go:139: Found 1 dependencies (including self)19062026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes19072026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/2/complete19082026/10/25 19:40:13 WARN Failed to register uploaded object key=fcp6jf8dq197011yhg0q0wqr4pgq0kpk.narinfo error="server returned 404: 404 page not found\n"19092026/10/25 19:40:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19102026/10/25 19:40:13 INFO Uploading 39ich7gfdwi4f3ygni56nfywq99yqsph-test-script (136B)19112026/10/25 19:40:13 WARN Failed to register uploaded object key=v6fcx7215i99rzn7ad2n15s162r0986d.narinfo error="server returned 404: 404 page not found\n"19122026/10/25 19:40:13 WARN Failed to register uploaded object key=vd51j8v9d5diw0a6y1bymnbapq9zi4md.narinfo error="server returned 404: 404 page not found\n"19132026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete19142026/10/25 19:40:13 WARN Failed to register uploaded object key=1fgcz12rxgz01vnq1cj5s5hp47xmxjhs.narinfo error="server returned 404: 404 page not found\n"19152026/10/25 19:40:13 INFO Completed push id=2 objects=3 duration=20.219051ms19162026/10/25 19:40:13 INFO Upload complete. (345ms)19172026/10/25 19:40:13 WARN Failed to register uploaded object key=39ich7gfdwi4f3ygni56nfywq99yqsph.ls error="server returned 404: 404 page not found\n"19182026/10/25 19:40:13 WARN Failed to register uploaded object key=log/7bgdr5a6yv0ig0749q5933ig7ia341by-test-script.drv error="server returned 404: 404 page not found\n"19192026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"19202026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19212026/10/25 19:40:13 INFO Signed narinfos id=1 count=119222026/10/25 19:40:13 INFO Uploading 1 narinfos1923=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1924=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1925=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1926=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1927=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1928=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1929=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1930=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1931=== CONT TestResolveDBConnectionString/flag_wins1932=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1933=== CONT TestResolveDBConnectionString/nothing_configured1934=== CONT TestResolveDBConnectionString/missing_file_is_an_error1935=== CONT TestResolveDBConnectionString/file_when_flag_empty1936=== CONT TestClientErrorHandling/InvalidStorePath1937--- PASS: TestResolveDBConnectionString (0.00s)1938 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1939 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1940 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1941 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1942 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19432026/10/25 19:40:13 INFO Received push request method=POST path=/api/pushes19442026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete19452026/10/25 19:40:13 WARN Failed to register uploaded object key=39ich7gfdwi4f3ygni56nfywq99yqsph.narinfo error="server returned 404: 404 page not found\n"19462026/10/25 19:40:13 INFO Completed push id=1 objects=9 duration=86.396405ms19472026/10/25 19:40:13 INFO Upload complete. (427ms)1948=== NAME TestClientMultipleUploads1949 client_integration_test.go:416: Uploaded 3 paths in 456.798256ms19502026/10/25 19:40:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures19512026/10/25 19:40:13 INFO Garbage collection started1952--- PASS: TestClientMultipleUploads (1.18s)1953=== CONT TestClientErrorHandling/ServerNotAvailable19542026/10/25 19:40:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19552026/10/25 19:40:13 INFO Uploading ih26a22455gradiphv3gfq447hqfk31c-ca-test (144B)19562026/10/25 19:40:13 INFO Completed push id=1 objects=4 duration=19.034582ms19572026/10/25 19:40:13 INFO Upload complete. (409ms)1958=== NAME TestClientWithDependencies1959 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies244315/001/store) requires matching store prefix19602026/10/25 19:40:13 INFO lead: released remote=192.0.2.1:12341961--- PASS: TestLeadEndsOnShutdown (1.44s)1962=== CONT TestClientErrorHandling/InvalidAuthToken19632026/10/25 19:40:13 WARN Failed to register uploaded object key=log/7jagmd632k12n9dw7kqw3zhl4cs8zls0-ca-test.drv error="server returned 404: 404 page not found\n"19642026/10/25 19:40:13 WARN Failed to register uploaded object key=ih26a22455gradiphv3gfq447hqfk31c.ls error="server returned 404: 404 page not found\n"19652026/10/25 19:40:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1966--- PASS: TestClientWithDependencies (1.21s)19672026/10/25 19:40:13 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1968=== CONT TestCacheConfigHandler/full_config,_no_issuer19692026/10/25 19:40:13 INFO Signed narinfos id=1 count=11970=== CONT TestCacheConfigHandler/no_signing_keys19712026/10/25 19:40:13 INFO Uploading 1 narinfos1972=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1973=== CONT TestCacheConfigHandler/no_cache_url_configured1974--- PASS: TestCacheConfigHandler (0.00s)1975 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1976 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1977 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1978 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1979=== CONT TestService_RequireScope_OIDC/builder_may_write1980=== CONT TestService_RequireScope_OIDC/reader_may_read1981=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1982=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19832026/10/25 19:40:13 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]1984=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1985=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1986=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1987=== CONT TestService_RequireScope_OIDC/writer_implies_read1988=== CONT TestService_RequireScope_OIDC/reader_may_not_write1989=== CONT TestService_RequireScope_OIDC/static_token_may_write1990=== CONT TestService_RequireScope_OIDC/static_token_may_admin1991=== CONT TestService_RequireScope_OIDC/ops_may_admin1992=== CONT TestService_RequireScope_OIDC/ops_may_not_write1993=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1994=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1995--- PASS: TestService_RequireScope_OIDC (0.62s)1996 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1997 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1998 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1999 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2000 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2001 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2002 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2006 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2010=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20112026/10/25 19:40:13 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]2012=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2013=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20142026/10/25 19:40:13 INFO Received complete push request method=POST path=/api/pushes/1/complete20152026/10/25 19:40:13 WARN Failed to register uploaded object key=ih26a22455gradiphv3gfq447hqfk31c.narinfo error="server returned 404: 404 page not found\n"20162026/10/25 19:40:13 WARN Authentication failed token_preview=eyJhbGciOi...BLAAO8LBTQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2017--- PASS: TestService_AuthMiddleware_OIDC (0.89s)2018 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2019 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2020 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2021 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20222026/10/25 19:40:13 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=020232026/10/25 19:40:13 INFO Completed push id=1 objects=4 duration=6.654358ms20242026/10/25 19:40:13 INFO Upload complete. (145ms)20252026/10/25 19:40:13 INFO Aborted multipart uploads count=0 kept=020262026/10/25 19:40:13 INFO Vacuumed table table=pending_closures2027=== NAME TestClientCADerivations2028 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3443862486/001/store/ih26a22455gradiphv3gfq447hqfk31c-ca-test2029 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2030 Compression: zstd2031 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2032 NarSize: 1442033 References: 2034 Deriver: /build/TestClientCADerivations3443862486/001/store/7jagmd632k12n9dw7kqw3zhl4cs8zls0-ca-test.drv2035 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2036 client_ca_test.go:185: Checking for realisation files in S3...2037 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2038 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20392026/10/25 19:40:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20402026/10/25 19:40:13 WARN mTLS auth: bound subjects configured but subject DN unavailable20412026/10/25 19:40:13 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2042--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.55s)20432026/10/25 19:40:13 WARN Force mode enabled - objects will be deleted immediately without grace period20442026/10/25 19:40:13 INFO Vacuumed table table=pending_objects20452026/10/25 19:40:13 INFO Vacuumed table table=multipart_uploads20462026/10/25 19:40:14 INFO Vacuumed table table=closures20472026/10/25 19:40:14 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=020482026/10/25 19:40:14 INFO Vacuumed table table=objects20492026/10/25 19:40:14 INFO Vacuumed table table=pending_closures20502026/10/25 19:40:14 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/present20512026/10/25 19:40:14 INFO Vacuumed table table=pending_objects20522026/10/25 19:40:14 INFO Vacuumed table table=multipart_uploads20532026/10/25 19:40:14 INFO Vacuumed table table=closures20542026/10/25 19:40:14 INFO Vacuumed table table=objects20552026/10/25 19:40:14 INFO lead: released remote=192.0.2.1:123420562026/10/25 19:40:14 INFO Aborted multipart uploads count=0 kept=02057--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2058 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.04s)2059 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2060 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.59s)20612026/10/25 19:40:14 WARN Force mode enabled - objects will be deleted immediately without grace period20622026/10/25 19:40:14 WARN Request failed, retrying attempt=2 backoff=208.542998ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20632026/10/25 19:40:14 INFO lead: acquired remote=192.0.2.1:123420642026/10/25 19:40:14 INFO Received uploads request method=POST path=/api/pending_closures20652026/10/25 19:40:14 INFO Aborted multipart uploads count=0 kept=020662026/10/25 19:40:14 WARN Force mode enabled - objects will be deleted immediately without grace period2067=== NAME TestClientCADerivations2068 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2069 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2070 error: binary cache 's3://bucket83?endpoint=http://localhost:46175®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3443862486/001/store'2071 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12072--- PASS: TestClientCADerivations (1.45s)20732026/10/25 19:40:14 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:46175/bucket94/?delete=\": context canceled"2074--- PASS: TestGCEndsOnShutdown (0.00s)2075 --- PASS: TestGCEndsOnShutdown/before_the_run (0.54s)2076 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.64s)2077 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.74s)20782026/10/25 19:40:14 INFO Received uploads request method=POST path=/api/pending_closures20792026/10/25 19:40:14 INFO Aborted multipart uploads count=0 kept=020802026/10/25 19:40:14 WARN Force mode enabled - objects will be deleted immediately without grace period20812026/10/25 19:40:14 INFO Received uploads request method=POST path=/api/pending_closures20822026/10/25 19:40:14 INFO Aborted multipart uploads count=0 kept=020832026/10/25 19:40:14 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=020842026/10/25 19:40:14 INFO Vacuumed table table=pending_closures20852026/10/25 19:40:14 WARN Force mode enabled - objects will be deleted immediately without grace period20862026/10/25 19:40:14 INFO Vacuumed table table=pending_objects20872026/10/25 19:40:14 INFO Vacuumed table table=multipart_uploads20882026/10/25 19:40:14 INFO Vacuumed table table=closures20892026/10/25 19:40:14 INFO Vacuumed table table=objects20902026/10/25 19:40:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020912026/10/25 19:40:14 INFO Vacuumed table table=pending_closures20922026/10/25 19:40:14 INFO Vacuumed table table=pending_objects20932026/10/25 19:40:14 INFO Vacuumed table table=multipart_uploads20942026/10/25 19:40:14 INFO Vacuumed table table=closures20952026/10/25 19:40:14 INFO Vacuumed table table=objects2096--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2097 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.78s)2098 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.79s)20992026/10/25 19:40:14 WARN Request failed, retrying attempt=3 backoff=432.250239ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21002026/10/25 19:40:14 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21012026/10/25 19:40:14 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2102--- PASS: TestDeleteClosuresRacingPins (1.79s)2103=== NAME TestOrphanedObjectsGCStressTest2104 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2105 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion21062026/10/25 19:40:14 WARN Request failed, retrying attempt=4 backoff=847.144539ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2107--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2108 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.57s)2109 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.56s)2110--- PASS: TestPendingClosureWriteTimeout (0.00s)2111 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2112 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2113 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2114 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.63s)21152026/10/25 19:40:15 INFO lead: released remote=192.0.2.1:12342116--- PASS: TestLeadElectsOneAndHandsOver (2.59s)21172026/10/25 19:40:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02118=== NAME TestClientIntegration2119 client_integration_test.go:370: Objects in database after GC:2120 client_integration_test.go:370: Successfully deleted all objects with GC --force2121--- PASS: TestClientIntegration (2.92s)21222026/10/25 19:40:15 WARN Request failed, retrying attempt=5 backoff=1.46416275s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21232026/10/25 19:40:15 WARN Rate limiter enabled after throttle name=s3-test rate=521242026/10/25 19:40:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2125=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2126 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102127 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002128--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.88s)2129--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.85s)21302026/10/25 19:40:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021312026/10/25 19:40:15 INFO Received create pin request method=POST path=/api/pins/myapp21322026/10/25 19:40:15 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2648889405/001/store/44vjpz6kqxhbapi566h11qbzczqnml7r-pinned-file.txt narinfo_key=44vjpz6kqxhbapi566h11qbzczqnml7r.narinfo21332026/10/25 19:40:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures21342026/10/25 19:40:15 INFO Garbage collection started21352026/10/25 19:40:15 INFO Aborted multipart uploads count=0 kept=021362026/10/25 19:40:15 WARN Force mode enabled - objects will be deleted immediately without grace period21372026/10/25 19:40:15 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021382026/10/25 19:40:15 INFO Vacuumed table table=pending_closures21392026/10/25 19:40:15 INFO Vacuumed table table=pending_objects21402026/10/25 19:40:15 INFO Vacuumed table table=multipart_uploads21412026/10/25 19:40:15 INFO Vacuumed table table=closures21422026/10/25 19:40:15 INFO Vacuumed table table=objects2143=== NAME TestOrphanedObjectsGCStressTest2144 orphaned_objects_gc_test.go:503: Stress test completed successfully:2145 orphaned_objects_gc_test.go:504: - Active objects preserved: 202146 orphaned_objects_gc_test.go:505: - Objects deleted: 2102147 orphaned_objects_gc_test.go:506: - Total GC'd: 2102148--- PASS: TestOrphanedObjectsGCStressTest (4.65s)21492026/10/25 19:40: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-config2150--- PASS: TestConnectWaitsForAPeerMigration (5.29s)21512026/10/25 19:40:17 WARN Request failed, retrying attempt=2 backoff=183.515954ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21522026/10/25 19:40:17 WARN Request failed, retrying attempt=3 backoff=435.269174ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21532026/10/25 19:40:17 WARN Request failed, retrying attempt=4 backoff=781.201529ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2154=== NAME TestPinProtectsFromGC2155 client_integration_test.go:887: Pin successfully protected closure from garbage collection2156--- PASS: TestPinProtectsFromGC (5.24s)21572026/10/25 19:40:18 INFO Aborted multipart uploads count=1 kept=021582026/10/25 19:40:18 INFO Received cleanup request method=DELETE path=/api/pending_closures21592026/10/25 19:40:18 INFO Aborted multipart uploads count=1 kept=02160--- PASS: TestPendingCleanupUsesOneCutoff (6.71s)21612026/10/25 19:40:18 WARN Request failed, retrying attempt=5 backoff=1.640454353s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21622026/10/25 19:40:20 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"21632026/10/25 19:40:20 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-config21642026/10/25 19:40:20 WARN Request failed, retrying attempt=2 backoff=181.240499ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21652026/10/25 19:40:20 WARN Request failed, retrying attempt=3 backoff=437.456635ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21662026/10/25 19:40:20 WARN Request failed, retrying attempt=4 backoff=816.835012ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21672026/10/25 19:40:21 WARN Request failed, retrying attempt=5 backoff=1.654764491s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21682026/10/25 19:40:23 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_closures21692026/10/25 19:40:23 WARN Request failed, retrying attempt=2 backoff=219.483025ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21702026/10/25 19:40:23 WARN Request failed, retrying attempt=3 backoff=426.168038ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21712026/10/25 19:40:24 WARN Request failed, retrying attempt=4 backoff=807.283136ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21722026/10/25 19:40:25 WARN Request failed, retrying attempt=5 backoff=1.621911737s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2173--- PASS: TestClientErrorHandling (0.00s)2174 --- PASS: TestClientErrorHandling/InvalidStorePath (0.44s)2175 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.48s)2176 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.70s)2177PASS2178{"timestamp":"2026-10-25T19:40:26.662202763Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57398","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(133)"}21792026-10-25 19:40:26.898 UTC [128] LOG: received smart shutdown request21802026-10-25 19:40:26.922 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 121812026-10-25 19:40:26.928 UTC [133] LOG: shutting down21822026-10-25 19:40:26.938 UTC [133] LOG: checkpoint starting: shutdown immediate21832026-10-25 19:40:28.580 UTC [133] LOG: checkpoint complete: wrote 11153 buffers (68.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 30 recycled; write=0.255 s, sync=1.331 s, total=1.652 s; sync files=34045, longest=0.305 s, average=0.001 s; distance=494055 kB, estimate=494055 kB; lsn=0/1F9DFA58, redo lsn=0/1F9DFA5821842026-10-25 19:40:28.634 UTC [128] LOG: database system is shut down2185Running OIDC tests...2186=== RUN TestAudienceForIssuer2187=== PAUSE TestAudienceForIssuer2188=== RUN TestGlobMatch2189=== PAUSE TestGlobMatch2190=== RUN TestValidateToken_ValidToken2191=== PAUSE TestValidateToken_ValidToken2192=== RUN TestValidateToken_WrongAudience2193=== PAUSE TestValidateToken_WrongAudience2194=== RUN TestValidateToken_Expired2195=== PAUSE TestValidateToken_Expired2196=== RUN TestValidateToken_BoundClaimsMismatch2197=== PAUSE TestValidateToken_BoundClaimsMismatch2198=== RUN TestValidateToken_BoundSubjectMismatch2199=== PAUSE TestValidateToken_BoundSubjectMismatch2200=== RUN TestValidateToken_MultipleProviders2201=== PAUSE TestValidateToken_MultipleProviders2202=== RUN TestValidateToken_NoMatchingProvider2203=== PAUSE TestValidateToken_NoMatchingProvider2204=== RUN TestValidateToken_KubernetesServiceAccount2205=== PAUSE TestValidateToken_KubernetesServiceAccount2206=== RUN TestNewValidator_KubernetesRequiresCA2207=== PAUSE TestNewValidator_KubernetesRequiresCA2208=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2209=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2210=== RUN TestPins_ReservedForMatchingRule2211=== PAUSE TestPins_ReservedForMatchingRule2212=== RUN TestPins_TopLevelShorthand2213=== PAUSE TestPins_TopLevelShorthand2214=== RUN TestPins_ConfigValidation2215=== PAUSE TestPins_ConfigValidation2216=== RUN TestScopes_LegacyProviderDefaultsToWrite2217=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2218=== RUN TestScopes_Rules2219=== PAUSE TestScopes_Rules2220=== RUN TestScopes_ConfigValidation2221=== PAUSE TestScopes_ConfigValidation2222=== CONT TestAudienceForIssuer2223=== CONT TestValidateToken_KubernetesServiceAccount2224=== CONT TestPins_ReservedForMatchingRule2225--- PASS: TestAudienceForIssuer (0.00s)2226=== CONT TestValidateToken_NoMatchingProvider2227=== CONT TestValidateToken_MultipleProviders2228=== CONT TestValidateToken_BoundSubjectMismatch2229=== CONT TestValidateToken_BoundClaimsMismatch2230=== CONT TestValidateToken_Expired2231=== CONT TestValidateToken_WrongAudience2232=== CONT TestValidateToken_ValidToken2233=== CONT TestGlobMatch2234=== RUN TestGlobMatch/foo_foo2235=== PAUSE TestGlobMatch/foo_foo2236=== CONT TestPins_TopLevelShorthand2237=== CONT TestScopes_Rules2238=== CONT TestScopes_ConfigValidation2239=== CONT TestScopes_LegacyProviderDefaultsToWrite2240=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2241=== CONT TestNewValidator_KubernetesRequiresCA2242=== CONT TestPins_ConfigValidation2243=== RUN TestGlobMatch/foo_bar2244=== PAUSE TestGlobMatch/foo_bar2245=== RUN TestGlobMatch/*_2246=== PAUSE TestGlobMatch/*_2247=== RUN TestGlobMatch/*_anything2248=== PAUSE TestGlobMatch/*_anything2249=== RUN TestGlobMatch/foo*_foo2250=== PAUSE TestGlobMatch/foo*_foo2251=== RUN TestGlobMatch/foo*_foobar2252=== PAUSE TestGlobMatch/foo*_foobar2253=== RUN TestGlobMatch/foo*_bar2254=== PAUSE TestGlobMatch/foo*_bar2255=== RUN TestGlobMatch/*bar_bar2256=== PAUSE TestGlobMatch/*bar_bar2257=== RUN TestGlobMatch/*bar_foobar2258=== PAUSE TestGlobMatch/*bar_foobar2259=== RUN TestGlobMatch/*bar_foo2260=== PAUSE TestGlobMatch/*bar_foo2261=== RUN TestGlobMatch/foo*bar_foobar2262=== PAUSE TestGlobMatch/foo*bar_foobar2263=== RUN TestGlobMatch/foo*bar_foo123bar2264=== PAUSE TestGlobMatch/foo*bar_foo123bar2265=== RUN TestGlobMatch/foo*bar_foobarbaz2266=== PAUSE TestGlobMatch/foo*bar_foobarbaz2267=== RUN TestGlobMatch/*/*_foo/bar2268=== PAUSE TestGlobMatch/*/*_foo/bar2269=== RUN TestGlobMatch/*/*_foo2270=== PAUSE TestGlobMatch/*/*_foo2271=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2272=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2273=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02274=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02275=== RUN TestGlobMatch/refs/*/main_refs/heads/main2276=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2277=== RUN TestGlobMatch/fo?_foo2278=== PAUSE TestGlobMatch/fo?_foo2279=== RUN TestGlobMatch/fo?_fo2280=== PAUSE TestGlobMatch/fo?_fo2281=== RUN TestGlobMatch/fo?_fooo2282=== PAUSE TestGlobMatch/fo?_fooo2283=== RUN TestGlobMatch/?oo_foo2284=== PAUSE TestGlobMatch/?oo_foo2285=== RUN TestGlobMatch/?oo_boo2286=== PAUSE TestGlobMatch/?oo_boo2287=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2288=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2289=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2290=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2291=== CONT TestGlobMatch/foo_foo2292=== CONT TestGlobMatch/?oo_boo2293=== CONT TestGlobMatch/?oo_foo2294=== CONT TestGlobMatch/fo?_foo2295=== CONT TestGlobMatch/foo*bar_foo123bar2296=== CONT TestGlobMatch/foo*_foobar2297=== CONT TestGlobMatch/fo?_fooo2298=== CONT TestGlobMatch/foo*_foo2299=== CONT TestGlobMatch/fo?_fo2300=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2301=== CONT TestGlobMatch/foo*bar_foobar2302=== CONT TestGlobMatch/*bar_foo2303=== CONT TestGlobMatch/*bar_foobar2304--- PASS: TestPins_ConfigValidation (0.00s)2305=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2306=== CONT TestGlobMatch/*bar_bar2307=== CONT TestGlobMatch/foo*_bar2308=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2309=== CONT TestGlobMatch/refs/*/main_refs/heads/main2310=== CONT TestGlobMatch/*_anything2311=== CONT TestGlobMatch/foo*bar_foobarbaz2312=== CONT TestGlobMatch/*_2313=== CONT TestGlobMatch/foo_bar2314--- PASS: TestScopes_ConfigValidation (0.00s)2315=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02316=== CONT TestGlobMatch/*/*_foo/bar2317=== CONT TestGlobMatch/*/*_foo2318--- PASS: TestGlobMatch (0.00s)2319 --- PASS: TestGlobMatch/foo_foo (0.00s)2320 --- PASS: TestGlobMatch/?oo_boo (0.00s)2321 --- PASS: TestGlobMatch/?oo_foo (0.00s)2322 --- PASS: TestGlobMatch/fo?_foo (0.00s)2323 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2324 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2325 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2326 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2327 --- PASS: TestGlobMatch/fo?_fo (0.00s)2328 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2329 --- PASS: TestGlobMatch/foo*_foo (0.00s)2330 --- PASS: TestGlobMatch/*bar_foo (0.00s)2331 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2332 --- PASS: TestGlobMatch/*bar_bar (0.00s)2333 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2334 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2335 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2336 --- PASS: TestGlobMatch/*_anything (0.00s)2337 --- PASS: TestGlobMatch/foo*_bar (0.00s)2338 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2339 --- PASS: TestGlobMatch/*_ (0.00s)2340 --- PASS: TestGlobMatch/foo_bar (0.00s)2341 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2342 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2343 --- PASS: TestGlobMatch/*/*_foo (0.00s)23442026/10/25 19:40:30 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232345--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)23462026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41659/oidc23472026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38829/oidc2348--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)2349--- PASS: TestPins_TopLevelShorthand (0.03s)23502026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38659/oidc23512026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39851/oidc2352--- PASS: TestPins_ReservedForMatchingRule (0.04s)2353--- PASS: TestValidateToken_Expired (0.04s)23542026/10/25 19:40:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3332523552026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35949/oidc2356--- PASS: TestValidateToken_KubernetesServiceAccount (0.06s)2357--- PASS: TestScopes_Rules (0.05s)23582026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43595/oidc2359--- PASS: TestValidateToken_ValidToken (0.06s)23602026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37283/oidc2361--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)23622026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32915/oidc2363--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)23642026/10/25 19:40:30 http: TLS handshake error from 127.0.0.1:53122: remote error: tls: bad certificate2365--- PASS: TestNewValidator_KubernetesRequiresCA (0.13s)23662026/10/25 19:40:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33385/oidc23672026/10/25 19:40:30 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43175/oidc2368--- PASS: TestValidateToken_MultipleProviders (0.15s)23692026/10/25 19:40:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45909/oidc2370--- PASS: TestValidateToken_WrongAudience (0.17s)23712026/10/25 19:40:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43709/oidc2372--- PASS: TestValidateToken_NoMatchingProvider (0.28s)2373PASS2374Running hook tests...2375=== RUN TestSendPathsEmpty2376=== PAUSE TestSendPathsEmpty2377=== RUN TestQueueEnqueueAndFetch2378=== PAUSE TestQueueEnqueueAndFetch2379=== RUN TestQueueDeduplication2380=== PAUSE TestQueueDeduplication2381=== RUN TestQueueRemove2382=== PAUSE TestQueueRemove2383=== RUN TestQueueFetchBatchLimit2384=== PAUSE TestQueueFetchBatchLimit2385=== RUN TestQueueRetryMovesToBack2386=== PAUSE TestQueueRetryMovesToBack2387=== RUN TestQueueFetchRemoveLifecycle2388=== PAUSE TestQueueFetchRemoveLifecycle2389=== RUN TestQueueConcurrentWriters2390=== PAUSE TestQueueConcurrentWriters2391=== RUN TestQueueRemoveLargeClosure2392=== PAUSE TestQueueRemoveLargeClosure2393=== RUN TestServerClientIntegration2394--- PASS: TestServerClientIntegration (0.00s)2395=== RUN TestServerQueueError23962026/10/25 19:40:30 ERROR Failed to queue paths error="permission denied" count=12397--- PASS: TestServerQueueError (0.00s)2398=== RUN TestGetListenerSocketActivation2399 server_test.go:218: === RUN TestGetListenerSocketActivation2400 --- PASS: TestGetListenerSocketActivation (0.00s)2401 PASS2402 2403--- PASS: TestGetListenerSocketActivation (0.01s)2404=== RUN TestServerStalledClientDoesNotBlockShutdown2405=== PAUSE TestServerStalledClientDoesNotBlockShutdown2406=== RUN TestServerBacksOffOnAcceptErrors2407=== PAUSE TestServerBacksOffOnAcceptErrors2408=== RUN TestDrainIsolatesPoisonPath2409=== PAUSE TestDrainIsolatesPoisonPath2410=== RUN TestRunNotBlockedByPoisonHead2411=== PAUSE TestRunNotBlockedByPoisonHead2412=== RUN TestDrainGivesUpWhenServerDown2413=== PAUSE TestDrainGivesUpWhenServerDown2414=== RUN TestFailedPathPrunedByLaterClosure2415=== PAUSE TestFailedPathPrunedByLaterClosure2416=== RUN TestWorkerUploadsAndRemoves2417=== PAUSE TestWorkerUploadsAndRemoves2418=== RUN TestWorkerSkipsGCdPaths2419=== PAUSE TestWorkerSkipsGCdPaths2420=== RUN TestWorkerPrunesClosureDeps2421=== PAUSE TestWorkerPrunesClosureDeps2422=== RUN TestDrainTimeout2423=== PAUSE TestDrainTimeout2424=== RUN TestWorkerRemoveFailureIsNotProgress2425=== PAUSE TestWorkerRemoveFailureIsNotProgress2426=== RUN TestWorkerKeepsPathItCannotStat2427=== PAUSE TestWorkerKeepsPathItCannotStat2428=== CONT TestSendPathsEmpty2429=== CONT TestDrainGivesUpWhenServerDown2430--- PASS: TestSendPathsEmpty (0.00s)2431=== CONT TestWorkerKeepsPathItCannotStat2432=== CONT TestWorkerRemoveFailureIsNotProgress2433=== CONT TestDrainTimeout2434=== CONT TestWorkerPrunesClosureDeps2435=== CONT TestWorkerSkipsGCdPaths2436=== CONT TestWorkerUploadsAndRemoves2437=== CONT TestFailedPathPrunedByLaterClosure2438=== CONT TestDrainIsolatesPoisonPath2439=== CONT TestQueueRetryMovesToBack2440=== CONT TestQueueFetchRemoveLifecycle2441=== CONT TestQueueFetchBatchLimit2442=== CONT TestServerBacksOffOnAcceptErrors24432026/10/25 19:40:30 ERROR Accept failed error="too many open files"2444=== CONT TestQueueRemove2445=== CONT TestServerStalledClientDoesNotBlockShutdown2446=== CONT TestQueueDeduplication2447=== CONT TestQueueRemoveLargeClosure2448=== CONT TestQueueEnqueueAndFetch2449=== CONT TestQueueConcurrentWriters2450=== CONT TestRunNotBlockedByPoisonHead24512026/10/25 19:40:30 ERROR Accept failed error="too many open files"24522026/10/25 19:40:30 ERROR Accept failed error="too many open files"24532026/10/25 19:40:30 ERROR Accept failed error="too many open files"24542026/10/25 19:40:30 ERROR Accept failed error="too many open files"24552026/10/25 19:40:30 ERROR Accept failed error="too many open files"24562026/10/25 19:40:30 ERROR Failed to decode request error="read unix /build/hook1580987972/test.sock->@: i/o timeout"24572026/10/25 19:40:30 ERROR Failed to write response error="write unix /build/hook1580987972/test.sock->@: i/o timeout"2458--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)24592026/10/25 19:40:31 ERROR Accept failed error="too many open files"24602026/10/25 19:40:31 ERROR Accept failed error="too many open files"2461--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)24622026/10/25 19:40:31 INFO Upload queue status pending=224632026/10/25 19:40:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3607284457/002/nonexistent24642026/10/25 19:40:31 INFO Uploading batch count=124652026/10/25 19:40:31 INFO Uploading batch count=224662026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=224672026/10/25 19:40:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa: permission denied"24682026/10/25 19:40:31 INFO Uploading batch count=224692026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/a2470--- PASS: TestQueueFetchBatchLimit (0.73s)24712026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/b2472--- PASS: TestQueueDeduplication (0.74s)24732026/10/25 19:40:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa: permission denied"2474--- PASS: TestQueueRetryMovesToBack (0.74s)2475--- PASS: TestQueueEnqueueAndFetch (0.74s)24762026/10/25 19:40:31 INFO Uploading batch count=424772026/10/25 19:40:31 INFO Upload queue status pending=324782026/10/25 19:40:31 INFO Uploading batch count=224792026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=224802026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/c24812026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=424822026/10/25 19:40:31 INFO Upload queue status pending=224832026/10/25 19:40:31 INFO Uploading batch count=124842026/10/25 19:40:31 INFO Upload queue status pending=224852026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=124862026/10/25 19:40:31 INFO Uploading batch count=124872026/10/25 19:40:31 INFO Uploading batch count=124882026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=124892026/10/25 19:40:31 INFO Uploading batch count=224902026/10/25 19:40:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat2665876097/002/locked/aaa: permission denied"24912026/10/25 19:40:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1543340033/002/nonexistent24922026/10/25 19:40:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124932026/10/25 19:40:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1543340033/002/nonexistent24942026/10/25 19:40:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124952026/10/25 19:40:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress1543340033/002/nonexistent24962026/10/25 19:40:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=124972026/10/25 19:40:31 ERROR Drain finished with paths left in queue remaining=12498--- PASS: TestWorkerRemoveFailureIsNotProgress (0.75s)24992026/10/25 19:40:31 INFO Uploading batch count=125002026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/d25012026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1425719612/002/bbb25022026/10/25 19:40:31 ERROR Drain finished with paths left in queue remaining=12503--- PASS: TestQueueFetchRemoveLifecycle (0.75s)25042026/10/25 19:40:31 INFO Uploading batch count=125052026/10/25 19:40:31 INFO Uploading batch count=225062026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=225072026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/e2508--- PASS: TestWorkerSkipsGCdPaths (0.77s)25092026/10/25 19:40:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown810433313/002/f2510--- PASS: TestQueueRemove (0.78s)2511--- PASS: TestWorkerPrunesClosureDeps (0.78s)2512--- PASS: TestWorkerKeepsPathItCannotStat (0.78s)2513--- PASS: TestWorkerUploadsAndRemoves (0.78s)25142026/10/25 19:40:31 ERROR Drain finished with paths left in queue remaining=1025152026/10/25 19:40:31 INFO Uploading batch count=125162026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=125172026/10/25 19:40:31 INFO Uploading batch count=125182026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=12519--- PASS: TestFailedPathPrunedByLaterClosure (0.79s)25202026/10/25 19:40:31 INFO Uploading batch count=125212026/10/25 19:40:31 ERROR Upload failed error="upload failed" count=12522--- PASS: TestDrainGivesUpWhenServerDown (0.80s)25232026/10/25 19:40:31 ERROR Drain finished with paths left in queue remaining=12524--- PASS: TestQueueRemoveLargeClosure (0.81s)2525--- PASS: TestDrainIsolatesPoisonPath (0.82s)25262026/10/25 19:40:31 ERROR Upload failed error="context deadline exceeded" count=225272026/10/25 19:40:31 ERROR Drain finished with paths left in queue remaining=42528--- PASS: TestDrainTimeout (0.94s)2529--- PASS: TestQueueConcurrentWriters (1.50s)25302026/10/25 19:40:32 INFO Uploading batch count=125312026/10/25 19:40:32 INFO Uploading batch count=125322026/10/25 19:40:32 INFO Uploading batch count=125332026/10/25 19:40:32 ERROR Upload failed error="upload failed" count=125342026/10/25 19:40:32 INFO Uploading batch count=125352026/10/25 19:40:32 ERROR Upload failed error="upload failed" count=125362026/10/25 19:40:32 INFO Uploading batch count=125372026/10/25 19:40:32 ERROR Upload failed error="upload failed" count=125382026/10/25 19:40:32 INFO Uploading batch count=125392026/10/25 19:40:32 ERROR Upload failed error="upload failed" count=125402026/10/25 19:40:32 ERROR Drain finished with paths left in queue remaining=12541--- PASS: TestRunNotBlockedByPoisonHead (1.83s)2542PASS2543Running signing tests...2544=== RUN TestExternalSigner2545=== PAUSE TestExternalSigner2546=== RUN TestExternalSignerWrongPublicKey2547=== PAUSE TestExternalSignerWrongPublicKey2548=== RUN TestExternalSignerErrors2549=== PAUSE TestExternalSignerErrors2550=== RUN TestExternalSignerRestartsAfterCrash2551=== PAUSE TestExternalSignerRestartsAfterCrash2552=== RUN TestExternalSignerProgramErrorKeepsProcess2553=== PAUSE TestExternalSignerProgramErrorKeepsProcess2554=== RUN TestExternalSignerClose2555=== PAUSE TestExternalSignerClose2556=== RUN TestExternalSignerRejectsInvalidPublicKey2557=== PAUSE TestExternalSignerRejectsInvalidPublicKey2558=== RUN TestExternalSignerCancellation2559=== PAUSE TestExternalSignerCancellation2560=== RUN TestGenerateFingerprint2561=== PAUSE TestGenerateFingerprint2562=== RUN TestParseSigningKey2563=== PAUSE TestParseSigningKey2564=== RUN TestSign2565=== PAUSE TestSign2566=== RUN TestSignBatch2567=== PAUSE TestSignBatch2568=== RUN TestNilKeyPublicKey2569=== PAUSE TestNilKeyPublicKey2570=== RUN TestSignErrors2571=== PAUSE TestSignErrors2572=== CONT TestExternalSigner2573=== CONT TestSignBatch2574=== CONT TestSignErrors2575=== CONT TestExternalSignerCancellation2576=== CONT TestSign2577=== CONT TestParseSigningKey2578=== CONT TestGenerateFingerprint2579=== CONT TestNilKeyPublicKey2580=== RUN TestGenerateFingerprint/basic_with_references2581=== PAUSE TestGenerateFingerprint/basic_with_references2582--- PASS: TestNilKeyPublicKey (0.00s)2583=== CONT TestExternalSignerRejectsInvalidPublicKey2584=== RUN TestExternalSignerRejectsInvalidPublicKey/#002585=== CONT TestExternalSignerClose2586=== RUN TestSignErrors/nil_key2587=== PAUSE TestSignErrors/nil_key2588=== RUN TestSignErrors/nil_narinfo2589=== PAUSE TestSignErrors/nil_narinfo2590=== RUN TestSignErrors/invalid_narinfo2591=== PAUSE TestSignErrors/invalid_narinfo2592=== RUN TestSignErrors/canceled2593=== PAUSE TestSignErrors/canceled2594=== CONT TestSignErrors/nil_key2595=== CONT TestSignErrors/canceled2596--- PASS: TestSignBatch (0.00s)2597=== CONT TestExternalSignerRestartsAfterCrash2598=== CONT TestExternalSignerWrongPublicKey2599=== RUN TestParseSigningKey/valid_32-byte_key2600=== CONT TestExternalSignerProgramErrorKeepsProcess2601=== RUN TestGenerateFingerprint/no_references2602=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002603=== CONT TestSignErrors/invalid_narinfo2604=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2605=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2606=== CONT TestSignErrors/nil_narinfo2607=== CONT TestExternalSignerErrors2608=== RUN TestExternalSignerErrors/too_few_signatures2609=== PAUSE TestExternalSignerErrors/too_few_signatures2610=== RUN TestExternalSignerErrors/missing_signature_name2611=== PAUSE TestExternalSignerErrors/missing_signature_name2612--- PASS: TestSign (0.00s)2613=== PAUSE TestParseSigningKey/valid_32-byte_key2614=== PAUSE TestGenerateFingerprint/no_references2615=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2616=== RUN TestExternalSignerErrors/wrong_signature_name2617--- PASS: TestSignErrors (0.00s)2618 --- PASS: TestSignErrors/nil_key (0.00s)2619 --- PASS: TestSignErrors/canceled (0.00s)2620 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2621 --- PASS: TestSignErrors/nil_narinfo (0.00s)2622=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2623=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2624=== RUN TestParseSigningKey/no_colon2625=== PAUSE TestParseSigningKey/no_colon2626=== RUN TestParseSigningKey/empty_name2627=== PAUSE TestParseSigningKey/empty_name2628=== RUN TestParseSigningKey/invalid_base642629=== PAUSE TestParseSigningKey/invalid_base642630=== RUN TestParseSigningKey/wrong_length2631=== PAUSE TestParseSigningKey/wrong_length2632=== CONT TestParseSigningKey/valid_32-byte_key2633=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2634=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2635=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2636=== CONT TestParseSigningKey/invalid_base642637=== PAUSE TestExternalSignerErrors/wrong_signature_name2638=== RUN TestExternalSignerErrors/exit_on_request2639=== PAUSE TestExternalSignerErrors/exit_on_request2640=== RUN TestExternalSignerErrors/invalid_JSON2641=== CONT TestParseSigningKey/wrong_length2642=== CONT TestParseSigningKey/empty_name2643=== CONT TestParseSigningKey/no_colon2644=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2645--- PASS: TestParseSigningKey (0.00s)2646 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2647 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2648 --- PASS: TestParseSigningKey/wrong_length (0.00s)2649 --- PASS: TestParseSigningKey/empty_name (0.00s)2650 --- PASS: TestParseSigningKey/no_colon (0.00s)2651 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2652=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2653=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2654=== PAUSE TestExternalSignerErrors/invalid_JSON2655=== RUN TestExternalSignerErrors/wrong_shape2656=== PAUSE TestExternalSignerErrors/wrong_shape2657=== RUN TestExternalSignerErrors/unrequested_key2658=== PAUSE TestExternalSignerErrors/unrequested_key2659=== RUN TestExternalSignerErrors/invalid_signature_base642660=== PAUSE TestExternalSignerErrors/invalid_signature_base642661=== RUN TestExternalSignerErrors/wrong_signature_length2662=== PAUSE TestExternalSignerErrors/wrong_signature_length2663=== RUN TestGenerateFingerprint/invalid_nar_hash_length2664=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2665=== RUN TestGenerateFingerprint/invalid_store_path_prefix2666=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2667=== RUN TestGenerateFingerprint/invalid_reference_prefix2668=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2669=== CONT TestGenerateFingerprint/basic_with_references2670=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2671=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2672=== CONT TestGenerateFingerprint/invalid_nar_hash_length2673=== RUN TestExternalSignerErrors/program_error2674=== PAUSE TestExternalSignerErrors/program_error2675=== CONT TestGenerateFingerprint/invalid_reference_prefix2676=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2677=== CONT TestGenerateFingerprint/invalid_store_path_prefix2678=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2679=== CONT TestGenerateFingerprint/no_references2680=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2681=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2682=== CONT TestExternalSignerRejectsInvalidPublicKey/#002683--- PASS: TestExternalSignerWrongPublicKey (0.00s)2684=== RUN TestExternalSignerErrors/null2685=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2686=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2687=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2688=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2689--- PASS: TestGenerateFingerprint (0.00s)2690 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2691 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2692 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2693 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2694 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2695 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2696 --- PASS: TestGenerateFingerprint/no_references (0.00s)2697--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2698=== PAUSE TestExternalSignerErrors/null2699--- PASS: TestExternalSignerClose (0.00s)2700=== RUN TestExternalSignerErrors/wrong_id2701--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2702 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2703 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2704 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2705 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2706 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2707=== PAUSE TestExternalSignerErrors/wrong_id2708=== RUN TestExternalSignerErrors/wrong_signatures_shape2709=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2710=== RUN TestExternalSignerErrors/exit_at_startup2711=== PAUSE TestExternalSignerErrors/exit_at_startup2712=== RUN TestExternalSignerErrors/missing_signatures2713=== PAUSE TestExternalSignerErrors/missing_signatures2714=== RUN TestExternalSignerErrors/null_signatures2715=== PAUSE TestExternalSignerErrors/null_signatures2716=== CONT TestExternalSignerErrors/too_few_signatures2717=== CONT TestExternalSignerErrors/exit_at_startup2718=== CONT TestExternalSignerErrors/null_signatures2719=== CONT TestExternalSignerErrors/missing_signatures2720=== CONT TestExternalSignerErrors/null2721=== CONT TestExternalSignerErrors/wrong_signatures_shape2722=== CONT TestExternalSignerErrors/wrong_id2723=== CONT TestExternalSignerErrors/invalid_signature_base642724=== CONT TestExternalSignerErrors/invalid_JSON2725=== CONT TestExternalSignerErrors/unrequested_key2726=== CONT TestExternalSignerErrors/program_error2727=== CONT TestExternalSignerErrors/wrong_shape2728--- PASS: TestExternalSigner (0.01s)2729=== CONT TestExternalSignerErrors/wrong_signature_name2730=== CONT TestExternalSignerErrors/wrong_signature_length2731=== CONT TestExternalSignerErrors/exit_on_request2732=== CONT TestExternalSignerErrors/missing_signature_name2733--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2734--- PASS: TestExternalSignerErrors (0.00s)2735 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2736 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2737 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2738 --- PASS: TestExternalSignerErrors/null (0.00s)2739 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2740 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2741 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2742 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2743 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)2744 --- PASS: TestExternalSignerErrors/program_error (0.01s)2745 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2746 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2747 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)2748 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2749 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2750 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2751--- PASS: TestExternalSignerCancellation (0.02s)2752PASS2753Running OpenBao signer tests...2754=== RUN TestSign2755=== PAUSE TestSign2756=== RUN TestSignErrors2757=== PAUSE TestSignErrors2758=== RUN TestServe2759=== PAUSE TestServe2760=== RUN TestServeRejectsGarbage2761=== PAUSE TestServeRejectsGarbage2762=== CONT TestSign2763=== CONT TestSignErrors2764=== CONT TestServeRejectsGarbage2765=== RUN TestSignErrors/invalid_json2766=== PAUSE TestSignErrors/invalid_json2767=== RUN TestSignErrors/no_prefix2768=== PAUSE TestSignErrors/no_prefix2769=== RUN TestSignErrors/invalid_base642770=== PAUSE TestSignErrors/invalid_base642771=== RUN TestSignErrors/http_error2772=== PAUSE TestSignErrors/http_error2773=== CONT TestSignErrors/invalid_json2774=== CONT TestSignErrors/http_error2775=== CONT TestServe2776=== CONT TestSignErrors/invalid_base642777--- PASS: TestServeRejectsGarbage (0.00s)2778=== CONT TestSignErrors/no_prefix2779--- PASS: TestServe (0.00s)2780--- PASS: TestSignErrors (0.00s)2781 --- PASS: TestSignErrors/http_error (0.00s)2782 --- PASS: TestSignErrors/invalid_json (0.00s)2783 --- PASS: TestSignErrors/no_prefix (0.00s)2784 --- PASS: TestSignErrors/invalid_base64 (0.00s)2785--- PASS: TestSign (0.00s)2786PASS