niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #409
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestPartSizeForNAR20=== PAUSE TestPartSizeForNAR21=== RUN TestUploadMultipart_SupersededByPeer22=== PAUSE TestUploadMultipart_SupersededByPeer23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.24s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestSupersededNARStillUploadsListing28=== PAUSE TestSupersededNARStillUploadsListing29=== RUN TestDumpPathMatchesNix30=== PAUSE TestDumpPathMatchesNix31=== RUN TestDumpPathSingleFile32=== PAUSE TestDumpPathSingleFile33=== RUN TestDumpPathWriterError34=== PAUSE TestDumpPathWriterError35=== RUN TestEncodeNixBase3236=== PAUSE TestEncodeNixBase3237=== RUN TestEncodeNixBase32WithRealHash38=== PAUSE TestEncodeNixBase32WithRealHash39=== RUN TestConvertHashToNix3240=== PAUSE TestConvertHashToNix3241=== RUN TestGetStorePathHash42=== PAUSE TestGetStorePathHash43=== RUN TestPathInfoHashCompatibility44=== PAUSE TestPathInfoHashCompatibility45=== RUN TestParsePathInfoJSON46=== PAUSE TestParsePathInfoJSON47=== RUN TestParsePathInfoJSONMultiplePaths48=== PAUSE TestParsePathInfoJSONMultiplePaths49=== RUN TestPathInfoCACompatibility50=== PAUSE TestPathInfoCACompatibility51=== RUN TestRateLimiterFeedback52=== PAUSE TestRateLimiterFeedback53=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess54=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess55=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer56=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade62=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade63=== 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 TestSetClientTLS117=== CONT TestStaticToken118=== CONT TestScriptTokenBadJSON119=== CONT TestPathInfoCACompatibility120=== CONT TestShellSplitErrors121=== RUN TestPathInfoCACompatibility/null_ca_field122=== CONT TestScriptTokenScriptFails123=== CONT TestScriptTokenEmptyCommand124=== CONT TestClientSignaturesByStorePath125=== CONT TestStreamPushReportsSkippedPaths126=== CONT TestScriptTokenEmptyToken127=== CONT TestScriptTokenCachesUntilRefresh128=== CONT TestFileTokenReadsAndCaches129=== CONT TestFileTokenEmpty130=== CONT TestFileTokenMissing131=== CONT TestSetClientTLSErrors132=== CONT TestDumpPathMatchesNix133=== CONT TestParsePathInfoJSONMultiplePaths134=== CONT TestParsePathInfoJSON135=== CONT TestPathInfoHashCompatibility136=== CONT TestGetStorePathHash137=== CONT TestConvertHashToNix32138=== CONT TestEncodeNixBase32WithRealHash139=== CONT TestEncodeNixBase32140=== CONT TestDumpPathWriterError141=== CONT TestDumpPathSingleFile142=== CONT TestScriptTokenNoExpiryRerunsEveryCall143--- PASS: TestStaticToken (0.00s)144--- PASS: TestShellSplitErrors (0.00s)145--- PASS: TestScriptTokenEmptyCommand (0.00s)146--- PASS: TestClientSignaturesByStorePath (0.00s)147=== PAUSE TestPathInfoCACompatibility/null_ca_field148=== CONT TestStreamPushStopsWhenCanceled149=== RUN TestEncodeNixBase32/test_string_hash150=== RUN TestConvertHashToNix32/SRI_format_to_Nix32151--- PASS: TestStreamPushReportsSkippedPaths (0.00s)152--- PASS: TestFileTokenReadsAndCaches (0.00s)153=== CONT TestStreamPushRequestLine154--- PASS: TestFileTokenMissing (0.00s)155=== RUN TestParsePathInfoJSON/Nix_format156--- PASS: TestEncodeNixBase32WithRealHash (0.00s)157=== CONT TestStreamPushIsolatesFailures158=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159--- PASS: TestFileTokenEmpty (0.00s)160=== CONT TestStreamPushBatchesUnderLoad161=== CONT TestStreamPushReportsSignatures1622026/10/11 04:52:46 ERROR Upload failed error=boom count=1163=== PAUSE TestParsePathInfoJSON/Nix_format164=== RUN TestParsePathInfoJSON/Lix_format165--- PASS: TestStreamPushStopsWhenCanceled (0.00s)166=== PAUSE TestParsePathInfoJSON/Lix_format167=== RUN TestParsePathInfoJSON/empty_input168=== RUN TestGetStorePathHash/valid_store_path169=== PAUSE TestGetStorePathHash/valid_store_path170=== RUN TestGetStorePathHash/basename_without_hyphen_should_error171=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error172=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error173=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon177=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512180=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512181=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths182=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths1832026/10/11 04:52:46 ERROR Upload failed error=boom count=1184=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== CONT TestFilterOversizedClosures186=== RUN TestFilterOversizedClosures/no_limit_keeps_everything187--- PASS: TestStreamPushReportsSignatures (0.00s)188=== CONT TestSupersededNARStillUploadsListing189=== CONT TestStreamPushReportsEveryPath190=== RUN TestSupersededNARStillUploadsListing/small_NAR191=== CONT TestStreamPushGivesUpOnDeadServer192=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything193=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped194=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== RUN TestPathInfoCACompatibility/old_string_format_-_text196=== CONT TestUploadMultipart_SupersededByPeer1972026/10/11 04:52:46 ERROR Upload failed error="connection refused" count=20198=== PAUSE TestSupersededNARStillUploadsListing/small_NAR199--- PASS: TestScriptTokenScriptFails (0.01s)200=== RUN TestSupersededNARStillUploadsListing/dump_cut_short201=== RUN TestFilterOversizedClosures/all_closures_skipped202=== PAUSE TestParsePathInfoJSON/empty_input2032026/10/11 04:52:46 ERROR Server seems unavailable, giving up on batch untried=172042026/10/11 04:52:46 ERROR Upload failed error="bad path" count=3205=== RUN TestParsePathInfoJSON/whitespace_only206=== PAUSE TestParsePathInfoJSON/whitespace_only207=== RUN TestParsePathInfoJSON/invalid_JSON208=== PAUSE TestParsePathInfoJSON/invalid_JSON209=== PAUSE TestFilterOversizedClosures/all_closures_skipped210=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun211=== CONT TestPartSizeForNAR212=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short213=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails214=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails215=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error216=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error217=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error218=== CONT TestSetClientTLSDoesNotMutateDefaultTransport219=== CONT TestShellSplit220=== CONT TestDoWithRetry_FinalResponseBodyReadable221=== CONT TestDoWithRetry_BodyReplayedViaGetBody222--- PASS: TestStreamPushReportsEveryPath (0.00s)223=== CONT TestUploadMultipart_PartsInParallel224=== PAUSE TestEncodeNixBase32/test_string_hash225=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32226=== RUN TestUploadMultipart_SupersededByPeer/exists227=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica228=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text229=== CONT TestCaseHackSuffix230=== CONT TestRegisterUploadedObjectReusesConnections231=== RUN TestPartSizeForNAR/zero_stays_at_minimum232--- PASS: TestStreamPushIsolatesFailures (0.00s)233--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)234--- PASS: TestDoServerRequestAttachesToken (0.01s)235--- PASS: TestShellSplit (0.00s)2362026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=server-test rate=52372026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58123238--- PASS: TestScriptTokenBadJSON (0.01s)239=== RUN TestEncodeNixBase32/empty_input240=== RUN TestConvertHashToNix32/already_Nix32_format241=== PAUSE TestConvertHashToNix32/already_Nix32_format242=== RUN TestConvertHashToNix32/invalid_format243=== PAUSE TestConvertHashToNix32/invalid_format244=== PAUSE TestEncodeNixBase32/empty_input245=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade246=== CONT TestRetryTimeoutOutlastsMaxRetries247=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive248=== PAUSE TestUploadMultipart_SupersededByPeer/exists249=== RUN TestUploadMultipart_SupersededByPeer/missing250=== PAUSE TestUploadMultipart_SupersededByPeer/missing251=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0253=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0254=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5255=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=52562026/10/11 04:52:46 INFO Garbage collection started2572026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=server-test rate=52582026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58125259=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer260=== RUN TestSetClientTLS/rejects_connection_without_client_cert261=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert262--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)263=== RUN TestSetClientTLSErrors/missing_cert_file264=== PAUSE TestSetClientTLSErrors/missing_cert_file265=== RUN TestSetClientTLSErrors/missing_key_file266=== CONT TestRateLimiterFeedback267=== RUN TestRateLimiterFeedback/429_enables_limiter268=== CONT TestResolveStorePath269=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA270=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA271=== RUN TestSetClientTLS/preserves_debug_logging_transport272=== PAUSE TestSetClientTLS/preserves_debug_logging_transport273=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry274=== RUN TestPathInfoCACompatibility/new_structured_format_-_text275=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess276=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum277=== RUN TestPartSizeForNAR/small_stays_at_minimum278=== PAUSE TestPartSizeForNAR/small_stays_at_minimum279=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts282=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts283=== RUN TestPartSizeForNAR/1_TiB284=== PAUSE TestPartSizeForNAR/1_TiB285=== RUN TestPartSizeForNAR/5_TiB_S3_max_object286=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object287=== RUN TestPartSizeForNAR/capped_at_5_GiB2882026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=server-test rate=52892026/10/11 04:52:46 WARN Rate limiter backed off name=server-test rate=5290=== PAUSE TestPartSizeForNAR/capped_at_5_GiB291=== PAUSE TestSetClientTLSErrors/missing_key_file292=== RUN TestSetClientTLSErrors/missing_ca_file293=== PAUSE TestSetClientTLSErrors/missing_ca_file294=== RUN TestSetClientTLSErrors/invalid_ca_file295=== PAUSE TestSetClientTLSErrors/invalid_ca_file296=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon297=== PAUSE TestRateLimiterFeedback/429_enables_limiter298=== RUN TestRateLimiterFeedback/503_enables_limiter299=== PAUSE TestRateLimiterFeedback/503_enables_limiter300=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter301=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text302=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512304=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths305=== CONT TestParsePathInfoJSON/Nix_format306=== CONT TestParsePathInfoJSON/Lix_format3072026/10/11 04:52:46 WARN Rate limiter backed off name=server-test rate=53082026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:581253092026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:581293102026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=s3-test rate=53112026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:581853122026/10/11 04:52:46 INFO Garbage collection started313=== CONT TestParsePathInfoJSON/invalid_JSON314=== CONT TestFilterOversizedClosures/all_closures_skipped3152026/10/11 04:52:46 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50316=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3172026/10/11 04:52:46 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=2000318=== CONT TestSupersededNARStillUploadsListing/small_NAR319=== CONT TestParsePathInfoJSON/whitespace_only320=== CONT TestGetStorePathHash/valid_store_path321=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error322=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error323=== CONT TestSupersededNARStillUploadsListing/dump_cut_short324=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)325=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails3262026/10/11 04:52:46 INFO Uploading abc-hello (1.0GB)327=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths328=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter329=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI330=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method331--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)332=== CONT TestFilterOversizedClosures/no_limit_keeps_everything333=== CONT TestParsePathInfoJSON/empty_input334--- PASS: TestResolveStorePath (0.00s)335--- PASS: TestScriptTokenEmptyToken (0.02s)336=== CONT TestGetStorePathHash/basename_without_hyphen_should_error337--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)338--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)339=== CONT TestConvertHashToNix32/SRI_format_to_Nix32340--- PASS: TestFilterOversizedClosures (0.00s)341 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)342 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)343 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)344=== CONT TestEncodeNixBase32/test_string_hash345=== CONT TestConvertHashToNix32/invalid_format346=== CONT TestConvertHashToNix32/already_Nix32_format347--- PASS: TestConvertHashToNix32 (0.01s)348 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)349 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)350 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)351=== CONT TestEncodeNixBase32/empty_input352--- PASS: TestEncodeNixBase32 (0.01s)353 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)354 --- PASS: TestEncodeNixBase32/empty_input (0.00s)355=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter356=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter357=== CONT TestUploadMultipart_SupersededByPeer/exists358=== CONT TestUploadMultipart_SupersededByPeer/missing359--- PASS: TestParsePathInfoJSON (0.00s)360 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)361 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)365=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0366=== CONT TestSetClientTLS/rejects_connection_without_client_cert367--- PASS: TestPathInfoHashCompatibility (0.00s)368 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)369 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)370 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)371 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)372--- PASS: TestGetStorePathHash (0.01s)373 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)375 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)376 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)377=== CONT TestSetClientTLS/preserves_debug_logging_transport378--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)379 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)380 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)381=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=53822026/10/11 04:52:46 INFO Uploading abc-hello (1.0GB)3832026/10/11 04:52:46 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=03842026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:581293852026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=s3-test rate=5386=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3872026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=s3-test rate=53882026/10/11 04:52:46 WARN Garbage collection finished on another replica. Its statistics are not available here389--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)390=== CONT TestPartSizeForNAR/zero_stays_at_minimum391=== CONT TestPartSizeForNAR/small_stays_at_minimum392--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.01s)393 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.00s)394 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)395=== CONT TestSetClientTLSErrors/missing_cert_file396=== CONT TestPartSizeForNAR/capped_at_5_GiB397=== CONT TestPartSizeForNAR/1_TiB398=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts399=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum400=== CONT TestPartSizeForNAR/5_TiB_S3_max_object401--- PASS: TestPartSizeForNAR (0.01s)402 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)403 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)404 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)405 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)406 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)407 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)408 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)409=== CONT TestSetClientTLSErrors/invalid_ca_file410--- PASS: TestStreamPushRequestLine (0.03s)411=== CONT TestSetClientTLSErrors/missing_key_file412=== CONT TestPathInfoCACompatibility/null_ca_field413=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method414=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive415=== CONT TestPathInfoCACompatibility/new_structured_format_-_text416=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter417=== CONT TestPathInfoCACompatibility/old_string_format_-_text418=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter419--- PASS: TestPathInfoCACompatibility (0.03s)420 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)421 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)422 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)423 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)424 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)425=== CONT TestRateLimiterFeedback/503_enables_limiter426=== CONT TestSetClientTLSErrors/missing_ca_file427=== CONT TestRateLimiterFeedback/429_enables_limiter428--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)429 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)430 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)431--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)4322026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:581294332026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=server-test rate=54342026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58226435--- PASS: TestSetClientTLSErrors (0.02s)436 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)437 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)438 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)439 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)4402026/10/11 04:52:46 WARN Rate limiter backed off name=server-test rate=54412026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:581294422026/10/11 04:52:46 WARN Rate limiter enabled after throttle name=server-test rate=54432026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:582294442026/10/11 04:52:46 WARN Rate limiter backed off name=server-test rate=5445--- PASS: TestRateLimiterFeedback (0.01s)446 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)447 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)448 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)449 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)4502026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:581294512026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:581294522026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:581294532026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:581294542026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:581294552026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:58129456--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4572026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:581294582026/10/11 04:52:46 http: TLS handshake error from 127.0.0.1:58217: remote error: tls: bad certificate459--- PASS: TestSetClientTLS (0.02s)460 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)461 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)462 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)4632026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:581294642026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:58129465--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)466--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)4672026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:581294682026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:581294692026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:581294702026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:581294712026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:581294722026/10/11 04:52:46 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:58129473--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.05s)4742026/10/11 04:52:46 INFO Uploading abc-hello (1.0GB)475--- PASS: TestDumpPathSingleFile (0.07s)476--- PASS: TestDumpPathWriterError (0.07s)4772026/10/11 04:52:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:58207/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:58207/part/24782026/10/11 04:52:46 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"479--- PASS: TestCaseHackSuffix (0.06s)480--- PASS: TestDumpPathMatchesNix (0.11s)481--- PASS: TestStreamPushBatchesUnderLoad (0.11s)4822026/10/11 04:52:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58157/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58157/api/uploads/complete4832026/10/11 04:52:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4842026/10/11 04:52:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58157/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58157/api/uploads/complete4852026/10/11 04:52:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4862026/10/11 04:52:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58157/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58157/api/uploads/complete4872026/10/11 04:52:46 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"488--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.20s)489--- PASS: TestSupersededNARStillUploadsListing (0.00s)490 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)491 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)492 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.55s)493--- PASS: TestUploadMultipart_PartsInParallel (0.61s)494--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)495PASS496Running server tests...497The files belonging to this database system will be owned by user "_tribuchetbld7".498This user must also own the server process.499500The database cluster will be initialized with locale "C".501The default database encoding has accordingly been set to "SQL_ASCII".502The default text search configuration will be set to "english".503504Data page checksums are enabled.505506creating directory /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/postgres2872039679/data ... ok507creating subdirectories ... ok508selecting dynamic shared memory implementation ... posix509selecting default "max_connections" ... 100510selecting default "shared_buffers" ... 128MB511selecting default time zone ... UTC512creating configuration files ... ok513running bootstrap script ... ok514performing post-bootstrap initialization ... ok515syncing data to disk ... ok516517initdb: warning: enabling "trust" authentication for local connections518initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.519520Success. You can now start the database server using:521522 pg_ctl -D /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/postgres2872039679/data -l logfile start5235242026-10-11 04:52:50.525 UTC [82752] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5252026-10-11 04:52:50.525 UTC [82752] LOG: listening on Unix socket "/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/postgres2872039679/.s.PGSQL.5432"5262026-10-11 04:52:50.527 UTC [82759] LOG: database system was shut down at 2026-10-11 04:52:50 UTC5272026-10-11 04:52:50.528 UTC [82752] LOG: database system is ready to accept connections528/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/postgres2872039679:5432 - accepting connections529{"timestamp":"2026-10-11T04:52:52.902894Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9652f2ba-b54d-418d-9cdb-a8ebdc503f79","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}530=== RUN TestService_AuthMiddleware531=== PAUSE TestService_AuthMiddleware532=== RUN TestService_AuthMiddleware_MTLSProxyHeader533=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader534=== RUN TestService_AuthMiddleware_MTLSBoundSubjects535=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects536=== RUN TestService_ReadAuthMiddleware537=== PAUSE TestService_ReadAuthMiddleware538=== RUN TestService_AuthMiddleware_OIDC539=== PAUSE TestService_AuthMiddleware_OIDC540=== RUN TestService_RequireScope_OIDC541=== PAUSE TestService_RequireScope_OIDC542=== RUN TestService_ReadScope_PublicByDefault543=== PAUSE TestService_ReadScope_PublicByDefault544=== RUN TestCacheConfigHandler545=== PAUSE TestCacheConfigHandler546=== RUN TestCacheStatsHandler547=== PAUSE TestCacheStatsHandler548=== RUN TestClientCADerivations549=== PAUSE TestClientCADerivations550=== RUN TestClientErrorHandling551=== PAUSE TestClientErrorHandling552=== RUN TestClientIntegration553=== PAUSE TestClientIntegration554=== RUN TestClientMultipleUploads555=== PAUSE TestClientMultipleUploads556=== RUN TestClientWithDependencies557=== PAUSE TestClientWithDependencies558=== RUN TestClientSharedPathCommittedMidPush559=== PAUSE TestClientSharedPathCommittedMidPush560=== RUN TestPinProtectsFromGC561=== PAUSE TestPinProtectsFromGC562=== RUN TestClientPushesUseOnePush563=== PAUSE TestClientPushesUseOnePush564=== RUN TestClientFallsBackToClosures565=== PAUSE TestClientFallsBackToClosures566=== RUN TestDeleteClosuresRacingPins567=== PAUSE TestDeleteClosuresRacingPins568=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock569=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== RUN TestResolveDBConnectionString571=== PAUSE TestResolveDBConnectionString572=== RUN TestConnectWaitsForAPeerMigration573=== PAUSE TestConnectWaitsForAPeerMigration574=== RUN TestLeadElectsOneAndHandsOver575=== PAUSE TestLeadElectsOneAndHandsOver576=== RUN TestLeadIncumbentWinsAfterRestart5772026/10/11 04:52:53 INFO lead: acquired remote=192.0.2.1:12345782026/10/11 04:52:54 INFO lead: released remote=192.0.2.1:12345792026/10/11 04:52:54 INFO lead: acquired remote=192.0.2.1:12345802026/10/11 04:52:55 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadIncumbentWinsAfterRestart (2.29s)582=== RUN TestLeadIncumbentAnnouncesAtOnce583=== PAUSE TestLeadIncumbentAnnouncesAtOnce584=== RUN TestLeadEndsOnShutdown585=== PAUSE TestLeadEndsOnShutdown586=== RUN TestLeadEndsWhenItsConnectionHangs5872026/10/11 04:52:55 INFO lead: acquired remote=192.0.2.1:12345882026-10-11 04:52:56.890 UTC [82794] FATAL: terminating connection due to administrator command5892026/10/11 04:52:57 INFO lead: acquired remote=192.0.2.1:12345902026/10/11 04:52:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"5912026/10/11 04:52:58 INFO lead: released remote=192.0.2.1:12345922026/10/11 04:52:58 INFO lead: released remote=192.0.2.1:1234593--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)594=== RUN TestGCAdvisoryLockBlocksConcurrentRun595=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun596=== RUN TestGCBugBareHashReferences597=== PAUSE TestGCBugBareHashReferences598=== RUN TestGCMetrics599=== PAUSE TestGCMetrics600=== RUN TestPushDedupSurvivesConcurrentGC601=== PAUSE TestPushDedupSurvivesConcurrentGC602=== RUN TestDeduplicatedObjectsRecordedAsPending603=== PAUSE TestDeduplicatedObjectsRecordedAsPending604=== RUN TestGCSweepSkipsPendingObjects605=== PAUSE TestGCSweepSkipsPendingObjects606=== RUN TestTombstonedObjectOfferedWithoutWaiting607=== PAUSE TestTombstonedObjectOfferedWithoutWaiting608=== RUN TestGCSweepDeliversEachKeyOnce609=== PAUSE TestGCSweepDeliversEachKeyOnce610=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection611=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== RUN TestForceGCDuringPushOffersSweptObject613=== PAUSE TestForceGCDuringPushOffersSweptObject614=== RUN TestFailedS3DeleteKeepsTombstone615=== PAUSE TestFailedS3DeleteKeepsTombstone616=== RUN TestSweepSkipsRowsLockedByPush617=== PAUSE TestSweepSkipsRowsLockedByPush618=== RUN TestRegisterCompletedObjectNeedsPendingRow619=== PAUSE TestRegisterCompletedObjectNeedsPendingRow620=== RUN TestGetExistingObjectsLocksRows621=== PAUSE TestGetExistingObjectsLocksRows622=== RUN TestSweepRechecksPendingAfterLocking623=== PAUSE TestSweepRechecksPendingAfterLocking624=== RUN TestPushWaitsForSweepHoldingRow625=== PAUSE TestPushWaitsForSweepHoldingRow626=== RUN TestCommitRacingPendingCleanupKeepsObjects627=== PAUSE TestCommitRacingPendingCleanupKeepsObjects628=== RUN TestGCEndsOnShutdown629=== PAUSE TestGCEndsOnShutdown630=== RUN TestGCTaskStore_StartNew631=== PAUSE TestGCTaskStore_StartNew632=== RUN TestGCTaskStore_DeduplicateSameParams633=== PAUSE TestGCTaskStore_DeduplicateSameParams634=== RUN TestGCTaskStore_ConflictDifferentParams635=== PAUSE TestGCTaskStore_ConflictDifferentParams636=== RUN TestGCTaskStore_GetEmpty637=== PAUSE TestGCTaskStore_GetEmpty638=== RUN TestGCTaskStore_GetReturnsLatest639=== PAUSE TestGCTaskStore_GetReturnsLatest640=== RUN TestGCTaskStore_CompletedAllowsNewTask641=== PAUSE TestGCTaskStore_CompletedAllowsNewTask642=== RUN TestGCTaskStore_PhaseUpdates643=== PAUSE TestGCTaskStore_PhaseUpdates644=== RUN TestGCTaskStore_Fail645=== PAUSE TestGCTaskStore_Fail646=== RUN TestGracefulShutdownDrainsInflight647=== PAUSE TestGracefulShutdownDrainsInflight648=== RUN TestService_healthCheckHandler649=== PAUSE TestService_healthCheckHandler650=== RUN TestService_readinessHandler651=== PAUSE TestService_readinessHandler652=== RUN TestGenerateLandingPage653=== PAUSE TestGenerateLandingPage654=== RUN TestCacheConfigHandlerMaxNarSize655=== PAUSE TestCacheConfigHandlerMaxNarSize656=== RUN TestCreatePendingClosureRejectsOversizedNAR657=== PAUSE TestCreatePendingClosureRejectsOversizedNAR658=== RUN TestNARDeduplicationMetadataUploadBug659=== PAUSE TestNARDeduplicationMetadataUploadBug660=== RUN TestMetricsInventory661=== PAUSE TestMetricsInventory662=== RUN TestMetricsCommit663=== PAUSE TestMetricsCommit664=== RUN TestService_NativeMTLS665=== PAUSE TestService_NativeMTLS666=== RUN TestServerTLSConfig667=== PAUSE TestServerTLSConfig668=== RUN TestMultipartCleanup669=== PAUSE TestMultipartCleanup670=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded671=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== RUN TestPendingCleanupUsesOneCutoff673=== PAUSE TestPendingCleanupUsesOneCutoff674=== RUN TestObjectStatsTrigger675=== PAUSE TestObjectStatsTrigger676=== RUN TestObjectStatsLargeCommit677=== PAUSE TestObjectStatsLargeCommit678=== RUN TestOrphanedObjectsGC679=== PAUSE TestOrphanedObjectsGC680=== RUN TestOrphanedObjectsGCStressTest681=== PAUSE TestOrphanedObjectsGCStressTest682=== RUN TestCreatePin_ReservedPins683=== PAUSE TestCreatePin_ReservedPins684=== RUN TestPresentReportsOnlyClosureRoots685=== PAUSE TestPresentReportsOnlyClosureRoots686=== RUN TestPresentRefreshesOnlyStaleClosures687=== PAUSE TestPresentRefreshesOnlyStaleClosures688=== RUN TestPresentNotReportedWhileGCDeletesClosure689=== PAUSE TestPresentNotReportedWhileGCDeletesClosure690=== RUN TestParseSingleRange691=== PAUSE TestParseSingleRange692=== RUN TestProxyHeadersOnlyTrustedOnSocket6932026/10/11 04:52:58 INFO Starting HTTP server address=127.0.0.1:582906942026/10/11 04:52:58 INFO Starting HTTP server address=proxy.sock6952026/10/11 04:52:58 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6962026/10/11 04:52:58 INFO Shutdown signal received, draining in-flight requests timeout=10s697--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)698=== RUN TestIsValidCachePath699=== PAUSE TestIsValidCachePath700=== RUN TestReadProxyNarinfo701=== PAUSE TestReadProxyNarinfo702=== RUN TestReadProxyNarinfoAlreadyDecompressed703=== PAUSE TestReadProxyNarinfoAlreadyDecompressed704=== RUN TestReadProxyContentNegotiation705=== PAUSE TestReadProxyContentNegotiation706=== RUN TestReadProxyNarStreaming707=== PAUSE TestReadProxyNarStreaming708=== RUN TestReadProxy404709=== PAUSE TestReadProxy404710=== RUN TestReadProxyInvalidPath711=== PAUSE TestReadProxyInvalidPath712=== RUN TestReadProxyHead713=== PAUSE TestReadProxyHead714=== RUN TestReadProxyOutlastsServerWriteTimeout715=== PAUSE TestReadProxyOutlastsServerWriteTimeout716=== RUN TestReadProxyConditionalGet717=== PAUSE TestReadProxyConditionalGet718=== RUN TestReadProxyRootRedirectsToIndexHTML719=== PAUSE TestReadProxyRootRedirectsToIndexHTML720=== RUN TestReadProxyDisabled721=== PAUSE TestReadProxyDisabled722=== RUN TestReadRedirectNar723=== PAUSE TestReadRedirectNar724=== RUN TestReadRedirectKeepsNarinfoProxied725=== PAUSE TestReadRedirectKeepsNarinfoProxied726=== RUN TestReadProxyRangeRequest727=== PAUSE TestReadProxyRangeRequest728=== RUN TestReadRedirectUsesPublicS3URL729=== PAUSE TestReadRedirectUsesPublicS3URL730=== RUN TestPush_OverlappingRootsStoreOneRowPerKey731=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey732=== RUN TestPush_CompleteCommitsEveryRoot733=== PAUSE TestPush_CompleteCommitsEveryRoot734=== RUN TestPush_RepeatedRootCommitsOnce735=== PAUSE TestPush_RepeatedRootCommitsOnce736=== RUN TestPush_CompleteWaitsForCleanupOfThePush737=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush738=== RUN TestPush_RootsAreLockedInByteOrder739=== PAUSE TestPush_RootsAreLockedInByteOrder740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/11 04:52:58 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"775--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)776=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== RUN TestProxyWriteTimeout779=== PAUSE TestProxyWriteTimeout780=== RUN TestPendingClosureWriteTimeout781=== PAUSE TestPendingClosureWriteTimeout782=== RUN TestIsValidUploadKey783=== PAUSE TestIsValidUploadKey784=== RUN TestUploadHandlersRejectInvalidKeys785=== PAUSE TestUploadHandlersRejectInvalidKeys786=== RUN TestUploadHandlersRejectOversizedBody787=== PAUSE TestUploadHandlersRejectOversizedBody788=== RUN TestService_cleanupPendingClosuresHandler789=== PAUSE TestService_cleanupPendingClosuresHandler790=== RUN TestService_createPendingClosureHandler791=== PAUSE TestService_createPendingClosureHandler792=== RUN TestService_verifyS3Integrity793=== PAUSE TestService_verifyS3Integrity794=== RUN TestCompleteMultipartUnregistered795=== PAUSE TestCompleteMultipartUnregistered796=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT797=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestPush_SignsNarinfosOfItsPendingObjects799=== CONT TestPendingClosureWriteTimeout800=== CONT TestReadRedirectNar801=== CONT TestGCTaskStore_StartNew802--- PASS: TestGCTaskStore_StartNew (0.00s)803=== CONT TestIsValidUploadKey804=== RUN TestPendingClosureWriteTimeout/empty805=== CONT TestCompleteMultipartUnregistered806=== CONT TestPush_RejectsBadRequests807=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit808=== CONT TestPush_RootsAreLockedInByteOrder809=== CONT TestPush_CompleteWaitsForCleanupOfThePush810=== CONT TestPush_RepeatedRootCommitsOnce811=== CONT TestPush_CompleteCommitsEveryRoot812=== CONT TestPush_OverlappingRootsStoreOneRowPerKey813=== CONT TestReadRedirectUsesPublicS3URL814=== CONT TestReadProxyRangeRequest815=== CONT TestService_createPendingClosureHandler816=== CONT TestReadRedirectKeepsNarinfoProxied817=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT818=== CONT TestService_verifyS3Integrity819=== CONT TestUploadHandlersRejectOversizedBody820=== CONT TestService_cleanupPendingClosuresHandler821=== CONT TestService_AuthMiddleware822=== CONT TestService_Rustfstest823=== CONT TestUploadHandlersRejectInvalidKeys824=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info825=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info826=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal827=== CONT TestProxyWriteTimeout828=== RUN TestIsValidUploadKey/narinfo829=== PAUSE TestPendingClosureWriteTimeout/empty830=== RUN TestPendingClosureWriteTimeout/400_objects831=== PAUSE TestIsValidUploadKey/narinfo832=== RUN TestIsValidUploadKey/nar_zst833=== PAUSE TestIsValidUploadKey/nar_zst834=== RUN TestIsValidUploadKey/nar_xz835=== PAUSE TestIsValidUploadKey/nar_xz836=== RUN TestIsValidUploadKey/nar_plain837=== PAUSE TestIsValidUploadKey/nar_plain838=== RUN TestIsValidUploadKey/listing839=== PAUSE TestIsValidUploadKey/listing840=== RUN TestIsValidUploadKey/build_log841=== PAUSE TestIsValidUploadKey/build_log842=== RUN TestIsValidUploadKey/build_log_home-manager_file843=== PAUSE TestIsValidUploadKey/build_log_home-manager_file844=== RUN TestIsValidUploadKey/build_log_plus_in_name845=== PAUSE TestIsValidUploadKey/build_log_plus_in_name846=== RUN TestIsValidUploadKey/build_log_question_mark847=== PAUSE TestIsValidUploadKey/build_log_question_mark848=== RUN TestIsValidUploadKey/build_log_equals849=== PAUSE TestPendingClosureWriteTimeout/400_objects850=== RUN TestProxyWriteTimeout/narinfo851=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal852=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key853=== RUN TestPendingClosureWriteTimeout/670k_objects854=== PAUSE TestIsValidUploadKey/build_log_equals855=== RUN TestIsValidUploadKey/realisation856=== PAUSE TestIsValidUploadKey/realisation857=== RUN TestIsValidUploadKey/realisation_plus_in_output858=== PAUSE TestIsValidUploadKey/realisation_plus_in_output859=== RUN TestIsValidUploadKey/nix-cache-info860=== PAUSE TestIsValidUploadKey/nix-cache-info861=== RUN TestIsValidUploadKey/index.html862=== PAUSE TestIsValidUploadKey/index.html863=== RUN TestIsValidUploadKey/narinfo_key,_nar_type864=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type865=== RUN TestIsValidUploadKey/nar_key,_narinfo_type866=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type867=== RUN TestIsValidUploadKey/listing_key,_narinfo_type868=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type869=== RUN TestIsValidUploadKey/traversal870=== PAUSE TestIsValidUploadKey/traversal871=== RUN TestIsValidUploadKey/traversal_nar872=== PAUSE TestIsValidUploadKey/traversal_nar873=== RUN TestIsValidUploadKey/absolute874=== PAUSE TestIsValidUploadKey/absolute875=== RUN TestIsValidUploadKey/empty_key876=== PAUSE TestIsValidUploadKey/empty_key877=== RUN TestIsValidUploadKey/unknown_type878=== PAUSE TestIsValidUploadKey/unknown_type879=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle880=== PAUSE TestProxyWriteTimeout/narinfo881=== RUN TestProxyWriteTimeout/1_GiB_nar882=== PAUSE TestProxyWriteTimeout/1_GiB_nar883=== RUN TestProxyWriteTimeout/10_GiB_nar884=== PAUSE TestProxyWriteTimeout/10_GiB_nar885=== RUN TestProxyWriteTimeout/unknown_size886=== PAUSE TestProxyWriteTimeout/unknown_size887=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key888=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key889=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key890=== CONT TestSkippedUploadsHandler891=== PAUSE TestPendingClosureWriteTimeout/670k_objects892=== CONT TestParseSize893=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline894--- PASS: TestParseSize (0.00s)895=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline896=== CONT TestCompletedNarNotReofferedAcrossClosures8972026/10/11 04:52:58 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000898=== CONT TestPresignedUploadRegisteredBeforeCommit899--- PASS: TestSkippedUploadsHandler (0.00s)900=== CONT TestReadProxyNarinfoAlreadyDecompressed901=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure902=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure903=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart904=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart905=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts906=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts907=== CONT TestReadProxyDisabled9082026/10/11 04:52:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9092026/10/11 04:52:59 INFO Aborted multipart uploads count=0 kept=09102026/10/11 04:52:59 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/11 04:52:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9122026/10/11 04:52:59 INFO Aborted multipart uploads count=1 kept=09132026/10/11 04:52:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9142026-10-11 04:52:59.971 UTC [82869] ERROR: Closure does not exist: id=19152026-10-11 04:52:59.971 UTC [82869] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9162026-10-11 04:52:59.971 UTC [82869] STATEMENT: -- name: CommitPendingClosure :one917 SELECT commit_pending_closure($1::bigint)::bigint918 919--- PASS: TestService_cleanupPendingClosuresHandler (1.27s)920=== CONT TestReadProxyRootRedirectsToIndexHTML921--- PASS: TestReadRedirectNar (1.34s)922=== CONT TestReadProxyConditionalGet9232026/10/11 04:53:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9242026/10/11 04:53:00 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst925--- PASS: TestCompleteMultipartUnregistered (1.66s)926=== CONT TestReadProxy4049272026/10/11 04:53:00 INFO Received push request method=POST path=/api/pushes9282026/10/11 04:53:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"929--- PASS: TestService_AuthMiddleware (2.20s)930=== CONT TestObjectStatsTrigger9312026/10/11 04:53:01 INFO Received push request method=POST path=/api/pushes9322026-10-11 04:53:01.081 UTC [82910] ERROR: Push does not exist: id=19332026-10-11 04:53:01.081 UTC [82910] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9342026-10-11 04:53:01.081 UTC [82910] STATEMENT: SELECT commit_push($1)935--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.37s)936=== CONT TestReadProxyNarStreaming9372026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9382026/10/11 04:53:01 INFO Signed narinfos id=1 count=19392026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9402026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9412026/10/11 04:53:01 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9422026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9432026/10/11 04:53:01 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9442026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9452026/10/11 04:53:01 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19462026/10/11 04:53:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9472026/10/11 04:53:01 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo948--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.44s)949=== CONT TestReadProxyNarinfo9502026/10/11 04:53:01 INFO Received push request method=POST path=/api/pushes9512026-10-11 04:53:01.389 UTC [82917] ERROR: could not obtain lock on row in relation "closures"9522026-10-11 04:53:01.389 UTC [82917] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9532026-10-11 04:53:01.391 UTC [82917] ERROR: could not obtain lock on row in relation "closures"9542026-10-11 04:53:01.391 UTC [82917] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9552026-10-11 04:53:01.399 UTC [82917] ERROR: could not obtain lock on row in relation "closures"9562026-10-11 04:53:01.399 UTC [82917] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9572026-10-11 04:53:01.400 UTC [82917] ERROR: could not obtain lock on row in relation "closures"9582026-10-11 04:53:01.400 UTC [82917] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT9592026-10-11 04:53:01.401 UTC [82917] ERROR: could not obtain lock on row in relation "closures"9602026-10-11 04:53:01.401 UTC [82917] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT961--- PASS: TestPush_RootsAreLockedInByteOrder (2.70s)962=== CONT TestReadProxyContentNegotiation963=== RUN TestPush_RejectsBadRequests/bad_root964=== PAUSE TestPush_RejectsBadRequests/bad_root965=== RUN TestPush_RejectsBadRequests/root_not_in_objects966=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects967=== RUN TestPush_RejectsBadRequests/no_roots968=== PAUSE TestPush_RejectsBadRequests/no_roots969=== RUN TestPush_RejectsBadRequests/no_objects970=== PAUSE TestPush_RejectsBadRequests/no_objects971=== CONT TestIsValidCachePath972=== RUN TestIsValidCachePath/narinfo973=== PAUSE TestIsValidCachePath/narinfo974=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars975=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars976=== RUN TestIsValidCachePath/nar_zst977=== PAUSE TestIsValidCachePath/nar_zst978=== RUN TestIsValidCachePath/nar_xz979=== PAUSE TestIsValidCachePath/nar_xz980=== RUN TestIsValidCachePath/nar_bz2981=== PAUSE TestIsValidCachePath/nar_bz2982=== RUN TestIsValidCachePath/nar_uncompressed983=== PAUSE TestIsValidCachePath/nar_uncompressed984=== RUN TestIsValidCachePath/ls985=== PAUSE TestIsValidCachePath/ls986=== RUN TestIsValidCachePath/log987=== PAUSE TestIsValidCachePath/log988=== RUN TestIsValidCachePath/realisation989=== PAUSE TestIsValidCachePath/realisation990=== RUN TestIsValidCachePath/nix-cache-info991=== PAUSE TestIsValidCachePath/nix-cache-info992=== RUN TestIsValidCachePath/index.html993=== PAUSE TestIsValidCachePath/index.html994=== RUN TestIsValidCachePath/traversal_parent995=== PAUSE TestIsValidCachePath/traversal_parent996=== RUN TestIsValidCachePath/traversal_in_middle997=== PAUSE TestIsValidCachePath/traversal_in_middle998=== RUN TestIsValidCachePath/invalid_char_e999=== PAUSE TestIsValidCachePath/invalid_char_e1000=== RUN TestIsValidCachePath/invalid_char_u1001=== PAUSE TestIsValidCachePath/invalid_char_u1002=== RUN TestIsValidCachePath/random_path1003=== PAUSE TestIsValidCachePath/random_path1004=== RUN TestIsValidCachePath/empty1005=== PAUSE TestIsValidCachePath/empty1006=== RUN TestIsValidCachePath/leading_slash1007=== PAUSE TestIsValidCachePath/leading_slash1008=== RUN TestIsValidCachePath/wrong_extension1009=== PAUSE TestIsValidCachePath/wrong_extension1010=== RUN TestIsValidCachePath/short_hash1011=== PAUSE TestIsValidCachePath/short_hash1012=== CONT TestReadProxyOutlastsServerWriteTimeout10132026/10/11 04:53:01 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/11 04:53:01 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/11 04:53:01 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/11 04:53:01 INFO Received push request method=POST path=/api/pushes10172026/10/11 04:53:02 INFO Received complete push request method=POST path=/api/pushes/1/complete10182026/10/11 04:53:02 INFO Completed push id=1 objects=4 duration=42.56825ms1019--- PASS: TestPush_RepeatedRootCommitsOnce (3.40s)1020=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10212026/10/11 04:53:02 INFO Received push request method=POST path=/api/pushes10222026/10/11 04:53:02 INFO Received complete push request method=POST path=/api/pushes/1/complete10232026/10/11 04:53:02 INFO Completed push id=1 objects=4 duration=28.61275ms10242026/10/11 04:53:02 INFO Received push request method=POST path=/api/pushes10252026/10/11 04:53:02 INFO Aborted multipart uploads count=0 kept=010262026/10/11 04:53:02 WARN Force mode enabled - objects will be deleted immediately without grace period10272026/10/11 04:53:02 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=010282026/10/11 04:53:02 INFO Vacuumed table table=pending_closures10292026/10/11 04:53:02 INFO Vacuumed table table=pending_objects1030--- PASS: TestReadProxyRangeRequest (3.78s)10312026/10/11 04:53:02 INFO Vacuumed table table=multipart_uploads1032=== CONT TestRedundantMultipartUpload10332026/10/11 04:53:02 INFO Vacuumed table table=closures10342026/10/11 04:53:02 INFO Vacuumed table table=objects10352026/10/11 04:53:02 INFO Received complete push request method=POST path=/api/pushes/2/complete10362026/10/11 04:53:02 INFO Completed push id=2 objects=4 duration=9.286417ms1037--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.85s)1038=== CONT TestReadProxyInvalidPath10392026/10/11 04:53:02 INFO Received uploads request method=POST path=/api/pending_closures1040--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.07s)1041=== CONT TestLeadElectsOneAndHandsOver10422026/10/11 04:53:02 INFO Received push request method=POST path=/api/pushes10432026/10/11 04:53:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10442026/10/11 04:53:03 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjc4ZWU0YmY4LTZiNWYtNDFjZS1iNjAyLWVjMjRlMGIzYTk4NHgxNzkxNjk0MzgxNzQ5NjU4MDAw parts=1010452026/10/11 04:53:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10462026/10/11 04:53:03 INFO Received complete push request method=POST path=/api/pushes/1/complete10472026/10/11 04:53:03 INFO Completed upload id=1 objects=2 duration=8.927625ms10482026/10/11 04:53:03 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010492026/10/11 04:53:03 INFO Received uploads request method=POST path=/api/pending_closures10502026/10/11 04:53:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures10512026/10/11 04:53:03 INFO Completed push id=1 objects=6 duration=33.957792ms1052--- PASS: TestPush_CompleteCommitsEveryRoot (4.41s)1053=== CONT TestReadProxyHead10542026/10/11 04:53:03 INFO Aborted multipart uploads count=0 kept=010552026/10/11 04:53:03 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=010562026/10/11 04:53:03 INFO Vacuumed table table=pending_closures10572026/10/11 04:53:03 INFO Vacuumed table table=pending_objects10582026/10/11 04:53:03 INFO Vacuumed table table=multipart_uploads10592026/10/11 04:53:03 INFO Vacuumed table table=closures1060--- PASS: TestReadRedirectKeepsNarinfoProxied (4.56s)1061=== CONT TestParseSingleRange1062=== RUN TestParseSingleRange/none1063=== PAUSE TestParseSingleRange/none10642026/10/11 04:53:03 INFO Vacuumed table table=objects1065=== RUN TestParseSingleRange/unknown_unit1066=== PAUSE TestParseSingleRange/unknown_unit1067=== RUN TestParseSingleRange/multi-range_ignored1068=== PAUSE TestParseSingleRange/multi-range_ignored1069=== RUN TestParseSingleRange/malformed_no_dash1070=== PAUSE TestParseSingleRange/malformed_no_dash1071=== RUN TestParseSingleRange/malformed_both_empty1072=== PAUSE TestParseSingleRange/malformed_both_empty1073=== RUN TestParseSingleRange/malformed_end_before_start1074=== PAUSE TestParseSingleRange/malformed_end_before_start1075=== RUN TestParseSingleRange/closed1076=== PAUSE TestParseSingleRange/closed1077=== RUN TestParseSingleRange/open-ended1078=== PAUSE TestParseSingleRange/open-ended1079=== RUN TestParseSingleRange/end_clamped_to_size1080=== PAUSE TestParseSingleRange/end_clamped_to_size1081=== RUN TestParseSingleRange/suffix1082=== PAUSE TestParseSingleRange/suffix1083=== RUN TestParseSingleRange/suffix_exceeds_size1084=== PAUSE TestParseSingleRange/suffix_exceeds_size1085=== RUN TestParseSingleRange/single_byte1086=== PAUSE TestParseSingleRange/single_byte1087=== RUN TestParseSingleRange/start_past_EOF1088=== PAUSE TestParseSingleRange/start_past_EOF1089=== RUN TestParseSingleRange/start_far_past_EOF1090=== PAUSE TestParseSingleRange/start_far_past_EOF1091=== CONT TestGCEndsOnShutdown1092=== RUN TestGCEndsOnShutdown/before_the_run1093=== PAUSE TestGCEndsOnShutdown/before_the_run1094=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1095=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1096=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1097=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1098=== CONT TestPresentNotReportedWhileGCDeletesClosure1099=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1100=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1101=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1102=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1103=== CONT TestCommitRacingPendingCleanupKeepsObjects11042026/10/11 04:53:03 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001105--- PASS: TestService_createPendingClosureHandler (4.60s)1106=== CONT TestPresentRefreshesOnlyStaleClosures11072026/10/11 04:53:03 INFO Received push request method=POST path=/api/pushes1108--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (4.81s)1109=== CONT TestClientIntegration1110--- PASS: TestReadProxyDisabled (4.87s)1111=== CONT TestPresentReportsOnlyClosureRoots11122026/10/11 04:53:03 INFO Received uploads request method=POST path=/api/pending_closures11132026/10/11 04:53:04 INFO Received uploads request method=POST path=/api/pending_closures11142026/10/11 04:53:04 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11152026/10/11 04:53:04 INFO Received uploads request method=POST path=/api/pending_closures1116--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.45s)1117=== CONT TestConnectWaitsForAPeerMigration11182026/10/11 04:53:04 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/11 04:53:04 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/11 04:53:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1121--- PASS: TestService_Rustfstest (6.33s)1122=== CONT TestCreatePin_ReservedPins11232026/10/11 04:53:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58342/oidc1124--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.60s)1125=== CONT TestResolveDBConnectionString1126=== RUN TestResolveDBConnectionString/flag_wins1127=== PAUSE TestResolveDBConnectionString/flag_wins1128=== RUN TestResolveDBConnectionString/file_when_flag_empty1129=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1130=== RUN TestResolveDBConnectionString/missing_file_is_an_error1131=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1132=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1133=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1134=== RUN TestResolveDBConnectionString/nothing_configured1135=== PAUSE TestResolveDBConnectionString/nothing_configured1136=== CONT TestOrphanedObjectsGCStressTest11372026/10/11 04:53:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11382026/10/11 04:53:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjlkYWZjZWY4LTFkOTgtNDRiOC04MDRlLTJhYjg1YTNlNzIzN3gxNzkxNjk0MzgzOTE0MzUwMDAw parts=1211392026/10/11 04:53:05 INFO Received uploads request method=POST path=/api/pending_closures1140--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.80s)1141=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1142--- PASS: TestReadRedirectUsesPublicS3URL (6.93s)1143=== CONT TestOrphanedObjectsGC1144--- PASS: TestReadProxy404 (5.64s)1145=== CONT TestDeleteClosuresRacingPins11462026/10/11 04:53:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1147--- PASS: TestReadProxyConditionalGet (6.25s)1148=== CONT TestObjectStatsLargeCommit11492026/10/11 04:53:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLmRhZjJkNTViLWMyY2MtNGNlZi04NzFlLTVmYzEzNTcyYjc0Y3gxNzkxNjk0Mzg0NzgxNjc4MDAw parts=1011502026/10/11 04:53:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11512026/10/11 04:53:06 INFO Completed upload id=1 objects=2 duration=17.601209ms11522026/10/11 04:53:06 INFO Received uploads request method=POST path=/api/pending_closures11532026/10/11 04:53:06 INFO Received uploads request method=POST path=/api/pending_closures11542026/10/11 04:53:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11552026/10/11 04:53:06 WARN Found objects in DB but missing from S3, will re-upload count=11156--- PASS: TestService_verifyS3Integrity (7.70s)1157=== CONT TestClientFallsBackToClosures1158--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.63s)1159=== CONT TestPushWaitsForSweepHoldingRow1160--- PASS: TestObjectStatsTrigger (6.05s)1161=== CONT TestSweepRechecksPendingAfterLocking1162--- PASS: TestReadProxyNarStreaming (6.10s)1163=== CONT TestGetExistingObjectsLocksRows11642026/10/11 04:53:07 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1165--- PASS: TestReadProxyNarinfo (6.45s)1166=== CONT TestRegisterCompletedObjectNeedsPendingRow1167--- PASS: TestReadProxyContentNegotiation (6.55s)1168=== CONT TestGenerateLandingPage1169--- PASS: TestGenerateLandingPage (0.00s)1170=== CONT TestClientPushesUseOnePush11712026/10/11 04:53:08 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/11 04:53:08 WARN Rate limiter enabled after throttle name=s3-test rate=511732026/10/11 04:53:08 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1174=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1175 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101176 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001177--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.00s)1178=== CONT TestPinProtectsFromGC11792026/10/11 04:53:08 INFO Received uploads request method=POST path=/api/pending_closures11802026/10/11 04:53:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11812026/10/11 04:53:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjJhY2U5ZGNhLTJiNzctNDNlOS1iZjc2LTYzMTYzMTAwY2U2NXgxNzkxNjk0Mzg4NjcxOTcxMDAw11822026/10/11 04:53:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjJhY2U5ZGNhLTJiNzctNDNlOS1iZjc2LTYzMTYzMTAwY2U2NXgxNzkxNjk0Mzg4NjcxOTcxMDAw parts=11183--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.94s)1184=== CONT TestSweepSkipsRowsLockedByPush11852026/10/11 04:53:09 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestReadProxyInvalidPath (6.78s)1187=== CONT TestClientSharedPathCommittedMidPush11882026/10/11 04:53:09 INFO lead: acquired remote=192.0.2.1:12341189--- PASS: TestReadProxyHead (6.98s)1190=== CONT TestClientWithDependencies1191--- PASS: TestPresentRefreshesOnlyStaleClosures (7.08s)1192=== CONT TestFailedS3DeleteKeepsTombstone11932026/10/11 04:53:10 INFO Aborted multipart uploads count=0 kept=011942026/10/11 04:53:10 WARN Force mode enabled - objects will be deleted immediately without grace period11952026/10/11 04:53:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011962026/10/11 04:53:10 INFO Vacuumed table table=pending_closures11972026/10/11 04:53:10 INFO Vacuumed table table=pending_objects11982026/10/11 04:53:10 INFO Vacuumed table table=multipart_uploads11992026/10/11 04:53:10 INFO Vacuumed table table=closures12002026/10/11 04:53:10 INFO Vacuumed table table=objects1201--- PASS: TestCommitRacingPendingCleanupKeepsObjects (7.45s)1202=== CONT TestPendingCleanupUsesOneCutoff12032026/10/11 04:53:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12042026/10/11 04:53:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjUzNWRiZTk2LTY0YjctNGNjYS04M2Y1LWEwZmQxMWFmMmVlY3gxNzkxNjk0Mzg5MDU3OTIwMDAw parts=1212052026/10/11 04:53:10 INFO Received uploads request method=POST path=/api/pending_closures12062026/10/11 04:53:10 INFO Received uploads request method=POST path=/api/pending_closures12072026/10/11 04:53:10 INFO lead: released remote=192.0.2.1:123412082026/10/11 04:53:10 INFO lead: acquired remote=192.0.2.1:12341209=== NAME TestClientIntegration1210 client_integration_test.go:286: Created store path: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientIntegration2901576463/002/store/ls9iy4j0044am67yjpw5x67zqpjj901z-test-file.txt1211--- PASS: TestPresentReportsOnlyClosureRoots (7.46s)1212=== CONT TestClientMultipleUploads12132026/10/11 04:53:11 INFO Received push request method=POST path=/api/pushes12142026/10/11 04:53:11 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12152026/10/11 04:53:11 INFO Uploading ls9iy4j0044am67yjpw5x67zqpjj901z-test-file.txt (152B)12162026/10/11 04:53:11 WARN Failed to register uploaded object key=ls9iy4j0044am67yjpw5x67zqpjj901z.ls error="server returned 404: 404 page not found\n"12172026/10/11 04:53:11 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12182026/10/11 04:53:11 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12192026/10/11 04:53:11 INFO Signed narinfos id=1 count=112202026/10/11 04:53:11 INFO Uploading 1 narinfos12212026/10/11 04:53:11 INFO Received complete push request method=POST path=/api/pushes/1/complete12222026/10/11 04:53:11 WARN Failed to register uploaded object key=ls9iy4j0044am67yjpw5x67zqpjj901z.narinfo error="server returned 404: 404 page not found\n"12232026/10/11 04:53:11 INFO Completed push id=1 objects=3 duration=24.375916ms12242026/10/11 04:53:11 INFO Upload complete. (160ms)12252026/10/11 04:53:11 INFO All 1 paths already cached1226=== NAME TestClientIntegration1227 client_integration_test.go:312: Retrieved narinfo from S3:1228 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientIntegration2901576463/002/store/ls9iy4j0044am67yjpw5x67zqpjj901z-test-file.txt1229 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1230 Compression: zstd1231 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11232 NarSize: 1521233 References: 1234 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11235 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)12362026/10/11 04:53:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12372026/10/11 04:53:11 WARN Refused reserved pin name=worker-x86_64-linux1238 client_integration_test.go:313: Decompressed .ls content (64 bytes):1239 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}12402026/10/11 04:53:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1241 client_integration_test.go:316: Testing garbage collection...12422026/10/11 04:53:11 INFO Received create pin request method=POST path=/api/pins/my-app12432026/10/11 04:53:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1244--- PASS: TestCreatePin_ReservedPins (6.24s)1245=== CONT TestForceGCDuringPushOffersSweptObject1246=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1247=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1248=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1249=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1250=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12512026/10/11 04:53:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures12522026/10/11 04:53:11 INFO Garbage collection started12532026/10/11 04:53:11 INFO Aborted multipart uploads count=0 kept=012542026/10/11 04:53:11 WARN Force mode enabled - objects will be deleted immediately without grace period12552026/10/11 04:53:11 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012562026/10/11 04:53:11 INFO Vacuumed table table=pending_closures12572026/10/11 04:53:11 INFO Vacuumed table table=pending_objects12582026/10/11 04:53:11 INFO Vacuumed table table=multipart_uploads12592026/10/11 04:53:11 INFO Vacuumed table table=closures12602026/10/11 04:53:11 INFO Vacuumed table table=objects1261--- PASS: TestConnectWaitsForAPeerMigration (7.75s)1262=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12632026/10/11 04:53:12 INFO lead: released remote=192.0.2.1:12341264--- PASS: TestLeadElectsOneAndHandsOver (9.25s)1265=== CONT TestMetricsCommit12662026/10/11 04:53:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1267--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.99s)12682026/10/11 04:53:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjU2NzljMmM5LTRkNGMtNDIxNS1hZjZkLTAyZWM1YjI1MzdlYXgxNzkxNjk0MzkwOTMwNzI5MDAw error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1269=== CONT TestMultipartCleanup12702026/10/11 04:53:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmIyYzEzZDAtMDM0MC00NzAyLTlkYzUtNDkzNTIxZDU5ZjlhLjAyYWY4M2I2LWI5YTktNGM1ZS1iMWExLWRiZWZhNDViYjMwMXgxNzkxNjk0MzkwOTAyMjY4MDAw parts=1212712026/10/11 04:53:12 INFO Received cleanup request method=DELETE path=/api/pending_closures12722026/10/11 04:53:12 INFO Aborted multipart uploads count=1 kept=01273--- PASS: TestRedundantMultipartUpload (10.04s)1274=== CONT TestMetricsInventory1275=== NAME TestOrphanedObjectsGC1276 orphaned_objects_gc_test.go:287: GC Test Summary:1277 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1278 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1279--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.30s)1280=== CONT TestServerTLSConfig1281=== NAME TestOrphanedObjectsGC1282 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1283=== RUN TestServerTLSConfig/no_client_CA1284=== PAUSE TestServerTLSConfig/no_client_CA1285=== RUN TestServerTLSConfig/missing_CA_file1286=== PAUSE TestServerTLSConfig/missing_CA_file1287=== NAME TestOrphanedObjectsGC1288 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1289 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1290=== RUN TestServerTLSConfig/not_a_PEM_file1291--- PASS: TestOrphanedObjectsGC (7.25s)1292=== CONT TestNARDeduplicationMetadataUploadBug1293=== PAUSE TestServerTLSConfig/not_a_PEM_file1294=== CONT TestService_NativeMTLS12952026/10/11 04:53:13 INFO Received uploads request method=POST path=/api/pending_closures12962026/10/11 04:53:13 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01297=== NAME TestClientIntegration1298 client_integration_test.go:323: Objects in database after GC:1299 client_integration_test.go:323: Successfully deleted all objects with GC --force1300--- PASS: TestClientIntegration (9.86s)1301=== CONT TestCreatePendingClosureRejectsOversizedNAR13022026/10/11 04:53:13 INFO Received uploads request method=POST path=/api/pending_closures1303--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1304=== CONT TestGCSweepDeliversEachKeyOnce13052026/10/11 04:53:13 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/11 04:53:13 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/11 04:53:13 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13082026/10/11 04:53:13 INFO Uploading 5984biga2vmdda2xk9lipsq3rviddjsd-shared-dep (136B)13092026/10/11 04:53:13 INFO Uploading s53pngjvcjrwhzgbr0hfj00cvq5l7dqq-a (256B)13102026/10/11 04:53:13 WARN Failed to register uploaded object key=lalf8r0brnxnx9r3h81h9wxcrsn3dgxk.ls error="server returned 404: 404 page not found\n"13112026/10/11 04:53:13 INFO Aborted multipart uploads count=0 kept=013122026/10/11 04:53:13 WARN Failed to register uploaded object key=s53pngjvcjrwhzgbr0hfj00cvq5l7dqq.ls error="server returned 404: 404 page not found\n"13132026/10/11 04:53:13 WARN Failed to register uploaded object key=5984biga2vmdda2xk9lipsq3rviddjsd.ls error="server returned 404: 404 page not found\n"13142026/10/11 04:53:13 WARN Failed to register uploaded object key=nar/1hxnflarpmrjym423w4l1ynsm4crjk6v8hgmbnfd9wvf9c1jq78n.nar.zst error="server returned 404: 404 page not found\n"13152026/10/11 04:53:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13162026/10/11 04:53:13 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13172026/10/11 04:53:13 INFO Signed narinfos id=1 count=213182026/10/11 04:53:13 WARN Force mode enabled - objects will be deleted immediately without grace period13192026/10/11 04:53:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13202026/10/11 04:53:13 INFO Signed narinfos id=2 count=213212026/10/11 04:53:13 INFO Uploading 4 narinfos13222026/10/11 04:53:13 WARN Failed to register uploaded object key=s53pngjvcjrwhzgbr0hfj00cvq5l7dqq.narinfo error="server returned 404: 404 page not found\n"13232026/10/11 04:53:13 WARN Failed to register uploaded object key=5984biga2vmdda2xk9lipsq3rviddjsd.narinfo error="server returned 404: 404 page not found\n"13242026/10/11 04:53:13 WARN Failed to register uploaded object key=lalf8r0brnxnx9r3h81h9wxcrsn3dgxk.narinfo error="server returned 404: 404 page not found\n"13252026/10/11 04:53:13 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013262026/10/11 04:53:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13272026/10/11 04:53:13 WARN Failed to register uploaded object key=5984biga2vmdda2xk9lipsq3rviddjsd.narinfo error="server returned 404: 404 page not found\n"13282026/10/11 04:53:13 INFO Vacuumed table table=pending_closures13292026/10/11 04:53:13 INFO Completed upload id=2 objects=6 duration=14.645083ms13302026/10/11 04:53:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13312026/10/11 04:53:13 INFO Completed upload id=1 objects=6 duration=584.833µs13322026/10/11 04:53:13 INFO Upload complete. (227ms)1333=== NAME TestClientFallsBackToClosures1334 client_pushes_test.go:112: Retrieved narinfo from S3:1335 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientFallsBackToClosures1114761172/001/store/5984biga2vmdda2xk9lipsq3rviddjsd-shared-dep1336 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1337 Compression: zstd1338 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821339 NarSize: 1361340 References: 1341 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13422026/10/11 04:53:13 INFO Vacuumed table table=pending_objects13432026/10/11 04:53:13 INFO Vacuumed table table=multipart_uploads1344 client_pushes_test.go:112: Retrieved narinfo from S3:13452026/10/11 04:53:13 INFO Vacuumed table table=closures1346 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientFallsBackToClosures1114761172/001/store/s53pngjvcjrwhzgbr0hfj00cvq5l7dqq-a1347 URL: nar/1hxnflarpmrjym423w4l1ynsm4crjk6v8hgmbnfd9wvf9c1jq78n.nar.zst1348 Compression: zstd1349 NarHash: sha256:1hxnflarpmrjym423w4l1ynsm4crjk6v8hgmbnfd9wvf9c1jq78n1350 NarSize: 2561351 References: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientFallsBackToClosures1114761172/001/store/5984biga2vmdda2xk9lipsq3rviddjsd-shared-dep1352 CA: text:sha256:1n9vii8zsqqnam7qr87wf71ika9rnppbfh92gxhgr7z9na54q23j1353 client_pushes_test.go:112: Retrieved narinfo from S3:1354 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientFallsBackToClosures1114761172/001/store/lalf8r0brnxnx9r3h81h9wxcrsn3dgxk-b1355 URL: nar/1hxnflarpmrjym423w4l1ynsm4crjk6v8hgmbnfd9wvf9c1jq78n.nar.zst1356 Compression: zstd1357 NarHash: sha256:1hxnflarpmrjym423w4l1ynsm4crjk6v8hgmbnfd9wvf9c1jq78n1358 NarSize: 2561359 References: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientFallsBackToClosures1114761172/001/store/5984biga2vmdda2xk9lipsq3rviddjsd-shared-dep1360 CA: text:sha256:1n9vii8zsqqnam7qr87wf71ika9rnppbfh92gxhgr7z9na54q23j13612026/10/11 04:53:13 INFO Vacuumed table table=objects1362--- PASS: TestSweepRechecksPendingAfterLocking (6.68s)1363=== CONT TestCacheConfigHandlerMaxNarSize1364--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1365=== CONT TestTombstonedObjectOfferedWithoutWaiting1366--- PASS: TestClientFallsBackToClosures (7.29s)1367=== CONT TestGCMetrics1368--- PASS: TestPushWaitsForSweepHoldingRow (7.11s)1369=== CONT TestGCSweepSkipsPendingObjects1370--- PASS: TestGetExistingObjectsLocksRows (6.60s)1371=== CONT TestDeduplicatedObjectsRecordedAsPending1372--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.43s)1373=== CONT TestGCTaskStore_CompletedAllowsNewTask1374--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1375=== CONT TestPushDedupSurvivesConcurrentGC1376=== NAME TestPinProtectsFromGC1377 client_integration_test.go:731: Pinned store path: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestPinProtectsFromGC271461328/001/store/r959gjy1fqbjfvx16njf6xdni25277qg-pinned-file.txt1378 client_integration_test.go:732: Unpinned store path: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestPinProtectsFromGC271461328/001/store/y489gcdizfjicwqx6gn6d3srbvh0398s-unpinned-file.txt13792026/10/11 04:53:14 INFO Received push request method=POST path=/api/pushes13802026/10/11 04:53:14 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13812026/10/11 04:53:14 INFO Uploading hnc91xdvd93cw0j1j2rm9gkfj3m3qxbr-a (256B)13822026/10/11 04:53:14 INFO Uploading whjywnbp8mlixdmbbdvkrr04rifh778r-shared-dep (136B)13832026/10/11 04:53:14 INFO Aborted multipart uploads count=0 kept=013842026/10/11 04:53:14 WARN Failed to register uploaded object key=84yw17j0xaix2g4icfhjkq0p9xdamfn1.ls error="server returned 404: 404 page not found\n"13852026/10/11 04:53:14 WARN Failed to register uploaded object key=whjywnbp8mlixdmbbdvkrr04rifh778r.ls error="server returned 404: 404 page not found\n"13862026/10/11 04:53:14 WARN Failed to register uploaded object key=hnc91xdvd93cw0j1j2rm9gkfj3m3qxbr.ls error="server returned 404: 404 page not found\n"13872026/10/11 04:53:14 WARN Failed to register uploaded object key=nar/0wvichx2hhhwlzxwaafrlifakxwy4097jhb3013rj8lq89rvmkyv.nar.zst error="server returned 404: 404 page not found\n"13882026/10/11 04:53:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13892026/10/11 04:53:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13902026/10/11 04:53:14 INFO Signed narinfos id=1 count=313912026/10/11 04:53:14 WARN Force mode enabled - objects will be deleted immediately without grace period13922026/10/11 04:53:14 INFO Uploading 3 narinfos13932026/10/11 04:53: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=013942026/10/11 04:53:14 INFO Vacuumed table table=pending_closures13952026/10/11 04:53:14 INFO Vacuumed table table=pending_objects13962026/10/11 04:53:14 WARN Failed to register uploaded object key=whjywnbp8mlixdmbbdvkrr04rifh778r.narinfo error="server returned 404: 404 page not found\n"13972026/10/11 04:53:14 WARN Failed to register uploaded object key=hnc91xdvd93cw0j1j2rm9gkfj3m3qxbr.narinfo error="server returned 404: 404 page not found\n"13982026/10/11 04:53:14 INFO Received complete push request method=POST path=/api/pushes/1/complete13992026/10/11 04:53:14 INFO Vacuumed table table=multipart_uploads14002026/10/11 04:53:14 WARN Failed to register uploaded object key=84yw17j0xaix2g4icfhjkq0p9xdamfn1.narinfo error="server returned 404: 404 page not found\n"14012026/10/11 04:53:14 INFO Vacuumed table table=closures14022026/10/11 04:53:14 INFO Received push request method=POST path=/api/pushes14032026/10/11 04:53:14 INFO Vacuumed table table=objects14042026/10/11 04:53:14 INFO Completed push id=1 objects=8 duration=35.111667ms14052026/10/11 04:53:14 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14062026/10/11 04:53:15 INFO Uploading r959gjy1fqbjfvx16njf6xdni25277qg-pinned-file.txt (128B)14072026/10/11 04:53:15 INFO Upload complete. (221ms)1408=== NAME TestClientPushesUseOnePush1409 client_pushes_test.go:97: Retrieved narinfo from S3:1410 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientPushesUseOnePush2924661568/001/store/whjywnbp8mlixdmbbdvkrr04rifh778r-shared-dep1411 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1412 Compression: zstd1413 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821414 NarSize: 1361415 References: 1416 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1417 client_pushes_test.go:97: Retrieved narinfo from S3:1418 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientPushesUseOnePush2924661568/001/store/hnc91xdvd93cw0j1j2rm9gkfj3m3qxbr-a1419 URL: nar/0wvichx2hhhwlzxwaafrlifakxwy4097jhb3013rj8lq89rvmkyv.nar.zst1420 Compression: zstd1421 NarHash: sha256:0wvichx2hhhwlzxwaafrlifakxwy4097jhb3013rj8lq89rvmkyv1422 NarSize: 2561423 References: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientPushesUseOnePush2924661568/001/store/whjywnbp8mlixdmbbdvkrr04rifh778r-shared-dep1424 CA: text:sha256:0i611n15sqn8anpl439basr4k5cmmz7wpdqzqbarsnpzchzn89zc14252026/10/11 04:53:15 INFO Aborted multipart uploads count=0 kept=01426 client_pushes_test.go:97: Retrieved narinfo from S3:14272026/10/11 04:53:15 WARN Force mode enabled - objects will be deleted immediately without grace period1428 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientPushesUseOnePush2924661568/001/store/84yw17j0xaix2g4icfhjkq0p9xdamfn1-b1429 URL: nar/0wvichx2hhhwlzxwaafrlifakxwy4097jhb3013rj8lq89rvmkyv.nar.zst1430 Compression: zstd1431 NarHash: sha256:0wvichx2hhhwlzxwaafrlifakxwy4097jhb3013rj8lq89rvmkyv1432 NarSize: 2561433 References: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientPushesUseOnePush2924661568/001/store/whjywnbp8mlixdmbbdvkrr04rifh778r-shared-dep1434 CA: text:sha256:0i611n15sqn8anpl439basr4k5cmmz7wpdqzqbarsnpzchzn89zc14352026/10/11 04:53:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14362026/10/11 04:53:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14372026/10/11 04:53:15 WARN Failed to register uploaded object key=r959gjy1fqbjfvx16njf6xdni25277qg.ls error="server returned 404: 404 page not found\n"14382026/10/11 04:53:15 INFO Signed narinfos id=1 count=114392026/10/11 04:53:15 INFO Uploading 1 narinfos14402026/10/11 04:53:15 INFO Received complete push request method=POST path=/api/pushes/1/complete14412026/10/11 04:53:15 WARN Failed to register uploaded object key=r959gjy1fqbjfvx16njf6xdni25277qg.narinfo error="server returned 404: 404 page not found\n"14422026/10/11 04:53:15 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=014432026/10/11 04:53:15 INFO Vacuumed table table=pending_closures14442026/10/11 04:53:15 INFO Vacuumed table table=pending_objects14452026/10/11 04:53:15 INFO Vacuumed table table=multipart_uploads14462026/10/11 04:53:15 INFO Vacuumed table table=closures1447--- PASS: TestClientPushesUseOnePush (7.12s)1448=== CONT TestService_readinessHandler14492026/10/11 04:53:15 INFO Completed push id=1 objects=3 duration=32.339208ms14502026/10/11 04:53:15 INFO Vacuumed table table=objects14512026/10/11 04:53:15 INFO Upload complete. (195ms)1452--- PASS: TestSweepSkipsRowsLockedByPush (6.04s)1453=== CONT TestGCTaskStore_ConflictDifferentParams1454--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1455=== CONT TestGCBugBareHashReferences14562026/10/11 04:53:15 INFO Received push request method=POST path=/api/pushes14572026/10/11 04:53:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/10/11 04:53:15 INFO Uploading y489gcdizfjicwqx6gn6d3srbvh0398s-unpinned-file.txt (128B)14592026/10/11 04:53:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14602026/10/11 04:53:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14612026/10/11 04:53:15 WARN Failed to register uploaded object key=y489gcdizfjicwqx6gn6d3srbvh0398s.ls error="server returned 404: 404 page not found\n"14622026/10/11 04:53:15 INFO Signed narinfos id=2 count=114632026/10/11 04:53:15 INFO Uploading 1 narinfos14642026/10/11 04:53:15 INFO Received complete push request method=POST path=/api/pushes/2/complete14652026/10/11 04:53:15 WARN Failed to register uploaded object key=y489gcdizfjicwqx6gn6d3srbvh0398s.narinfo error="server returned 404: 404 page not found\n"14662026/10/11 04:53:15 INFO Completed push id=2 objects=3 duration=665.125µs14672026/10/11 04:53:15 INFO Upload complete. (138ms)14682026/10/11 04:53:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures14692026/10/11 04:53:15 INFO Garbage collection started14702026/10/11 04:53:15 INFO Aborted multipart uploads count=0 kept=014712026/10/11 04:53:15 WARN Force mode enabled - objects will be deleted immediately without grace period14722026/10/11 04:53:15 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=014732026/10/11 04:53:15 INFO Vacuumed table table=pending_closures14742026/10/11 04:53:15 INFO Received push request method=POST path=/api/pushes14752026/10/11 04:53:15 INFO Vacuumed table table=pending_objects14762026/10/11 04:53:15 INFO Vacuumed table table=multipart_uploads14772026/10/11 04:53:15 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14782026/10/11 04:53:15 INFO Uploading qsk7m22yr3bv3xwqv2ig70acjf7hskal-top (264B)14792026/10/11 04:53:15 INFO Uploading 2lm2jjsdnc9i1bwvbcmq5bp3wrvlymrq-shared-dep (136B)14802026/10/11 04:53:15 INFO Vacuumed table table=closures14812026/10/11 04:53:15 WARN Failed to register uploaded object key=qsk7m22yr3bv3xwqv2ig70acjf7hskal.ls error="server returned 404: 404 page not found\n"14822026/10/11 04:53:15 WARN Failed to register uploaded object key=2lm2jjsdnc9i1bwvbcmq5bp3wrvlymrq.ls error="server returned 404: 404 page not found\n"14832026/10/11 04:53:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14842026/10/11 04:53:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14852026/10/11 04:53:15 WARN Failed to register uploaded object key=nar/1n4jkb7y4qwi090k034z2kixiw56f14b3hbamj900043rsj7ns8n.nar.zst error="server returned 404: 404 page not found\n"14862026/10/11 04:53:15 INFO Signed narinfos id=1 count=214872026/10/11 04:53:15 INFO Uploading 2 narinfos14882026/10/11 04:53:15 INFO Vacuumed table table=objects14892026/10/11 04:53:15 WARN Failed to register uploaded object key=qsk7m22yr3bv3xwqv2ig70acjf7hskal.narinfo error="server returned 404: 404 page not found\n"14902026/10/11 04:53:15 INFO Received complete push request method=POST path=/api/pushes/1/complete14912026/10/11 04:53:15 WARN Failed to register uploaded object key=2lm2jjsdnc9i1bwvbcmq5bp3wrvlymrq.narinfo error="server returned 404: 404 page not found\n"14922026/10/11 04:53:15 INFO Completed push id=1 objects=6 duration=22.536708ms14932026/10/11 04:53:15 INFO Upload complete. (218ms)1494=== NAME TestClientSharedPathCommittedMidPush1495 client_integration_test.go:680: Retrieved narinfo from S3:1496 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientSharedPathCommittedMidPush1345924837/001/store/2lm2jjsdnc9i1bwvbcmq5bp3wrvlymrq-shared-dep1497 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1498 Compression: zstd1499 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821500 NarSize: 1361501 References: 1502 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1503 client_integration_test.go:680: Retrieved narinfo from S3:1504 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientSharedPathCommittedMidPush1345924837/001/store/qsk7m22yr3bv3xwqv2ig70acjf7hskal-top1505 URL: nar/1n4jkb7y4qwi090k034z2kixiw56f14b3hbamj900043rsj7ns8n.nar.zst1506 Compression: zstd1507 NarHash: sha256:1n4jkb7y4qwi090k034z2kixiw56f14b3hbamj900043rsj7ns8n1508 NarSize: 2641509 References: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientSharedPathCommittedMidPush1345924837/001/store/2lm2jjsdnc9i1bwvbcmq5bp3wrvlymrq-shared-dep1510 CA: text:sha256:1ppyapc902ph45npwqcrxqc8d49h9yibsv410a4fg405kaknhary1511--- PASS: TestClientSharedPathCommittedMidPush (6.39s)1512=== CONT TestGCTaskStore_GetReturnsLatest1513--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1514=== CONT TestGCAdvisoryLockBlocksConcurrentRun15152026/10/11 04:53:15 INFO Received uploads request method=POST path=/api/pending_closures1516=== NAME TestClientWithDependencies1517 client_integration_test.go:613: Built derivation: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientWithDependencies3480886669/001/store/nz7ldvf1n5izqq78jjva4rxngvgd3ac3-test-script1518 client_integration_test.go:615: Found 1 dependencies (including self)15192026/10/11 04:53:15 INFO Aborted multipart uploads count=0 kept=015202026/10/11 04:53:15 WARN Force mode enabled - objects will be deleted immediately without grace period15212026/10/11 04:53:15 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15222026/10/11 04:53:15 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1523--- PASS: TestFailedS3DeleteKeepsTombstone (5.60s)1524=== CONT TestGCTaskStore_GetEmpty1525--- PASS: TestGCTaskStore_GetEmpty (0.00s)1526=== CONT TestLeadEndsOnShutdown15272026/10/11 04:53:16 INFO Received push request method=POST path=/api/pushes15282026/10/11 04:53:16 INFO Received uploads request method=POST path=/api/pending_closures15292026/10/11 04:53:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15302026/10/11 04:53:16 INFO Uploading nz7ldvf1n5izqq78jjva4rxngvgd3ac3-test-script (136B)15312026/10/11 04:53:16 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15322026/10/11 04:53:16 WARN Failed to register uploaded object key=nz7ldvf1n5izqq78jjva4rxngvgd3ac3.ls error="server returned 404: 404 page not found\n"15332026/10/11 04:53:16 WARN Failed to register uploaded object key=log/69f8204l1yhib8ly75pkxipyygvdhsy5-test-script.drv error="server returned 404: 404 page not found\n"15342026/10/11 04:53:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15352026/10/11 04:53:16 INFO Signed narinfos id=1 count=115362026/10/11 04:53:16 INFO Uploading 1 narinfos15372026/10/11 04:53:16 INFO Received complete push request method=POST path=/api/pushes/1/complete15382026/10/11 04:53:16 WARN Failed to register uploaded object key=nz7ldvf1n5izqq78jjva4rxngvgd3ac3.narinfo error="server returned 404: 404 page not found\n"15392026/10/11 04:53:16 INFO Received uploads request method=POST path=/api/pending_closures15402026/10/11 04:53:16 INFO Completed push id=1 objects=4 duration=29.583542ms15412026/10/11 04:53:16 INFO Upload complete. (172ms)1542=== NAME TestClientWithDependencies1543 client_integration_test.go:617: Skipping nix copy test - isolated store (/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientWithDependencies3480886669/001/store) requires matching store prefix15442026/10/11 04:53:16 INFO Received cleanup request method=DELETE path=/api/pending_closures1545--- PASS: TestClientWithDependencies (6.12s)1546=== CONT TestLeadIncumbentAnnouncesAtOnce1547--- PASS: TestDeleteClosuresRacingPins (10.37s)1548=== CONT TestGCTaskStore_Fail1549--- PASS: TestGCTaskStore_Fail (0.00s)1550=== CONT TestService_healthCheckHandler1551=== NAME TestClientMultipleUploads1552 client_integration_test.go:358: Created store path 0: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientMultipleUploads2165953095/001/store/b088xy9kjpkwbmmcx8797i1babx2ynby-test-file-0.txt1553 client_integration_test.go:358: Created store path 1: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientMultipleUploads2165953095/001/store/jksqqv38jjjmsnh5lqa7q51madai3n64-test-file-1.txt15542026/10/11 04:53:16 INFO Received uploads request method=POST path=/api/pending_closures1555 client_integration_test.go:358: Created store path 2: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientMultipleUploads2165953095/001/store/pc08km9qz4jyjk0xxpcwhl5r022jpsnh-test-file-2.txt1556--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.36s)1557=== CONT TestGracefulShutdownDrainsInflight15582026/10/11 04:53:16 INFO Starting HTTP server address=127.0.0.1:5847415592026/10/11 04:53:16 INFO Shutdown signal received, draining in-flight requests timeout=10s1560--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1561=== CONT TestGCTaskStore_DeduplicateSameParams1562--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1563=== CONT TestGCTaskStore_PhaseUpdates1564--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1565=== CONT TestService_ReadAuthMiddleware15662026/10/11 04:53:16 INFO Received push request method=POST path=/api/pushes15672026/10/11 04:53:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15682026/10/11 04:53:16 INFO Uploading pc08km9qz4jyjk0xxpcwhl5r022jpsnh-test-file-2.txt (160B)15692026/10/11 04:53:16 INFO Uploading b088xy9kjpkwbmmcx8797i1babx2ynby-test-file-0.txt (160B)15702026/10/11 04:53:16 INFO Uploading jksqqv38jjjmsnh5lqa7q51madai3n64-test-file-1.txt (160B)15712026/10/11 04:53:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15722026/10/11 04:53:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15732026/10/11 04:53:16 WARN Failed to register uploaded object key=b088xy9kjpkwbmmcx8797i1babx2ynby.ls error="server returned 404: 404 page not found\n"15742026/10/11 04:53:16 WARN Failed to register uploaded object key=pc08km9qz4jyjk0xxpcwhl5r022jpsnh.ls error="server returned 404: 404 page not found\n"15752026/10/11 04:53:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15762026/10/11 04:53:16 WARN Failed to register uploaded object key=jksqqv38jjjmsnh5lqa7q51madai3n64.ls error="server returned 404: 404 page not found\n"15772026/10/11 04:53:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15782026/10/11 04:53:16 INFO Signed narinfos id=1 count=315792026/10/11 04:53:16 INFO Uploading 3 narinfos15802026/10/11 04:53:16 WARN Failed to register uploaded object key=jksqqv38jjjmsnh5lqa7q51madai3n64.narinfo error="server returned 404: 404 page not found\n"15812026/10/11 04:53:16 WARN Failed to register uploaded object key=pc08km9qz4jyjk0xxpcwhl5r022jpsnh.narinfo error="server returned 404: 404 page not found\n"15822026/10/11 04:53:16 INFO Received complete push request method=POST path=/api/pushes/1/complete15832026/10/11 04:53:16 WARN Failed to register uploaded object key=b088xy9kjpkwbmmcx8797i1babx2ynby.narinfo error="server returned 404: 404 page not found\n"15842026/10/11 04:53:16 INFO Received uploads request method=POST path=/api/pending_closures15852026/10/11 04:53:16 INFO Completed push id=1 objects=9 duration=22.702333ms15862026/10/11 04:53:16 INFO Upload complete. (182ms)1587=== NAME TestClientMultipleUploads1588 client_integration_test.go:369: Uploaded 3 paths in 218.212208ms1589--- PASS: TestClientMultipleUploads (5.75s)1590=== CONT TestClientCADerivations1591=== NAME TestOrphanedObjectsGCStressTest1592 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1593 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1594--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (5.10s)1595=== CONT TestClientErrorHandling1596=== RUN TestClientErrorHandling/InvalidStorePath1597=== PAUSE TestClientErrorHandling/InvalidStorePath1598=== RUN TestClientErrorHandling/InvalidAuthToken1599=== PAUSE TestClientErrorHandling/InvalidAuthToken1600=== RUN TestClientErrorHandling/ServerNotAvailable1601=== PAUSE TestClientErrorHandling/ServerNotAvailable1602=== CONT TestCacheStatsHandler16032026/10/11 04:53:17 INFO Received push request method=POST path=/api/pushes16042026/10/11 04:53:17 INFO Received complete push request method=POST path=/api/pushes/1/complete16052026/10/11 04:53:17 INFO Completed push id=1 objects=4 duration=25.612042ms16062026/10/11 04:53:17 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16072026/10/11 04:53:17 INFO Completed upload id=2 objects=2 duration=1.700125ms1608--- PASS: TestMetricsCommit (5.18s)1609=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16102026/10/11 04:53:17 INFO Received uploads request method=POST path=/api/pending_closures16112026/10/11 04:53:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016122026/10/11 04:53:17 INFO Received create pin request method=POST path=/api/pins/myapp16132026/10/11 04:53:17 INFO Created/updated pin name=myapp store_path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestPinProtectsFromGC271461328/001/store/r959gjy1fqbjfvx16njf6xdni25277qg-pinned-file.txt narinfo_key=r959gjy1fqbjfvx16njf6xdni25277qg.narinfo16142026/10/11 04:53:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures16152026/10/11 04:53:17 INFO Garbage collection started16162026/10/11 04:53:17 INFO Aborted multipart uploads count=0 kept=016172026/10/11 04:53:17 WARN Force mode enabled - objects will be deleted immediately without grace period16182026/10/11 04:53:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016192026/10/11 04:53:17 INFO Vacuumed table table=pending_closures16202026/10/11 04:53:17 INFO Vacuumed table table=pending_objects16212026/10/11 04:53:17 INFO Vacuumed table table=multipart_uploads16222026/10/11 04:53:17 INFO Vacuumed table table=closures16232026/10/11 04:53:17 INFO Vacuumed table table=objects16242026/10/11 04:53:17 INFO Received cleanup request method=DELETE path=/api/pending_closures16252026/10/11 04:53:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket67/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16262026/10/11 04:53:17 INFO Aborted multipart uploads count=0 kept=116272026/10/11 04:53:17 INFO Received cleanup request method=DELETE path=/api/pending_closures16282026/10/11 04:53:17 INFO Aborted multipart uploads count=1 kept=01629--- PASS: TestMultipartCleanup (5.10s)1630=== CONT TestService_ReadScope_PublicByDefault1631--- PASS: TestMetricsInventory (5.08s)1632=== CONT TestService_AuthMiddleware_MTLSProxyHeader16332026/10/11 04:53:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16342026/10/11 04:53:17 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1635--- PASS: TestService_NativeMTLS (4.87s)1636=== CONT TestCacheConfigHandler1637=== RUN TestCacheConfigHandler/full_config,_no_issuer1638=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1639=== RUN TestCacheConfigHandler/no_cache_url_configured1640=== PAUSE TestCacheConfigHandler/no_cache_url_configured1641=== RUN TestCacheConfigHandler/no_signing_keys1642=== PAUSE TestCacheConfigHandler/no_signing_keys1643=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1644=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1645=== CONT TestService_RequireScope_OIDC16462026/10/11 04:53:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58493/oidc1647=== NAME TestNARDeduplicationMetadataUploadBug1648 metadata_upload_test.go:48: First store path: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestNARDeduplicationMetadataUploadBug436798908/001/store/hdr3xrlmmw45l6df8fhj5nl1yxi4hqww-file1.txt16492026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes16502026/10/11 04:53:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16512026/10/11 04:53:18 INFO Uploading hdr3xrlmmw45l6df8fhj5nl1yxi4hqww-file1.txt (160B)16522026/10/11 04:53:18 INFO Aborted multipart uploads count=0 kept=016532026/10/11 04:53:18 WARN Failed to register uploaded object key=hdr3xrlmmw45l6df8fhj5nl1yxi4hqww.ls error="server returned 404: 404 page not found\n"16542026/10/11 04:53:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16552026/10/11 04:53:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16562026/10/11 04:53:18 INFO Signed narinfos id=1 count=116572026/10/11 04:53:18 WARN Force mode enabled - objects will be deleted immediately without grace period16582026/10/11 04:53:18 INFO Uploading 1 narinfos16592026/10/11 04:53:18 INFO Received complete push request method=POST path=/api/pushes/1/complete16602026/10/11 04:53:18 WARN Failed to register uploaded object key=hdr3xrlmmw45l6df8fhj5nl1yxi4hqww.narinfo error="server returned 404: 404 page not found\n"16612026/10/11 04:53:18 INFO Completed push id=1 objects=3 duration=20.575833ms16622026/10/11 04:53:18 INFO Upload complete. (165ms)1663 metadata_upload_test.go:54: Retrieved narinfo from S3:1664 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestNARDeduplicationMetadataUploadBug436798908/001/store/hdr3xrlmmw45l6df8fhj5nl1yxi4hqww-file1.txt1665 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1666 Compression: zstd1667 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1668 NarSize: 1601669 References: 1670 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1671 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1672 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1673 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16742026/10/11 04:53:18 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=016752026/10/11 04:53:18 INFO Vacuumed table table=pending_closures16762026/10/11 04:53:18 INFO Vacuumed table table=pending_objects16772026/10/11 04:53:18 INFO Vacuumed table table=multipart_uploads16782026/10/11 04:53:18 INFO Vacuumed table table=closures1679 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestNARDeduplicationMetadataUploadBug436798908/001/store/qrgicjf8qg4bm467c8a196d6y93052kw-file2.txt16802026/10/11 04:53:18 INFO Vacuumed table table=objects1681--- PASS: TestGCSweepDeliversEachKeyOnce (5.04s)1682=== CONT TestService_AuthMiddleware_OIDC16832026/10/11 04:53:18 INFO Aborted multipart uploads count=0 kept=016842026/10/11 04:53:18 WARN Force mode enabled - objects will be deleted immediately without grace period16852026/10/11 04:53:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58505/oidc16862026/10/11 04:53:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016872026/10/11 04:53:18 INFO Vacuumed table table=pending_closures16882026/10/11 04:53:18 INFO Vacuumed table table=pending_objects16892026/10/11 04:53:18 INFO Vacuumed table table=multipart_uploads16902026/10/11 04:53:18 INFO Vacuumed table table=closures16912026/10/11 04:53:18 INFO Vacuumed table table=objects1692--- PASS: TestGCMetrics (4.81s)1693=== CONT TestIsValidUploadKey/narinfo1694=== CONT TestIsValidUploadKey/realisation_plus_in_output1695=== CONT TestIsValidUploadKey/traversal1696=== CONT TestIsValidUploadKey/unknown_type1697=== CONT TestIsValidUploadKey/empty_key1698=== CONT TestIsValidUploadKey/absolute1699=== CONT TestIsValidUploadKey/traversal_nar1700=== CONT TestIsValidUploadKey/build_log_home-manager_file1701=== CONT TestIsValidUploadKey/realisation1702=== CONT TestIsValidUploadKey/build_log_equals1703=== CONT TestIsValidUploadKey/nar_xz1704=== CONT TestIsValidUploadKey/build_log_question_mark1705=== CONT TestIsValidUploadKey/build_log_plus_in_name1706=== CONT TestIsValidUploadKey/narinfo_key,_nar_type17072026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes1708=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1709=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1710=== CONT TestIsValidUploadKey/nar_plain1711=== CONT TestIsValidUploadKey/build_log1712=== CONT TestIsValidUploadKey/listing1713=== CONT TestIsValidUploadKey/nar_zst1714=== CONT TestProxyWriteTimeout/narinfo1715=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17162026/10/11 04:53:18 INFO Received uploads request method=POST path=/1717=== CONT TestIsValidUploadKey/index.html1718=== CONT TestProxyWriteTimeout/10_GiB_nar1719=== CONT TestProxyWriteTimeout/unknown_size1720=== CONT TestProxyWriteTimeout/1_GiB_nar1721=== CONT TestIsValidUploadKey/nix-cache-info1722--- PASS: TestProxyWriteTimeout (0.05s)1723 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1724 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1725 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1726 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1727=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17282026/10/11 04:53:18 INFO Received request for more parts method=POST path=/1729--- PASS: TestIsValidUploadKey (0.05s)1730 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1731 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1732 --- PASS: TestIsValidUploadKey/traversal (0.00s)1733 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1734 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1735 --- PASS: TestIsValidUploadKey/absolute (0.00s)1736 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1737 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1738 --- PASS: TestIsValidUploadKey/realisation (0.00s)1739 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1740 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1741 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1742 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1743 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1744 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1745 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1746 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1747 --- PASS: TestIsValidUploadKey/build_log (0.00s)1748 --- PASS: TestIsValidUploadKey/listing (0.00s)1749 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1750 --- PASS: TestIsValidUploadKey/index.html (0.00s)1751 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1752=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17532026/10/11 04:53:18 INFO Received complete multipart upload request method=POST path=/1754=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17552026/10/11 04:53:18 INFO Received uploads request method=POST path=/1756--- PASS: TestUploadHandlersRejectInvalidKeys (0.05s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1760 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1761=== CONT TestPendingClosureWriteTimeout/empty1762=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17632026/10/11 04:53:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17642026/10/11 04:53:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17652026/10/11 04:53:18 WARN Failed to register uploaded object key=qrgicjf8qg4bm467c8a196d6y93052kw.ls error="server returned 404: 404 page not found\n"17662026/10/11 04:53:18 INFO Signed narinfos id=2 count=117672026/10/11 04:53:18 INFO Uploading 1 narinfos17682026/10/11 04:53:18 INFO Received complete push request method=POST path=/api/pushes/2/complete17692026/10/11 04:53:18 WARN Failed to register uploaded object key=qrgicjf8qg4bm467c8a196d6y93052kw.narinfo error="server returned 404: 404 page not found\n"17702026/10/11 04:53:18 INFO Completed push id=2 objects=3 duration=1.000125ms17712026/10/11 04:53:18 INFO Upload complete. (100ms)1772=== NAME TestNARDeduplicationMetadataUploadBug1773 metadata_upload_test.go:76: Retrieved narinfo from S3:1774 StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestNARDeduplicationMetadataUploadBug436798908/001/store/qrgicjf8qg4bm467c8a196d6y93052kw-file2.txt1775 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1776 Compression: zstd1777 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1778 NarSize: 1601779 References: 1780 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1781 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1782 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1783 {"version":1,"root":{"type":"regular","size":44}}1784--- PASS: TestNARDeduplicationMetadataUploadBug (5.75s)1785=== CONT TestPendingClosureWriteTimeout/670k_objects1786=== CONT TestPendingClosureWriteTimeout/400_objects1787=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17882026/10/11 04:53:18 INFO Received uploads request method=POST path=/17892026/10/11 04:53:18 INFO Received uploads request method=POST path=/api/pending_closures1790--- PASS: TestTombstonedObjectOfferedWithoutWaiting (5.12s)1791=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17922026/10/11 04:53:18 INFO Received request for more parts method=POST path=/1793=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17942026/10/11 04:53:18 INFO Received complete multipart upload request method=POST path=/1795=== CONT TestPush_RejectsBadRequests/bad_root17962026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes1797=== CONT TestPush_RejectsBadRequests/no_roots17982026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes1799=== CONT TestPush_RejectsBadRequests/no_objects18002026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes1801=== CONT TestIsValidCachePath/narinfo1802=== CONT TestPush_RejectsBadRequests/root_not_in_objects18032026/10/11 04:53:18 INFO Received push request method=POST path=/api/pushes1804--- PASS: TestPush_RejectsBadRequests (2.80s)1805 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1806 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1807 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1808 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1809=== CONT TestIsValidCachePath/index.html1810=== CONT TestIsValidCachePath/short_hash1811=== CONT TestIsValidCachePath/wrong_extension1812=== CONT TestIsValidCachePath/leading_slash1813=== CONT TestIsValidCachePath/empty1814=== CONT TestIsValidCachePath/random_path1815=== CONT TestIsValidCachePath/invalid_char_u1816=== CONT TestIsValidCachePath/invalid_char_e1817=== CONT TestIsValidCachePath/traversal_in_middle1818=== CONT TestIsValidCachePath/traversal_parent1819=== CONT TestIsValidCachePath/nar_uncompressed1820=== CONT TestIsValidCachePath/nix-cache-info1821=== CONT TestIsValidCachePath/realisation1822=== CONT TestIsValidCachePath/log1823=== CONT TestIsValidCachePath/ls1824=== CONT TestIsValidCachePath/nar_xz1825=== CONT TestIsValidCachePath/nar_bz21826=== CONT TestIsValidCachePath/nar_zst1827=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1828--- PASS: TestIsValidCachePath (0.00s)1829 --- PASS: TestIsValidCachePath/narinfo (0.00s)1830 --- PASS: TestIsValidCachePath/index.html (0.00s)1831 --- PASS: TestIsValidCachePath/short_hash (0.00s)1832 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1833 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1834 --- PASS: TestIsValidCachePath/empty (0.00s)1835 --- PASS: TestIsValidCachePath/random_path (0.00s)1836 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1837 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1838 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1839 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1840 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1841 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1842 --- PASS: TestIsValidCachePath/realisation (0.00s)1843 --- PASS: TestIsValidCachePath/log (0.00s)1844 --- PASS: TestIsValidCachePath/ls (0.00s)1845 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1846 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1847 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1848 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1849=== CONT TestParseSingleRange/none1850=== CONT TestParseSingleRange/open-ended1851=== CONT TestParseSingleRange/closed1852=== CONT TestParseSingleRange/malformed_end_before_start1853=== CONT TestParseSingleRange/malformed_both_empty1854=== CONT TestParseSingleRange/malformed_no_dash1855=== CONT TestParseSingleRange/multi-range_ignored1856=== CONT TestParseSingleRange/unknown_unit1857=== CONT TestParseSingleRange/end_clamped_to_size1858=== CONT TestParseSingleRange/start_past_EOF1859=== CONT TestParseSingleRange/single_byte1860=== CONT TestParseSingleRange/suffix_exceeds_size1861=== CONT TestParseSingleRange/suffix1862=== CONT TestParseSingleRange/start_far_past_EOF1863--- PASS: TestParseSingleRange (0.01s)1864 --- PASS: TestParseSingleRange/none (0.00s)1865 --- PASS: TestParseSingleRange/open-ended (0.00s)1866 --- PASS: TestParseSingleRange/closed (0.00s)1867 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1868 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1869 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1870 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1871 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1872 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1873 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1874 --- PASS: TestParseSingleRange/single_byte (0.00s)1875 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1876 --- PASS: TestParseSingleRange/suffix (0.00s)1877 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1878=== CONT TestGCEndsOnShutdown/before_the_run1879--- PASS: TestObjectStatsLargeCommit (12.60s)1880=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1881--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)1882 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1883 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1884 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1885=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18862026/10/11 04:53:18 INFO Received uploads request method=POST path=/api/pending_closures1887--- PASS: TestDeduplicatedObjectsRecordedAsPending (5.22s)1888=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18892026/10/11 04:53:19 INFO Received uploads request method=POST path=/api/pending_closures18902026/10/11 04:53:19 INFO Aborted multipart uploads count=0 kept=018912026/10/11 04:53:19 WARN Force mode enabled - objects will be deleted immediately without grace period18922026/10/11 04:53:19 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=018932026/10/11 04:53:19 INFO Vacuumed table table=pending_closures1894=== NAME TestOrphanedObjectsGCStressTest1895 orphaned_objects_gc_test.go:503: Stress test completed successfully:1896 orphaned_objects_gc_test.go:504: - Active objects preserved: 201897 orphaned_objects_gc_test.go:505: - Objects deleted: 2101898 orphaned_objects_gc_test.go:506: - Total GC'd: 2101899--- PASS: TestOrphanedObjectsGCStressTest (13.95s)1900=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19012026/10/11 04:53:19 INFO Vacuumed table table=pending_objects19022026/10/11 04:53:19 INFO Vacuumed table table=multipart_uploads19032026/10/11 04:53:19 INFO Vacuumed table table=closures19042026/10/11 04:53:19 INFO Vacuumed table table=objects1905=== NAME TestPinProtectsFromGC1906 client_integration_test.go:840: Pin successfully protected closure from garbage collection1907--- PASS: TestGCSweepSkipsPendingObjects (5.65s)1908=== CONT TestResolveDBConnectionString/flag_wins1909=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1910=== CONT TestResolveDBConnectionString/nothing_configured1911=== CONT TestResolveDBConnectionString/missing_file_is_an_error1912=== CONT TestResolveDBConnectionString/file_when_flag_empty1913=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1914--- PASS: TestResolveDBConnectionString (0.02s)1915 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1916 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1917 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1918 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1919 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1920--- PASS: TestPinProtectsFromGC (10.68s)1921=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19222026/10/11 04:53:19 INFO Received uploads request method=POST path=/api/pending_closures19232026/10/11 04:53:19 INFO Aborted multipart uploads count=0 kept=019242026/10/11 04:53:19 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=019252026/10/11 04:53:19 INFO Vacuumed table table=pending_closures19262026/10/11 04:53:19 INFO Vacuumed table table=pending_objects19272026/10/11 04:53:19 INFO Vacuumed table table=multipart_uploads19282026/10/11 04:53:19 INFO Vacuumed table table=closures19292026/10/11 04:53:19 INFO Vacuumed table table=objects19302026/10/11 04:53:19 INFO Aborted multipart uploads count=0 kept=019312026/10/11 04:53:19 WARN Force mode enabled - objects will be deleted immediately without grace period19322026/10/11 04:53:19 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=019332026/10/11 04:53:19 INFO Vacuumed table table=pending_closures19342026/10/11 04:53:19 INFO Vacuumed table table=pending_objects19352026/10/11 04:53:19 INFO Vacuumed table table=multipart_uploads19362026/10/11 04:53:19 INFO Vacuumed table table=closures19372026/10/11 04:53:19 INFO Vacuumed table table=objects1938--- PASS: TestPushDedupSurvivesConcurrentGC (5.82s)1939=== CONT TestServerTLSConfig/no_client_CA1940=== CONT TestServerTLSConfig/not_a_PEM_file1941=== CONT TestServerTLSConfig/missing_CA_file1942--- PASS: TestServerTLSConfig (0.00s)1943 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1944 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1945 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1946=== CONT TestClientErrorHandling/InvalidStorePath19472026/10/11 04:53:19 WARN readiness check failed error="closed pool"1948--- PASS: TestService_readinessHandler (4.84s)1949=== CONT TestClientErrorHandling/ServerNotAvailable1950--- PASS: TestGCBugBareHashReferences (4.89s)1951=== CONT TestClientErrorHandling/InvalidAuthToken19522026/10/11 04:53:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19532026/10/11 04:53:20 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld7 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1954--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (4.47s)1955=== CONT TestCacheConfigHandler/full_config,_no_issuer1956=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1957=== CONT TestCacheConfigHandler/no_signing_keys1958=== CONT TestCacheConfigHandler/no_cache_url_configured1959--- PASS: TestCacheConfigHandler (0.00s)1960 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1961 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1962 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1963 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)19642026/10/11 04:53:20 WARN Request failed, retrying attempt=2 backoff=187.32732ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19652026/10/11 04:53:20 INFO lead: acquired remote=192.0.2.1:123419662026/10/11 04:53:20 WARN Request failed, retrying attempt=3 backoff=413.495983ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19672026/10/11 04:53:20 INFO lead: acquired remote=192.0.2.1:123419682026/10/11 04:53:20 INFO lead: released remote=192.0.2.1:12341969--- PASS: TestLeadIncumbentAnnouncesAtOnce (4.62s)19702026/10/11 04:53:20 WARN Request failed, retrying attempt=4 backoff=853.933912ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19712026-10-11 04:53:20.924 UTC [82757] LOG: checkpoint starting: wal1972--- PASS: TestService_healthCheckHandler (4.77s)19732026/10/11 04:53:21 INFO lead: released remote=192.0.2.1:12341974--- PASS: TestLeadEndsOnShutdown (5.53s)1975--- PASS: TestService_ReadAuthMiddleware (4.81s)19762026/10/11 04:53:21 WARN Request failed, retrying attempt=5 backoff=1.661889654s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1977--- PASS: TestCacheStatsHandler (5.07s)19782026/10/11 04:53:22 INFO Aborted multipart uploads count=1 kept=019792026/10/11 04:53:22 INFO Received cleanup request method=DELETE path=/api/pending_closures19802026/10/11 04:53:22 INFO Aborted multipart uploads count=1 kept=01981--- PASS: TestPendingCleanupUsesOneCutoff (11.46s)1982=== NAME TestClientCADerivations1983 client_ca_test.go:136: Built CA derivation: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientCADerivations3675197369/001/store/fw9gd2mjmpsm8ry8i3jk55lh8qz1xn4a-ca-test19842026/10/11 04:53:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19852026/10/11 04:53:22 WARN mTLS auth: bound subjects configured but subject DN unavailable19862026/10/11 04:53:22 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1987--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.16s)1988=== NAME TestClientCADerivations1989 client_ca_test.go:139: Found 1 dependencies (including self)19902026/10/11 04:53:22 INFO Received push request method=POST path=/api/pushes19912026/10/11 04:53:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19922026/10/11 04:53:22 INFO Uploading fw9gd2mjmpsm8ry8i3jk55lh8qz1xn4a-ca-test (144B)19932026/10/11 04:53:22 WARN Failed to register uploaded object key=fw9gd2mjmpsm8ry8i3jk55lh8qz1xn4a.ls error="server returned 404: 404 page not found\n"19942026/10/11 04:53:22 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19952026/10/11 04:53:22 WARN Failed to register uploaded object key=log/42yjdv7m4670dr62a8bbxj5fksm8ravy-ca-test.drv error="server returned 404: 404 page not found\n"19962026/10/11 04:53:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19972026/10/11 04:53:22 INFO Signed narinfos id=1 count=119982026/10/11 04:53:22 INFO Uploading 1 narinfos19992026/10/11 04:53:22 INFO Received complete push request method=POST path=/api/pushes/1/complete20002026/10/11 04:53:22 WARN Failed to register uploaded object key=fw9gd2mjmpsm8ry8i3jk55lh8qz1xn4a.narinfo error="server returned 404: 404 page not found\n"2001--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.92s)20022026/10/11 04:53:22 INFO Completed push id=1 objects=4 duration=11.377917ms20032026/10/11 04:53:22 INFO Upload complete. (160ms)2004=== NAME TestClientCADerivations2005 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientCADerivations3675197369/001/store/fw9gd2mjmpsm8ry8i3jk55lh8qz1xn4a-ca-test2006 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2007 Compression: zstd2008 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2009 NarSize: 1442010 References: 2011 Deriver: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientCADerivations3675197369/001/store/42yjdv7m4670dr62a8bbxj5fksm8ravy-ca-test.drv2012 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2013 client_ca_test.go:185: Checking for realisation files in S3...2014 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2015 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2016 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket84?endpoint=http://localhost:58237®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestClientCADerivations3675197369/001/store'2017 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12018--- PASS: TestClientCADerivations (5.83s)2019--- PASS: TestService_ReadScope_PublicByDefault (5.14s)2020=== RUN TestService_RequireScope_OIDC/builder_may_write2021=== PAUSE TestService_RequireScope_OIDC/builder_may_write2022=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2023=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2024=== RUN TestService_RequireScope_OIDC/ops_may_admin2025=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2026=== RUN TestService_RequireScope_OIDC/ops_may_not_write2027=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2028=== RUN TestService_RequireScope_OIDC/reader_may_not_write2029=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2030=== RUN TestService_RequireScope_OIDC/static_token_may_admin2031=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2032=== RUN TestService_RequireScope_OIDC/static_token_may_write2033=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2034=== RUN TestService_RequireScope_OIDC/reader_may_read2035=== PAUSE TestService_RequireScope_OIDC/reader_may_read2036=== RUN TestService_RequireScope_OIDC/writer_implies_read2037=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2038=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2039=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2040=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2041=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2042=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2043=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2044=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2045=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2046=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2047=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2048=== CONT TestService_RequireScope_OIDC/builder_may_write2049=== CONT TestService_RequireScope_OIDC/reader_may_read2050=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2051=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2052=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2053=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2054=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc20552026/10/11 04:53:22 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]2056=== CONT TestService_RequireScope_OIDC/reader_may_not_write2057=== CONT TestService_RequireScope_OIDC/static_token_may_write2058=== CONT TestService_RequireScope_OIDC/static_token_may_admin2059=== CONT TestService_RequireScope_OIDC/writer_implies_read2060=== CONT TestService_RequireScope_OIDC/ops_may_admin2061=== CONT TestService_RequireScope_OIDC/ops_may_not_write2062=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2063--- PASS: TestService_RequireScope_OIDC (5.22s)2064 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2065 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2066 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2067 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2068 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2069 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2070 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2071 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2072 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2073 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2074 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2078=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2079=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2080=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2081=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2082=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2083=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2084=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2085=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2086=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2087=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2088=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2089=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20902026/10/11 04:53:23 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]20912026/10/11 04:53:23 WARN Authentication failed token_preview=eyJhbGciOi...d3rs_CDWJg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2092--- PASS: TestService_AuthMiddleware_OIDC (4.68s)2093 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2094 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2095 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2096 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20972026/10/11 04:53:23 INFO Received uploads request method=POST path=/api/pending_closures20982026/10/11 04:53:23 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20992026/10/11 04:53:23 WARN Request failed, retrying attempt=2 backoff=192.321092ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21002026/10/11 04:53:23 WARN Request failed, retrying attempt=3 backoff=368.103814ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21012026/10/11 04:53:23 INFO Aborted multipart uploads count=0 kept=021022026/10/11 04:53:23 WARN Force mode enabled - objects will be deleted immediately without grace period21032026-10-11 04:53:23.866 UTC [83285] ERROR: canceling statement due to user request21042026-10-11 04:53:23.866 UTC [83285] STATEMENT: -- name: MarkStaleObjects :execrows2105 WITH RECURSIVE ct AS (2106 SELECT timezone('UTC', now()) AS now2107 ),2108 closure_reach AS (2109 -- Start with all closure keys2110 SELECT o.key, o.refs2111 FROM objects o2112 INNER JOIN closures c ON o.key = c.key2113 UNION2114 -- Recursively add all referenced objects2115 SELECT o.key, o.refs2116 FROM objects o2117 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2118 ),2119 reachable_objects AS (2120 SELECT DISTINCT key FROM closure_reach2121 ),2122 stale_objects AS (2123 SELECT o.key2124 FROM objects AS o, ct2125 WHERE2126 NOT EXISTS (2127 SELECT 12128 FROM reachable_objects ro2129 WHERE ro.key = o.key2130 )2131 AND NOT EXISTS (2132 SELECT 12133 FROM pending_objects AS po2134 WHERE po.key = o.key2135 )2136 AND o.deleted_at IS NULL -- Only mark fresh objects2137 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2138 FOR UPDATE2139 )2140 UPDATE objects2141 SET2142 deleted_at = ct.now,2143 first_deleted_at = COALESCE(first_deleted_at, ct.now)2144 FROM stale_objects, ct2145 WHERE objects.key = stale_objects.key2146 21472026/10/11 04:53:24 INFO Aborted multipart uploads count=0 kept=021482026/10/11 04:53:24 WARN Force mode enabled - objects will be deleted immediately without grace period21492026/10/11 04:53:24 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58237/bucket95/?delete=\": context canceled"2150--- PASS: TestGCEndsOnShutdown (0.00s)2151 --- PASS: TestGCEndsOnShutdown/before_the_run (4.62s)2152 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.95s)2153 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.11s)2154--- PASS: TestPendingClosureWriteTimeout (0.06s)2155 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2156 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2157 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2158 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (5.57s)21592026/10/11 04:53:24 WARN Request failed, retrying attempt=4 backoff=836.575278ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21602026/10/11 04:53:24 INFO Received uploads request method=POST path=/api/pending_closures21612026/10/11 04:53:24 INFO Aborted multipart uploads count=0 kept=021622026/10/11 04:53:24 WARN Force mode enabled - objects will be deleted immediately without grace period21632026/10/11 04:53:24 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=021642026/10/11 04:53:24 INFO Vacuumed table table=pending_closures21652026/10/11 04:53:24 INFO Vacuumed table table=pending_objects21662026/10/11 04:53:24 INFO Vacuumed table table=multipart_uploads21672026/10/11 04:53:24 INFO Vacuumed table table=closures21682026/10/11 04:53:24 INFO Vacuumed table table=objects21692026/10/11 04:53:24 INFO Received uploads request method=POST path=/api/pending_closures21702026/10/11 04:53:24 INFO Aborted multipart uploads count=0 kept=021712026/10/11 04:53:24 WARN Force mode enabled - objects will be deleted immediately without grace period21722026/10/11 04:53:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021732026/10/11 04:53:24 INFO Vacuumed table table=pending_closures21742026/10/11 04:53:24 INFO Vacuumed table table=pending_objects2175--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2176 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.09s)2177 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.34s)21782026/10/11 04:53:24 INFO Vacuumed table table=multipart_uploads21792026/10/11 04:53:24 INFO Vacuumed table table=closures21802026/10/11 04:53:24 INFO Vacuumed table table=objects2181--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2182 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (5.09s)2183 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (5.25s)21842026/10/11 04:53:25 WARN Request failed, retrying attempt=5 backoff=1.520572815s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/10/11 04:53:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21862026/10/11 04:53:25 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21872026/10/11 04:53:26 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 127.0.0.1:19999: connect: connection refused"21882026/10/11 04:53:26 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21892026/10/11 04:53:26 WARN Request failed, retrying attempt=2 backoff=191.510856ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21902026/10/11 04:53:26 WARN Request failed, retrying attempt=3 backoff=380.924422ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21912026/10/11 04:53:27 WARN Request failed, retrying attempt=4 backoff=821.653749ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21922026/10/11 04:53:28 WARN Request failed, retrying attempt=5 backoff=1.531331792s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21932026/10/11 04:53:29 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21942026/10/11 04:53:29 WARN Request failed, retrying attempt=2 backoff=196.463617ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21952026/10/11 04:53:29 WARN Request failed, retrying attempt=3 backoff=418.864559ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21962026/10/11 04:53:30 WARN Request failed, retrying attempt=4 backoff=791.959955ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures21972026/10/11 04:53:31 WARN Request failed, retrying attempt=5 backoff=1.606086536s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2198--- PASS: TestClientErrorHandling (0.01s)2199 --- PASS: TestClientErrorHandling/InvalidStorePath (4.94s)2200 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.05s)2201 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.79s)2202PASS2203{"timestamp":"2026-10-11T04:53:32.717445Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58359","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}22042026-10-11 04:53:32.858 UTC [82752] LOG: received smart shutdown request22052026-10-11 04:53:32.859 UTC [82752] LOG: background worker "logical replication launcher" (PID 82762) exited with exit code 122062026-10-11 04:53:34.037 UTC [82757] LOG: checkpoint complete: wrote 11077 buffers (67.6%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.414 s, sync=0.652 s, total=13.114 s; sync files=34044, longest=0.001 s, average=0.001 s; distance=533083 kB, estimate=533083 kB; lsn=0/228D99E0, redo lsn=0/22023CE822072026-10-11 04:53:34.038 UTC [82757] LOG: shutting down22082026-10-11 04:53:34.038 UTC [82757] LOG: checkpoint starting: shutdown immediate22092026-10-11 04:53:34.104 UTC [82757] LOG: checkpoint complete: wrote 1333 buffers (8.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.040 s, sync=0.025 s, total=0.066 s; sync files=539, longest=0.001 s, average=0.001 s; distance=8919 kB, estimate=480666 kB; lsn=0/228D9A58, redo lsn=0/228D9A5822102026-10-11 04:53:34.111 UTC [82752] LOG: database system is shut down2211Running OIDC tests...2212=== RUN TestAudienceForIssuer2213=== PAUSE TestAudienceForIssuer2214=== RUN TestGlobMatch2215=== PAUSE TestGlobMatch2216=== RUN TestValidateToken_ValidToken2217=== PAUSE TestValidateToken_ValidToken2218=== RUN TestValidateToken_WrongAudience2219=== PAUSE TestValidateToken_WrongAudience2220=== RUN TestValidateToken_Expired2221=== PAUSE TestValidateToken_Expired2222=== RUN TestValidateToken_BoundClaimsMismatch2223=== PAUSE TestValidateToken_BoundClaimsMismatch2224=== RUN TestValidateToken_BoundSubjectMismatch2225=== PAUSE TestValidateToken_BoundSubjectMismatch2226=== RUN TestValidateToken_MultipleProviders2227=== PAUSE TestValidateToken_MultipleProviders2228=== RUN TestValidateToken_NoMatchingProvider2229=== PAUSE TestValidateToken_NoMatchingProvider2230=== RUN TestValidateToken_KubernetesServiceAccount2231=== PAUSE TestValidateToken_KubernetesServiceAccount2232=== RUN TestNewValidator_KubernetesRequiresCA2233=== PAUSE TestNewValidator_KubernetesRequiresCA2234=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2235=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2236=== RUN TestPins_ReservedForMatchingRule2237=== PAUSE TestPins_ReservedForMatchingRule2238=== RUN TestPins_TopLevelShorthand2239=== PAUSE TestPins_TopLevelShorthand2240=== RUN TestPins_ConfigValidation2241=== PAUSE TestPins_ConfigValidation2242=== RUN TestScopes_LegacyProviderDefaultsToWrite2243=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2244=== RUN TestScopes_Rules2245=== PAUSE TestScopes_Rules2246=== RUN TestScopes_ConfigValidation2247=== PAUSE TestScopes_ConfigValidation2248=== CONT TestAudienceForIssuer2249=== CONT TestValidateToken_KubernetesServiceAccount2250=== CONT TestPins_ConfigValidation2251--- PASS: TestAudienceForIssuer (0.00s)2252=== CONT TestValidateToken_NoMatchingProvider2253=== CONT TestValidateToken_MultipleProviders2254=== CONT TestValidateToken_BoundSubjectMismatch2255=== CONT TestValidateToken_BoundClaimsMismatch2256=== CONT TestValidateToken_Expired2257=== CONT TestValidateToken_WrongAudience2258--- PASS: TestPins_ConfigValidation (0.01s)2259=== CONT TestValidateToken_ValidToken2260=== CONT TestGlobMatch2261=== RUN TestGlobMatch/foo_foo2262=== PAUSE TestGlobMatch/foo_foo2263=== RUN TestGlobMatch/foo_bar2264=== PAUSE TestGlobMatch/foo_bar2265=== RUN TestGlobMatch/*_2266=== CONT TestScopes_Rules2267=== CONT TestScopes_ConfigValidation2268=== CONT TestScopes_LegacyProviderDefaultsToWrite2269--- PASS: TestScopes_ConfigValidation (0.00s)2270=== CONT TestPins_ReservedForMatchingRule2271=== CONT TestPins_TopLevelShorthand2272=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2273=== CONT TestNewValidator_KubernetesRequiresCA2274=== PAUSE TestGlobMatch/*_2275=== RUN TestGlobMatch/*_anything2276=== PAUSE TestGlobMatch/*_anything2277=== RUN TestGlobMatch/foo*_foo2278=== PAUSE TestGlobMatch/foo*_foo2279=== RUN TestGlobMatch/foo*_foobar2280=== PAUSE TestGlobMatch/foo*_foobar2281=== RUN TestGlobMatch/foo*_bar2282=== PAUSE TestGlobMatch/foo*_bar2283=== RUN TestGlobMatch/*bar_bar2284=== PAUSE TestGlobMatch/*bar_bar2285=== RUN TestGlobMatch/*bar_foobar2286=== PAUSE TestGlobMatch/*bar_foobar2287=== RUN TestGlobMatch/*bar_foo2288=== PAUSE TestGlobMatch/*bar_foo2289=== RUN TestGlobMatch/foo*bar_foobar2290=== PAUSE TestGlobMatch/foo*bar_foobar2291=== RUN TestGlobMatch/foo*bar_foo123bar2292=== PAUSE TestGlobMatch/foo*bar_foo123bar2293=== RUN TestGlobMatch/foo*bar_foobarbaz2294=== PAUSE TestGlobMatch/foo*bar_foobarbaz2295=== RUN TestGlobMatch/*/*_foo/bar2296=== PAUSE TestGlobMatch/*/*_foo/bar2297=== RUN TestGlobMatch/*/*_foo2298=== PAUSE TestGlobMatch/*/*_foo2299=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2300=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2301=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02302=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02303=== RUN TestGlobMatch/refs/*/main_refs/heads/main2304=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2305=== RUN TestGlobMatch/fo?_foo2306=== PAUSE TestGlobMatch/fo?_foo2307=== RUN TestGlobMatch/fo?_fo2308=== PAUSE TestGlobMatch/fo?_fo2309=== RUN TestGlobMatch/fo?_fooo2310=== PAUSE TestGlobMatch/fo?_fooo2311=== RUN TestGlobMatch/?oo_foo2312=== PAUSE TestGlobMatch/?oo_foo2313=== RUN TestGlobMatch/?oo_boo2314=== PAUSE TestGlobMatch/?oo_boo2315=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2316=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2317=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2318=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2319=== CONT TestGlobMatch/foo_foo2320=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2321=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2322=== CONT TestGlobMatch/?oo_boo2323=== CONT TestGlobMatch/?oo_foo2324=== CONT TestGlobMatch/fo?_fooo2325=== CONT TestGlobMatch/fo?_fo2326=== CONT TestGlobMatch/fo?_foo2327=== CONT TestGlobMatch/refs/*/main_refs/heads/main2328=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02329=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2330=== CONT TestGlobMatch/*/*_foo2331=== CONT TestGlobMatch/*/*_foo/bar2332=== CONT TestGlobMatch/foo*bar_foobarbaz2333=== CONT TestGlobMatch/foo*bar_foo123bar2334=== CONT TestGlobMatch/foo*bar_foobar2335=== CONT TestGlobMatch/*bar_foo2336=== CONT TestGlobMatch/*bar_foobar2337=== CONT TestGlobMatch/*bar_bar2338=== CONT TestGlobMatch/foo*_bar2339=== CONT TestGlobMatch/foo*_foobar2340=== CONT TestGlobMatch/foo*_foo2341=== CONT TestGlobMatch/*_anything2342=== CONT TestGlobMatch/*_2343=== CONT TestGlobMatch/foo_bar2344--- PASS: TestGlobMatch (0.01s)2345 --- PASS: TestGlobMatch/foo_foo (0.00s)2346 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2347 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2348 --- PASS: TestGlobMatch/?oo_boo (0.00s)2349 --- PASS: TestGlobMatch/?oo_foo (0.00s)2350 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2351 --- PASS: TestGlobMatch/fo?_fo (0.00s)2352 --- PASS: TestGlobMatch/fo?_foo (0.00s)2353 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2354 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2355 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2356 --- PASS: TestGlobMatch/*/*_foo (0.00s)2357 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2358 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2359 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2360 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2361 --- PASS: TestGlobMatch/*bar_foo (0.00s)2362 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2363 --- PASS: TestGlobMatch/*bar_bar (0.00s)2364 --- PASS: TestGlobMatch/foo*_bar (0.00s)2365 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2366 --- PASS: TestGlobMatch/foo*_foo (0.00s)2367 --- PASS: TestGlobMatch/*_anything (0.00s)2368 --- PASS: TestGlobMatch/*_ (0.00s)2369 --- PASS: TestGlobMatch/foo_bar (0.00s)23702026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58601/oidc23712026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58600/oidc2372--- PASS: TestValidateToken_Expired (0.08s)2373--- PASS: TestValidateToken_ValidToken (0.08s)23742026/10/11 04:53:35 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5860423752026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58606/oidc2376--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2377--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)23782026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58608/oidc23792026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58610/oidc2380--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)2381--- PASS: TestPins_ReservedForMatchingRule (0.09s)23822026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58614/oidc2383--- PASS: TestScopes_Rules (0.12s)23842026/10/11 04:53:35 http: TLS handshake error from 127.0.0.1:58617: remote error: tls: bad certificate2385--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)23862026/10/11 04:53:35 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:58619/oidc23872026/10/11 04:53:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58613/oidc23882026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58622/oidc2389--- PASS: TestValidateToken_MultipleProviders (0.15s)2390--- PASS: TestValidateToken_WrongAudience (0.15s)23912026/10/11 04:53:35 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12323922026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58625/oidc2393--- PASS: TestPins_TopLevelShorthand (0.14s)2394--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.14s)23952026/10/11 04:53:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58628/oidc2396--- PASS: TestValidateToken_BoundClaimsMismatch (0.17s)23972026/10/11 04:53:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:58618/oidc2398--- PASS: TestValidateToken_NoMatchingProvider (0.19s)2399PASS2400Running hook tests...2401=== RUN TestSendPathsEmpty2402=== PAUSE TestSendPathsEmpty2403=== RUN TestQueueEnqueueAndFetch2404=== PAUSE TestQueueEnqueueAndFetch2405=== RUN TestQueueDeduplication2406=== PAUSE TestQueueDeduplication2407=== RUN TestQueueRemove2408=== PAUSE TestQueueRemove2409=== RUN TestQueueFetchBatchLimit2410=== PAUSE TestQueueFetchBatchLimit2411=== RUN TestQueueRetryMovesToBack2412=== PAUSE TestQueueRetryMovesToBack2413=== RUN TestQueueFetchRemoveLifecycle2414=== PAUSE TestQueueFetchRemoveLifecycle2415=== RUN TestQueueConcurrentWriters2416=== PAUSE TestQueueConcurrentWriters2417=== RUN TestQueueRemoveLargeClosure2418=== PAUSE TestQueueRemoveLargeClosure2419=== RUN TestServerClientIntegration2420--- PASS: TestServerClientIntegration (0.00s)2421=== RUN TestServerQueueError24222026/10/11 04:53:36 ERROR Failed to queue paths error="permission denied" count=12423--- PASS: TestServerQueueError (0.00s)2424=== RUN TestGetListenerSocketActivation2425 server_test.go:146: systemd socket activation does not exist on darwin2426--- SKIP: TestGetListenerSocketActivation (0.00s)2427=== RUN TestDrainIsolatesPoisonPath2428=== PAUSE TestDrainIsolatesPoisonPath2429=== RUN TestRunNotBlockedByPoisonHead2430=== PAUSE TestRunNotBlockedByPoisonHead2431=== RUN TestDrainGivesUpWhenServerDown2432=== PAUSE TestDrainGivesUpWhenServerDown2433=== RUN TestFailedPathPrunedByLaterClosure2434=== PAUSE TestFailedPathPrunedByLaterClosure2435=== RUN TestWorkerUploadsAndRemoves2436=== PAUSE TestWorkerUploadsAndRemoves2437=== RUN TestWorkerSkipsGCdPaths2438=== PAUSE TestWorkerSkipsGCdPaths2439=== RUN TestWorkerPrunesClosureDeps2440=== PAUSE TestWorkerPrunesClosureDeps2441=== RUN TestDrainTimeout2442=== PAUSE TestDrainTimeout2443=== CONT TestSendPathsEmpty2444=== CONT TestDrainIsolatesPoisonPath2445=== CONT TestWorkerUploadsAndRemoves2446=== CONT TestDrainGivesUpWhenServerDown2447=== CONT TestQueueRemoveLargeClosure2448=== CONT TestQueueConcurrentWriters2449=== CONT TestQueueFetchRemoveLifecycle2450=== CONT TestQueueRetryMovesToBack2451=== CONT TestQueueFetchBatchLimit2452=== CONT TestQueueRemove2453=== CONT TestQueueDeduplication2454=== CONT TestQueueEnqueueAndFetch2455=== CONT TestFailedPathPrunedByLaterClosure2456=== CONT TestWorkerPrunesClosureDeps2457=== CONT TestDrainTimeout2458=== CONT TestWorkerSkipsGCdPaths2459=== CONT TestRunNotBlockedByPoisonHead2460--- PASS: TestSendPathsEmpty (0.00s)24612026/10/11 04:53:36 INFO Uploading batch count=224622026/10/11 04:53:36 INFO Uploading batch count=124632026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=12464--- PASS: TestQueueEnqueueAndFetch (0.01s)24652026/10/11 04:53:36 INFO Upload queue status pending=22466--- PASS: TestQueueDeduplication (0.01s)24672026/10/11 04:53:36 INFO Upload queue status pending=224682026/10/11 04:53:36 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestWorkerSkipsGCdPaths522452998/002/nonexistent24692026/10/11 04:53:36 INFO Uploading batch count=424702026/10/11 04:53:36 INFO Uploading batch count=224712026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=424722026/10/11 04:53:36 INFO Upload queue status pending=224732026/10/11 04:53:36 INFO Upload queue status pending=324742026/10/11 04:53:36 INFO Uploading batch count=124752026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=12476--- PASS: TestQueueRetryMovesToBack (0.01s)24772026/10/11 04:53:36 INFO Uploading batch count=124782026/10/11 04:53:36 INFO Uploading batch count=124792026/10/11 04:53:36 INFO Uploading batch count=124802026/10/11 04:53:36 INFO Uploading batch count=224812026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=224822026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/a24832026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainIsolatesPoisonPath730154251/002/bbb24842026/10/11 04:53:36 INFO Uploading batch count=124852026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/b2486--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2487--- PASS: TestQueueFetchBatchLimit (0.01s)2488--- PASS: TestQueueRemove (0.01s)24892026/10/11 04:53:36 INFO Uploading batch count=224902026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=224912026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/c24922026/10/11 04:53:36 INFO Uploading batch count=124932026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=124942026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/d24952026/10/11 04:53:36 INFO Uploading batch count=124962026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=124972026/10/11 04:53:36 INFO Uploading batch count=224982026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=224992026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/e25002026/10/11 04:53:36 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestDrainGivesUpWhenServerDown21394520/002/f25012026/10/11 04:53:36 INFO Uploading batch count=125022026/10/11 04:53:36 ERROR Upload failed error="upload failed" count=125032026/10/11 04:53:36 ERROR Drain finished with paths left in queue remaining=125042026/10/11 04:53:36 ERROR Drain finished with paths left in queue remaining=102505--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)2506--- PASS: TestDrainIsolatesPoisonPath (0.02s)2507--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2508--- PASS: TestWorkerSkipsGCdPaths (0.03s)2509--- PASS: TestWorkerUploadsAndRemoves (0.03s)2510--- PASS: TestWorkerPrunesClosureDeps (0.03s)2511--- PASS: TestQueueRemoveLargeClosure (0.05s)2512--- PASS: TestQueueConcurrentWriters (0.16s)25132026/10/11 04:53:36 ERROR Upload failed error="context deadline exceeded" count=225142026/10/11 04:53:36 ERROR Drain finished with paths left in queue remaining=42515--- PASS: TestDrainTimeout (0.21s)25162026/10/11 04:53:37 INFO Uploading batch count=125172026/10/11 04:53:37 INFO Uploading batch count=125182026/10/11 04:53:37 INFO Uploading batch count=125192026/10/11 04:53:37 ERROR Upload failed error="upload failed" count=125202026/10/11 04:53:37 INFO Uploading batch count=125212026/10/11 04:53:37 ERROR Upload failed error="upload failed" count=125222026/10/11 04:53:37 INFO Uploading batch count=125232026/10/11 04:53:37 ERROR Upload failed error="upload failed" count=125242026/10/11 04:53:37 INFO Uploading batch count=125252026/10/11 04:53:37 ERROR Upload failed error="upload failed" count=125262026/10/11 04:53:37 ERROR Drain finished with paths left in queue remaining=12527--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2528PASS2529Running signing tests...2530=== RUN TestExternalSigner2531=== PAUSE TestExternalSigner2532=== RUN TestExternalSignerWrongPublicKey2533=== PAUSE TestExternalSignerWrongPublicKey2534=== RUN TestExternalSignerErrors2535=== PAUSE TestExternalSignerErrors2536=== RUN TestExternalSignerRestartsAfterCrash2537=== PAUSE TestExternalSignerRestartsAfterCrash2538=== RUN TestExternalSignerProgramErrorKeepsProcess2539=== PAUSE TestExternalSignerProgramErrorKeepsProcess2540=== RUN TestExternalSignerClose2541=== PAUSE TestExternalSignerClose2542=== RUN TestExternalSignerRejectsInvalidPublicKey2543=== PAUSE TestExternalSignerRejectsInvalidPublicKey2544=== RUN TestExternalSignerCancellation2545=== PAUSE TestExternalSignerCancellation2546=== RUN TestGenerateFingerprint2547=== PAUSE TestGenerateFingerprint2548=== RUN TestParseSigningKey2549=== PAUSE TestParseSigningKey2550=== RUN TestSign2551=== PAUSE TestSign2552=== RUN TestSignBatch2553=== PAUSE TestSignBatch2554=== RUN TestNilKeyPublicKey2555=== PAUSE TestNilKeyPublicKey2556=== RUN TestSignErrors2557=== PAUSE TestSignErrors2558=== CONT TestExternalSigner2559=== CONT TestSignBatch2560=== CONT TestExternalSignerRestartsAfterCrash2561=== CONT TestExternalSignerProgramErrorKeepsProcess2562=== CONT TestExternalSignerRejectsInvalidPublicKey2563=== RUN TestExternalSignerRejectsInvalidPublicKey/#002564=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002565=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2566=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2567=== CONT TestSignErrors2568=== CONT TestNilKeyPublicKey2569--- PASS: TestNilKeyPublicKey (0.00s)2570=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2571=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2572=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2573=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2574=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2575=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2576=== CONT TestExternalSignerRejectsInvalidPublicKey/#002577=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2578=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2579=== CONT TestSign2580=== CONT TestParseSigningKey2581=== CONT TestGenerateFingerprint2582=== CONT TestExternalSignerErrors2583=== CONT TestExternalSignerWrongPublicKey2584=== CONT TestExternalSignerCancellation2585=== RUN TestGenerateFingerprint/basic_with_references2586=== RUN TestExternalSignerErrors/invalid_signature_base642587=== CONT TestExternalSignerClose2588=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2589=== PAUSE TestGenerateFingerprint/basic_with_references2590=== RUN TestGenerateFingerprint/no_references2591=== PAUSE TestGenerateFingerprint/no_references2592=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2593=== RUN TestParseSigningKey/valid_32-byte_key2594--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2595 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2596 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2597 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2598 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2599 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2600=== PAUSE TestExternalSignerErrors/invalid_signature_base642601=== PAUSE TestParseSigningKey/valid_32-byte_key2602=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2603=== RUN TestExternalSignerErrors/program_error2604=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2605=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2606=== PAUSE TestExternalSignerErrors/program_error2607=== RUN TestExternalSignerErrors/exit_on_request2608=== PAUSE TestExternalSignerErrors/exit_on_request2609=== RUN TestExternalSignerErrors/null2610=== PAUSE TestExternalSignerErrors/null2611=== RUN TestExternalSignerErrors/wrong_id2612=== PAUSE TestExternalSignerErrors/wrong_id2613=== RUN TestExternalSignerErrors/missing_signatures2614=== PAUSE TestExternalSignerErrors/missing_signatures2615=== RUN TestExternalSignerErrors/wrong_signatures_shape2616=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2617=== RUN TestExternalSignerErrors/unrequested_key2618=== PAUSE TestExternalSignerErrors/unrequested_key2619=== RUN TestExternalSignerErrors/invalid_JSON2620=== PAUSE TestExternalSignerErrors/invalid_JSON2621=== RUN TestExternalSignerErrors/wrong_shape2622=== PAUSE TestExternalSignerErrors/wrong_shape2623=== RUN TestExternalSignerErrors/null_signatures2624=== PAUSE TestExternalSignerErrors/null_signatures2625=== RUN TestExternalSignerErrors/too_few_signatures2626=== PAUSE TestExternalSignerErrors/too_few_signatures2627=== RUN TestExternalSignerErrors/wrong_signature_length2628=== PAUSE TestExternalSignerErrors/wrong_signature_length2629=== RUN TestExternalSignerErrors/exit_at_startup2630=== PAUSE TestExternalSignerErrors/exit_at_startup2631=== RUN TestExternalSignerErrors/missing_signature_name2632=== PAUSE TestExternalSignerErrors/missing_signature_name2633=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2634=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2635=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2636=== RUN TestExternalSignerErrors/wrong_signature_name2637=== PAUSE TestExternalSignerErrors/wrong_signature_name2638=== CONT TestExternalSignerErrors/invalid_signature_base642639=== CONT TestExternalSignerErrors/missing_signatures2640=== CONT TestExternalSignerErrors/unrequested_key2641=== RUN TestGenerateFingerprint/invalid_nar_hash_length2642=== CONT TestExternalSignerErrors/wrong_signatures_shape2643=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2644=== RUN TestParseSigningKey/no_colon2645=== RUN TestSignErrors/nil_key2646=== RUN TestGenerateFingerprint/invalid_store_path_prefix2647=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2648=== RUN TestGenerateFingerprint/invalid_reference_prefix2649=== PAUSE TestParseSigningKey/no_colon2650=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2651=== CONT TestExternalSignerErrors/exit_on_request2652=== PAUSE TestSignErrors/nil_key2653=== RUN TestSignErrors/nil_narinfo2654=== PAUSE TestSignErrors/nil_narinfo2655--- PASS: TestSign (0.00s)2656=== RUN TestParseSigningKey/empty_name2657=== PAUSE TestParseSigningKey/empty_name2658=== RUN TestParseSigningKey/invalid_base642659=== PAUSE TestParseSigningKey/invalid_base642660=== RUN TestSignErrors/invalid_narinfo2661=== PAUSE TestSignErrors/invalid_narinfo2662=== RUN TestSignErrors/canceled2663=== PAUSE TestSignErrors/canceled2664=== CONT TestExternalSignerErrors/missing_signature_name2665=== CONT TestExternalSignerErrors/invalid_JSON2666=== CONT TestExternalSignerErrors/exit_at_startup2667=== CONT TestExternalSignerErrors/wrong_signature_length2668--- PASS: TestSignBatch (0.00s)2669=== CONT TestGenerateFingerprint/basic_with_references2670=== CONT TestGenerateFingerprint/invalid_nar_hash_length2671=== CONT TestGenerateFingerprint/invalid_reference_prefix2672=== CONT TestGenerateFingerprint/invalid_store_path_prefix2673=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2674=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2675=== CONT TestExternalSignerErrors/too_few_signatures2676=== CONT TestGenerateFingerprint/no_references2677--- PASS: TestGenerateFingerprint (0.00s)2678 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2679 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2680 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2681 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2682 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2683 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2684 --- PASS: TestGenerateFingerprint/no_references (0.00s)2685=== CONT TestSignErrors/nil_key2686=== CONT TestSignErrors/invalid_narinfo2687=== CONT TestSignErrors/nil_narinfo2688=== CONT TestSignErrors/canceled2689--- PASS: TestSignErrors (0.00s)2690 --- PASS: TestSignErrors/nil_key (0.00s)2691 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2692 --- PASS: TestSignErrors/nil_narinfo (0.00s)2693 --- PASS: TestSignErrors/canceled (0.00s)2694=== CONT TestExternalSignerErrors/null_signatures2695=== CONT TestExternalSignerErrors/wrong_id2696=== CONT TestExternalSignerErrors/null2697=== CONT TestExternalSignerErrors/wrong_shape2698=== CONT TestExternalSignerErrors/wrong_signature_name2699=== CONT TestExternalSignerErrors/program_error2700=== RUN TestParseSigningKey/wrong_length2701=== PAUSE TestParseSigningKey/wrong_length2702=== CONT TestParseSigningKey/valid_32-byte_key2703=== CONT TestParseSigningKey/empty_name2704=== CONT TestParseSigningKey/invalid_base642705=== CONT TestParseSigningKey/no_colon2706=== CONT TestParseSigningKey/wrong_length2707=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2708--- PASS: TestParseSigningKey (0.00s)2709 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2710 --- PASS: TestParseSigningKey/empty_name (0.00s)2711 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2712 --- PASS: TestParseSigningKey/no_colon (0.00s)2713 --- PASS: TestParseSigningKey/wrong_length (0.00s)2714 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2715--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.25s)2716--- PASS: TestExternalSignerWrongPublicKey (0.44s)2717--- PASS: TestExternalSigner (1.22s)2718--- PASS: TestExternalSignerRestartsAfterCrash (1.61s)2719/private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestExternalSignerRestartsAfterCrash547668866/001/sign program: line 7: /private/var/tb/7/scratch/4f4ba35b59ba4c5c/build/TestExternalSignerRestartsAfterCrash547668866/001/sign program.starts: No such file or directory2720--- PASS: TestExternalSignerClose (1.78s)2721--- PASS: TestExternalSignerCancellation (2.19s)2722--- PASS: TestExternalSignerErrors (0.00s)2723 --- PASS: TestExternalSignerErrors/unrequested_key (0.63s)2724 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.82s)2725 --- PASS: TestExternalSignerErrors/invalid_JSON (1.01s)2726 --- PASS: TestExternalSignerErrors/null (1.39s)2727 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.98s)2728 --- PASS: TestExternalSignerErrors/exit_at_startup (2.36s)2729 --- PASS: TestExternalSignerErrors/missing_signatures (2.55s)2730 --- PASS: TestExternalSignerErrors/null_signatures (2.75s)2731 --- PASS: TestExternalSignerErrors/too_few_signatures (2.94s)2732 --- PASS: TestExternalSignerErrors/program_error (3.13s)2733 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.34s)2734 --- PASS: TestExternalSignerErrors/wrong_id (3.53s)2735 --- PASS: TestExternalSignerErrors/wrong_signature_length (3.72s)2736 --- PASS: TestExternalSignerErrors/exit_on_request (3.92s)2737 --- PASS: TestExternalSignerErrors/wrong_shape (4.10s)2738 --- PASS: TestExternalSignerErrors/missing_signature_name (4.30s)2739PASS2740Running OpenBao signer tests...2741=== RUN TestSign2742=== PAUSE TestSign2743=== RUN TestSignErrors2744=== PAUSE TestSignErrors2745=== RUN TestServe2746=== PAUSE TestServe2747=== RUN TestServeRejectsGarbage2748=== PAUSE TestServeRejectsGarbage2749=== CONT TestSign2750=== CONT TestSignErrors2751=== RUN TestSignErrors/http_error2752=== PAUSE TestSignErrors/http_error2753=== RUN TestSignErrors/invalid_json2754=== CONT TestServeRejectsGarbage2755=== CONT TestServe2756--- PASS: TestServeRejectsGarbage (0.00s)2757=== PAUSE TestSignErrors/invalid_json2758=== RUN TestSignErrors/no_prefix2759=== PAUSE TestSignErrors/no_prefix2760=== RUN TestSignErrors/invalid_base642761=== PAUSE TestSignErrors/invalid_base642762=== CONT TestSignErrors/http_error2763=== CONT TestSignErrors/no_prefix2764=== CONT TestSignErrors/invalid_base642765=== CONT TestSignErrors/invalid_json2766--- PASS: TestServe (0.00s)2767--- PASS: TestSign (0.00s)2768--- PASS: TestSignErrors (0.00s)2769 --- PASS: TestSignErrors/http_error (0.00s)2770 --- PASS: TestSignErrors/no_prefix (0.00s)2771 --- PASS: TestSignErrors/invalid_base64 (0.00s)2772 --- PASS: TestSignErrors/invalid_json (0.00s)2773PASS