niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #440
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.07s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestStreamPushReportsSkippedPaths117=== CONT TestUploadMultipart_SupersededByPeer118=== CONT TestFileTokenMissing119=== RUN TestUploadMultipart_SupersededByPeer/exists120=== CONT TestCaseHackSuffix121=== CONT TestStreamPushReportsSignatures122=== CONT TestStreamPushRequestLine123=== CONT TestStreamPushGivesUpOnDeadServer124=== CONT TestStreamPushIsolatesFailures125--- PASS: TestFileTokenMissing (0.00s)126=== CONT TestUploadMultipart_PartsInParallel127=== CONT TestStreamPushBatchesUnderLoad128=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false129=== CONT TestStreamPushReportsEveryPath1302026/10/27 08:39:27 ERROR Upload failed error="connection refused" count=20131=== CONT TestShellSplitErrors132=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false133--- PASS: TestShellSplitErrors (0.00s)134=== CONT TestShellSplit135=== CONT TestDoWithRetry_FinalResponseBodyReadable136=== CONT TestRetryTimeoutOutlastsMaxRetries137=== CONT TestDoWithRetry_BodyReplayedViaGetBody138=== CONT TestResolveStorePath139=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer140=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess141=== CONT TestRateLimiterFeedback142=== CONT TestPathInfoCACompatibility143=== CONT TestParsePathInfoJSONMultiplePaths144=== CONT TestParsePathInfoJSON145=== PAUSE TestUploadMultipart_SupersededByPeer/exists146=== CONT TestPathInfoHashCompatibility147=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true148=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1492026/10/27 08:39:27 ERROR Server seems unavailable, giving up on batch untried=171502026/10/27 08:39:27 ERROR Upload failed error="bad path" count=3151=== CONT TestFilterOversizedClosures152=== RUN TestFilterOversizedClosures/no_limit_keeps_everything153=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)156=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== CONT TestScriptTokenEmptyToken158=== RUN TestRateLimiterFeedback/429_enables_limiter159=== PAUSE TestRateLimiterFeedback/429_enables_limiter160=== RUN TestRateLimiterFeedback/503_enables_limiter1612026/10/27 08:39:27 ERROR Upload failed error=boom count=1162=== RUN TestPathInfoCACompatibility/null_ca_field163=== PAUSE TestRateLimiterFeedback/503_enables_limiter164=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== CONT TestScriptTokenEmptyCommand166=== CONT TestScriptTokenScriptFails167=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon168=== PAUSE TestPathInfoCACompatibility/null_ca_field1692026/10/27 08:39:27 ERROR Upload failed error=boom count=1170=== RUN TestPathInfoCACompatibility/old_string_format_-_text171=== CONT TestEncodeNixBase32172=== RUN TestEncodeNixBase32/test_string_hash173=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true1742026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=server-test rate=5175=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped176=== CONT TestScriptTokenBadJSON177=== RUN TestParsePathInfoJSON/Nix_format178=== RUN TestUploadMultipart_SupersededByPeer/missing179=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths180=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter181--- PASS: TestShellSplit (0.00s)182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon183=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text184=== PAUSE TestEncodeNixBase32/test_string_hash185=== RUN TestEncodeNixBase32/empty_input186=== CONT TestGetStorePathHash187=== CONT TestConvertHashToNix32188--- PASS: TestStreamPushReportsSignatures (0.00s)189=== CONT TestEncodeNixBase32WithRealHash190--- PASS: TestScriptTokenEmptyCommand (0.00s)191--- PASS: TestStreamPushIsolatesFailures (0.00s)192--- PASS: TestStreamPushReportsSkippedPaths (0.00s)193--- PASS: TestStreamPushReportsEveryPath (0.00s)194--- PASS: TestResolveStorePath (0.00s)195=== PAUSE TestUploadMultipart_SupersededByPeer/missing196=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped197=== RUN TestFilterOversizedClosures/all_closures_skipped198=== PAUSE TestFilterOversizedClosures/all_closures_skipped199=== CONT TestScriptTokenNoExpiryRerunsEveryCall200=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica201=== PAUSE TestParsePathInfoJSON/Nix_format202=== RUN TestParsePathInfoJSON/Lix_format203=== PAUSE TestParsePathInfoJSON/Lix_format204=== RUN TestParsePathInfoJSON/empty_input205--- PASS: TestScriptTokenScriptFails (0.01s)206=== PAUSE TestEncodeNixBase32/empty_input207=== CONT TestDumpPathSingleFile208=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter209=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter210=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter211=== CONT TestFileTokenEmpty212=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun213=== CONT TestDumpPathWriterError214=== RUN TestConvertHashToNix32/SRI_format_to_Nix32215=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32216=== RUN TestGetStorePathHash/valid_store_path217=== PAUSE TestGetStorePathHash/valid_store_path218=== RUN TestConvertHashToNix32/already_Nix32_format219=== CONT TestScriptTokenCachesUntilRefresh220=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI221=== RUN TestGetStorePathHash/basename_without_hyphen_should_error222=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI223=== PAUSE TestParsePathInfoJSON/empty_input224=== PAUSE TestConvertHashToNix32/already_Nix32_format225=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive226=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive227=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error228--- PASS: TestEncodeNixBase32WithRealHash (0.00s)229--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)230=== CONT TestRegisterUploadedObjectReusesConnections2312026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:633912322026/10/27 08:39:27 INFO Garbage collection started233=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512234--- PASS: TestDoServerRequestAttachesToken (0.01s)235=== CONT TestSetClientTLSDoesNotMutateDefaultTransport236=== RUN TestParsePathInfoJSON/whitespace_only237=== PAUSE TestParsePathInfoJSON/whitespace_only238=== RUN TestParsePathInfoJSON/invalid_JSON239=== RUN TestConvertHashToNix32/invalid_format240=== RUN TestPathInfoCACompatibility/new_structured_format_-_text241=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text242=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method243=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error245=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error246=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error247=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error248=== CONT TestFileTokenReadsAndCaches249--- PASS: TestFileTokenEmpty (0.00s)250=== CONT TestSetClientTLSErrors251--- PASS: TestFileTokenReadsAndCaches (0.00s)252=== CONT TestStreamPushStopsWhenCanceled253--- PASS: TestStreamPushStopsWhenCanceled (0.00s)254=== CONT TestSetClientTLS255=== RUN TestSetClientTLSErrors/missing_cert_file256=== PAUSE TestSetClientTLSErrors/missing_cert_file257=== RUN TestSetClientTLSErrors/missing_key_file258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== RUN TestSetClientTLSErrors/missing_ca_file260=== PAUSE TestSetClientTLSErrors/missing_ca_file261=== RUN TestSetClientTLSErrors/invalid_ca_file262=== PAUSE TestSetClientTLSErrors/invalid_ca_file263=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry264--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)265=== CONT TestDumpPathMatchesNix266=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512267=== PAUSE TestParsePathInfoJSON/invalid_JSON268=== CONT TestClientSignaturesByStorePath269--- PASS: TestClientSignaturesByStorePath (0.00s)270=== CONT TestUploadMultipart_FailedPartBufferNotReused271=== PAUSE TestConvertHashToNix32/invalid_format272=== CONT TestSupersededNARStillUploadsListing273=== RUN TestSupersededNARStillUploadsListing/small_NAR274=== PAUSE TestSupersededNARStillUploadsListing/small_NAR275=== RUN TestSupersededNARStillUploadsListing/dump_cut_short276=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short277=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails278=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails279=== CONT TestPartSizeForNAR280=== RUN TestPartSizeForNAR/zero_stays_at_minimum281=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum282=== RUN TestPartSizeForNAR/small_stays_at_minimum283=== PAUSE TestPartSizeForNAR/small_stays_at_minimum284=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum285=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum286=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts287=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts288=== RUN TestPartSizeForNAR/1_TiB289=== PAUSE TestPartSizeForNAR/1_TiB290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object291=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object292=== RUN TestPartSizeForNAR/capped_at_5_GiB293=== PAUSE TestPartSizeForNAR/capped_at_5_GiB294=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false295=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true296=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths297=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)301--- PASS: TestStreamPushBatchesUnderLoad (0.00s)302 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)303 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)304=== CONT TestUploadMultipart_SupersededByPeer/exists3052026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=server-test rate=53062026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:63394307=== CONT TestUploadMultipart_SupersededByPeer/missing308=== CONT TestStaticToken3092026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:63391310--- PASS: TestScriptTokenEmptyToken (0.02s)311=== CONT TestFilterOversizedClosures/no_limit_keeps_everything312=== CONT TestFilterOversizedClosures/all_closures_skipped3132026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=server-test rate=53142026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:633933152026/10/27 08:39:27 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50316=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3172026/10/27 08:39:27 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--- PASS: TestFilterOversizedClosures (0.01s)319 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)320 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)321 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)322=== CONT TestEncodeNixBase32/test_string_hash323=== CONT TestRateLimiterFeedback/429_enables_limiter324--- PASS: TestStaticToken (0.00s)325=== RUN TestSetClientTLS/rejects_connection_without_client_cert326=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert327=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA328=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA329=== RUN TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestSetClientTLS/preserves_debug_logging_transport331=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter332=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3332026/10/27 08:39:27 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=03342026/10/27 08:39:27 WARN Rate limiter backed off name=server-test rate=53352026/10/27 08:39:27 WARN Rate limiter backed off name=server-test rate=53362026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:63394337--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)338=== CONT TestRateLimiterFeedback/503_enables_limiter3392026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=s3-test rate=53402026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:634443412026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=server-test rate=53422026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:634593432026/10/27 08:39:27 WARN Garbage collection finished on another replica. Its statistics are not available here3442026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:63391345--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)346=== CONT TestEncodeNixBase32/empty_input347--- PASS: TestEncodeNixBase32 (0.01s)348 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)349 --- PASS: TestEncodeNixBase32/empty_input (0.00s)350=== CONT TestPathInfoCACompatibility/null_ca_field351=== CONT TestGetStorePathHash/valid_store_path3522026/10/27 08:39:27 INFO Garbage collection started353=== CONT TestSetClientTLSErrors/missing_cert_file3542026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=server-test rate=5355=== CONT TestSetClientTLSErrors/missing_ca_file356=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method357=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)358=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive359=== CONT TestPathInfoCACompatibility/old_string_format_-_text360=== CONT TestParsePathInfoJSON/Nix_format361=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512362=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI363=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon364=== CONT TestConvertHashToNix32/SRI_format_to_Nix32365=== CONT TestSupersededNARStillUploadsListing/small_NAR366=== CONT TestParsePathInfoJSON/invalid_JSON367=== CONT TestParsePathInfoJSON/whitespace_only368=== CONT TestParsePathInfoJSON/empty_input369=== CONT TestParsePathInfoJSON/Lix_format370=== CONT TestSetClientTLSErrors/missing_key_file371=== CONT TestPartSizeForNAR/zero_stays_at_minimum372=== CONT TestConvertHashToNix32/invalid_format373=== CONT TestConvertHashToNix32/already_Nix32_format374=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails375=== CONT TestSupersededNARStillUploadsListing/dump_cut_short376=== CONT TestSetClientTLSErrors/invalid_ca_file377=== CONT TestPartSizeForNAR/capped_at_5_GiB378=== CONT TestPartSizeForNAR/5_TiB_S3_max_object379=== CONT TestPartSizeForNAR/1_TiB380=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts381=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum382=== CONT TestPartSizeForNAR/small_stays_at_minimum383=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error384=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error385=== CONT TestGetStorePathHash/basename_without_hyphen_should_error386=== CONT TestSetClientTLS/rejects_connection_without_client_cert387=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA388=== CONT TestSetClientTLS/preserves_debug_logging_transport389--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)390=== CONT TestPathInfoCACompatibility/new_structured_format_-_text391--- PASS: TestPathInfoCACompatibility (0.01s)392 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)393 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)395 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)396 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)397--- PASS: TestPathInfoHashCompatibility (0.01s)398 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)399 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)400 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)401 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)402--- PASS: TestStreamPushRequestLine (0.02s)403--- PASS: TestParsePathInfoJSON (0.01s)404 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)405 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)406 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)407 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)408 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)409--- PASS: TestConvertHashToNix32 (0.00s)410 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)411 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)412 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)413--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)414 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)415 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)416--- PASS: TestPartSizeForNAR (0.00s)417 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)418 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)419 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)420 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)421 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)422 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)424--- PASS: TestGetStorePathHash (0.00s)425 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)426 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)427 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)428 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)429--- PASS: TestSetClientTLSErrors (0.00s)430 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)431 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)433 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)434--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)4352026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:634874362026/10/27 08:39:27 WARN Rate limiter backed off name=server-test rate=54372026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:633914382026/10/27 08:39:27 INFO Uploading abc-hello (1.0GB)439--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)4402026/10/27 08:39:27 WARN Rate limiter backed off name=server-test rate=5441--- PASS: TestRateLimiterFeedback (0.01s)442 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)443 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)444 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)445 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)446--- PASS: TestScriptTokenBadJSON (0.02s)4472026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:633914482026/10/27 08:39:27 INFO Uploading abc-hello (1.0GB)4492026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:633914502026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:633914512026/10/27 08:39:27 WARN Rate limiter enabled after throttle name=s3-test rate=54522026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:633914532026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:633914542026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:633914552026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:633914562026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:633914572026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:63391458--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)4592026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:633914602026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:633914612026/10/27 08:39:27 http: TLS handshake error from 127.0.0.1:63497: remote error: tls: bad certificate462--- PASS: TestSetClientTLS (0.01s)463 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)464 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)465 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4662026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:633914672026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:633914682026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:63391469--- PASS: TestCaseHackSuffix (0.06s)4702026/10/27 08:39:27 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:63391471--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.06s)472--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)473--- PASS: TestDumpPathSingleFile (0.05s)474--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)4752026/10/27 08:39:27 INFO Uploading abc-hello (1.0GB)476--- PASS: TestDumpPathWriterError (0.07s)4772026/10/27 08:39:27 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:63495/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:63495/part/24782026/10/27 08:39:27 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"479--- PASS: TestDumpPathMatchesNix (0.10s)480--- PASS: TestSupersededNARStillUploadsListing (0.00s)481 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)482 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)483 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.56s)484--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.58s)485--- PASS: TestUploadMultipart_PartsInParallel (0.62s)4862026/10/27 08:39:28 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:63390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:63390/api/uploads/complete4872026/10/27 08:39:28 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4882026/10/27 08:39:28 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:63390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:63390/api/uploads/complete4892026/10/27 08:39:28 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4902026/10/27 08:39:28 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:63390/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:63390/api/uploads/complete491--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)4922026/10/27 08:39:28 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"493--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)494PASS495Running server tests...496The files belonging to this database system will be owned by user "_tribuchetbld5".497This user must also own the server process.498499The database cluster will be initialized with locale "C".500The default database encoding has accordingly been set to "SQL_ASCII".501The default text search configuration will be set to "english".502503Data page checksums are enabled.504505creating directory /private/var/tb/5/scratch/c7420197c191de2e/build/postgres1830655335/data ... ok506creating subdirectories ... ok507selecting dynamic shared memory implementation ... posix508selecting default "max_connections" ... 100509selecting default "shared_buffers" ... 128MB510selecting default time zone ... UTC511creating configuration files ... ok512running bootstrap script ... ok513performing post-bootstrap initialization ... ok514syncing data to disk ... ok515516initdb: warning: enabling "trust" authentication for local connections517initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.518519Success. You can now start the database server using:520521 pg_ctl -D /private/var/tb/5/scratch/c7420197c191de2e/build/postgres1830655335/data -l logfile start522523/private/var/tb/5/scratch/c7420197c191de2e/build/postgres1830655335:5432 - no response5242026-10-27 08:39:29.444 UTC [73978] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5252026-10-27 08:39:29.444 UTC [73978] LOG: listening on Unix socket "/private/var/tb/5/scratch/c7420197c191de2e/build/postgres1830655335/.s.PGSQL.5432"5262026-10-27 08:39:29.447 UTC [73985] LOG: database system was shut down at 2026-10-27 08:39:29 UTC5272026-10-27 08:39:29.447 UTC [73978] LOG: database system is ready to accept connections528/private/var/tb/5/scratch/c7420197c191de2e/build/postgres1830655335:5432 - accepting connections529{"timestamp":"2026-10-27T08:39:29.663476Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"d2f1b89c-8634-4ef4-8b78-5e8e77537d26","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}530=== RUN TestService_AuthMiddleware531=== PAUSE TestService_AuthMiddleware532=== RUN TestService_AuthMiddleware_MTLSProxyHeader533=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader534=== RUN TestService_AuthMiddleware_MTLSBoundSubjects535=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects536=== RUN TestService_ReadAuthMiddleware537=== PAUSE TestService_ReadAuthMiddleware538=== RUN TestService_AuthMiddleware_OIDC539=== PAUSE TestService_AuthMiddleware_OIDC540=== RUN TestService_RequireScope_OIDC541=== PAUSE TestService_RequireScope_OIDC542=== RUN TestService_ReadScope_PublicByDefault543=== PAUSE TestService_ReadScope_PublicByDefault544=== RUN TestCacheConfigHandler545=== PAUSE TestCacheConfigHandler546=== RUN TestCacheStatsHandler547=== PAUSE TestCacheStatsHandler548=== RUN TestClientCADerivations549=== PAUSE TestClientCADerivations550=== RUN TestClientErrorHandling551=== PAUSE TestClientErrorHandling552=== RUN TestClientIntegration553=== PAUSE TestClientIntegration554=== RUN TestClientMultipleUploads555=== PAUSE TestClientMultipleUploads556=== RUN TestClientWithDependencies557=== PAUSE TestClientWithDependencies558=== RUN TestClientSharedPathCommittedMidPush559=== PAUSE TestClientSharedPathCommittedMidPush560=== RUN TestPinProtectsFromGC561=== PAUSE TestPinProtectsFromGC562=== RUN TestClientPushesUseOnePush563=== PAUSE TestClientPushesUseOnePush564=== RUN TestClientFallsBackToClosures565=== PAUSE TestClientFallsBackToClosures566=== RUN TestDeleteClosuresRacingPins567=== PAUSE TestDeleteClosuresRacingPins568=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock569=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock570=== RUN TestResolveDBConnectionString571=== PAUSE TestResolveDBConnectionString572=== RUN TestConnectWaitsForAPeerMigration573=== PAUSE TestConnectWaitsForAPeerMigration574=== RUN TestLeadElectsOneAndHandsOver575=== PAUSE TestLeadElectsOneAndHandsOver576=== RUN TestLeadIncumbentWinsAfterRestart5772026/10/27 08:39:29 INFO lead: acquired remote=192.0.2.1:12345782026/10/27 08:39:30 INFO lead: released remote=192.0.2.1:12345792026/10/27 08:39:30 INFO lead: acquired remote=192.0.2.1:12345802026/10/27 08:39:31 INFO lead: released remote=192.0.2.1:1234581--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)582=== RUN TestLeadIncumbentAnnouncesAtOnce583=== PAUSE TestLeadIncumbentAnnouncesAtOnce584=== RUN TestLeadEndsOnShutdown585=== PAUSE TestLeadEndsOnShutdown586=== RUN TestLeadEndsWhenItsConnectionHangs5872026/10/27 08:39:31 INFO lead: acquired remote=192.0.2.1:12345882026-10-27 08:39:33.023 UTC [74034] FATAL: terminating connection due to administrator command5892026/10/27 08:39:33 INFO lead: acquired remote=192.0.2.1:12345902026/10/27 08:39:34 WARN lead: lock connection lost error="timeout: context deadline exceeded"5912026/10/27 08:39:34 INFO lead: released remote=192.0.2.1:12345922026/10/27 08:39:34 INFO lead: released remote=192.0.2.1:1234593--- PASS: TestLeadEndsWhenItsConnectionHangs (2.76s)594=== RUN TestGCAdvisoryLockBlocksConcurrentRun595=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun596=== RUN TestGCBugBareHashReferences597=== PAUSE TestGCBugBareHashReferences598=== RUN TestGCMetrics599=== PAUSE TestGCMetrics600=== RUN TestPushDedupSurvivesConcurrentGC601=== PAUSE TestPushDedupSurvivesConcurrentGC602=== RUN TestDeduplicatedObjectsRecordedAsPending603=== PAUSE TestDeduplicatedObjectsRecordedAsPending604=== RUN TestGCSweepSkipsPendingObjects605=== PAUSE TestGCSweepSkipsPendingObjects606=== RUN TestTombstonedObjectOfferedWithoutWaiting607=== PAUSE TestTombstonedObjectOfferedWithoutWaiting608=== RUN TestGCSweepDeliversEachKeyOnce609=== PAUSE TestGCSweepDeliversEachKeyOnce610=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection611=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection612=== RUN TestForceGCDuringPushOffersSweptObject613=== PAUSE TestForceGCDuringPushOffersSweptObject614=== RUN TestFailedS3DeleteKeepsTombstone615=== PAUSE TestFailedS3DeleteKeepsTombstone616=== RUN TestSweepSkipsRowsLockedByPush617=== PAUSE TestSweepSkipsRowsLockedByPush618=== RUN TestRegisterCompletedObjectNeedsPendingRow619=== PAUSE TestRegisterCompletedObjectNeedsPendingRow620=== RUN TestGetExistingObjectsLocksRows621=== PAUSE TestGetExistingObjectsLocksRows622=== RUN TestSweepRechecksPendingAfterLocking623=== PAUSE TestSweepRechecksPendingAfterLocking624=== RUN TestPushWaitsForSweepHoldingRow625=== PAUSE TestPushWaitsForSweepHoldingRow626=== RUN TestCommitRacingPendingCleanupKeepsObjects627=== PAUSE TestCommitRacingPendingCleanupKeepsObjects628=== RUN TestGCEndsOnShutdown629=== PAUSE TestGCEndsOnShutdown630=== RUN TestGCTaskStore_StartNew631=== PAUSE TestGCTaskStore_StartNew632=== RUN TestGCTaskStore_DeduplicateSameParams633=== PAUSE TestGCTaskStore_DeduplicateSameParams634=== RUN TestGCTaskStore_ConflictDifferentParams635=== PAUSE TestGCTaskStore_ConflictDifferentParams636=== RUN TestGCTaskStore_GetEmpty637=== PAUSE TestGCTaskStore_GetEmpty638=== RUN TestGCTaskStore_GetReturnsLatest639=== PAUSE TestGCTaskStore_GetReturnsLatest640=== RUN TestGCTaskStore_CompletedAllowsNewTask641=== PAUSE TestGCTaskStore_CompletedAllowsNewTask642=== RUN TestGCTaskStore_PhaseUpdates643=== PAUSE TestGCTaskStore_PhaseUpdates644=== RUN TestGCTaskStore_Fail645=== PAUSE TestGCTaskStore_Fail646=== RUN TestGracefulShutdownDrainsInflight647=== PAUSE TestGracefulShutdownDrainsInflight648=== RUN TestService_healthCheckHandler649=== PAUSE TestService_healthCheckHandler650=== RUN TestService_readinessHandler651=== PAUSE TestService_readinessHandler652=== RUN TestGenerateLandingPage653=== PAUSE TestGenerateLandingPage654=== RUN TestCacheConfigHandlerMaxNarSize655=== PAUSE TestCacheConfigHandlerMaxNarSize656=== RUN TestCreatePendingClosureRejectsOversizedNAR657=== PAUSE TestCreatePendingClosureRejectsOversizedNAR658=== RUN TestNARDeduplicationMetadataUploadBug659=== PAUSE TestNARDeduplicationMetadataUploadBug660=== RUN TestMetricsInventory661=== PAUSE TestMetricsInventory662=== RUN TestMetricsCommit663=== PAUSE TestMetricsCommit664=== RUN TestService_NativeMTLS665=== PAUSE TestService_NativeMTLS666=== RUN TestServerTLSConfig667=== PAUSE TestServerTLSConfig668=== RUN TestMultipartCleanup669=== PAUSE TestMultipartCleanup670=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded671=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded672=== RUN TestPendingCleanupUsesOneCutoff673=== PAUSE TestPendingCleanupUsesOneCutoff674=== RUN TestObjectStatsTrigger675=== PAUSE TestObjectStatsTrigger676=== RUN TestObjectStatsUpdatedOncePerCommit677=== PAUSE TestObjectStatsUpdatedOncePerCommit678=== RUN TestOrphanedObjectsGC679=== PAUSE TestOrphanedObjectsGC680=== RUN TestOrphanedObjectsGCStressTest681=== PAUSE TestOrphanedObjectsGCStressTest682=== RUN TestCreatePin_ReservedPins683=== PAUSE TestCreatePin_ReservedPins684=== RUN TestPresentReportsOnlyClosureRoots685=== PAUSE TestPresentReportsOnlyClosureRoots686=== RUN TestPresentRefreshesOnlyStaleClosures687=== PAUSE TestPresentRefreshesOnlyStaleClosures688=== RUN TestPresentNotReportedWhileGCDeletesClosure689=== PAUSE TestPresentNotReportedWhileGCDeletesClosure690=== RUN TestParseSingleRange691=== PAUSE TestParseSingleRange692=== RUN TestProxyHeadersOnlyTrustedOnSocket6932026/10/27 08:39:34 INFO Starting HTTP server address=127.0.0.1:635306942026/10/27 08:39:34 INFO Starting HTTP server address=proxy.sock6952026/10/27 08:39:34 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6962026/10/27 08:39:34 INFO Shutdown signal received, draining in-flight requests timeout=10s697--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)698=== RUN TestIsValidCachePath699=== PAUSE TestIsValidCachePath700=== RUN TestReadProxyNarinfo701=== PAUSE TestReadProxyNarinfo702=== RUN TestReadProxyNarinfoAlreadyDecompressed703=== PAUSE TestReadProxyNarinfoAlreadyDecompressed704=== RUN TestReadProxyContentNegotiation705=== PAUSE TestReadProxyContentNegotiation706=== RUN TestReadProxyNarStreaming707=== PAUSE TestReadProxyNarStreaming708=== RUN TestReadProxy404709=== PAUSE TestReadProxy404710=== RUN TestReadProxyInvalidPath711=== PAUSE TestReadProxyInvalidPath712=== RUN TestReadProxyHead713=== PAUSE TestReadProxyHead714=== RUN TestReadProxyOutlastsServerWriteTimeout715=== PAUSE TestReadProxyOutlastsServerWriteTimeout716=== RUN TestReadProxyConditionalGet717=== PAUSE TestReadProxyConditionalGet718=== RUN TestReadProxyRootRedirectsToIndexHTML719=== PAUSE TestReadProxyRootRedirectsToIndexHTML720=== RUN TestReadProxyDisabled721=== PAUSE TestReadProxyDisabled722=== RUN TestReadRedirectNar723=== PAUSE TestReadRedirectNar724=== RUN TestReadRedirectKeepsNarinfoProxied725=== PAUSE TestReadRedirectKeepsNarinfoProxied726=== RUN TestReadProxyRangeRequest727=== PAUSE TestReadProxyRangeRequest728=== RUN TestReadRedirectUsesPublicS3URL729=== PAUSE TestReadRedirectUsesPublicS3URL730=== RUN TestPush_OverlappingRootsStoreOneRowPerKey731=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey732=== RUN TestPush_CompleteCommitsEveryRoot733=== PAUSE TestPush_CompleteCommitsEveryRoot734=== RUN TestPush_RepeatedRootCommitsOnce735=== PAUSE TestPush_RepeatedRootCommitsOnce736=== RUN TestPush_CompleteWaitsForCleanupOfThePush737=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush738=== RUN TestPush_RootsAreLockedInByteOrder739=== PAUSE TestPush_RootsAreLockedInByteOrder740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/27 08:39:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/27 08:39:34 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 TestService_AuthMiddleware799=== CONT TestIsValidUploadKey800=== CONT TestForceGCDuringPushOffersSweptObject801=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows802=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows803=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check804=== CONT TestReadProxyRangeRequest805=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check806=== CONT TestReadProxyOutlastsServerWriteTimeout807=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT808=== CONT TestCompleteMultipartUnregistered809=== CONT TestService_verifyS3Integrity810=== CONT TestService_createPendingClosureHandler811=== CONT TestService_cleanupPendingClosuresHandler812=== CONT TestUploadHandlersRejectOversizedBody813=== CONT TestUploadHandlersRejectInvalidKeys814=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info815=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info816=== RUN TestIsValidUploadKey/narinfo817=== CONT TestPendingClosureWriteTimeout818=== RUN TestPendingClosureWriteTimeout/empty819=== PAUSE TestPendingClosureWriteTimeout/empty820=== RUN TestPendingClosureWriteTimeout/400_objects821=== PAUSE TestPendingClosureWriteTimeout/400_objects822=== RUN TestPendingClosureWriteTimeout/670k_objects823=== PAUSE TestPendingClosureWriteTimeout/670k_objects824=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline825=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline826=== CONT TestReadRedirectKeepsNarinfoProxied827=== CONT TestCompletedNarNotReofferedAcrossClosures828=== CONT TestProxyWriteTimeout829=== RUN TestProxyWriteTimeout/narinfo830=== PAUSE TestProxyWriteTimeout/narinfo831=== RUN TestProxyWriteTimeout/1_GiB_nar832=== PAUSE TestProxyWriteTimeout/1_GiB_nar833=== RUN TestProxyWriteTimeout/10_GiB_nar834=== PAUSE TestProxyWriteTimeout/10_GiB_nar835=== RUN TestProxyWriteTimeout/unknown_size836=== PAUSE TestProxyWriteTimeout/unknown_size837=== CONT TestReadRedirectNar838=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle839=== CONT TestReadProxyDisabled840=== CONT TestSkippedUploadsHandler841=== CONT TestReadProxyRootRedirectsToIndexHTML842=== CONT TestParseSize843=== CONT TestService_Rustfstest844=== CONT TestReadProxyConditionalGet845=== CONT TestPresignedUploadRegisteredBeforeCommit846=== CONT TestOrphanedObjectsGCStressTest847=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal848=== PAUSE TestIsValidUploadKey/narinfo849=== RUN TestIsValidUploadKey/nar_zst850=== CONT TestReadProxyHead8512026/10/27 08:39:34 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000852--- PASS: TestParseSize (0.00s)853=== CONT TestCompleteMultipartUpload_ErrorButObjectExists854=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal855=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key856=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key857=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key858=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key859=== PAUSE TestIsValidUploadKey/nar_zst860=== RUN TestIsValidUploadKey/nar_xz861=== PAUSE TestIsValidUploadKey/nar_xz862=== RUN TestIsValidUploadKey/nar_plain863=== PAUSE TestIsValidUploadKey/nar_plain864=== RUN TestIsValidUploadKey/listing865=== PAUSE TestIsValidUploadKey/listing866=== RUN TestIsValidUploadKey/build_log867=== PAUSE TestIsValidUploadKey/build_log868=== RUN TestIsValidUploadKey/build_log_home-manager_file869=== PAUSE TestIsValidUploadKey/build_log_home-manager_file870=== RUN TestIsValidUploadKey/build_log_plus_in_name871=== PAUSE TestIsValidUploadKey/build_log_plus_in_name872=== RUN TestIsValidUploadKey/build_log_question_mark873=== PAUSE TestIsValidUploadKey/build_log_question_mark874=== RUN TestIsValidUploadKey/build_log_equals875=== PAUSE TestIsValidUploadKey/build_log_equals876=== RUN TestIsValidUploadKey/realisation877=== PAUSE TestIsValidUploadKey/realisation878=== RUN TestIsValidUploadKey/realisation_plus_in_output879=== PAUSE TestIsValidUploadKey/realisation_plus_in_output880=== RUN TestIsValidUploadKey/nix-cache-info881=== PAUSE TestIsValidUploadKey/nix-cache-info882=== RUN TestIsValidUploadKey/index.html883=== PAUSE TestIsValidUploadKey/index.html884=== RUN TestIsValidUploadKey/narinfo_key,_nar_type885=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type886=== RUN TestIsValidUploadKey/nar_key,_narinfo_type887=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type888=== RUN TestIsValidUploadKey/listing_key,_narinfo_type889=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type890=== RUN TestIsValidUploadKey/traversal891=== PAUSE TestIsValidUploadKey/traversal892=== RUN TestIsValidUploadKey/traversal_nar893=== PAUSE TestIsValidUploadKey/traversal_nar894=== RUN TestIsValidUploadKey/absolute895=== PAUSE TestIsValidUploadKey/absolute896=== RUN TestIsValidUploadKey/empty_key897=== PAUSE TestIsValidUploadKey/empty_key898=== RUN TestIsValidUploadKey/unknown_type899=== PAUSE TestIsValidUploadKey/unknown_type900=== CONT TestReadProxyInvalidPath901--- PASS: TestSkippedUploadsHandler (0.04s)902=== CONT TestReadProxy404903=== CONT TestRedundantMultipartUpload904=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure905=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure906=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart907=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart908=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts909=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts910=== CONT TestPush_SignsNarinfosOfItsPendingObjects911--- PASS: TestReadProxyRangeRequest (0.71s)912=== CONT TestReadProxyNarStreaming9132026/10/27 08:39:35 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"914--- PASS: TestService_AuthMiddleware (0.93s)915=== CONT TestPush_RejectsBadRequests916--- PASS: TestReadRedirectKeepsNarinfoProxied (1.60s)917=== CONT TestReadProxyContentNegotiation9182026/10/27 08:39:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9192026/10/27 08:39:36 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst920--- PASS: TestCompleteMultipartUnregistered (2.05s)921=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit922--- PASS: TestReadProxyDisabled (2.19s)923=== CONT TestReadProxyNarinfoAlreadyDecompressed9242026/10/27 08:39:37 INFO Received cleanup request method=DELETE path=/api/pending_closures9252026/10/27 08:39:37 INFO Aborted multipart uploads count=0 kept=09262026/10/27 08:39:37 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/27 08:39:37 INFO Received cleanup request method=DELETE path=/api/pending_closures9282026/10/27 08:39:37 INFO Aborted multipart uploads count=1 kept=09292026/10/27 08:39:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9302026-10-27 08:39:37.255 UTC [74121] ERROR: Closure does not exist: id=19312026-10-27 08:39:37.255 UTC [74121] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9322026-10-27 08:39:37.255 UTC [74121] STATEMENT: -- name: CommitPendingClosure :one933 SELECT commit_pending_closure($1::bigint)::bigint934 935--- PASS: TestService_cleanupPendingClosuresHandler (2.44s)936=== CONT TestPush_RootsAreLockedInByteOrder9372026/10/27 08:39:37 INFO Received uploads request method=POST path=/api/pending_closures938--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.57s)939=== CONT TestReadProxyNarinfo9402026/10/27 08:39:37 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/27 08:39:37 INFO Received uploads request method=POST path=/api/pending_closures942--- PASS: TestReadProxyHead (3.15s)943=== CONT TestPush_CompleteWaitsForCleanupOfThePush9442026/10/27 08:39:38 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/27 08:39:38 INFO Received uploads request method=POST path=/api/pending_closures9462026/10/27 08:39:38 INFO Received uploads request method=POST path=/api/pending_closures947--- PASS: TestReadRedirectNar (3.73s)948=== CONT TestIsValidCachePath949=== RUN TestIsValidCachePath/narinfo950=== PAUSE TestIsValidCachePath/narinfo951=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars952=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars953=== RUN TestIsValidCachePath/nar_zst954=== PAUSE TestIsValidCachePath/nar_zst955=== RUN TestIsValidCachePath/nar_xz956=== PAUSE TestIsValidCachePath/nar_xz957=== RUN TestIsValidCachePath/nar_bz2958=== PAUSE TestIsValidCachePath/nar_bz2959=== RUN TestIsValidCachePath/nar_uncompressed960=== PAUSE TestIsValidCachePath/nar_uncompressed961=== RUN TestIsValidCachePath/ls962=== PAUSE TestIsValidCachePath/ls963=== RUN TestIsValidCachePath/log964=== PAUSE TestIsValidCachePath/log965=== RUN TestIsValidCachePath/realisation966=== PAUSE TestIsValidCachePath/realisation967=== RUN TestIsValidCachePath/nix-cache-info968=== PAUSE TestIsValidCachePath/nix-cache-info969=== RUN TestIsValidCachePath/index.html970=== PAUSE TestIsValidCachePath/index.html971=== RUN TestIsValidCachePath/traversal_parent972=== PAUSE TestIsValidCachePath/traversal_parent973=== RUN TestIsValidCachePath/traversal_in_middle974=== PAUSE TestIsValidCachePath/traversal_in_middle975=== RUN TestIsValidCachePath/invalid_char_e976=== PAUSE TestIsValidCachePath/invalid_char_e977=== RUN TestIsValidCachePath/invalid_char_u978=== PAUSE TestIsValidCachePath/invalid_char_u979=== RUN TestIsValidCachePath/random_path980=== PAUSE TestIsValidCachePath/random_path981=== RUN TestIsValidCachePath/empty982=== PAUSE TestIsValidCachePath/empty983=== RUN TestIsValidCachePath/leading_slash984=== PAUSE TestIsValidCachePath/leading_slash985=== RUN TestIsValidCachePath/wrong_extension986=== PAUSE TestIsValidCachePath/wrong_extension987=== RUN TestIsValidCachePath/short_hash988=== PAUSE TestIsValidCachePath/short_hash989=== CONT TestPush_RepeatedRootCommitsOnce9902026/10/27 08:39:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9912026/10/27 08:39:38 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjFhMmQxMDk0LWI2MjctNDgwYy1iZjIzLWNhNjBiMTVjNTgxOXgxNzkzMDkwMzc3NTMxMDkwMDAw parts=109922026/10/27 08:39:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9932026/10/27 08:39:38 INFO Completed upload id=1 objects=2 duration=16.473875ms9942026/10/27 08:39:38 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/27 08:39:38 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/27 08:39:38 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9972026/10/27 08:39:38 WARN Found objects in DB but missing from S3, will re-upload count=1998--- PASS: TestService_verifyS3Integrity (4.18s)999=== CONT TestParseSingleRange1000=== RUN TestParseSingleRange/none1001=== PAUSE TestParseSingleRange/none1002=== RUN TestParseSingleRange/unknown_unit1003=== PAUSE TestParseSingleRange/unknown_unit1004=== RUN TestParseSingleRange/multi-range_ignored1005=== PAUSE TestParseSingleRange/multi-range_ignored1006=== RUN TestParseSingleRange/malformed_no_dash1007=== PAUSE TestParseSingleRange/malformed_no_dash1008=== RUN TestParseSingleRange/malformed_both_empty1009=== PAUSE TestParseSingleRange/malformed_both_empty1010=== RUN TestParseSingleRange/malformed_end_before_start1011=== PAUSE TestParseSingleRange/malformed_end_before_start1012=== RUN TestParseSingleRange/closed1013=== PAUSE TestParseSingleRange/closed1014=== RUN TestParseSingleRange/open-ended1015=== PAUSE TestParseSingleRange/open-ended1016=== RUN TestParseSingleRange/end_clamped_to_size1017=== PAUSE TestParseSingleRange/end_clamped_to_size1018=== RUN TestParseSingleRange/suffix1019=== PAUSE TestParseSingleRange/suffix1020=== RUN TestParseSingleRange/suffix_exceeds_size1021=== PAUSE TestParseSingleRange/suffix_exceeds_size1022=== RUN TestParseSingleRange/single_byte1023=== PAUSE TestParseSingleRange/single_byte1024=== RUN TestParseSingleRange/start_past_EOF1025=== PAUSE TestParseSingleRange/start_past_EOF1026=== RUN TestParseSingleRange/start_far_past_EOF1027=== PAUSE TestParseSingleRange/start_far_past_EOF1028=== CONT TestPush_CompleteCommitsEveryRoot10292026/10/27 08:39:39 INFO Received push request method=POST path=/api/pushes10302026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10312026/10/27 08:39:39 INFO Signed narinfos id=1 count=110322026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10332026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10342026/10/27 08:39:39 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10352026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10362026/10/27 08:39:39 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10372026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10382026/10/27 08:39:39 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110392026/10/27 08:39:39 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10402026/10/27 08:39:39 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1041--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (4.39s)1042=== CONT TestPresentNotReportedWhileGCDeletesClosure1043=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1044=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1045=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1046=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1047=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1048--- PASS: TestReadProxy404 (4.52s)1049=== CONT TestPresentRefreshesOnlyStaleClosures10502026/10/27 08:39:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10512026/10/27 08:39:39 INFO Received uploads request method=POST path=/api/pending_closures10522026/10/27 08:39:39 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjFhOWZhZTU0LTBkN2UtNGIwMC05NzYwLTUxMWUwZWNlYzNiM3gxNzkzMDkwMzc3Njg4MDk0MDAw parts=1210532026/10/27 08:39:39 INFO Received uploads request method=POST path=/api/pending_closures1054--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.72s)1055=== CONT TestReadRedirectUsesPublicS3URL10562026/10/27 08:39:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10572026/10/27 08:39:39 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjAzMGEyZjA4LWI0NTgtNDE3OS1hY2JlLWNlNWRiZTI5ZDI0N3gxNzkzMDkwMzc4MjM3NjU2MDAw parts=1010582026/10/27 08:39:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10592026/10/27 08:39:39 INFO Completed upload id=1 objects=2 duration=25.031083ms10602026/10/27 08:39:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/10/27 08:39:39 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010622026/10/27 08:39:39 INFO Received uploads request method=POST path=/api/pending_closures10632026/10/27 08:39:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures10642026/10/27 08:39:39 INFO Aborted multipart uploads count=0 kept=010652026/10/27 08:39:39 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=010662026/10/27 08:39:39 INFO Vacuumed table table=pending_closures10672026/10/27 08:39:39 INFO Vacuumed table table=pending_objects10682026/10/27 08:39:39 INFO Vacuumed table table=multipart_uploads10692026/10/27 08:39:39 INFO Vacuumed table table=closures10702026/10/27 08:39:39 INFO Received uploads request method=POST path=/api/pending_closures10712026/10/27 08:39:39 INFO Vacuumed table table=objects10722026/10/27 08:39:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001073--- PASS: TestService_createPendingClosureHandler (5.22s)1074=== CONT TestGCBugBareHashReferences10752026/10/27 08:39:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10762026/10/27 08:39:40 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjNmOTg2NTMzLTM0N2QtNDAxMi1iMTdjLTBmNDA3NTE2YTRlNngxNzkzMDkwMzgwMDMzMzQ0MDAw1077--- PASS: TestReadProxyConditionalGet (5.46s)1078=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10792026/10/27 08:39:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjNmOTg2NTMzLTM0N2QtNDAxMi1iMTdjLTBmNDA3NTE2YTRlNngxNzkzMDkwMzgwMDMzMzQ0MDAw parts=11080--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.48s)1081=== CONT TestClientFallsBackToClosures1082--- PASS: TestService_Rustfstest (5.60s)1083=== CONT TestGCAdvisoryLockBlocksConcurrentRun10842026/10/27 08:39:40 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/27 08:39:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10862026/10/27 08:39:40 INFO Received uploads request method=POST path=/api/pending_closures1087--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.94s)1088=== CONT TestLeadEndsOnShutdown1089--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.12s)1090=== CONT TestLeadIncumbentAnnouncesAtOnce1091--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.16s)1092=== CONT TestLeadElectsOneAndHandsOver10932026/10/27 08:39:41 INFO Received uploads request method=POST path=/api/pending_closures10942026/10/27 08:39:41 INFO Received uploads request method=POST path=/api/pending_closures1095--- PASS: TestReadProxyInvalidPath (6.80s)1096=== CONT TestConnectWaitsForAPeerMigration1097=== RUN TestPush_RejectsBadRequests/no_roots1098=== PAUSE TestPush_RejectsBadRequests/no_roots1099=== RUN TestPush_RejectsBadRequests/no_objects1100=== PAUSE TestPush_RejectsBadRequests/no_objects1101=== RUN TestPush_RejectsBadRequests/bad_root1102=== PAUSE TestPush_RejectsBadRequests/bad_root1103=== RUN TestPush_RejectsBadRequests/root_not_in_objects1104=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1105=== CONT TestPresentReportsOnlyClosureRoots1106--- PASS: TestReadProxyNarStreaming (7.01s)1107=== CONT TestResolveDBConnectionString1108=== RUN TestResolveDBConnectionString/flag_wins1109=== PAUSE TestResolveDBConnectionString/flag_wins1110=== RUN TestResolveDBConnectionString/file_when_flag_empty1111=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1112=== RUN TestResolveDBConnectionString/missing_file_is_an_error1113=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1114=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1115=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1116=== RUN TestResolveDBConnectionString/nothing_configured1117=== PAUSE TestResolveDBConnectionString/nothing_configured1118=== CONT TestCreatePin_ReservedPins11192026/10/27 08:39:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63636/oidc1120--- PASS: TestReadProxyContentNegotiation (6.67s)1121=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11222026/10/27 08:39:43 INFO Received push request method=POST path=/api/pushes11232026/10/27 08:39:43 INFO Received complete push request method=POST path=/api/pushes/1/complete11242026/10/27 08:39:43 INFO Completed push id=1 objects=4 duration=59.431084ms11252026/10/27 08:39:43 INFO Received push request method=POST path=/api/pushes11262026/10/27 08:39:43 INFO Aborted multipart uploads count=0 kept=011272026/10/27 08:39:43 WARN Force mode enabled - objects will be deleted immediately without grace period11282026/10/27 08:39:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11292026/10/27 08:39:43 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=01130--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.69s)1131=== CONT TestDeleteClosuresRacingPins11322026/10/27 08:39:43 INFO Vacuumed table table=pending_closures11332026/10/27 08:39:43 INFO Vacuumed table table=pending_objects11342026/10/27 08:39:43 INFO Vacuumed table table=multipart_uploads11352026/10/27 08:39:43 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjk0MWJjYzc3LTMwNTktNGM3MS1hNjQ5LTRiYjBiOWYzZWVmMHgxNzkzMDkwMzgxMzQ5MzM5MDAw parts=1211362026/10/27 08:39:43 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/27 08:39:43 INFO Vacuumed table table=closures11382026/10/27 08:39:43 INFO Vacuumed table table=objects11392026/10/27 08:39:43 INFO Received complete push request method=POST path=/api/pushes/2/complete11402026/10/27 08:39:43 INFO Received uploads request method=POST path=/api/pending_closures11412026/10/27 08:39:43 INFO Completed push id=2 objects=4 duration=13.818084ms1142--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.00s)1143=== CONT TestGCSweepDeliversEachKeyOnce11442026/10/27 08:39:43 INFO Received push request method=POST path=/api/pushes11452026-10-27 08:39:44.181 UTC [74210] ERROR: could not obtain lock on row in relation "closures"11462026-10-27 08:39:44.181 UTC [74210] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11472026-10-27 08:39:44.188 UTC [74210] ERROR: could not obtain lock on row in relation "closures"11482026-10-27 08:39:44.188 UTC [74210] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11492026-10-27 08:39:44.194 UTC [74210] ERROR: could not obtain lock on row in relation "closures"11502026-10-27 08:39:44.194 UTC [74210] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11512026-10-27 08:39:44.200 UTC [74210] ERROR: could not obtain lock on row in relation "closures"11522026-10-27 08:39:44.200 UTC [74210] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11532026-10-27 08:39:44.205 UTC [74210] ERROR: could not obtain lock on row in relation "closures"11542026-10-27 08:39:44.205 UTC [74210] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1155--- PASS: TestPush_RootsAreLockedInByteOrder (6.99s)1156=== CONT TestTombstonedObjectOfferedWithoutWaiting11572026/10/27 08:39:44 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1158--- PASS: TestReadProxyNarinfo (7.16s)1159=== CONT TestClientCADerivations11602026/10/27 08:39:44 INFO Received push request method=POST path=/api/pushes11612026/10/27 08:39:45 INFO Received push request method=POST path=/api/pushes11622026-10-27 08:39:45.202 UTC [74219] ERROR: Push does not exist: id=111632026-10-27 08:39:45.202 UTC [74219] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11642026-10-27 08:39:45.202 UTC [74219] STATEMENT: SELECT commit_push($1)1165--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (7.23s)1166=== CONT TestGCSweepSkipsPendingObjects11672026/10/27 08:39:45 INFO Received complete push request method=POST path=/api/pushes/1/complete11682026/10/27 08:39:45 INFO Completed push id=1 objects=4 duration=57.9165ms1169--- PASS: TestPush_RepeatedRootCommitsOnce (6.72s)1170=== CONT TestClientPushesUseOnePush11712026/10/27 08:39:45 WARN Rate limiter enabled after throttle name=s3-test rate=511722026/10/27 08:39:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1173=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1174 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101175 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001176--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (10.59s)1177=== CONT TestPinProtectsFromGC11782026/10/27 08:39:45 INFO Received push request method=POST path=/api/pushes11792026/10/27 08:39:45 INFO Received complete push request method=POST path=/api/pushes/1/complete11802026/10/27 08:39:45 INFO Completed push id=1 objects=6 duration=20.265833ms1181--- PASS: TestPush_CompleteCommitsEveryRoot (6.63s)1182=== CONT TestDeduplicatedObjectsRecordedAsPending11832026/10/27 08:39:45 INFO Received push request method=POST path=/api/pushes11842026/10/27 08:39:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11852026/10/27 08:39:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLjlkZWNlYjExLTFhM2UtNDZhZi1hZjMwLWU3ZWZiMmZlYzBiZHgxNzkzMDkwMzgzODgxOTkxMDAw error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11862026/10/27 08:39:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjQ4MjI1NmItYzY3NS00NmUzLTkwYTUtODU5NjhlNzJhN2FhLmNiZTA5ZWU5LTg3ZGQtNDYxNC04ZTQyLWRiM2M0ODc2ODNkMHgxNzkzMDkwMzgzODE4OTQ2MDAw parts=1211872026/10/27 08:39:45 INFO Received cleanup request method=DELETE path=/api/pending_closures1188--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (6.68s)1189=== CONT TestPushDedupSurvivesConcurrentGC11902026/10/27 08:39:46 INFO Aborted multipart uploads count=1 kept=01191--- PASS: TestRedundantMultipartUpload (11.16s)1192=== CONT TestGCMetrics1193--- PASS: TestPresentRefreshesOnlyStaleClosures (6.78s)1194=== CONT TestGracefulShutdownDrainsInflight11952026/10/27 08:39:46 INFO Starting HTTP server address=127.0.0.1:6369711962026/10/27 08:39:46 INFO Shutdown signal received, draining in-flight requests timeout=10s1197--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1198=== CONT TestOrphanedObjectsGC1199--- PASS: TestReadRedirectUsesPublicS3URL (6.93s)1200=== CONT TestObjectStatsUpdatedOncePerCommit1201--- PASS: TestGCBugBareHashReferences (6.95s)1202=== CONT TestClientSharedPathCommittedMidPush12032026/10/27 08:39:47 INFO Received uploads request method=POST path=/api/pending_closures1204--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.95s)1205=== CONT TestClientWithDependencies12062026/10/27 08:39:47 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld5 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1207--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (7.20s)1208=== CONT TestClientMultipleUploads12092026/10/27 08:39:47 INFO Received uploads request method=POST path=/api/pending_closures12102026/10/27 08:39:47 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/27 08:39:47 INFO lead: acquired remote=192.0.2.1:123412122026/10/27 08:39:47 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12132026/10/27 08:39:47 INFO Uploading 3dan741gzyngzlr3500kd3phd84ag3d5-b (256B)12142026/10/27 08:39:47 INFO Uploading y7dlln3wpsmpbcm2w2lwnbrafahvxgi1-shared-dep (136B)12152026/10/27 08:39:47 WARN Failed to register uploaded object key=kh3ilpwdzyzgn0k1cknmlhsjqcn5c9xk.ls error="server returned 404: 404 page not found\n"12162026/10/27 08:39:47 WARN Failed to register uploaded object key=y7dlln3wpsmpbcm2w2lwnbrafahvxgi1.ls error="server returned 404: 404 page not found\n"12172026/10/27 08:39:47 WARN Failed to register uploaded object key=3dan741gzyngzlr3500kd3phd84ag3d5.ls error="server returned 404: 404 page not found\n"12182026/10/27 08:39:47 WARN Failed to register uploaded object key=nar/1yv633s0mmvzcb58wh4qvlhmbs63blpiqxzbzv7cmxzxbzd18wza.nar.zst error="server returned 404: 404 page not found\n"12192026/10/27 08:39:47 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12202026/10/27 08:39:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12212026/10/27 08:39:47 INFO Signed narinfos id=1 count=212222026/10/27 08:39:47 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12232026/10/27 08:39:47 INFO Signed narinfos id=2 count=212242026/10/27 08:39:47 INFO Uploading 4 narinfos12252026/10/27 08:39:48 WARN Failed to register uploaded object key=3dan741gzyngzlr3500kd3phd84ag3d5.narinfo error="server returned 404: 404 page not found\n"12262026/10/27 08:39:48 WARN Failed to register uploaded object key=y7dlln3wpsmpbcm2w2lwnbrafahvxgi1.narinfo error="server returned 404: 404 page not found\n"12272026/10/27 08:39:48 WARN Failed to register uploaded object key=kh3ilpwdzyzgn0k1cknmlhsjqcn5c9xk.narinfo error="server returned 404: 404 page not found\n"12282026/10/27 08:39:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12292026/10/27 08:39:48 WARN Failed to register uploaded object key=y7dlln3wpsmpbcm2w2lwnbrafahvxgi1.narinfo error="server returned 404: 404 page not found\n"12302026/10/27 08:39:48 INFO Completed upload id=1 objects=6 duration=33.044708ms12312026/10/27 08:39:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12322026/10/27 08:39:48 INFO Completed upload id=2 objects=6 duration=1.279125ms12332026/10/27 08:39:48 INFO Upload complete. (388ms)1234=== NAME TestClientFallsBackToClosures1235 client_pushes_test.go:112: Retrieved narinfo from S3:1236 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientFallsBackToClosures1646983063/001/store/y7dlln3wpsmpbcm2w2lwnbrafahvxgi1-shared-dep1237 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1238 Compression: zstd1239 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821240 NarSize: 1361241 References: 1242 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1243 client_pushes_test.go:112: Retrieved narinfo from S3:1244 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientFallsBackToClosures1646983063/001/store/kh3ilpwdzyzgn0k1cknmlhsjqcn5c9xk-a1245 URL: nar/1yv633s0mmvzcb58wh4qvlhmbs63blpiqxzbzv7cmxzxbzd18wza.nar.zst1246 Compression: zstd1247 NarHash: sha256:1yv633s0mmvzcb58wh4qvlhmbs63blpiqxzbzv7cmxzxbzd18wza1248 NarSize: 2561249 References: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientFallsBackToClosures1646983063/001/store/y7dlln3wpsmpbcm2w2lwnbrafahvxgi1-shared-dep1250 CA: text:sha256:06m3rr1cbqp314qai3irp44qb6cginmf0q15rh3ghny210mam3l41251 client_pushes_test.go:112: Retrieved narinfo from S3:1252 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientFallsBackToClosures1646983063/001/store/3dan741gzyngzlr3500kd3phd84ag3d5-b1253 URL: nar/1yv633s0mmvzcb58wh4qvlhmbs63blpiqxzbzv7cmxzxbzd18wza.nar.zst1254 Compression: zstd1255 NarHash: sha256:1yv633s0mmvzcb58wh4qvlhmbs63blpiqxzbzv7cmxzxbzd18wza1256 NarSize: 2561257 References: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientFallsBackToClosures1646983063/001/store/y7dlln3wpsmpbcm2w2lwnbrafahvxgi1-shared-dep1258 CA: text:sha256:06m3rr1cbqp314qai3irp44qb6cginmf0q15rh3ghny210mam3l412592026/10/27 08:39:48 INFO lead: acquired remote=192.0.2.1:123412602026/10/27 08:39:48 INFO lead: released remote=192.0.2.1:12341261--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.31s)1262=== CONT TestClientIntegration1263--- PASS: TestClientFallsBackToClosures (7.98s)1264=== CONT TestGCEndsOnShutdown1265=== RUN TestGCEndsOnShutdown/before_the_run1266=== PAUSE TestGCEndsOnShutdown/before_the_run1267=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1268=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1269=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1270=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1271=== CONT TestGCTaskStore_Fail1272--- PASS: TestGCTaskStore_Fail (0.00s)1273=== CONT TestGCTaskStore_PhaseUpdates1274--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1275=== CONT TestObjectStatsTrigger12762026/10/27 08:39:48 INFO lead: acquired remote=192.0.2.1:12341277--- PASS: TestPresentReportsOnlyClosureRoots (6.81s)1278=== CONT TestPendingCleanupUsesOneCutoff12792026/10/27 08:39:48 INFO lead: released remote=192.0.2.1:12341280--- PASS: TestLeadEndsOnShutdown (8.14s)1281=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12822026/10/27 08:39:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12832026/10/27 08:39:49 WARN Refused reserved pin name=worker-x86_64-linux12842026/10/27 08:39:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12852026/10/27 08:39:49 INFO Received create pin request method=POST path=/api/pins/my-app12862026/10/27 08:39:49 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1287--- PASS: TestCreatePin_ReservedPins (6.65s)1288=== CONT TestMultipartCleanup12892026/10/27 08:39:49 INFO lead: released remote=192.0.2.1:123412902026/10/27 08:39:49 INFO lead: acquired remote=192.0.2.1:12341291--- PASS: TestConnectWaitsForAPeerMigration (8.39s)1292=== CONT TestClientErrorHandling1293=== RUN TestClientErrorHandling/InvalidStorePath1294=== PAUSE TestClientErrorHandling/InvalidStorePath1295=== RUN TestClientErrorHandling/InvalidAuthToken1296=== PAUSE TestClientErrorHandling/InvalidAuthToken1297=== RUN TestClientErrorHandling/ServerNotAvailable1298=== PAUSE TestClientErrorHandling/ServerNotAvailable1299=== CONT TestGCTaskStore_CompletedAllowsNewTask1300--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1301=== CONT TestGCTaskStore_GetReturnsLatest1302--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1303=== CONT TestGCTaskStore_GetEmpty1304--- PASS: TestGCTaskStore_GetEmpty (0.00s)1305=== CONT TestServerTLSConfig1306=== RUN TestServerTLSConfig/no_client_CA1307=== PAUSE TestServerTLSConfig/no_client_CA1308=== RUN TestServerTLSConfig/missing_CA_file1309=== PAUSE TestServerTLSConfig/missing_CA_file1310=== RUN TestServerTLSConfig/not_a_PEM_file1311=== PAUSE TestServerTLSConfig/not_a_PEM_file1312=== CONT TestCacheConfigHandlerMaxNarSize1313--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1314=== CONT TestCreatePendingClosureRejectsOversizedNAR13152026/10/27 08:39:50 INFO Received uploads request method=POST path=/api/pending_closures1316--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1317=== CONT TestGenerateLandingPage1318--- PASS: TestGenerateLandingPage (0.00s)1319=== CONT TestService_NativeMTLS13202026/10/27 08:39:50 INFO Aborted multipart uploads count=0 kept=013212026/10/27 08:39:50 WARN Force mode enabled - objects will be deleted immediately without grace period13222026/10/27 08:39:50 INFO Received uploads request method=POST path=/api/pending_closures1323--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.48s)1324=== CONT TestService_readinessHandler13252026/10/27 08:39:50 INFO lead: released remote=192.0.2.1:12341326--- PASS: TestLeadElectsOneAndHandsOver (9.95s)1327=== CONT TestMetricsCommit13282026/10/27 08:39:51 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=013292026/10/27 08:39:51 INFO Vacuumed table table=pending_closures13302026/10/27 08:39:51 INFO Vacuumed table table=pending_objects13312026/10/27 08:39:51 INFO Vacuumed table table=multipart_uploads13322026/10/27 08:39:51 INFO Vacuumed table table=closures13332026/10/27 08:39:51 INFO Vacuumed table table=objects1334--- PASS: TestGCSweepDeliversEachKeyOnce (7.20s)1335=== CONT TestService_healthCheckHandler1336--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.03s)1337=== CONT TestGCTaskStore_ConflictDifferentParams1338--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1339=== CONT TestMetricsInventory13402026/10/27 08:39:51 INFO Received uploads request method=POST path=/api/pending_closures13412026/10/27 08:39:51 INFO Aborted multipart uploads count=0 kept=013422026/10/27 08:39:51 WARN Force mode enabled - objects will be deleted immediately without grace period13432026/10/27 08:39:51 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=013442026/10/27 08:39:51 INFO Vacuumed table table=pending_closures13452026/10/27 08:39:51 INFO Vacuumed table table=pending_objects13462026/10/27 08:39:51 INFO Vacuumed table table=multipart_uploads13472026/10/27 08:39:51 INFO Vacuumed table table=closures1348=== NAME TestClientCADerivations1349 client_ca_test.go:136: Built CA derivation: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientCADerivations166766691/001/store/nisbxhl038b6xx0pw634c0f4gqla240r-ca-test13502026/10/27 08:39:51 INFO Vacuumed table table=objects1351 client_ca_test.go:139: Found 1 dependencies (including self)1352--- PASS: TestGCSweepSkipsPendingObjects (6.38s)1353=== CONT TestService_RequireScope_OIDC13542026/10/27 08:39:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63752/oidc13552026/10/27 08:39:51 INFO Received push request method=POST path=/api/pushes13562026/10/27 08:39:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13572026/10/27 08:39:51 INFO Uploading nisbxhl038b6xx0pw634c0f4gqla240r-ca-test (144B)13582026/10/27 08:39:51 WARN Failed to register uploaded object key=nisbxhl038b6xx0pw634c0f4gqla240r.ls error="server returned 404: 404 page not found\n"13592026/10/27 08:39:51 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13602026/10/27 08:39:51 WARN Failed to register uploaded object key=log/rykwvlmm5r2dbilm1xhsc36fs6ih8f52-ca-test.drv error="server returned 404: 404 page not found\n"13612026/10/27 08:39:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13622026/10/27 08:39:51 INFO Signed narinfos id=1 count=113632026/10/27 08:39:51 INFO Uploading 1 narinfos13642026/10/27 08:39:51 INFO Received complete push request method=POST path=/api/pushes/1/complete13652026/10/27 08:39:51 WARN Failed to register uploaded object key=nisbxhl038b6xx0pw634c0f4gqla240r.narinfo error="server returned 404: 404 page not found\n"13662026/10/27 08:39:51 INFO Completed push id=1 objects=4 duration=19.010917ms13672026/10/27 08:39:51 INFO Upload complete. (350ms)1368=== NAME TestClientCADerivations1369 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientCADerivations166766691/001/store/nisbxhl038b6xx0pw634c0f4gqla240r-ca-test1370 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1371 Compression: zstd1372 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1373 NarSize: 1441374 References: 1375 Deriver: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientCADerivations166766691/001/store/rykwvlmm5r2dbilm1xhsc36fs6ih8f52-ca-test.drv1376 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1377 client_ca_test.go:185: Checking for realisation files in S3...1378=== NAME TestOrphanedObjectsGCStressTest1379 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1380=== NAME TestClientCADerivations1381 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1382 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1383=== NAME TestOrphanedObjectsGCStressTest1384 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1385=== NAME TestClientCADerivations1386 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket54?endpoint=http://localhost:63510®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/5/scratch/c7420197c191de2e/build/TestClientCADerivations166766691/001/store'1387 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11388--- PASS: TestClientCADerivations (7.57s)1389=== CONT TestGCTaskStore_DeduplicateSameParams1390--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1391=== CONT TestNARDeduplicationMetadataUploadBug13922026/10/27 08:39:52 INFO Received uploads request method=POST path=/api/pending_closures13932026/10/27 08:39:52 INFO Received push request method=POST path=/api/pushes1394=== NAME TestPinProtectsFromGC1395 client_integration_test.go:778: Pinned store path: /private/var/tb/5/scratch/c7420197c191de2e/build/TestPinProtectsFromGC3944462225/001/store/rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb-pinned-file.txt1396 client_integration_test.go:779: Unpinned store path: /private/var/tb/5/scratch/c7420197c191de2e/build/TestPinProtectsFromGC3944462225/001/store/hgyji5i3h5a4hx9vv06hbazcd0pqfb5i-unpinned-file.txt1397--- PASS: TestDeduplicatedObjectsRecordedAsPending (6.60s)1398=== CONT TestCacheStatsHandler13992026/10/27 08:39:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14002026/10/27 08:39:52 INFO Uploading wgp8a718v6mlp4xja44g624qbp85a74q-a (256B)14012026/10/27 08:39:52 INFO Uploading 5q5qnn6mhdmxb5giassbyd5ggy6r6wn1-shared-dep (136B)14022026/10/27 08:39:52 WARN Failed to register uploaded object key=727pj3n13vd71614zbwqs6mqavp6mi8n.ls error="server returned 404: 404 page not found\n"14032026/10/27 08:39:52 WARN Failed to register uploaded object key=5q5qnn6mhdmxb5giassbyd5ggy6r6wn1.ls error="server returned 404: 404 page not found\n"14042026/10/27 08:39:52 WARN Failed to register uploaded object key=nar/0niy9nd3bmhi0rx0lsnfkw6fr5jvmb8vap3in2jrj6pv7dcdii3x.nar.zst error="server returned 404: 404 page not found\n"14052026/10/27 08:39:52 WARN Failed to register uploaded object key=wgp8a718v6mlp4xja44g624qbp85a74q.ls error="server returned 404: 404 page not found\n"14062026/10/27 08:39:52 INFO Received push request method=POST path=/api/pushes14072026/10/27 08:39:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/10/27 08:39:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14092026/10/27 08:39:52 INFO Signed narinfos id=1 count=314102026/10/27 08:39:52 INFO Uploading 3 narinfos14112026/10/27 08:39:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14122026/10/27 08:39:52 INFO Uploading rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb-pinned-file.txt (128B)14132026/10/27 08:39:52 WARN Failed to register uploaded object key=5q5qnn6mhdmxb5giassbyd5ggy6r6wn1.narinfo error="server returned 404: 404 page not found\n"14142026/10/27 08:39:52 WARN Failed to register uploaded object key=wgp8a718v6mlp4xja44g624qbp85a74q.narinfo error="server returned 404: 404 page not found\n"14152026/10/27 08:39:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14162026/10/27 08:39:52 WARN Failed to register uploaded object key=727pj3n13vd71614zbwqs6mqavp6mi8n.narinfo error="server returned 404: 404 page not found\n"14172026/10/27 08:39:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14182026/10/27 08:39:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14192026/10/27 08:39:52 WARN Failed to register uploaded object key=rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb.ls error="server returned 404: 404 page not found\n"14202026/10/27 08:39:52 INFO Signed narinfos id=1 count=114212026/10/27 08:39:52 INFO Uploading 1 narinfos14222026/10/27 08:39:52 INFO Completed push id=1 objects=8 duration=41.682416ms14232026/10/27 08:39:52 INFO Upload complete. (312ms)1424=== NAME TestClientPushesUseOnePush1425 client_pushes_test.go:97: Retrieved narinfo from S3:1426 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientPushesUseOnePush1533936139/001/store/5q5qnn6mhdmxb5giassbyd5ggy6r6wn1-shared-dep1427 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1428 Compression: zstd1429 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821430 NarSize: 1361431 References: 1432 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1433 client_pushes_test.go:97: Retrieved narinfo from S3:1434 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientPushesUseOnePush1533936139/001/store/wgp8a718v6mlp4xja44g624qbp85a74q-a1435 URL: nar/0niy9nd3bmhi0rx0lsnfkw6fr5jvmb8vap3in2jrj6pv7dcdii3x.nar.zst1436 Compression: zstd1437 NarHash: sha256:0niy9nd3bmhi0rx0lsnfkw6fr5jvmb8vap3in2jrj6pv7dcdii3x1438 NarSize: 2561439 References: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientPushesUseOnePush1533936139/001/store/5q5qnn6mhdmxb5giassbyd5ggy6r6wn1-shared-dep1440 CA: text:sha256:1zh0gk88vc6qjyl8l65xha9685fijhhdknyrkdwhxgmk1rx0zgjx1441 client_pushes_test.go:97: Retrieved narinfo from S3:1442 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientPushesUseOnePush1533936139/001/store/727pj3n13vd71614zbwqs6mqavp6mi8n-b1443 URL: nar/0niy9nd3bmhi0rx0lsnfkw6fr5jvmb8vap3in2jrj6pv7dcdii3x.nar.zst1444 Compression: zstd1445 NarHash: sha256:0niy9nd3bmhi0rx0lsnfkw6fr5jvmb8vap3in2jrj6pv7dcdii3x1446 NarSize: 2561447 References: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientPushesUseOnePush1533936139/001/store/5q5qnn6mhdmxb5giassbyd5ggy6r6wn1-shared-dep1448 CA: text:sha256:1zh0gk88vc6qjyl8l65xha9685fijhhdknyrkdwhxgmk1rx0zgjx14492026/10/27 08:39:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14502026/10/27 08:39:52 WARN Failed to register uploaded object key=rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb.narinfo error="server returned 404: 404 page not found\n"14512026/10/27 08:39:52 INFO Completed push id=1 objects=3 duration=18.146709ms14522026/10/27 08:39:52 INFO Upload complete. (254ms)1453--- PASS: TestClientPushesUseOnePush (7.27s)1454=== CONT TestGCTaskStore_StartNew1455--- PASS: TestGCTaskStore_StartNew (0.00s)1456=== CONT TestService_ReadAuthMiddleware14572026/10/27 08:39:52 INFO Received push request method=POST path=/api/pushes14582026/10/27 08:39:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14592026/10/27 08:39:52 INFO Uploading hgyji5i3h5a4hx9vv06hbazcd0pqfb5i-unpinned-file.txt (128B)14602026/10/27 08:39:52 INFO Received uploads request method=POST path=/api/pending_closures14612026/10/27 08:39:52 WARN Failed to register uploaded object key=hgyji5i3h5a4hx9vv06hbazcd0pqfb5i.ls error="server returned 404: 404 page not found\n"14622026/10/27 08:39:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14632026/10/27 08:39:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14642026/10/27 08:39:52 INFO Signed narinfos id=2 count=114652026/10/27 08:39:52 INFO Uploading 1 narinfos14662026/10/27 08:39:52 INFO Received complete push request method=POST path=/api/pushes/2/complete14672026/10/27 08:39:52 WARN Failed to register uploaded object key=hgyji5i3h5a4hx9vv06hbazcd0pqfb5i.narinfo error="server returned 404: 404 page not found\n"14682026/10/27 08:39:52 INFO Completed push id=2 objects=3 duration=956.583µs14692026/10/27 08:39:52 INFO Upload complete. (212ms)14702026/10/27 08:39:52 INFO Aborted multipart uploads count=0 kept=014712026/10/27 08:39:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures14722026/10/27 08:39:52 WARN Force mode enabled - objects will be deleted immediately without grace period14732026/10/27 08:39:52 INFO Garbage collection started14742026/10/27 08:39:52 INFO Aborted multipart uploads count=0 kept=014752026/10/27 08:39:52 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=014762026/10/27 08:39:52 INFO Vacuumed table table=pending_closures14772026/10/27 08:39:52 INFO Aborted multipart uploads count=0 kept=014782026/10/27 08:39:52 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=014792026/10/27 08:39:52 INFO Vacuumed table table=pending_objects14802026/10/27 08:39:52 INFO Vacuumed table table=multipart_uploads14812026/10/27 08:39:52 INFO Vacuumed table table=closures14822026/10/27 08:39:52 INFO Vacuumed table table=objects14832026/10/27 08:39:52 WARN Force mode enabled - objects will be deleted immediately without grace period1484--- PASS: TestGCMetrics (6.86s)1485=== CONT TestCacheConfigHandler1486=== RUN TestCacheConfigHandler/full_config,_no_issuer1487=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1488=== RUN TestCacheConfigHandler/no_cache_url_configured1489=== PAUSE TestCacheConfigHandler/no_cache_url_configured1490=== RUN TestCacheConfigHandler/no_signing_keys1491=== PAUSE TestCacheConfigHandler/no_signing_keys1492=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1493=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1494=== CONT TestGetExistingObjectsLocksRows14952026/10/27 08:39:52 INFO Vacuumed table table=pending_closures14962026/10/27 08:39:52 INFO Vacuumed table table=pending_objects14972026/10/27 08:39:52 INFO Vacuumed table table=multipart_uploads14982026/10/27 08:39:52 INFO Vacuumed table table=closures14992026/10/27 08:39:53 INFO Vacuumed table table=objects15002026/10/27 08:39:53 INFO Aborted multipart uploads count=0 kept=015012026/10/27 08:39:53 WARN Force mode enabled - objects will be deleted immediately without grace period15022026/10/27 08:39:53 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=015032026/10/27 08:39:53 INFO Vacuumed table table=pending_closures15042026/10/27 08:39:53 INFO Vacuumed table table=pending_objects15052026/10/27 08:39:53 INFO Vacuumed table table=multipart_uploads15062026/10/27 08:39:53 INFO Vacuumed table table=closures15072026/10/27 08:39:53 INFO Vacuumed table table=objects1508--- PASS: TestPushDedupSurvivesConcurrentGC (7.16s)1509=== CONT TestService_AuthMiddleware_OIDC15102026/10/27 08:39:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:63800/oidc15112026/10/27 08:39:53 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=015122026/10/27 08:39:53 INFO Vacuumed table table=pending_closures15132026/10/27 08:39:53 INFO Vacuumed table table=pending_objects15142026/10/27 08:39:53 INFO Vacuumed table table=multipart_uploads15152026/10/27 08:39:53 INFO Vacuumed table table=closures15162026/10/27 08:39:53 INFO Vacuumed table table=objects1517--- PASS: TestObjectStatsUpdatedOncePerCommit (7.51s)1518=== CONT TestService_ReadScope_PublicByDefault15192026/10/27 08:39:54 INFO Received push request method=POST path=/api/pushes15202026/10/27 08:39:54 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15212026/10/27 08:39:54 INFO Uploading q3k25ycbhdmw8v15zx9kr3jvn334d2zl-top (264B)15222026/10/27 08:39:54 INFO Uploading pg1b13sip9n7lvwijx93rg37xd61g0sb-shared-dep (136B)15232026/10/27 08:39:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15242026/10/27 08:39:54 WARN Failed to register uploaded object key=pg1b13sip9n7lvwijx93rg37xd61g0sb.ls error="server returned 404: 404 page not found\n"15252026/10/27 08:39:54 WARN Failed to register uploaded object key=q3k25ycbhdmw8v15zx9kr3jvn334d2zl.ls error="server returned 404: 404 page not found\n"15262026/10/27 08:39:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15272026/10/27 08:39:54 WARN Failed to register uploaded object key=nar/0hbkn10qilcj7zzghq7m0rnmkzadamy5xq71m0bk0vd0mjlggrv4.nar.zst error="server returned 404: 404 page not found\n"15282026/10/27 08:39:54 INFO Signed narinfos id=1 count=215292026/10/27 08:39:54 INFO Uploading 2 narinfos15302026/10/27 08:39:54 WARN Failed to register uploaded object key=q3k25ycbhdmw8v15zx9kr3jvn334d2zl.narinfo error="server returned 404: 404 page not found\n"15312026/10/27 08:39:54 INFO Received complete push request method=POST path=/api/pushes/1/complete15322026/10/27 08:39:54 WARN Failed to register uploaded object key=pg1b13sip9n7lvwijx93rg37xd61g0sb.narinfo error="server returned 404: 404 page not found\n"15332026/10/27 08:39:54 INFO Completed push id=1 objects=6 duration=29.713792ms15342026/10/27 08:39:54 INFO Upload complete. (328ms)1535=== NAME TestClientSharedPathCommittedMidPush1536 client_integration_test.go:727: Retrieved narinfo from S3:1537 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientSharedPathCommittedMidPush3542408666/001/store/pg1b13sip9n7lvwijx93rg37xd61g0sb-shared-dep1538 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1539 Compression: zstd1540 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821541 NarSize: 1361542 References: 1543 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1544 client_integration_test.go:727: Retrieved narinfo from S3:1545 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientSharedPathCommittedMidPush3542408666/001/store/q3k25ycbhdmw8v15zx9kr3jvn334d2zl-top1546 URL: nar/0hbkn10qilcj7zzghq7m0rnmkzadamy5xq71m0bk0vd0mjlggrv4.nar.zst1547 Compression: zstd1548 NarHash: sha256:0hbkn10qilcj7zzghq7m0rnmkzadamy5xq71m0bk0vd0mjlggrv41549 NarSize: 2641550 References: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientSharedPathCommittedMidPush3542408666/001/store/pg1b13sip9n7lvwijx93rg37xd61g0sb-shared-dep1551 CA: text:sha256:0acfz5ykj3cx4fayixd7lcyxr0zm02wqdj7k75kgvwczj9i24vk315522026/10/27 08:39:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01553=== NAME TestClientWithDependencies1554 client_integration_test.go:660: Built derivation: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientWithDependencies1386739093/001/store/v33vln4j6n1lbi6qn4vzvac0jan73b5y-test-script15552026/10/27 08:39:54 INFO Received create pin request method=POST path=/api/pins/myapp1556=== NAME TestClientMultipleUploads1557 client_integration_test.go:405: Created store path 0: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientMultipleUploads3803631396/001/store/wb4nd7a8wipgs2gwp6cs30v378a16pxw-test-file-0.txt1558=== NAME TestClientWithDependencies1559 client_integration_test.go:662: Found 1 dependencies (including self)15602026/10/27 08:39:54 INFO Created/updated pin name=myapp store_path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestPinProtectsFromGC3944462225/001/store/rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb-pinned-file.txt narinfo_key=rg7rgrjyxmhlm0qdqcnhsgaicn92gmkb.narinfo15612026/10/27 08:39:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures1562--- PASS: TestClientSharedPathCommittedMidPush (7.95s)15632026/10/27 08:39:54 INFO Garbage collection started15642026/10/27 08:39:54 INFO Aborted multipart uploads count=0 kept=01565=== CONT TestCommitRacingPendingCleanupKeepsObjects15662026/10/27 08:39:54 WARN Force mode enabled - objects will be deleted immediately without grace period15672026/10/27 08:39:54 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=015682026/10/27 08:39:54 INFO Vacuumed table table=pending_closures15692026/10/27 08:39:54 INFO Vacuumed table table=pending_objects15702026/10/27 08:39:54 INFO Vacuumed table table=multipart_uploads15712026/10/27 08:39:54 INFO Vacuumed table table=closures15722026/10/27 08:39:55 INFO Vacuumed table table=objects15732026/10/27 08:39:55 INFO Received push request method=POST path=/api/pushes15742026/10/27 08:39:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15752026/10/27 08:39:55 INFO Uploading v33vln4j6n1lbi6qn4vzvac0jan73b5y-test-script (136B)1576=== NAME TestClientMultipleUploads1577 client_integration_test.go:405: Created store path 1: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientMultipleUploads3803631396/001/store/prg4acwl761hbjfj5gsz6yi6fw4yi85z-test-file-1.txt15782026/10/27 08:39:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15792026/10/27 08:39:55 WARN Failed to register uploaded object key=log/yxlr77kjpq49qdnzvqycq8qwaafna4fz-test-script.drv error="server returned 404: 404 page not found\n"15802026/10/27 08:39:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15812026/10/27 08:39:55 WARN Failed to register uploaded object key=v33vln4j6n1lbi6qn4vzvac0jan73b5y.ls error="server returned 404: 404 page not found\n"15822026/10/27 08:39:55 INFO Signed narinfos id=1 count=115832026/10/27 08:39:55 INFO Uploading 1 narinfos1584=== NAME TestOrphanedObjectsGC1585 orphaned_objects_gc_test.go:287: GC Test Summary:1586 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1587 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1588 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1589 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1590 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1591--- PASS: TestOrphanedObjectsGC (9.15s)1592=== CONT TestPushWaitsForSweepHoldingRow15932026/10/27 08:39:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15942026/10/27 08:39:55 WARN Failed to register uploaded object key=v33vln4j6n1lbi6qn4vzvac0jan73b5y.narinfo error="server returned 404: 404 page not found\n"1595=== NAME TestClientMultipleUploads1596 client_integration_test.go:405: Created store path 2: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientMultipleUploads3803631396/001/store/i98j64f58xylic46s7sbhqnagy3fb9rm-test-file-2.txt15972026/10/27 08:39:55 INFO Completed push id=1 objects=4 duration=11.760417ms15982026/10/27 08:39:55 INFO Upload complete. (482ms)1599=== NAME TestClientWithDependencies1600 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/5/scratch/c7420197c191de2e/build/TestClientWithDependencies1386739093/001/store) requires matching store prefix16012026/10/27 08:39:55 INFO Received push request method=POST path=/api/pushes1602--- PASS: TestClientWithDependencies (8.26s)1603=== CONT TestSweepRechecksPendingAfterLocking1604=== NAME TestClientIntegration1605 client_integration_test.go:291: Created store path: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientIntegration2923733307/002/store/lwkmpf0gb0jzzrd505681r841xnypni3-test-file.txt16062026/10/27 08:39:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16072026/10/27 08:39:55 INFO Uploading prg4acwl761hbjfj5gsz6yi6fw4yi85z-test-file-1.txt (160B)16082026/10/27 08:39:55 INFO Uploading wb4nd7a8wipgs2gwp6cs30v378a16pxw-test-file-0.txt (160B)16092026/10/27 08:39:55 INFO Uploading i98j64f58xylic46s7sbhqnagy3fb9rm-test-file-2.txt (160B)1610--- PASS: TestDeleteClosuresRacingPins (11.87s)1611=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16122026/10/27 08:39:55 WARN Failed to register uploaded object key=wb4nd7a8wipgs2gwp6cs30v378a16pxw.ls error="server returned 404: 404 page not found\n"16132026/10/27 08:39:55 WARN Failed to register uploaded object key=prg4acwl761hbjfj5gsz6yi6fw4yi85z.ls error="server returned 404: 404 page not found\n"16142026/10/27 08:39:55 WARN Failed to register uploaded object key=i98j64f58xylic46s7sbhqnagy3fb9rm.ls error="server returned 404: 404 page not found\n"16152026/10/27 08:39:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16162026/10/27 08:39:55 INFO Received push request method=POST path=/api/pushes1617--- PASS: TestObjectStatsTrigger (7.34s)1618=== CONT TestService_AuthMiddleware_MTLSProxyHeader16192026/10/27 08:39:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16202026/10/27 08:39:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16212026/10/27 08:39:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16222026/10/27 08:39:55 INFO Signed narinfos id=1 count=316232026/10/27 08:39:55 INFO Uploading 3 narinfos16242026/10/27 08:39:55 WARN Failed to register uploaded object key=prg4acwl761hbjfj5gsz6yi6fw4yi85z.narinfo error="server returned 404: 404 page not found\n"16252026/10/27 08:39:55 WARN Failed to register uploaded object key=i98j64f58xylic46s7sbhqnagy3fb9rm.narinfo error="server returned 404: 404 page not found\n"16262026/10/27 08:39:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16272026/10/27 08:39:55 WARN Failed to register uploaded object key=wb4nd7a8wipgs2gwp6cs30v378a16pxw.narinfo error="server returned 404: 404 page not found\n"16282026/10/27 08:39:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16292026/10/27 08:39:55 INFO Uploading lwkmpf0gb0jzzrd505681r841xnypni3-test-file.txt (152B)16302026/10/27 08:39:55 INFO Completed push id=1 objects=9 duration=29.143208ms16312026/10/27 08:39:55 INFO Upload complete. (325ms)1632=== NAME TestClientMultipleUploads1633 client_integration_test.go:416: Uploaded 3 paths in 366.366208ms16342026/10/27 08:39:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16352026/10/27 08:39:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16362026/10/27 08:39:55 WARN Failed to register uploaded object key=lwkmpf0gb0jzzrd505681r841xnypni3.ls error="server returned 404: 404 page not found\n"16372026/10/27 08:39:55 INFO Signed narinfos id=1 count=116382026/10/27 08:39:55 INFO Uploading 1 narinfos16392026/10/27 08:39:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16402026/10/27 08:39:55 WARN Failed to register uploaded object key=lwkmpf0gb0jzzrd505681r841xnypni3.narinfo error="server returned 404: 404 page not found\n"1641--- PASS: TestClientMultipleUploads (8.27s)1642=== CONT TestSweepSkipsRowsLockedByPush16432026/10/27 08:39:55 INFO Completed push id=1 objects=3 duration=56.944792ms16442026/10/27 08:39:55 INFO Upload complete. (354ms)16452026/10/27 08:39:55 INFO Received uploads request method=POST path=/api/pending_closures16462026/10/27 08:39:55 INFO All 1 paths already cached1647=== NAME TestClientIntegration1648 client_integration_test.go:317: Retrieved narinfo from S3:1649 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestClientIntegration2923733307/002/store/lwkmpf0gb0jzzrd505681r841xnypni3-test-file.txt1650 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1651 Compression: zstd1652 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11653 NarSize: 1521654 References: 1655 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11656 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1657 client_integration_test.go:318: Decompressed .ls content (64 bytes):1658 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}16592026/10/27 08:39:56 INFO Received uploads request method=POST path=/api/pending_closures16602026/10/27 08:39:56 INFO Received cleanup request method=DELETE path=/api/pending_closures16612026/10/27 08:39:56 INFO Received uploads request method=POST path=/api/pending_closures16622026/10/27 08:39:56 INFO Received push request method=POST path=/api/pushes16632026/10/27 08:39:56 INFO Object in database but missing from S3 key=lwkmpf0gb0jzzrd505681r841xnypni3.ls16642026/10/27 08:39:56 WARN Found objects in DB but missing from S3, will re-upload count=116652026/10/27 08:39:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16662026/10/27 08:39:56 INFO Received complete push request method=POST path=/api/pushes/2/complete16672026/10/27 08:39:56 WARN Failed to register uploaded object key=lwkmpf0gb0jzzrd505681r841xnypni3.ls error="server returned 404: 404 page not found\n"16682026/10/27 08:39:56 INFO Completed push id=2 objects=3 duration=1.178459ms1669--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.51s)1670=== CONT TestFailedS3DeleteKeepsTombstone16712026/10/27 08:39:56 INFO Upload complete. (124ms)1672=== NAME TestClientIntegration1673 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1674 client_integration_test.go:335: Decompressed .ls content (49 bytes):1675 {"version":1,"root":{"type":"regular","size":39}}16762026/10/27 08:39:56 INFO Received uploads request method=POST path=/api/pending_closures16772026/10/27 08:39:56 INFO Received push request method=POST path=/api/pushes16782026/10/27 08:39:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16792026/10/27 08:39:56 INFO Received complete push request method=POST path=/api/pushes/3/complete16802026/10/27 08:39:56 WARN Failed to register uploaded object key=lwkmpf0gb0jzzrd505681r841xnypni3.ls error="server returned 404: 404 page not found\n"16812026/10/27 08:39:56 INFO Completed push id=3 objects=3 duration=943.709µs16822026/10/27 08:39:56 INFO Upload complete. (122ms)1683 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1684 client_integration_test.go:352: Decompressed .ls content (49 bytes):1685 {"version":1,"root":{"type":"regular","size":39}}1686 client_integration_test.go:363: Testing garbage collection...16872026/10/27 08:39:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures16882026/10/27 08:39:56 INFO Garbage collection started1689=== NAME TestPinProtectsFromGC1690 client_integration_test.go:887: Pin successfully protected closure from garbage collection16912026/10/27 08:39:56 INFO Received cleanup request method=DELETE path=/api/pending_closures16922026/10/27 08:39:56 INFO Aborted multipart uploads count=0 kept=016932026/10/27 08:39:56 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket70/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16942026/10/27 08:39:56 INFO Aborted multipart uploads count=0 kept=116952026/10/27 08:39:56 WARN Force mode enabled - objects will be deleted immediately without grace period16962026/10/27 08:39:56 INFO Received cleanup request method=DELETE path=/api/pending_closures16972026/10/27 08:39:56 INFO Aborted multipart uploads count=1 kept=016982026/10/27 08:39:56 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16992026/10/27 08:39:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1700--- PASS: TestService_NativeMTLS (6.89s)1701=== CONT TestRegisterCompletedObjectNeedsPendingRow1702--- PASS: TestMultipartCleanup (7.79s)1703=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1704--- PASS: TestPinProtectsFromGC (11.66s)1705=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check17062026/10/27 08:39:57 WARN readiness check failed error="closed pool"1707--- PASS: TestService_readinessHandler (6.64s)1708=== CONT TestPendingClosureWriteTimeout/empty1709=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17102026/10/27 08:39:57 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=017112026/10/27 08:39:57 INFO Vacuumed table table=pending_closures17122026/10/27 08:39:57 INFO Vacuumed table table=pending_objects17132026/10/27 08:39:57 INFO Vacuumed table table=multipart_uploads17142026/10/27 08:39:57 INFO Vacuumed table table=closures17152026/10/27 08:39:57 INFO Vacuumed table table=objects17162026/10/27 08:39:57 INFO Received push request method=POST path=/api/pushes17172026/10/27 08:39:57 INFO Received complete push request method=POST path=/api/pushes/1/complete17182026/10/27 08:39:57 INFO Completed push id=1 objects=4 duration=52.003458ms17192026/10/27 08:39:57 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17202026/10/27 08:39:57 INFO Completed upload id=2 objects=2 duration=1.347459ms1721--- PASS: TestMetricsCommit (7.02s)1722=== CONT TestPendingClosureWriteTimeout/670k_objects1723=== CONT TestPendingClosureWriteTimeout/400_objects1724=== CONT TestProxyWriteTimeout/narinfo1725=== CONT TestProxyWriteTimeout/unknown_size1726=== CONT TestProxyWriteTimeout/10_GiB_nar1727=== CONT TestProxyWriteTimeout/1_GiB_nar1728--- PASS: TestProxyWriteTimeout (0.00s)1729 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1730 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1731 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1732 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1733=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17342026/10/27 08:39:57 INFO Received uploads request method=POST path=/1735=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17362026/10/27 08:39:57 INFO Received request for more parts method=POST path=/1737=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17382026/10/27 08:39:57 INFO Received complete multipart upload request method=POST path=/1739=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17402026/10/27 08:39:57 INFO Received uploads request method=POST path=/1741--- PASS: TestUploadHandlersRejectInvalidKeys (0.04s)1742 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1743 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1744 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1745 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)1746=== CONT TestIsValidUploadKey/narinfo1747=== CONT TestIsValidUploadKey/unknown_type1748=== CONT TestIsValidUploadKey/empty_key1749=== CONT TestIsValidUploadKey/absolute1750=== CONT TestIsValidUploadKey/traversal_nar1751=== CONT TestIsValidUploadKey/traversal1752=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1753=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1754=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1755=== CONT TestIsValidUploadKey/index.html1756=== CONT TestIsValidUploadKey/nix-cache-info1757=== CONT TestIsValidUploadKey/realisation_plus_in_output1758=== CONT TestIsValidUploadKey/realisation1759=== CONT TestIsValidUploadKey/build_log_equals1760=== CONT TestIsValidUploadKey/build_log_question_mark1761=== CONT TestIsValidUploadKey/build_log_plus_in_name1762=== CONT TestIsValidUploadKey/build_log_home-manager_file1763=== CONT TestIsValidUploadKey/build_log1764=== CONT TestIsValidUploadKey/listing1765=== CONT TestIsValidUploadKey/nar_plain1766=== CONT TestIsValidUploadKey/nar_xz1767=== CONT TestIsValidUploadKey/nar_zst1768--- PASS: TestIsValidUploadKey (0.04s)1769 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1770 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1771 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1772 --- PASS: TestIsValidUploadKey/absolute (0.00s)1773 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1774 --- PASS: TestIsValidUploadKey/traversal (0.00s)1775 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1776 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1777 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1778 --- PASS: TestIsValidUploadKey/index.html (0.00s)1779 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1780 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1781 --- PASS: TestIsValidUploadKey/realisation (0.00s)1782 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1783 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1784 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1785 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1786 --- PASS: TestIsValidUploadKey/build_log (0.00s)1787 --- PASS: TestIsValidUploadKey/listing (0.00s)1788 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1789 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1790 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1791=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17922026/10/27 08:39:58 INFO Received uploads request method=POST path=/1793--- PASS: TestMetricsInventory (6.96s)1794=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17952026/10/27 08:39:58 INFO Received request for more parts method=POST path=/1796=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17972026/10/27 08:39:58 INFO Received complete multipart upload request method=POST path=/1798=== CONT TestIsValidCachePath/narinfo1799=== CONT TestIsValidCachePath/index.html1800=== CONT TestIsValidCachePath/short_hash1801=== CONT TestIsValidCachePath/wrong_extension1802=== CONT TestIsValidCachePath/leading_slash1803=== CONT TestIsValidCachePath/empty1804=== CONT TestIsValidCachePath/random_path1805=== CONT TestIsValidCachePath/invalid_char_u1806=== CONT TestIsValidCachePath/invalid_char_e1807=== CONT TestIsValidCachePath/traversal_in_middle1808=== CONT TestIsValidCachePath/traversal_parent1809=== CONT TestIsValidCachePath/nar_uncompressed1810=== CONT TestIsValidCachePath/nix-cache-info1811=== CONT TestIsValidCachePath/realisation1812=== CONT TestIsValidCachePath/log1813=== CONT TestIsValidCachePath/ls1814=== CONT TestIsValidCachePath/nar_zst1815=== CONT TestIsValidCachePath/nar_bz21816=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1817=== CONT TestIsValidCachePath/nar_xz1818--- PASS: TestIsValidCachePath (0.02s)1819 --- PASS: TestIsValidCachePath/narinfo (0.00s)1820 --- PASS: TestIsValidCachePath/index.html (0.00s)1821 --- PASS: TestIsValidCachePath/short_hash (0.00s)1822 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1823 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1824 --- PASS: TestIsValidCachePath/empty (0.00s)1825 --- PASS: TestIsValidCachePath/random_path (0.00s)1826 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1827 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1828 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1829 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1830 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1831 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1832 --- PASS: TestIsValidCachePath/realisation (0.00s)1833 --- PASS: TestIsValidCachePath/log (0.00s)1834 --- PASS: TestIsValidCachePath/ls (0.00s)1835 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1836 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1837 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1838 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1839=== CONT TestParseSingleRange/none1840=== CONT TestParseSingleRange/open-ended1841=== CONT TestParseSingleRange/start_far_past_EOF1842=== CONT TestParseSingleRange/start_past_EOF1843=== CONT TestParseSingleRange/single_byte1844=== CONT TestParseSingleRange/suffix_exceeds_size1845=== CONT TestParseSingleRange/suffix1846=== CONT TestParseSingleRange/end_clamped_to_size1847=== CONT TestParseSingleRange/malformed_both_empty1848=== CONT TestParseSingleRange/closed1849=== CONT TestParseSingleRange/malformed_end_before_start1850=== CONT TestParseSingleRange/multi-range_ignored1851=== CONT TestParseSingleRange/malformed_no_dash1852=== CONT TestParseSingleRange/unknown_unit1853--- PASS: TestParseSingleRange (0.00s)1854 --- PASS: TestParseSingleRange/none (0.00s)1855 --- PASS: TestParseSingleRange/open-ended (0.00s)1856 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1857 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1858 --- PASS: TestParseSingleRange/single_byte (0.00s)1859 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1860 --- PASS: TestParseSingleRange/suffix (0.00s)1861 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1862 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1863 --- PASS: TestParseSingleRange/closed (0.00s)1864 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1865 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1866 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1867 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1868=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1869=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1870--- PASS: TestUploadHandlersRejectOversizedBody (0.08s)1871 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1872 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1873 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.32s)1874--- PASS: TestService_healthCheckHandler (7.27s)1875=== CONT TestPush_RejectsBadRequests/no_roots18762026/10/27 08:39:58 INFO Received push request method=POST path=/api/pushes1877=== CONT TestPush_RejectsBadRequests/bad_root18782026/10/27 08:39:58 INFO Received push request method=POST path=/api/pushes1879=== CONT TestPush_RejectsBadRequests/root_not_in_objects18802026/10/27 08:39:58 INFO Received push request method=POST path=/api/pushes1881=== CONT TestPush_RejectsBadRequests/no_objects18822026/10/27 08:39:58 INFO Received push request method=POST path=/api/pushes1883--- PASS: TestPush_RejectsBadRequests (6.36s)1884 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1885 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)1886 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1887 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1888=== CONT TestResolveDBConnectionString/flag_wins1889=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1890=== CONT TestResolveDBConnectionString/nothing_configured1891=== CONT TestResolveDBConnectionString/missing_file_is_an_error1892=== CONT TestResolveDBConnectionString/file_when_flag_empty1893=== CONT TestGCEndsOnShutdown/before_the_run1894--- PASS: TestResolveDBConnectionString (0.02s)1895 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1896 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1897 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1898 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1899 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1900=== RUN TestService_RequireScope_OIDC/builder_may_write1901=== PAUSE TestService_RequireScope_OIDC/builder_may_write1902=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1903=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1904=== RUN TestService_RequireScope_OIDC/ops_may_admin1905=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1906=== RUN TestService_RequireScope_OIDC/ops_may_not_write1907=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1908=== RUN TestService_RequireScope_OIDC/reader_may_not_write1909=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1910=== RUN TestService_RequireScope_OIDC/static_token_may_admin1911=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1912=== RUN TestService_RequireScope_OIDC/static_token_may_write1913=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1914=== RUN TestService_RequireScope_OIDC/reader_may_read1915=== PAUSE TestService_RequireScope_OIDC/reader_may_read1916=== RUN TestService_RequireScope_OIDC/writer_implies_read1917=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1918=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1919=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1920=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1921=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1922=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1923=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1924=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1925=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1926=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1927=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1928=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19292026/10/27 08:39:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01930=== NAME TestClientIntegration1931 client_integration_test.go:370: Objects in database after GC:1932 client_integration_test.go:370: Successfully deleted all objects with GC --force1933--- PASS: TestClientIntegration (10.74s)1934=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1935=== NAME TestNARDeduplicationMetadataUploadBug1936 metadata_upload_test.go:48: First store path: /private/var/tb/5/scratch/c7420197c191de2e/build/TestNARDeduplicationMetadataUploadBug1150960966/001/store/5ad0qp3b8sdbybs2q5lxvid6miap81pq-file1.txt1937--- PASS: TestCacheStatsHandler (7.16s)1938=== CONT TestClientErrorHandling/InvalidStorePath19392026/10/27 08:39:59 INFO Received push request method=POST path=/api/pushes19402026/10/27 08:39:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19412026/10/27 08:39:59 INFO Uploading 5ad0qp3b8sdbybs2q5lxvid6miap81pq-file1.txt (160B)19422026/10/27 08:39:59 WARN Failed to register uploaded object key=5ad0qp3b8sdbybs2q5lxvid6miap81pq.ls error="server returned 404: 404 page not found\n"19432026/10/27 08:39:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19442026/10/27 08:39:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19452026/10/27 08:39:59 INFO Signed narinfos id=1 count=119462026/10/27 08:39:59 INFO Uploading 1 narinfos19472026/10/27 08:39:59 INFO Received complete push request method=POST path=/api/pushes/1/complete19482026/10/27 08:39:59 WARN Failed to register uploaded object key=5ad0qp3b8sdbybs2q5lxvid6miap81pq.narinfo error="server returned 404: 404 page not found\n"19492026/10/27 08:39:59 INFO Completed push id=1 objects=3 duration=35.286917ms19502026/10/27 08:39:59 INFO Upload complete. (239ms)1951=== NAME TestNARDeduplicationMetadataUploadBug1952 metadata_upload_test.go:54: Retrieved narinfo from S3:1953 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestNARDeduplicationMetadataUploadBug1150960966/001/store/5ad0qp3b8sdbybs2q5lxvid6miap81pq-file1.txt1954 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1955 Compression: zstd1956 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1957 NarSize: 1601958 References: 1959 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1960 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1961 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1962 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1963--- PASS: TestGetExistingObjectsLocksRows (6.81s)1964=== CONT TestClientErrorHandling/ServerNotAvailable1965=== NAME TestNARDeduplicationMetadataUploadBug1966 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/5/scratch/c7420197c191de2e/build/TestNARDeduplicationMetadataUploadBug1150960966/001/store/ndb9nximcxwlva1picpz6hnbfxdj6lzg-file2.txt19672026/10/27 08:39:59 INFO Received push request method=POST path=/api/pushes19682026/10/27 08:39:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19692026/10/27 08:39:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19702026/10/27 08:39:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19712026/10/27 08:39:59 WARN Failed to register uploaded object key=ndb9nximcxwlva1picpz6hnbfxdj6lzg.ls error="server returned 404: 404 page not found\n"19722026/10/27 08:39:59 INFO Signed narinfos id=2 count=119732026/10/27 08:39:59 INFO Uploading 1 narinfos1974--- PASS: TestService_ReadAuthMiddleware (7.38s)1975=== CONT TestClientErrorHandling/InvalidAuthToken19762026/10/27 08:39:59 INFO Received complete push request method=POST path=/api/pushes/2/complete19772026/10/27 08:39:59 WARN Failed to register uploaded object key=ndb9nximcxwlva1picpz6hnbfxdj6lzg.narinfo error="server returned 404: 404 page not found\n"19782026/10/27 08:39:59 INFO Completed push id=2 objects=3 duration=935.459µs19792026/10/27 08:40:00 INFO Upload complete. (173ms)1980=== NAME TestNARDeduplicationMetadataUploadBug1981 metadata_upload_test.go:76: Retrieved narinfo from S3:1982 StorePath: /private/var/tb/5/scratch/c7420197c191de2e/build/TestNARDeduplicationMetadataUploadBug1150960966/001/store/ndb9nximcxwlva1picpz6hnbfxdj6lzg-file2.txt1983 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1984 Compression: zstd1985 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1986 NarSize: 1601987 References: 1988 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1989 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1990 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1991 {"version":1,"root":{"type":"regular","size":44}}19922026/10/27 08:40:00 WARN Request failed, retrying attempt=2 backoff=185.226253ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1993--- PASS: TestNARDeduplicationMetadataUploadBug (7.93s)1994=== CONT TestServerTLSConfig/no_client_CA1995=== CONT TestServerTLSConfig/not_a_PEM_file1996=== CONT TestServerTLSConfig/missing_CA_file1997--- PASS: TestServerTLSConfig (0.00s)1998 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1999 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2000 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2001=== CONT TestCacheConfigHandler/full_config,_no_issuer2002=== CONT TestCacheConfigHandler/no_signing_keys2003=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2004=== CONT TestCacheConfigHandler/no_cache_url_configured2005--- PASS: TestCacheConfigHandler (0.00s)2006 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2007 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2008 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2009 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2010=== CONT TestService_RequireScope_OIDC/builder_may_write2011=== CONT TestService_RequireScope_OIDC/reader_may_read2012=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2013=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20142026/10/27 08:40:00 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]2015=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2016=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2017=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2018=== CONT TestService_RequireScope_OIDC/writer_implies_read2019=== CONT TestService_RequireScope_OIDC/reader_may_not_write2020=== CONT TestService_RequireScope_OIDC/static_token_may_write2021=== CONT TestService_RequireScope_OIDC/static_token_may_admin2022=== CONT TestService_RequireScope_OIDC/ops_may_admin2023=== CONT TestService_RequireScope_OIDC/ops_may_not_write2024=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2025--- PASS: TestService_RequireScope_OIDC (7.12s)2026 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2027 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2028 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2029 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2030 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2031 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2032 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2033 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2034 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2035 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20402026/10/27 08:40:00 WARN Request failed, retrying attempt=3 backoff=370.765692ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2041=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2042=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2043=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2044=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2045=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2046=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2047=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2048=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2049=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2050=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20512026/10/27 08:40:00 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]2052=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2053=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20542026/10/27 08:40:00 WARN Authentication failed token_preview=eyJhbGciOi...u4tzr13E2w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2055--- PASS: TestService_AuthMiddleware_OIDC (7.12s)2056 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2057 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2058 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2059 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20602026/10/27 08:40:00 WARN Request failed, retrying attempt=4 backoff=808.309414ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2061--- PASS: TestService_ReadScope_PublicByDefault (6.60s)20622026/10/27 08:40:01 INFO Aborted multipart uploads count=0 kept=020632026/10/27 08:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period20642026/10/27 08:40:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020652026/10/27 08:40:01 INFO Vacuumed table table=pending_closures20662026/10/27 08:40:01 INFO Vacuumed table table=pending_objects20672026/10/27 08:40:01 INFO Vacuumed table table=multipart_uploads20682026/10/27 08:40:01 INFO Vacuumed table table=closures20692026/10/27 08:40:01 INFO Vacuumed table table=objects2070--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.36s)20712026/10/27 08:40:01 INFO Received uploads request method=POST path=/api/pending_closures20722026/10/27 08:40:01 WARN Request failed, retrying attempt=5 backoff=1.458374003s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20732026/10/27 08:40:01 INFO Aborted multipart uploads count=0 kept=020742026/10/27 08:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period20752026/10/27 08:40:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020762026/10/27 08:40:01 INFO Vacuumed table table=pending_closures20772026/10/27 08:40:01 INFO Vacuumed table table=pending_objects20782026/10/27 08:40:01 INFO Vacuumed table table=multipart_uploads20792026/10/27 08:40:01 INFO Vacuumed table table=closures20802026/10/27 08:40:01 INFO Vacuumed table table=objects2081--- PASS: TestSweepRechecksPendingAfterLocking (6.27s)2082--- PASS: TestPushWaitsForSweepHoldingRow (6.42s)20832026/10/27 08:40:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20842026/10/27 08:40:01 WARN mTLS auth: bound subjects configured but subject DN unavailable20852026/10/27 08:40:01 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2086--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.36s)2087--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.52s)20882026/10/27 08:40:02 INFO Aborted multipart uploads count=1 kept=020892026/10/27 08:40:02 INFO Received cleanup request method=DELETE path=/api/pending_closures20902026/10/27 08:40:02 INFO Aborted multipart uploads count=1 kept=02091--- PASS: TestPendingCleanupUsesOneCutoff (13.29s)20922026/10/27 08:40:02 INFO Aborted multipart uploads count=0 kept=020932026/10/27 08:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period20942026/10/27 08:40:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020952026/10/27 08:40:02 INFO Vacuumed table table=pending_closures20962026/10/27 08:40:02 INFO Vacuumed table table=pending_objects20972026/10/27 08:40:02 INFO Vacuumed table table=multipart_uploads20982026/10/27 08:40:02 INFO Vacuumed table table=closures20992026/10/27 08:40:02 INFO Vacuumed table table=objects21002026/10/27 08:40:02 INFO Aborted multipart uploads count=0 kept=021012026/10/27 08:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period21022026/10/27 08:40:02 INFO Received uploads request method=POST path=/api/pending_closures21032026/10/27 08:40:02 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=021042026/10/27 08:40:02 INFO Vacuumed table table=pending_closures21052026/10/27 08:40:02 INFO Vacuumed table table=pending_objects21062026/10/27 08:40:02 INFO Vacuumed table table=multipart_uploads21072026/10/27 08:40:02 INFO Vacuumed table table=closures21082026/10/27 08:40:02 INFO Vacuumed table table=objects2109--- PASS: TestSweepSkipsRowsLockedByPush (6.88s)21102026/10/27 08:40:02 INFO Aborted multipart uploads count=0 kept=021112026/10/27 08:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period21122026/10/27 08:40:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."21132026/10/27 08:40:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."2114--- PASS: TestFailedS3DeleteKeepsTombstone (6.47s)21152026/10/27 08:40:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21162026/10/27 08:40:03 INFO Received uploads request method=POST path=/api/pending_closures21172026/10/27 08:40:03 INFO Aborted multipart uploads count=0 kept=021182026/10/27 08:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period21192026/10/27 08:40:03 WARN Request failed, retrying attempt=2 backoff=194.309039ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21202026/10/27 08:40:03 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=021212026/10/27 08:40:03 INFO Vacuumed table table=pending_closures21222026/10/27 08:40:03 INFO Vacuumed table table=pending_objects21232026/10/27 08:40:03 INFO Vacuumed table table=multipart_uploads21242026/10/27 08:40:03 INFO Vacuumed table table=closures21252026/10/27 08:40:03 WARN Request failed, retrying attempt=3 backoff=411.931838ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21262026/10/27 08:40:03 INFO Vacuumed table table=objects21272026/10/27 08:40:03 INFO Received uploads request method=POST path=/api/pending_closures21282026/10/27 08:40:03 INFO Aborted multipart uploads count=0 kept=021292026/10/27 08:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period21302026/10/27 08:40:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021312026/10/27 08:40:03 INFO Vacuumed table table=pending_closures21322026/10/27 08:40:03 INFO Vacuumed table table=pending_objects21332026/10/27 08:40:03 INFO Vacuumed table table=multipart_uploads21342026/10/27 08:40:03 INFO Vacuumed table table=closures21352026/10/27 08:40:03 INFO Vacuumed table table=objects2136--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2137 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.38s)2138 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.38s)2139--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.49s)21402026/10/27 08:40:03 WARN Request failed, retrying attempt=4 backoff=796.213571ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21412026/10/27 08:40:03 INFO Received uploads request method=POST path=/api/pending_closures21422026/10/27 08:40:04 WARN Request failed, retrying attempt=5 backoff=1.630029276s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2143--- PASS: TestPendingClosureWriteTimeout (0.00s)2144 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2145 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2146 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2147 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (7.16s)21482026/10/27 08:40:04 INFO Aborted multipart uploads count=0 kept=021492026/10/27 08:40:04 WARN Force mode enabled - objects will be deleted immediately without grace period21502026-10-27 08:40:04.690 UTC [74468] ERROR: canceling statement due to user request21512026-10-27 08:40:04.690 UTC [74468] STATEMENT: -- name: MarkStaleObjects :execrows2152 WITH RECURSIVE ct AS (2153 SELECT timezone('UTC', now()) AS now2154 ),2155 closure_reach AS (2156 -- Start with all closure keys2157 SELECT o.key, o.refs2158 FROM objects o2159 INNER JOIN closures c ON o.key = c.key2160 UNION2161 -- Recursively add all referenced objects2162 SELECT o.key, o.refs2163 FROM objects o2164 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2165 ),2166 reachable_objects AS (2167 SELECT DISTINCT key FROM closure_reach2168 ),2169 stale_objects AS (2170 SELECT o.key2171 FROM objects AS o, ct2172 WHERE2173 NOT EXISTS (2174 SELECT 12175 FROM reachable_objects ro2176 WHERE ro.key = o.key2177 )2178 AND NOT EXISTS (2179 SELECT 12180 FROM pending_objects AS po2181 WHERE po.key = o.key2182 )2183 AND o.deleted_at IS NULL -- Only mark fresh objects2184 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2185 FOR UPDATE2186 )2187 UPDATE objects2188 SET2189 deleted_at = ct.now,2190 first_deleted_at = COALESCE(first_deleted_at, ct.now)2191 FROM stale_objects, ct2192 WHERE objects.key = stale_objects.key2193 21942026/10/27 08:40:04 INFO Aborted multipart uploads count=0 kept=021952026/10/27 08:40:04 WARN Force mode enabled - objects will be deleted immediately without grace period21962026/10/27 08:40:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:63510/bucket98/?delete=\": context canceled"2197--- PASS: TestGCEndsOnShutdown (0.00s)2198 --- PASS: TestGCEndsOnShutdown/before_the_run (5.85s)2199 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.99s)2200 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.88s)2201--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2202 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.34s)2203 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.57s)22042026/10/27 08:40:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22052026/10/27 08:40:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22062026/10/27 08:40:06 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22072026/10/27 08:40:06 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/10/27 08:40:06 WARN Request failed, retrying attempt=2 backoff=188.13134ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/10/27 08:40:06 WARN Request failed, retrying attempt=3 backoff=430.139045ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22102026/10/27 08:40:06 WARN Request failed, retrying attempt=4 backoff=794.54724ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22112026/10/27 08:40:07 WARN Request failed, retrying attempt=5 backoff=1.503797896s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22122026/10/27 08:40:09 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22132026/10/27 08:40:09 WARN Request failed, retrying attempt=2 backoff=204.434194ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22142026/10/27 08:40:09 WARN Request failed, retrying attempt=3 backoff=378.007788ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2215=== NAME TestOrphanedObjectsGCStressTest2216 orphaned_objects_gc_test.go:503: Stress test completed successfully:2217 orphaned_objects_gc_test.go:504: - Active objects preserved: 202218 orphaned_objects_gc_test.go:505: - Objects deleted: 2102219 orphaned_objects_gc_test.go:506: - Total GC'd: 2102220--- PASS: TestOrphanedObjectsGCStressTest (34.83s)22212026/10/27 08:40:09 WARN Request failed, retrying attempt=4 backoff=727.402563ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22222026/10/27 08:40:10 WARN Request failed, retrying attempt=5 backoff=1.725356465s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2223--- PASS: TestClientErrorHandling (0.01s)2224 --- PASS: TestClientErrorHandling/InvalidStorePath (5.65s)2225 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.48s)2226 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.64s)2227PASS2228{"timestamp":"2026-10-27T08:40:12.349322Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63867","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}2229{"timestamp":"2026-10-27T08:40:12.349657Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:63592","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}22302026-10-27 08:40:12.457 UTC [73978] LOG: received smart shutdown request22312026-10-27 08:40:12.458 UTC [73978] LOG: background worker "logical replication launcher" (PID 73988) exited with exit code 122322026-10-27 08:40:12.485 UTC [73983] LOG: shutting down22332026-10-27 08:40:12.485 UTC [73983] LOG: checkpoint starting: shutdown immediate22342026-10-27 08:40:13.796 UTC [73983] LOG: checkpoint complete: wrote 11968 buffers (73.0%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 31 recycled; write=0.618 s, sync=0.651 s, total=1.311 s; sync files=34045, longest=0.001 s, average=0.001 s; distance=501980 kB, estimate=501980 kB; lsn=0/201C4270, redo lsn=0/201C427022352026-10-27 08:40:13.802 UTC [73978] LOG: database system is shut down2236Running OIDC tests...2237=== RUN TestAudienceForIssuer2238=== PAUSE TestAudienceForIssuer2239=== RUN TestGlobMatch2240=== PAUSE TestGlobMatch2241=== RUN TestValidateToken_ValidToken2242=== PAUSE TestValidateToken_ValidToken2243=== RUN TestValidateToken_WrongAudience2244=== PAUSE TestValidateToken_WrongAudience2245=== RUN TestValidateToken_Expired2246=== PAUSE TestValidateToken_Expired2247=== RUN TestValidateToken_BoundClaimsMismatch2248=== PAUSE TestValidateToken_BoundClaimsMismatch2249=== RUN TestValidateToken_BoundSubjectMismatch2250=== PAUSE TestValidateToken_BoundSubjectMismatch2251=== RUN TestValidateToken_MultipleProviders2252=== PAUSE TestValidateToken_MultipleProviders2253=== RUN TestValidateToken_NoMatchingProvider2254=== PAUSE TestValidateToken_NoMatchingProvider2255=== RUN TestValidateToken_KubernetesServiceAccount2256=== PAUSE TestValidateToken_KubernetesServiceAccount2257=== RUN TestNewValidator_KubernetesRequiresCA2258=== PAUSE TestNewValidator_KubernetesRequiresCA2259=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2260=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2261=== RUN TestPins_ReservedForMatchingRule2262=== PAUSE TestPins_ReservedForMatchingRule2263=== RUN TestPins_TopLevelShorthand2264=== PAUSE TestPins_TopLevelShorthand2265=== RUN TestPins_ConfigValidation2266=== PAUSE TestPins_ConfigValidation2267=== RUN TestScopes_LegacyProviderDefaultsToWrite2268=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2269=== RUN TestScopes_Rules2270=== PAUSE TestScopes_Rules2271=== RUN TestScopes_ConfigValidation2272=== PAUSE TestScopes_ConfigValidation2273=== CONT TestAudienceForIssuer2274--- PASS: TestAudienceForIssuer (0.00s)2275=== CONT TestValidateToken_NoMatchingProvider2276=== CONT TestScopes_Rules2277=== CONT TestPins_ConfigValidation2278=== CONT TestValidateToken_Expired2279=== CONT TestScopes_ConfigValidation2280=== CONT TestValidateToken_KubernetesServiceAccount2281=== CONT TestPins_TopLevelShorthand2282=== CONT TestPins_ReservedForMatchingRule2283=== CONT TestNewValidator_KubernetesRequiresCA2284--- PASS: TestPins_ConfigValidation (0.01s)2285--- PASS: TestScopes_ConfigValidation (0.01s)2286=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2287=== CONT TestValidateToken_WrongAudience2288=== CONT TestValidateToken_BoundSubjectMismatch2289=== CONT TestValidateToken_ValidToken2290=== CONT TestGlobMatch2291=== RUN TestGlobMatch/foo_foo2292=== PAUSE TestGlobMatch/foo_foo2293=== RUN TestGlobMatch/foo_bar2294=== PAUSE TestGlobMatch/foo_bar2295=== RUN TestGlobMatch/*_2296=== PAUSE TestGlobMatch/*_2297=== RUN TestGlobMatch/*_anything2298=== PAUSE TestGlobMatch/*_anything2299=== RUN TestGlobMatch/foo*_foo2300=== PAUSE TestGlobMatch/foo*_foo2301=== RUN TestGlobMatch/foo*_foobar2302=== PAUSE TestGlobMatch/foo*_foobar2303=== RUN TestGlobMatch/foo*_bar2304=== PAUSE TestGlobMatch/foo*_bar2305=== RUN TestGlobMatch/*bar_bar2306=== PAUSE TestGlobMatch/*bar_bar2307=== RUN TestGlobMatch/*bar_foobar2308=== PAUSE TestGlobMatch/*bar_foobar2309=== RUN TestGlobMatch/*bar_foo2310=== PAUSE TestGlobMatch/*bar_foo2311=== RUN TestGlobMatch/foo*bar_foobar2312=== PAUSE TestGlobMatch/foo*bar_foobar2313=== RUN TestGlobMatch/foo*bar_foo123bar2314=== PAUSE TestGlobMatch/foo*bar_foo123bar2315=== RUN TestGlobMatch/foo*bar_foobarbaz2316=== PAUSE TestGlobMatch/foo*bar_foobarbaz2317=== RUN TestGlobMatch/*/*_foo/bar2318=== PAUSE TestGlobMatch/*/*_foo/bar2319=== RUN TestGlobMatch/*/*_foo2320=== PAUSE TestGlobMatch/*/*_foo2321=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2322=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2323=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02324=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02325=== RUN TestGlobMatch/refs/*/main_refs/heads/main2326=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2327=== RUN TestGlobMatch/fo?_foo2328=== PAUSE TestGlobMatch/fo?_foo2329=== RUN TestGlobMatch/fo?_fo2330=== PAUSE TestGlobMatch/fo?_fo2331=== RUN TestGlobMatch/fo?_fooo2332=== PAUSE TestGlobMatch/fo?_fooo2333=== RUN TestGlobMatch/?oo_foo2334=== PAUSE TestGlobMatch/?oo_foo2335=== RUN TestGlobMatch/?oo_boo2336=== PAUSE TestGlobMatch/?oo_boo2337=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2338=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2339=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2340=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2341=== CONT TestGlobMatch/foo_foo2342=== CONT TestScopes_LegacyProviderDefaultsToWrite2343=== CONT TestGlobMatch/*/*_foo/bar2344=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2345=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2346=== CONT TestGlobMatch/?oo_boo2347=== CONT TestGlobMatch/?oo_foo2348=== CONT TestGlobMatch/fo?_fooo2349=== CONT TestGlobMatch/fo?_fo2350=== CONT TestGlobMatch/fo?_foo2351=== CONT TestGlobMatch/refs/*/main_refs/heads/main2352=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02353=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2354=== CONT TestGlobMatch/*/*_foo2355=== CONT TestGlobMatch/*bar_bar2356=== CONT TestGlobMatch/foo*bar_foobarbaz2357=== CONT TestGlobMatch/foo*bar_foo123bar2358=== CONT TestGlobMatch/foo*bar_foobar2359=== CONT TestGlobMatch/*bar_foo2360=== CONT TestGlobMatch/*bar_foobar2361=== CONT TestGlobMatch/foo*_foo2362=== CONT TestGlobMatch/foo*_bar2363=== CONT TestGlobMatch/foo*_foobar2364=== CONT TestGlobMatch/*_2365=== CONT TestGlobMatch/*_anything2366=== CONT TestGlobMatch/foo_bar2367--- PASS: TestGlobMatch (0.00s)2368 --- PASS: TestGlobMatch/foo_foo (0.00s)2369 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2370 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2371 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/?oo_boo (0.00s)2373 --- PASS: TestGlobMatch/?oo_foo (0.00s)2374 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2375 --- PASS: TestGlobMatch/fo?_fo (0.00s)2376 --- PASS: TestGlobMatch/fo?_foo (0.00s)2377 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2378 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2379 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2380 --- PASS: TestGlobMatch/*/*_foo (0.00s)2381 --- PASS: TestGlobMatch/*bar_bar (0.00s)2382 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2383 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2384 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2385 --- PASS: TestGlobMatch/*bar_foo (0.00s)2386 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2387 --- PASS: TestGlobMatch/foo*_foo (0.00s)2388 --- PASS: TestGlobMatch/foo*_bar (0.00s)2389 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2390 --- PASS: TestGlobMatch/*_ (0.00s)2391 --- PASS: TestGlobMatch/*_anything (0.00s)2392 --- PASS: TestGlobMatch/foo_bar (0.00s)2393=== CONT TestValidateToken_BoundClaimsMismatch2394=== CONT TestValidateToken_MultipleProviders23952026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64017/oidc2396--- PASS: TestValidateToken_WrongAudience (0.04s)23972026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64023/oidc2398--- PASS: TestPins_TopLevelShorthand (0.09s)23992026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64026/oidc24002026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64021/oidc24012026/10/27 08:40:15 http: TLS handshake error from 127.0.0.1:64022: read tcp 127.0.0.1:64020->127.0.0.1:64022: use of closed network connection2402--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)2403--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)24042026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64029/oidc2405--- PASS: TestPins_ReservedForMatchingRule (0.11s)2406--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24072026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64032/oidc24082026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64034/oidc2409--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)2410--- PASS: TestValidateToken_Expired (0.12s)24112026/10/27 08:40:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64031/oidc24122026/10/27 08:40:15 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:64036/oidc2413--- PASS: TestValidateToken_MultipleProviders (0.11s)24142026/10/27 08:40:15 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324152026/10/27 08:40:15 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:64019/oidc2416--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.14s)2417--- PASS: TestValidateToken_NoMatchingProvider (0.16s)24182026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64044/oidc24192026/10/27 08:40:15 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:640462420--- PASS: TestScopes_Rules (0.20s)2421--- PASS: TestValidateToken_KubernetesServiceAccount (0.20s)24222026/10/27 08:40:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64048/oidc2423--- PASS: TestValidateToken_ValidToken (0.26s)2424PASS2425Running hook tests...2426=== RUN TestSendPathsEmpty2427=== PAUSE TestSendPathsEmpty2428=== RUN TestQueueEnqueueAndFetch2429=== PAUSE TestQueueEnqueueAndFetch2430=== RUN TestQueueDeduplication2431=== PAUSE TestQueueDeduplication2432=== RUN TestQueueRemove2433=== PAUSE TestQueueRemove2434=== RUN TestQueueFetchBatchLimit2435=== PAUSE TestQueueFetchBatchLimit2436=== RUN TestQueueRetryMovesToBack2437=== PAUSE TestQueueRetryMovesToBack2438=== RUN TestQueueFetchRemoveLifecycle2439=== PAUSE TestQueueFetchRemoveLifecycle2440=== RUN TestQueueConcurrentWriters2441=== PAUSE TestQueueConcurrentWriters2442=== RUN TestQueueRemoveLargeClosure2443=== PAUSE TestQueueRemoveLargeClosure2444=== RUN TestServerClientIntegration2445--- PASS: TestServerClientIntegration (0.00s)2446=== RUN TestServerQueueError24472026/10/27 08:40:16 ERROR Failed to queue paths error="permission denied" count=12448--- PASS: TestServerQueueError (0.00s)2449=== RUN TestGetListenerSocketActivation2450 server_test.go:145: systemd socket activation does not exist on darwin2451--- SKIP: TestGetListenerSocketActivation (0.00s)2452=== RUN TestServerStalledClientDoesNotBlockShutdown2453=== PAUSE TestServerStalledClientDoesNotBlockShutdown2454=== RUN TestServerBacksOffOnAcceptErrors2455=== PAUSE TestServerBacksOffOnAcceptErrors2456=== RUN TestDrainIsolatesPoisonPath2457=== PAUSE TestDrainIsolatesPoisonPath2458=== RUN TestRunNotBlockedByPoisonHead2459=== PAUSE TestRunNotBlockedByPoisonHead2460=== RUN TestDrainGivesUpWhenServerDown2461=== PAUSE TestDrainGivesUpWhenServerDown2462=== RUN TestFailedPathPrunedByLaterClosure2463=== PAUSE TestFailedPathPrunedByLaterClosure2464=== RUN TestWorkerUploadsAndRemoves2465=== PAUSE TestWorkerUploadsAndRemoves2466=== RUN TestWorkerSkipsGCdPaths2467=== PAUSE TestWorkerSkipsGCdPaths2468=== RUN TestWorkerPrunesClosureDeps2469=== PAUSE TestWorkerPrunesClosureDeps2470=== RUN TestDrainTimeout2471=== PAUSE TestDrainTimeout2472=== RUN TestWorkerRemoveFailureIsNotProgress2473=== PAUSE TestWorkerRemoveFailureIsNotProgress2474=== RUN TestWorkerKeepsPathItCannotStat2475=== PAUSE TestWorkerKeepsPathItCannotStat2476=== CONT TestSendPathsEmpty2477=== CONT TestWorkerKeepsPathItCannotStat2478=== CONT TestQueueFetchRemoveLifecycle2479=== CONT TestDrainGivesUpWhenServerDown2480=== CONT TestQueueRetryMovesToBack2481--- PASS: TestSendPathsEmpty (0.00s)2482=== CONT TestDrainIsolatesPoisonPath2483=== CONT TestServerBacksOffOnAcceptErrors2484=== CONT TestServerStalledClientDoesNotBlockShutdown24852026/10/27 08:40:16 ERROR Accept failed error="too many open files"2486=== CONT TestQueueRemoveLargeClosure2487=== CONT TestQueueRemove2488=== CONT TestQueueDeduplication2489=== CONT TestQueueFetchBatchLimit2490=== CONT TestQueueEnqueueAndFetch2491=== CONT TestQueueConcurrentWriters2492=== CONT TestWorkerSkipsGCdPaths2493=== CONT TestWorkerRemoveFailureIsNotProgress2494=== CONT TestDrainTimeout2495=== CONT TestWorkerPrunesClosureDeps2496=== CONT TestFailedPathPrunedByLaterClosure2497=== CONT TestWorkerUploadsAndRemoves2498=== CONT TestRunNotBlockedByPoisonHead24992026/10/27 08:40:16 ERROR Accept failed error="too many open files"25002026/10/27 08:40:16 INFO Upload queue status pending=225012026/10/27 08:40:16 INFO Uploading batch count=225022026/10/27 08:40:16 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa error="stat /private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa: permission denied"25032026/10/27 08:40:16 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa error="stat /private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa: permission denied"25042026/10/27 08:40:16 INFO Uploading batch count=225052026/10/27 08:40:16 INFO Upload queue status pending=325062026/10/27 08:40:16 INFO Uploading batch count=125072026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=12508--- PASS: TestQueueEnqueueAndFetch (0.01s)25092026/10/27 08:40:16 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa error="stat /private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerKeepsPathItCannotStat769988728/002/locked/aaa: permission denied"25102026/10/27 08:40:16 INFO Uploading batch count=225112026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=225122026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/a25132026/10/27 08:40:16 ERROR Drain finished with paths left in queue remaining=12514--- PASS: TestQueueRetryMovesToBack (0.02s)25152026/10/27 08:40:16 INFO Uploading batch count=425162026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=425172026/10/27 08:40:16 INFO Upload queue status pending=225182026/10/27 08:40:16 INFO Uploading batch count=125192026/10/27 08:40:16 ERROR Accept failed error="too many open files"25202026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/b25212026/10/27 08:40:16 INFO Uploading batch count=225222026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=225232026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/c25242026/10/27 08:40:16 INFO Uploading batch count=125252026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=125262026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainIsolatesPoisonPath3346507287/002/bbb2527--- PASS: TestQueueDeduplication (0.02s)25282026/10/27 08:40:16 INFO Upload queue status pending=225292026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/d25302026/10/27 08:40:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerRemoveFailureIsNotProgress3643052848/002/nonexistent25312026/10/27 08:40:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125322026/10/27 08:40:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerRemoveFailureIsNotProgress3643052848/002/nonexistent25332026/10/27 08:40:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125342026/10/27 08:40:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerRemoveFailureIsNotProgress3643052848/002/nonexistent25352026/10/27 08:40:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125362026/10/27 08:40:16 ERROR Drain finished with paths left in queue remaining=125372026/10/27 08:40:16 INFO Uploading batch count=125382026/10/27 08:40:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestWorkerSkipsGCdPaths3642328588/002/nonexistent25392026/10/27 08:40:16 INFO Uploading batch count=125402026/10/27 08:40:16 INFO Uploading batch count=12541--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)25422026/10/27 08:40:16 INFO Uploading batch count=225432026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=225442026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/e2545--- PASS: TestQueueRemove (0.02s)2546--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)25472026/10/27 08:40:16 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/c7420197c191de2e/build/TestDrainGivesUpWhenServerDown239831276/002/f25482026/10/27 08:40:16 INFO Uploading batch count=125492026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=12550--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25512026/10/27 08:40:16 ERROR Drain finished with paths left in queue remaining=1025522026/10/27 08:40:16 INFO Uploading batch count=125532026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=12554--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25552026/10/27 08:40:16 INFO Uploading batch count=125562026/10/27 08:40:16 ERROR Upload failed error="upload failed" count=12557--- PASS: TestQueueFetchBatchLimit (0.02s)25582026/10/27 08:40:16 ERROR Drain finished with paths left in queue remaining=12559--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2560--- PASS: TestDrainIsolatesPoisonPath (0.02s)2561--- PASS: TestWorkerUploadsAndRemoves (0.03s)2562--- PASS: TestWorkerPrunesClosureDeps (0.03s)25632026/10/27 08:40:16 ERROR Accept failed error="too many open files"2564--- PASS: TestWorkerSkipsGCdPaths (0.04s)2565--- PASS: TestQueueRemoveLargeClosure (0.05s)25662026/10/27 08:40:16 ERROR Accept failed error="too many open files"25672026/10/27 08:40:16 ERROR Accept failed error="too many open files"2568--- PASS: TestQueueConcurrentWriters (0.16s)25692026/10/27 08:40:16 ERROR Failed to decode request error="read unix /private/var/tb/5/scratch/c7420197c191de2e/build/hook208318060/test.sock->: i/o timeout"25702026/10/27 08:40:16 ERROR Failed to write response error="write unix /private/var/tb/5/scratch/c7420197c191de2e/build/hook208318060/test.sock->: i/o timeout"2571--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25722026/10/27 08:40:16 ERROR Upload failed error="context deadline exceeded" count=225732026/10/27 08:40:16 ERROR Drain finished with paths left in queue remaining=42574--- PASS: TestDrainTimeout (0.21s)25752026/10/27 08:40:16 ERROR Accept failed error="too many open files"25762026/10/27 08:40:16 ERROR Accept failed error="too many open files"2577--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25782026/10/27 08:40:17 INFO Uploading batch count=125792026/10/27 08:40:17 INFO Uploading batch count=125802026/10/27 08:40:17 INFO Uploading batch count=125812026/10/27 08:40:17 ERROR Upload failed error="upload failed" count=125822026/10/27 08:40:17 INFO Uploading batch count=125832026/10/27 08:40:17 ERROR Upload failed error="upload failed" count=125842026/10/27 08:40:17 INFO Uploading batch count=125852026/10/27 08:40:17 ERROR Upload failed error="upload failed" count=125862026/10/27 08:40:17 INFO Uploading batch count=125872026/10/27 08:40:17 ERROR Upload failed error="upload failed" count=125882026/10/27 08:40:17 ERROR Drain finished with paths left in queue remaining=12589--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2590PASS2591Running signing tests...2592=== RUN TestExternalSigner2593=== PAUSE TestExternalSigner2594=== RUN TestExternalSignerWrongPublicKey2595=== PAUSE TestExternalSignerWrongPublicKey2596=== RUN TestExternalSignerErrors2597=== PAUSE TestExternalSignerErrors2598=== RUN TestExternalSignerRestartsAfterCrash2599=== PAUSE TestExternalSignerRestartsAfterCrash2600=== RUN TestExternalSignerProgramErrorKeepsProcess2601=== PAUSE TestExternalSignerProgramErrorKeepsProcess2602=== RUN TestExternalSignerClose2603=== PAUSE TestExternalSignerClose2604=== RUN TestExternalSignerRejectsInvalidPublicKey2605=== PAUSE TestExternalSignerRejectsInvalidPublicKey2606=== RUN TestExternalSignerCancellation2607=== PAUSE TestExternalSignerCancellation2608=== RUN TestGenerateFingerprint2609=== PAUSE TestGenerateFingerprint2610=== RUN TestParseSigningKey2611=== PAUSE TestParseSigningKey2612=== RUN TestSign2613=== PAUSE TestSign2614=== RUN TestSignBatch2615=== PAUSE TestSignBatch2616=== RUN TestNilKeyPublicKey2617=== PAUSE TestNilKeyPublicKey2618=== RUN TestSignErrors2619=== PAUSE TestSignErrors2620=== CONT TestExternalSigner2621=== CONT TestExternalSignerCancellation2622=== CONT TestSignBatch2623=== CONT TestNilKeyPublicKey2624--- PASS: TestNilKeyPublicKey (0.00s)2625=== CONT TestExternalSignerProgramErrorKeepsProcess2626=== CONT TestExternalSignerRejectsInvalidPublicKey2627=== RUN TestExternalSignerRejectsInvalidPublicKey/#002628=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002629=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2630=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2631=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2632=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2633=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2634=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2635=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2636=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2637=== CONT TestExternalSignerClose2638=== CONT TestExternalSignerErrors2639=== CONT TestExternalSignerRestartsAfterCrash2640=== CONT TestExternalSignerWrongPublicKey2641=== CONT TestParseSigningKey2642=== CONT TestSign2643=== CONT TestGenerateFingerprint2644=== CONT TestExternalSignerRejectsInvalidPublicKey/#002645=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2646=== RUN TestGenerateFingerprint/basic_with_references2647=== PAUSE TestGenerateFingerprint/basic_with_references2648=== RUN TestGenerateFingerprint/no_references2649=== PAUSE TestGenerateFingerprint/no_references2650=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2651=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2652=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2653=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2654=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2655=== RUN TestGenerateFingerprint/invalid_nar_hash_length2656=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2657=== RUN TestGenerateFingerprint/invalid_store_path_prefix2658=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2659=== RUN TestGenerateFingerprint/invalid_reference_prefix2660=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2661=== CONT TestGenerateFingerprint/basic_with_references2662=== CONT TestGenerateFingerprint/invalid_reference_prefix2663=== CONT TestGenerateFingerprint/invalid_store_path_prefix2664=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2665=== CONT TestSignErrors2666=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2667--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2668 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2669 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2670 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2671 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2672 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2673=== RUN TestExternalSignerErrors/null_signatures2674=== PAUSE TestExternalSignerErrors/null_signatures2675=== RUN TestExternalSignerErrors/missing_signature_name2676=== PAUSE TestExternalSignerErrors/missing_signature_name2677=== RUN TestExternalSignerErrors/invalid_signature_base642678=== PAUSE TestExternalSignerErrors/invalid_signature_base642679=== RUN TestExternalSignerErrors/program_error2680=== PAUSE TestExternalSignerErrors/program_error2681=== RUN TestExternalSignerErrors/exit_at_startup2682=== PAUSE TestExternalSignerErrors/exit_at_startup2683=== RUN TestExternalSignerErrors/wrong_shape2684=== PAUSE TestExternalSignerErrors/wrong_shape2685=== RUN TestExternalSignerErrors/unrequested_key2686=== PAUSE TestExternalSignerErrors/unrequested_key2687=== RUN TestExternalSignerErrors/wrong_signature_length2688=== PAUSE TestExternalSignerErrors/wrong_signature_length2689=== RUN TestExternalSignerErrors/exit_on_request2690=== PAUSE TestExternalSignerErrors/exit_on_request2691=== RUN TestExternalSignerErrors/wrong_signatures_shape2692=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2693=== RUN TestExternalSignerErrors/too_few_signatures2694=== PAUSE TestExternalSignerErrors/too_few_signatures2695=== RUN TestExternalSignerErrors/wrong_signature_name2696=== PAUSE TestExternalSignerErrors/wrong_signature_name2697=== RUN TestExternalSignerErrors/invalid_JSON2698=== PAUSE TestExternalSignerErrors/invalid_JSON2699=== RUN TestExternalSignerErrors/null2700=== PAUSE TestExternalSignerErrors/null2701=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2702=== CONT TestGenerateFingerprint/invalid_nar_hash_length2703=== RUN TestParseSigningKey/valid_32-byte_key2704=== PAUSE TestParseSigningKey/valid_32-byte_key2705=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2706=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2707=== RUN TestParseSigningKey/no_colon2708=== PAUSE TestParseSigningKey/no_colon2709=== RUN TestParseSigningKey/empty_name2710=== PAUSE TestParseSigningKey/empty_name2711=== RUN TestParseSigningKey/invalid_base642712=== PAUSE TestParseSigningKey/invalid_base642713=== RUN TestParseSigningKey/wrong_length2714=== PAUSE TestParseSigningKey/wrong_length2715=== CONT TestParseSigningKey/valid_32-byte_key2716=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2717=== RUN TestSignErrors/nil_key2718=== CONT TestGenerateFingerprint/no_references2719=== RUN TestExternalSignerErrors/wrong_id2720=== PAUSE TestExternalSignerErrors/wrong_id2721--- PASS: TestSignBatch (0.00s)2722=== CONT TestParseSigningKey/empty_name2723=== CONT TestParseSigningKey/wrong_length2724=== CONT TestParseSigningKey/invalid_base642725--- PASS: TestSign (0.00s)2726--- PASS: TestGenerateFingerprint (0.00s)2727 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2728 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2729 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2730 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2731 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2732 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2733 --- PASS: TestGenerateFingerprint/no_references (0.00s)2734=== CONT TestParseSigningKey/no_colon2735=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2736--- PASS: TestParseSigningKey (0.00s)2737 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2738 --- PASS: TestParseSigningKey/empty_name (0.00s)2739 --- PASS: TestParseSigningKey/wrong_length (0.00s)2740 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2741 --- PASS: TestParseSigningKey/no_colon (0.00s)2742 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2743=== PAUSE TestSignErrors/nil_key2744=== RUN TestExternalSignerErrors/missing_signatures2745=== RUN TestSignErrors/nil_narinfo2746=== PAUSE TestSignErrors/nil_narinfo2747=== RUN TestSignErrors/invalid_narinfo2748=== PAUSE TestSignErrors/invalid_narinfo2749=== RUN TestSignErrors/canceled2750=== PAUSE TestSignErrors/canceled2751=== CONT TestSignErrors/nil_key2752=== PAUSE TestExternalSignerErrors/missing_signatures2753=== CONT TestExternalSignerErrors/null_signatures2754=== CONT TestExternalSignerErrors/too_few_signatures2755=== CONT TestExternalSignerErrors/missing_signatures2756=== CONT TestExternalSignerErrors/wrong_id2757=== CONT TestSignErrors/invalid_narinfo2758=== CONT TestExternalSignerErrors/wrong_shape2759=== CONT TestSignErrors/canceled2760=== CONT TestExternalSignerErrors/exit_on_request2761=== CONT TestExternalSignerErrors/exit_at_startup2762=== CONT TestExternalSignerErrors/null2763=== CONT TestExternalSignerErrors/wrong_signature_length2764=== CONT TestExternalSignerErrors/wrong_signatures_shape2765=== CONT TestExternalSignerErrors/program_error2766=== CONT TestExternalSignerErrors/invalid_JSON2767=== CONT TestExternalSignerErrors/wrong_signature_name2768=== CONT TestSignErrors/nil_narinfo2769--- PASS: TestSignErrors (0.00s)2770 --- PASS: TestSignErrors/nil_key (0.00s)2771 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2772 --- PASS: TestSignErrors/canceled (0.00s)2773 --- PASS: TestSignErrors/nil_narinfo (0.00s)2774=== CONT TestExternalSignerErrors/unrequested_key2775=== CONT TestExternalSignerErrors/invalid_signature_base642776=== CONT TestExternalSignerErrors/missing_signature_name2777--- PASS: TestExternalSignerCancellation (0.24s)2778--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.40s)2779--- PASS: TestExternalSigner (0.61s)2780--- PASS: TestExternalSignerRestartsAfterCrash (0.80s)2781/private/var/tb/5/scratch/c7420197c191de2e/build/TestExternalSignerRestartsAfterCrash1005561155/001/sign program: line 7: /private/var/tb/5/scratch/c7420197c191de2e/build/TestExternalSignerRestartsAfterCrash1005561155/001/sign program.starts: No such file or directory2782--- PASS: TestExternalSignerClose (0.97s)2783--- PASS: TestExternalSignerWrongPublicKey (1.15s)2784--- PASS: TestExternalSignerErrors (0.00s)2785 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.34s)2786 --- PASS: TestExternalSignerErrors/wrong_shape (1.53s)2787 --- PASS: TestExternalSignerErrors/missing_signature_name (1.72s)2788 --- PASS: TestExternalSignerErrors/unrequested_key (1.91s)2789 --- PASS: TestExternalSignerErrors/too_few_signatures (2.10s)2790 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.29s)2791 --- PASS: TestExternalSignerErrors/null_signatures (2.49s)2792 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.67s)2793 --- PASS: TestExternalSignerErrors/exit_on_request (2.86s)2794 --- PASS: TestExternalSignerErrors/invalid_JSON (3.06s)2795 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.25s)2796 --- PASS: TestExternalSignerErrors/missing_signatures (3.44s)2797 --- PASS: TestExternalSignerErrors/null (3.63s)2798 --- PASS: TestExternalSignerErrors/wrong_id (3.82s)2799 --- PASS: TestExternalSignerErrors/program_error (4.00s)2800 --- PASS: TestExternalSignerErrors/exit_at_startup (4.20s)2801PASS2802Running OpenBao signer tests...2803=== RUN TestSign2804=== PAUSE TestSign2805=== RUN TestSignErrors2806=== PAUSE TestSignErrors2807=== RUN TestServe2808=== PAUSE TestServe2809=== RUN TestServeRejectsGarbage2810=== PAUSE TestServeRejectsGarbage2811=== CONT TestSign2812=== CONT TestServeRejectsGarbage2813=== CONT TestSignErrors2814=== RUN TestSignErrors/http_error2815--- PASS: TestServeRejectsGarbage (0.00s)2816=== CONT TestServe2817=== PAUSE TestSignErrors/http_error2818=== RUN TestSignErrors/invalid_json2819=== PAUSE TestSignErrors/invalid_json2820=== RUN TestSignErrors/no_prefix2821=== PAUSE TestSignErrors/no_prefix2822=== RUN TestSignErrors/invalid_base642823=== PAUSE TestSignErrors/invalid_base642824=== CONT TestSignErrors/http_error2825=== CONT TestSignErrors/no_prefix2826=== CONT TestSignErrors/invalid_base642827--- PASS: TestServe (0.00s)2828=== CONT TestSignErrors/invalid_json2829--- PASS: TestSign (0.00s)2830--- PASS: TestSignErrors (0.00s)2831 --- PASS: TestSignErrors/no_prefix (0.00s)2832 --- PASS: TestSignErrors/http_error (0.00s)2833 --- PASS: TestSignErrors/invalid_json (0.00s)2834 --- PASS: TestSignErrors/invalid_base64 (0.00s)2835PASS