niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #456
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestScriptTokenEmptyToken117=== CONT TestScriptTokenScriptFails118=== CONT TestScriptTokenEmptyCommand119--- PASS: TestScriptTokenEmptyCommand (0.00s)120=== CONT TestSetClientTLS121=== CONT TestScriptTokenBadJSON122=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer123=== CONT TestStreamPushReportsSignatures124=== CONT TestStreamPushReportsSkippedPaths125=== CONT TestStreamPushRequestLine126=== CONT TestScriptTokenCachesUntilRefresh127=== CONT TestShellSplit128--- PASS: TestShellSplit (0.00s)129=== CONT TestScriptTokenNoExpiryRerunsEveryCall130=== CONT TestDoWithRetry_FinalResponseBodyReadable131=== CONT TestFileTokenEmpty132--- PASS: TestScriptTokenScriptFails (0.00s)133=== CONT TestRetryTimeoutOutlastsMaxRetries134=== CONT TestFileTokenMissing135=== CONT TestDoWithRetry_BodyReplayedViaGetBody136=== CONT TestFileTokenReadsAndCaches137=== CONT TestResolveStorePath138=== CONT TestStaticToken139=== CONT TestSetClientTLSErrors140=== CONT TestStreamPushIsolatesFailures141=== CONT TestSetClientTLSDoesNotMutateDefaultTransport142=== CONT TestStreamPushGivesUpOnDeadServer143=== CONT TestStreamPushStopsWhenCanceled144--- PASS: TestScriptTokenEmptyToken (0.00s)145=== CONT TestDumpPathSingleFile146=== CONT TestClientSignaturesByStorePath147--- PASS: TestScriptTokenBadJSON (0.00s)148=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess149--- PASS: TestStreamPushReportsSkippedPaths (0.00s)150=== CONT TestPathInfoHashCompatibility151=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)152=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)153=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon154=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon155=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI156=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI157=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512158=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512159=== CONT TestGetStorePathHash160=== RUN TestGetStorePathHash/valid_store_path161=== PAUSE TestGetStorePathHash/valid_store_path162=== RUN TestGetStorePathHash/basename_without_hyphen_should_error163=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error164=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error165=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error166=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error167--- PASS: TestStreamPushStopsWhenCanceled (0.00s)168=== CONT TestRateLimiterFeedback169=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error1702026/11/02 09:25:58 ERROR Upload failed error="bad path" count=31712026/11/02 09:25:58 ERROR Upload failed error="connection refused" count=201722026/11/02 09:25:58 ERROR Server seems unavailable, giving up on batch untried=17173--- PASS: TestStreamPushIsolatesFailures (0.00s)174=== CONT TestConvertHashToNix32175--- PASS: TestFileTokenReadsAndCaches (0.00s)1762026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=server-test rate=5177=== CONT TestPathInfoCACompatibility178--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)179=== CONT TestEncodeNixBase32WithRealHash1802026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:42601181=== CONT TestEncodeNixBase32182=== RUN TestEncodeNixBase32/test_string_hash183=== CONT TestParsePathInfoJSONMultiplePaths184=== CONT TestParsePathInfoJSON185--- PASS: TestFileTokenMissing (0.00s)186--- PASS: TestEncodeNixBase32WithRealHash (0.00s)187--- PASS: TestResolveStorePath (0.00s)1882026/11/02 09:25:58 ERROR Upload failed error=boom count=1189--- PASS: TestStreamPushReportsSignatures (0.01s)190=== CONT TestDumpPathWriterError191--- PASS: TestStaticToken (0.00s)1922026/11/02 09:25:58 ERROR Upload failed error=boom count=1193=== CONT TestUploadMultipart_PartsInParallel194=== PAUSE TestEncodeNixBase32/test_string_hash195=== RUN TestEncodeNixBase32/empty_input196--- PASS: TestDoServerRequestAttachesToken (0.01s)197=== CONT TestUploadMultipart_SupersededByPeer198=== RUN TestParsePathInfoJSON/Nix_format199=== RUN TestSetClientTLSErrors/missing_cert_file200=== CONT TestPartSizeForNAR201=== PAUSE TestEncodeNixBase32/empty_input202--- PASS: TestFileTokenEmpty (0.00s)203--- PASS: TestClientSignaturesByStorePath (0.00s)204=== CONT TestUploadMultipart_FailedPartBufferNotReused2052026/11/02 09:25:58 WARN Rate limiter backed off name=server-test rate=5206=== CONT TestDumpPathMatchesNix207=== CONT TestSupersededNARStillUploadsListing208=== PAUSE TestParsePathInfoJSON/Nix_format209--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)2102026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=server-test rate=5211=== CONT TestStreamPushBatchesUnderLoad2122026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:35751213=== PAUSE TestSetClientTLSErrors/missing_cert_file2142026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=server-test rate=52152026/11/02 09:25:58 WARN Rate limiter backed off name=server-test rate=5216--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)217=== CONT TestStreamPushReportsEveryPath218=== RUN TestConvertHashToNix32/SRI_format_to_Nix32219=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths220=== RUN TestPathInfoCACompatibility/null_ca_field221=== RUN TestRateLimiterFeedback/429_enables_limiter222=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32223=== RUN TestUploadMultipart_SupersededByPeer/exists224=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths225=== RUN TestSupersededNARStillUploadsListing/small_NAR226=== RUN TestParsePathInfoJSON/Lix_format227=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false228=== RUN TestSetClientTLSErrors/missing_key_file229--- PASS: TestStreamPushReportsEveryPath (0.00s)230=== PAUSE TestRateLimiterFeedback/429_enables_limiter231=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun2322026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:35751233=== PAUSE TestSetClientTLSErrors/missing_key_file234=== PAUSE TestParsePathInfoJSON/Lix_format235=== PAUSE TestUploadMultipart_SupersededByPeer/exists236=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false237=== PAUSE TestSupersededNARStillUploadsListing/small_NAR238=== PAUSE TestPathInfoCACompatibility/null_ca_field2392026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46707240=== RUN TestPartSizeForNAR/zero_stays_at_minimum241=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum242=== RUN TestConvertHashToNix32/already_Nix32_format243=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths244=== RUN TestSetClientTLSErrors/missing_ca_file245=== PAUSE TestConvertHashToNix32/already_Nix32_format246=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true247=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true248=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths249=== CONT TestFilterOversizedClosures250=== RUN TestSupersededNARStillUploadsListing/dump_cut_short251=== RUN TestConvertHashToNix32/invalid_format252=== RUN TestFilterOversizedClosures/no_limit_keeps_everything253=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything254=== CONT TestRegisterUploadedObjectReusesConnections255--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)256=== RUN TestRateLimiterFeedback/503_enables_limiter257=== RUN TestParsePathInfoJSON/empty_input258=== PAUSE TestParsePathInfoJSON/empty_input259=== RUN TestParsePathInfoJSON/whitespace_only260=== PAUSE TestSetClientTLSErrors/missing_ca_file2612026/11/02 09:25:58 INFO Garbage collection started262=== RUN TestUploadMultipart_SupersededByPeer/missing263=== PAUSE TestUploadMultipart_SupersededByPeer/missing264=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica265=== CONT TestCaseHackSuffix266=== RUN TestSetClientTLS/rejects_connection_without_client_cert267=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert268=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA269=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA270=== RUN TestSetClientTLS/preserves_debug_logging_transport271=== PAUSE TestSetClientTLS/preserves_debug_logging_transport272=== RUN TestPathInfoCACompatibility/old_string_format_-_text273=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text274=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive275=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive276=== RUN TestPathInfoCACompatibility/new_structured_format_-_text277=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text278=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method279=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method280=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2812026/11/02 09:25:58 INFO Garbage collection started2822026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46707283=== CONT TestShellSplitErrors284--- PASS: TestShellSplitErrors (0.00s)285=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)286=== RUN TestPartSizeForNAR/small_stays_at_minimum287=== PAUSE TestPartSizeForNAR/small_stays_at_minimum288=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum289=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum290=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts291=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts292=== RUN TestPartSizeForNAR/1_TiB293=== PAUSE TestPartSizeForNAR/1_TiB294=== RUN TestPartSizeForNAR/5_TiB_S3_max_object295=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object296=== RUN TestPartSizeForNAR/capped_at_5_GiB297=== PAUSE TestPartSizeForNAR/capped_at_5_GiB298=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI299=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon300=== PAUSE TestConvertHashToNix32/invalid_format301=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512302--- PASS: TestPathInfoHashCompatibility (0.00s)303 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)304 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)305 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)306 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)307=== CONT TestGetStorePathHash/valid_store_path308=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short309=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails310=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails311=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error312=== CONT TestEncodeNixBase32/empty_input313=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false314=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error315=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths316=== CONT TestGetStorePathHash/basename_without_hyphen_should_error317--- PASS: TestGetStorePathHash (0.00s)318 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)319 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)320 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)321 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)322=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped323=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped324=== RUN TestFilterOversizedClosures/all_closures_skipped325=== PAUSE TestFilterOversizedClosures/all_closures_skipped326=== CONT TestEncodeNixBase32/test_string_hash327--- PASS: TestEncodeNixBase32 (0.00s)328 --- PASS: TestEncodeNixBase32/empty_input (0.00s)329 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)330=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true331=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths332--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)333 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)334 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)335=== PAUSE TestRateLimiterFeedback/503_enables_limiter336=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter337=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter338=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter339=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter340=== CONT TestUploadMultipart_SupersededByPeer/exists3412026/11/02 09:25:58 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=0342--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)343=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA344=== CONT TestUploadMultipart_SupersededByPeer/missing3452026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=s3-test rate=53462026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:39479347=== CONT TestSetClientTLS/rejects_connection_without_client_cert3482026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:46707349=== PAUSE TestParsePathInfoJSON/whitespace_only350=== RUN TestParsePathInfoJSON/invalid_JSON351=== PAUSE TestParsePathInfoJSON/invalid_JSON352=== CONT TestPathInfoCACompatibility/null_ca_field353=== RUN TestSetClientTLSErrors/invalid_ca_file354=== CONT TestConvertHashToNix32/SRI_format_to_Nix32355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/5_TiB_S3_max_object357=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum358=== CONT TestPartSizeForNAR/small_stays_at_minimum359=== CONT TestSupersededNARStillUploadsListing/small_NAR360=== CONT TestConvertHashToNix32/already_Nix32_format3612026/11/02 09:25:58 WARN Garbage collection finished on another replica. Its statistics are not available here362=== CONT TestPathInfoCACompatibility/new_structured_format_-_text363=== CONT TestFilterOversizedClosures/no_limit_keeps_everything364=== CONT TestSupersededNARStillUploadsListing/dump_cut_short3652026/11/02 09:25:58 INFO Uploading abc-hello (1.0GB)3662026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:46707367=== PAUSE TestSetClientTLSErrors/invalid_ca_file368=== CONT TestConvertHashToNix32/invalid_format369=== CONT TestRateLimiterFeedback/429_enables_limiter370=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails371=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method372=== CONT TestPathInfoCACompatibility/old_string_format_-_text373=== CONT TestPartSizeForNAR/1_TiB374=== CONT TestPartSizeForNAR/zero_stays_at_minimum375=== CONT TestSetClientTLS/preserves_debug_logging_transport376--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)377=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive378=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts379=== CONT TestParsePathInfoJSON/Nix_format380--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)381=== CONT TestFilterOversizedClosures/all_closures_skipped3822026/11/02 09:25:58 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-small nar_size=1000 max_nar_size=50383=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter3842026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:46707385=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3862026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=server-test rate=5387--- PASS: TestStreamPushBatchesUnderLoad (0.03s)388 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)389 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)3902026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:44499391--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)3922026/11/02 09:25:58 INFO Uploading abc-hello (1.0GB)393--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)3942026/11/02 09:25:58 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=2000395=== CONT TestRateLimiterFeedback/503_enables_limiter396=== CONT TestParsePathInfoJSON/empty_input397=== CONT TestParsePathInfoJSON/Lix_format398=== CONT TestSetClientTLSErrors/missing_cert_file399=== CONT TestSetClientTLSErrors/missing_ca_file4002026/11/02 09:25:58 WARN Rate limiter backed off name=server-test rate=5401=== CONT TestParsePathInfoJSON/invalid_JSON402=== CONT TestSetClientTLSErrors/invalid_ca_file403=== CONT TestSetClientTLSErrors/missing_key_file404=== CONT TestParsePathInfoJSON/whitespace_only405--- PASS: TestConvertHashToNix32 (0.03s)406 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)407 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)408 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)409--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)410 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)411 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)412--- PASS: TestFilterOversizedClosures (0.00s)413 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)414 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)415 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)416=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter417--- PASS: TestPartSizeForNAR (0.03s)418 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)419 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)420 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)421 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)422 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)423 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)424 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)425--- PASS: TestParsePathInfoJSON (0.03s)426 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)427 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)428 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)429 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)430 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)431--- PASS: TestPathInfoCACompatibility (0.03s)432 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)433 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)434 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)435 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)436 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)4372026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:46707438--- PASS: TestSetClientTLSErrors (0.04s)439 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)440 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)441 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)442 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4432026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=server-test rate=54442026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:453854452026/11/02 09:25:58 WARN Rate limiter backed off name=server-test rate=5446--- PASS: TestRateLimiterFeedback (0.03s)447 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.26s)448 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)449 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)450 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)4512026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:467074522026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:46707453--- PASS: TestDumpPathSingleFile (0.30s)4542026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:46707455--- PASS: TestCaseHackSuffix (0.27s)4562026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:467074572026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:467074582026/11/02 09:25:58 http: TLS handshake error from 127.0.0.1:53776: remote error: tls: bad certificate4592026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:46707460--- PASS: TestSetClientTLS (0.04s)461 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.27s)462 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)463 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.28s)4642026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:467074652026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:467074662026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:46707467--- PASS: TestRegisterUploadedObjectReusesConnections (0.28s)4682026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:46707469--- PASS: TestStreamPushRequestLine (0.32s)4702026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:467074712026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:467074722026/11/02 09:25:58 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:46707473--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.32s)474--- PASS: TestDumpPathWriterError (0.32s)4752026/11/02 09:25:58 WARN Rate limiter enabled after throttle name=s3-test rate=54762026/11/02 09:25:58 INFO Uploading abc-hello (1.0GB)477--- PASS: TestDumpPathMatchesNix (0.36s)4782026/11/02 09:25:58 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:38521/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:38521/part/24792026/11/02 09:25:58 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"480--- PASS: TestSupersededNARStillUploadsListing (0.03s)481 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)482 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.00s)483 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.82s)484--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.88s)485--- PASS: TestUploadMultipart_PartsInParallel (0.90s)4862026/11/02 09:25:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42477/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42477/api/uploads/complete4872026/11/02 09:25:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4882026/11/02 09:25:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42477/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42477/api/uploads/complete4892026/11/02 09:25:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4902026/11/02 09:25:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42477/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:42477/api/uploads/complete4912026/11/02 09:25:59 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"492--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)493--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)494PASS495Running server tests...496The files belonging to this database system will be owned by user "nixbld".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 /build/postgres2479395394/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 /build/postgres2479395394/data -l logfile start522523/build/postgres2479395394:5432 - no response5242026-11-02 09:26:00.382 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5252026-11-02 09:26:00.382 UTC [128] LOG: listening on Unix socket "/build/postgres2479395394/.s.PGSQL.5432"5262026-11-02 09:26:00.386 UTC [135] LOG: database system was shut down at 2026-11-02 09:26:00 UTC5272026-11-02 09:26:00.390 UTC [128] LOG: database system is ready to accept connections528/build/postgres2479395394:5432 - accepting connections529{"timestamp":"2026-11-02T09:26:00.687229162Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"24448747-da77-4f85-83d7-2be5ade4ac72","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}530=== RUN TestAbortSucceeded531=== PAUSE TestAbortSucceeded532=== RUN TestService_AuthMiddleware533=== PAUSE TestService_AuthMiddleware534=== RUN TestService_AuthMiddleware_MTLSProxyHeader535=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader536=== RUN TestService_AuthMiddleware_MTLSBoundSubjects537=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects538=== RUN TestService_ReadAuthMiddleware539=== PAUSE TestService_ReadAuthMiddleware540=== RUN TestService_AuthMiddleware_OIDC541=== PAUSE TestService_AuthMiddleware_OIDC542=== RUN TestService_RequireScope_OIDC543=== PAUSE TestService_RequireScope_OIDC544=== RUN TestService_ReadScope_PublicByDefault545=== PAUSE TestService_ReadScope_PublicByDefault546=== RUN TestCacheConfigHandler547=== PAUSE TestCacheConfigHandler548=== RUN TestCacheStatsHandler549=== PAUSE TestCacheStatsHandler550=== RUN TestClientCADerivations551=== PAUSE TestClientCADerivations552=== RUN TestClientErrorHandling553=== PAUSE TestClientErrorHandling554=== RUN TestClientIntegration555=== PAUSE TestClientIntegration556=== RUN TestClientMultipleUploads557=== PAUSE TestClientMultipleUploads558=== RUN TestClientWithDependencies559=== PAUSE TestClientWithDependencies560=== RUN TestClientSharedPathCommittedMidPush561=== PAUSE TestClientSharedPathCommittedMidPush562=== RUN TestPinProtectsFromGC563=== PAUSE TestPinProtectsFromGC564=== RUN TestClientPushesUseOnePush565=== PAUSE TestClientPushesUseOnePush566=== RUN TestClientFallsBackToClosures567=== PAUSE TestClientFallsBackToClosures568=== RUN TestDeleteClosuresRacingPins569=== PAUSE TestDeleteClosuresRacingPins570=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock571=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock572=== RUN TestResolveDBConnectionString573=== PAUSE TestResolveDBConnectionString574=== RUN TestConnectWaitsForAPeerMigration575=== PAUSE TestConnectWaitsForAPeerMigration576=== RUN TestLeadElectsOneAndHandsOver577=== PAUSE TestLeadElectsOneAndHandsOver578=== RUN TestLeadIncumbentWinsAfterRestart5792026/11/02 09:26:00 INFO lead: acquired remote=192.0.2.1:12345802026/11/02 09:26:01 INFO lead: released remote=192.0.2.1:12345812026/11/02 09:26:01 INFO lead: acquired remote=192.0.2.1:12345822026/11/02 09:26:02 INFO lead: released remote=192.0.2.1:1234583--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)584=== RUN TestLeadIncumbentAnnouncesAtOnce585=== PAUSE TestLeadIncumbentAnnouncesAtOnce586=== RUN TestLeadEndsOnShutdown587=== PAUSE TestLeadEndsOnShutdown588=== RUN TestLeadEndsWhenItsConnectionHangs5892026/11/02 09:26:02 INFO lead: acquired remote=192.0.2.1:12345902026-11-02 09:26:04.187 UTC [381] FATAL: terminating connection due to administrator command5912026/11/02 09:26:04 INFO lead: acquired remote=192.0.2.1:12345922026/11/02 09:26:05 WARN lead: lock connection lost error="timeout: context deadline exceeded"5932026/11/02 09:26:05 INFO lead: released remote=192.0.2.1:12345942026/11/02 09:26:05 INFO lead: released remote=192.0.2.1:1234595--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)596=== RUN TestGCAdvisoryLockBlocksConcurrentRun597=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun598=== RUN TestGCBugBareHashReferences599=== PAUSE TestGCBugBareHashReferences600=== RUN TestGCMetrics601=== PAUSE TestGCMetrics602=== RUN TestPushDedupSurvivesConcurrentGC603=== PAUSE TestPushDedupSurvivesConcurrentGC604=== RUN TestDeduplicatedObjectsRecordedAsPending605=== PAUSE TestDeduplicatedObjectsRecordedAsPending606=== RUN TestGCSweepSkipsPendingObjects607=== PAUSE TestGCSweepSkipsPendingObjects608=== RUN TestTombstonedObjectOfferedWithoutWaiting609=== PAUSE TestTombstonedObjectOfferedWithoutWaiting610=== RUN TestGCSweepDeliversEachKeyOnce611=== PAUSE TestGCSweepDeliversEachKeyOnce612=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection613=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection614=== RUN TestForceGCDuringPushOffersSweptObject615=== PAUSE TestForceGCDuringPushOffersSweptObject616=== RUN TestFailedS3DeleteKeepsTombstone617=== PAUSE TestFailedS3DeleteKeepsTombstone618=== RUN TestSweepSkipsRowsLockedByPush619=== PAUSE TestSweepSkipsRowsLockedByPush620=== RUN TestRegisterCompletedObjectNeedsPendingRow621=== PAUSE TestRegisterCompletedObjectNeedsPendingRow622=== RUN TestGetExistingObjectsLocksRows623=== PAUSE TestGetExistingObjectsLocksRows624=== RUN TestSweepRechecksPendingAfterLocking625=== PAUSE TestSweepRechecksPendingAfterLocking626=== RUN TestPushWaitsForSweepHoldingRow627=== PAUSE TestPushWaitsForSweepHoldingRow628=== RUN TestCommitRacingPendingCleanupKeepsObjects629=== PAUSE TestCommitRacingPendingCleanupKeepsObjects630=== RUN TestGCEndsOnShutdown631=== PAUSE TestGCEndsOnShutdown632=== RUN TestGCTaskStore_StartNew633=== PAUSE TestGCTaskStore_StartNew634=== RUN TestGCTaskStore_DeduplicateSameParams635=== PAUSE TestGCTaskStore_DeduplicateSameParams636=== RUN TestGCTaskStore_ConflictDifferentParams637=== PAUSE TestGCTaskStore_ConflictDifferentParams638=== RUN TestGCTaskStore_GetEmpty639=== PAUSE TestGCTaskStore_GetEmpty640=== RUN TestGCTaskStore_GetReturnsLatest641=== PAUSE TestGCTaskStore_GetReturnsLatest642=== RUN TestGCTaskStore_CompletedAllowsNewTask643=== PAUSE TestGCTaskStore_CompletedAllowsNewTask644=== RUN TestGCTaskStore_PhaseUpdates645=== PAUSE TestGCTaskStore_PhaseUpdates646=== RUN TestGCTaskStore_Fail647=== PAUSE TestGCTaskStore_Fail648=== RUN TestGracefulShutdownDrainsInflight649=== PAUSE TestGracefulShutdownDrainsInflight650=== RUN TestService_healthCheckHandler651=== PAUSE TestService_healthCheckHandler652=== RUN TestService_readinessHandler653=== PAUSE TestService_readinessHandler654=== RUN TestGenerateLandingPage655=== PAUSE TestGenerateLandingPage656=== RUN TestCacheConfigHandlerMaxNarSize657=== PAUSE TestCacheConfigHandlerMaxNarSize658=== RUN TestCreatePendingClosureRejectsOversizedNAR659=== PAUSE TestCreatePendingClosureRejectsOversizedNAR660=== RUN TestNARDeduplicationMetadataUploadBug661=== PAUSE TestNARDeduplicationMetadataUploadBug662=== RUN TestMetricsInventory663=== PAUSE TestMetricsInventory664=== RUN TestMetricsCommit665=== PAUSE TestMetricsCommit666=== RUN TestService_NativeMTLS667=== PAUSE TestService_NativeMTLS668=== RUN TestServerTLSConfig669=== PAUSE TestServerTLSConfig670=== RUN TestMultipartCleanup671=== PAUSE TestMultipartCleanup672=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded673=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded674=== RUN TestPendingCleanupUsesOneCutoff675=== PAUSE TestPendingCleanupUsesOneCutoff676=== RUN TestObjectStatsTrigger677=== PAUSE TestObjectStatsTrigger678=== RUN TestObjectStatsUpdatedOncePerCommit679=== PAUSE TestObjectStatsUpdatedOncePerCommit680=== RUN TestOrphanedObjectsGC681=== PAUSE TestOrphanedObjectsGC682=== RUN TestOrphanedObjectsGCStressTest683=== PAUSE TestOrphanedObjectsGCStressTest684=== RUN TestCreatePin_ReservedPins685=== PAUSE TestCreatePin_ReservedPins686=== RUN TestPresentReportsOnlyClosureRoots687=== PAUSE TestPresentReportsOnlyClosureRoots688=== RUN TestPresentRefreshesOnlyStaleClosures689=== PAUSE TestPresentRefreshesOnlyStaleClosures690=== RUN TestPresentNotReportedWhileGCDeletesClosure691=== PAUSE TestPresentNotReportedWhileGCDeletesClosure692=== RUN TestParseSingleRange693=== PAUSE TestParseSingleRange694=== RUN TestProxyHeadersOnlyTrustedOnSocket6952026/11/02 09:26:05 INFO Starting HTTP server address=127.0.0.1:436396962026/11/02 09:26:05 INFO Starting HTTP server address=proxy.sock6972026/11/02 09:26:05 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6982026/11/02 09:26:05 INFO Shutdown signal received, draining in-flight requests timeout=10s699--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.11s)700=== RUN TestIsValidCachePath701=== PAUSE TestIsValidCachePath702=== RUN TestReadProxyNarinfo703=== PAUSE TestReadProxyNarinfo704=== RUN TestReadProxyNarinfoAlreadyDecompressed705=== PAUSE TestReadProxyNarinfoAlreadyDecompressed706=== RUN TestReadProxyContentNegotiation707=== PAUSE TestReadProxyContentNegotiation708=== RUN TestReadProxyNarStreaming709=== PAUSE TestReadProxyNarStreaming710=== RUN TestReadProxy404711=== PAUSE TestReadProxy404712=== RUN TestReadProxyInvalidPath713=== PAUSE TestReadProxyInvalidPath714=== RUN TestReadProxyHead715=== PAUSE TestReadProxyHead716=== RUN TestReadProxyOutlastsServerWriteTimeout717=== PAUSE TestReadProxyOutlastsServerWriteTimeout718=== RUN TestReadProxyConditionalGet719=== PAUSE TestReadProxyConditionalGet720=== RUN TestReadProxyRootRedirectsToIndexHTML721=== PAUSE TestReadProxyRootRedirectsToIndexHTML722=== RUN TestReadProxyDisabled723=== PAUSE TestReadProxyDisabled724=== RUN TestReadRedirectNar725=== PAUSE TestReadRedirectNar726=== RUN TestReadRedirectKeepsNarinfoProxied727=== PAUSE TestReadRedirectKeepsNarinfoProxied728=== RUN TestReadProxyRangeRequest729=== PAUSE TestReadProxyRangeRequest730=== RUN TestReadRedirectUsesPublicS3URL731=== PAUSE TestReadRedirectUsesPublicS3URL732=== RUN TestPush_OverlappingRootsStoreOneRowPerKey733=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey734=== RUN TestPush_CompleteCommitsEveryRoot735=== PAUSE TestPush_CompleteCommitsEveryRoot736=== RUN TestPush_RepeatedRootCommitsOnce737=== PAUSE TestPush_RepeatedRootCommitsOnce738=== RUN TestPush_CompleteWaitsForCleanupOfThePush739=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush740=== RUN TestPush_RootsAreLockedInByteOrder741=== PAUSE TestPush_RootsAreLockedInByteOrder742=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit743=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit744=== RUN TestPush_RejectsBadRequests745=== PAUSE TestPush_RejectsBadRequests746=== RUN TestPush_SignsNarinfosOfItsPendingObjects747=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects748=== RUN TestRedundantMultipartUpload749=== PAUSE TestRedundantMultipartUpload750=== RUN TestCompleteMultipartUpload_ErrorButObjectExists751=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists752=== RUN TestRedundantAbortSkipsCompletingUpload753=== PAUSE TestRedundantAbortSkipsCompletingUpload754=== RUN TestCompleteRefusedAfterAbortClaim755=== PAUSE TestCompleteRefusedAfterAbortClaim756=== RUN TestCompletedNarNotReofferedAcrossClosures757=== PAUSE TestCompletedNarNotReofferedAcrossClosures758=== RUN TestPresignedUploadRegisteredBeforeCommit759=== PAUSE TestPresignedUploadRegisteredBeforeCommit760=== RUN TestService_Rustfstest761=== PAUSE TestService_Rustfstest762=== RUN TestParseSize763=== PAUSE TestParseSize764=== RUN TestSkippedUploadsHandler765=== PAUSE TestSkippedUploadsHandler766=== RUN TestSystemdListenerNotActivated767--- PASS: TestSystemdListenerNotActivated (0.00s)768=== RUN TestWatchdogBeatsWhenHealthy769--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)770=== RUN TestWatchdogSkipsWhenUnhealthy7712026/11/02 09:26:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/11/02 09:26:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/11/02 09:26:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7792026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7802026/11/02 09:26:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"781--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)782=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle783=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle784=== RUN TestProxyWriteTimeout785=== PAUSE TestProxyWriteTimeout786=== RUN TestPendingClosureWriteTimeout787=== PAUSE TestPendingClosureWriteTimeout788=== RUN TestIsValidUploadKey789=== PAUSE TestIsValidUploadKey790=== RUN TestUploadHandlersRejectInvalidKeys791=== PAUSE TestUploadHandlersRejectInvalidKeys792=== RUN TestUploadHandlersRejectOversizedBody793=== PAUSE TestUploadHandlersRejectOversizedBody794=== RUN TestService_cleanupPendingClosuresHandler795=== PAUSE TestService_cleanupPendingClosuresHandler796=== RUN TestService_createPendingClosureHandler797=== PAUSE TestService_createPendingClosureHandler798=== RUN TestService_verifyS3Integrity799=== PAUSE TestService_verifyS3Integrity800=== RUN TestService_verifyS3ReuploadsStaleNarinfo801=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo802=== RUN TestCompleteMultipartUnregistered803=== PAUSE TestCompleteMultipartUnregistered804=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT805=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT806=== CONT TestIsValidUploadKey807=== CONT TestParseSize808=== CONT TestService_healthCheckHandler809--- PASS: TestParseSize (0.00s)810=== CONT TestPendingClosureWriteTimeout811=== RUN TestPendingClosureWriteTimeout/empty812=== PAUSE TestPendingClosureWriteTimeout/empty813=== CONT TestProxyWriteTimeout814=== RUN TestProxyWriteTimeout/narinfo815=== PAUSE TestProxyWriteTimeout/narinfo816=== RUN TestProxyWriteTimeout/1_GiB_nar817=== PAUSE TestProxyWriteTimeout/1_GiB_nar818=== RUN TestProxyWriteTimeout/10_GiB_nar819=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle820=== CONT TestSkippedUploadsHandler821=== CONT TestAbortSucceeded822=== CONT TestGCAdvisoryLockBlocksConcurrentRun823=== CONT TestLeadEndsOnShutdown824=== CONT TestLeadIncumbentAnnouncesAtOnce8252026/11/02 09:26:06 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000826=== CONT TestLeadElectsOneAndHandsOver827=== CONT TestConnectWaitsForAPeerMigration828=== CONT TestResolveDBConnectionString829=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock830=== RUN TestResolveDBConnectionString/flag_wins831=== PAUSE TestResolveDBConnectionString/flag_wins832=== RUN TestResolveDBConnectionString/file_when_flag_empty833=== CONT TestDeleteClosuresRacingPins834=== RUN TestIsValidUploadKey/narinfo835=== PAUSE TestIsValidUploadKey/narinfo836=== CONT TestClientFallsBackToClosures837=== RUN TestIsValidUploadKey/nar_zst838=== PAUSE TestIsValidUploadKey/nar_zst839=== RUN TestIsValidUploadKey/nar_xz840=== PAUSE TestIsValidUploadKey/nar_xz841=== RUN TestIsValidUploadKey/nar_plain842=== PAUSE TestIsValidUploadKey/nar_plain843=== RUN TestIsValidUploadKey/listing844=== PAUSE TestIsValidUploadKey/listing845=== RUN TestIsValidUploadKey/build_log846=== PAUSE TestIsValidUploadKey/build_log847=== RUN TestIsValidUploadKey/build_log_home-manager_file848=== PAUSE TestIsValidUploadKey/build_log_home-manager_file849=== RUN TestIsValidUploadKey/build_log_plus_in_name850=== PAUSE TestIsValidUploadKey/build_log_plus_in_name851=== RUN TestIsValidUploadKey/build_log_question_mark852=== PAUSE TestIsValidUploadKey/build_log_question_mark853=== RUN TestIsValidUploadKey/build_log_equals854=== PAUSE TestIsValidUploadKey/build_log_equals855=== RUN TestIsValidUploadKey/realisation856=== PAUSE TestIsValidUploadKey/realisation857=== RUN TestIsValidUploadKey/realisation_plus_in_output858=== PAUSE TestIsValidUploadKey/realisation_plus_in_output859=== RUN TestIsValidUploadKey/nix-cache-info860=== PAUSE TestIsValidUploadKey/nix-cache-info861=== RUN TestIsValidUploadKey/index.html862=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT863=== CONT TestClientPushesUseOnePush864=== CONT TestGCBugBareHashReferences865=== CONT TestPinProtectsFromGC866=== CONT TestCompleteMultipartUnregistered867=== CONT TestClientSharedPathCommittedMidPush868=== CONT TestGracefulShutdownDrainsInflight869=== CONT TestService_verifyS3ReuploadsStaleNarinfo870=== RUN TestPendingClosureWriteTimeout/400_objects871=== PAUSE TestProxyWriteTimeout/10_GiB_nar872--- PASS: TestAbortSucceeded (0.00s)873=== CONT TestClientWithDependencies874=== PAUSE TestResolveDBConnectionString/file_when_flag_empty875=== RUN TestResolveDBConnectionString/missing_file_is_an_error876=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error877=== RUN TestResolveDBConnectionString/PGHOST_allows_empty878=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty879=== RUN TestResolveDBConnectionString/nothing_configured880=== PAUSE TestResolveDBConnectionString/nothing_configured881=== RUN TestProxyWriteTimeout/unknown_size882=== PAUSE TestProxyWriteTimeout/unknown_size883=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed884=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed885=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed886=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed887=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost888=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost889=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed890=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed891=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed892=== PAUSE TestIsValidUploadKey/index.html893=== RUN TestIsValidUploadKey/narinfo_key,_nar_type894=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type895=== RUN TestIsValidUploadKey/nar_key,_narinfo_type896=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type897=== RUN TestIsValidUploadKey/listing_key,_narinfo_type898=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type899=== RUN TestIsValidUploadKey/traversal900=== PAUSE TestIsValidUploadKey/traversal901=== RUN TestIsValidUploadKey/traversal_nar902=== PAUSE TestIsValidUploadKey/traversal_nar903=== RUN TestIsValidUploadKey/absolute904=== PAUSE TestIsValidUploadKey/absolute905=== RUN TestIsValidUploadKey/empty_key906=== PAUSE TestIsValidUploadKey/empty_key907=== RUN TestIsValidUploadKey/unknown_type908=== PAUSE TestIsValidUploadKey/unknown_type909=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed910=== CONT TestService_verifyS3Integrity911--- PASS: TestSkippedUploadsHandler (0.00s)912=== CONT TestClientIntegration913=== CONT TestGCTaskStore_Fail914--- PASS: TestGCTaskStore_Fail (0.00s)915=== CONT TestService_createPendingClosureHandler9162026/11/02 09:26:06 INFO Starting HTTP server address=127.0.0.1:41747917=== PAUSE TestPendingClosureWriteTimeout/400_objects918=== RUN TestPendingClosureWriteTimeout/670k_objects919=== CONT TestClientMultipleUploads920=== CONT TestGCTaskStore_PhaseUpdates921--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)922=== CONT TestGCTaskStore_CompletedAllowsNewTask923--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)924=== PAUSE TestPendingClosureWriteTimeout/670k_objects925=== CONT TestClientErrorHandling926=== RUN TestClientErrorHandling/InvalidStorePath927=== PAUSE TestClientErrorHandling/InvalidStorePath928=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline929=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline930=== RUN TestClientErrorHandling/InvalidAuthToken931=== PAUSE TestClientErrorHandling/InvalidAuthToken932=== CONT TestService_cleanupPendingClosuresHandler933=== RUN TestClientErrorHandling/ServerNotAvailable934=== PAUSE TestClientErrorHandling/ServerNotAvailable935=== CONT TestGCTaskStore_GetReturnsLatest936--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)937=== CONT TestClientCADerivations9382026/11/02 09:26:06 INFO Shutdown signal received, draining in-flight requests timeout=10s939--- PASS: TestGracefulShutdownDrainsInflight (0.07s)940=== CONT TestGCTaskStore_GetEmpty941--- PASS: TestGCTaskStore_GetEmpty (0.00s)942=== CONT TestCacheStatsHandler9432026/11/02 09:26:06 INFO lead: acquired remote=192.0.2.1:12349442026/11/02 09:26:06 INFO lead: released remote=192.0.2.1:1234945--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.28s)946=== CONT TestGCTaskStore_ConflictDifferentParams947--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)948=== CONT TestCacheConfigHandler949=== RUN TestCacheConfigHandler/full_config,_no_issuer950=== PAUSE TestCacheConfigHandler/full_config,_no_issuer951=== RUN TestCacheConfigHandler/no_cache_url_configured952=== PAUSE TestCacheConfigHandler/no_cache_url_configured953=== RUN TestCacheConfigHandler/no_signing_keys954=== PAUSE TestCacheConfigHandler/no_signing_keys955=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator956=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator957=== CONT TestUploadHandlersRejectOversizedBody9582026/11/02 09:26:06 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"959--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.31s)960=== CONT TestService_ReadScope_PublicByDefault961--- PASS: TestService_healthCheckHandler (0.31s)962=== CONT TestGCTaskStore_DeduplicateSameParams963--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)964=== CONT TestUploadHandlersRejectInvalidKeys965=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info966=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info967=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal968=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal969=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key970=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key971=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key972=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key973=== CONT TestGCTaskStore_StartNew974--- PASS: TestGCTaskStore_StartNew (0.00s)975=== CONT TestGCEndsOnShutdown976=== RUN TestGCEndsOnShutdown/before_the_run977=== PAUSE TestGCEndsOnShutdown/before_the_run978=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete979=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete980=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark981=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark982=== CONT TestForceGCDuringPushOffersSweptObject983=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows9842026/11/02 09:26:06 INFO lead: acquired remote=192.0.2.1:1234985=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows986=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check987=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check988=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9892026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures990--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.41s)991=== CONT TestService_RequireScope_OIDC992=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart993=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart994=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts995=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts996=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure997=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure998=== CONT TestCommitRacingPendingCleanupKeepsObjects9992026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures10002026/11/02 09:26:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10012026/11/02 09:26:06 INFO Aborted multipart uploads count=0 kept=010022026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures10032026/11/02 09:26:06 INFO Received cleanup request method=DELETE path=/api/pending_closures10042026/11/02 09:26:06 INFO Aborted multipart uploads count=1 kept=010052026/11/02 09:26:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10062026-11-02 09:26:06.616 UTC [485] ERROR: Closure does not exist: id=110072026-11-02 09:26:06.616 UTC [485] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10082026-11-02 09:26:06.616 UTC [485] STATEMENT: -- name: CommitPendingClosure :one1009 SELECT commit_pending_closure($1::bigint)::bigint1010 1011--- PASS: TestService_cleanupPendingClosuresHandler (0.49s)1012=== CONT TestGCSweepDeliversEachKeyOnce10132026/11/02 09:26:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026/11/02 09:26:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33585/oidc10152026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures10162026/11/02 09:26:06 INFO lead: acquired remote=192.0.2.1:12341017--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.59s)1018=== CONT TestService_AuthMiddleware_OIDC10192026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes10202026/11/02 09:26:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10212026/11/02 09:26:06 INFO Uploading x1z8ndlv4x9vf2hwnp2pa76bq8xyzkkd-top (224B)10222026/11/02 09:26:06 INFO Uploading afgyvwchd5afw6vg1lb2hfzqq6vi3i0a-shared-dep (136B)10232026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures1024=== NAME TestClientCADerivations1025 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1961553641/001/store/md55mq03mjpca8l9jylcyyanj1xmjv6w-ca-test10262026/11/02 09:26:06 WARN Failed to register uploaded object key=afgyvwchd5afw6vg1lb2hfzqq6vi3i0a.ls error="server returned 404: 404 page not found\n"10272026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10282026/11/02 09:26:06 WARN Failed to register uploaded object key=x1z8ndlv4x9vf2hwnp2pa76bq8xyzkkd.ls error="server returned 404: 404 page not found\n"10292026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10302026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/09xwn7wvkqcd7zvi4r9qxivyixzc61qz54xzdl5hc8l2rp65c5vi.nar.zst error="server returned 404: 404 page not found\n"10312026/11/02 09:26:06 INFO Signed narinfos id=1 count=210322026/11/02 09:26:06 INFO Uploading 2 narinfos10332026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures10342026/11/02 09:26:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10352026/11/02 09:26:06 INFO Uploading 09kcpjsqx9a4mxgraiwjzqrw57h9qwzg-b (216B)10362026/11/02 09:26:06 INFO Uploading 4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr-shared-dep (136B)10372026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/1/complete10382026/11/02 09:26:06 WARN Failed to register uploaded object key=afgyvwchd5afw6vg1lb2hfzqq6vi3i0a.narinfo error="server returned 404: 404 page not found\n"10392026/11/02 09:26:06 WARN Failed to register uploaded object key=x1z8ndlv4x9vf2hwnp2pa76bq8xyzkkd.narinfo error="server returned 404: 404 page not found\n"10402026/11/02 09:26:06 WARN Failed to register uploaded object key=4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr.ls error="server returned 404: 404 page not found\n"10412026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10422026/11/02 09:26:06 WARN Failed to register uploaded object key=m0nrri7n8asliygdq3x91fbfrzywb2yn.ls error="server returned 404: 404 page not found\n"10432026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1mdc30y9h8yfx00g880b56wv32hx81r14020b1xl0nbszl8snal7.nar.zst error="server returned 404: 404 page not found\n"10442026/11/02 09:26:06 WARN Failed to register uploaded object key=09kcpjsqx9a4mxgraiwjzqrw57h9qwzg.ls error="server returned 404: 404 page not found\n"10452026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10462026/11/02 09:26:06 INFO Signed narinfos id=1 count=210472026/11/02 09:26:06 INFO Completed push id=1 objects=6 duration=6.487478ms10482026/11/02 09:26:06 INFO Upload complete. (64ms)10492026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10502026/11/02 09:26:06 INFO Signed narinfos id=2 count=210512026/11/02 09:26:06 INFO Uploading 4 narinfos1052--- PASS: TestCacheStatsHandler (0.56s)1053=== CONT TestTombstonedObjectOfferedWithoutWaiting1054=== NAME TestClientSharedPathCommittedMidPush1055 client_integration_test.go:727: Retrieved narinfo from S3:1056 StorePath: /build/TestClientSharedPathCommittedMidPush4175778413/001/store/afgyvwchd5afw6vg1lb2hfzqq6vi3i0a-shared-dep1057 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1058 Compression: zstd1059 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821060 NarSize: 1361061 References: 1062 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10632026/11/02 09:26:06 WARN Failed to register uploaded object key=4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr.narinfo error="server returned 404: 404 page not found\n"10642026/11/02 09:26:06 WARN Failed to register uploaded object key=m0nrri7n8asliygdq3x91fbfrzywb2yn.narinfo error="server returned 404: 404 page not found\n"10652026/11/02 09:26:06 WARN Failed to register uploaded object key=09kcpjsqx9a4mxgraiwjzqrw57h9qwzg.narinfo error="server returned 404: 404 page not found\n"1066 client_integration_test.go:727: Retrieved narinfo from S3:1067 StorePath: /build/TestClientSharedPathCommittedMidPush4175778413/001/store/x1z8ndlv4x9vf2hwnp2pa76bq8xyzkkd-top1068 URL: nar/09xwn7wvkqcd7zvi4r9qxivyixzc61qz54xzdl5hc8l2rp65c5vi.nar.zst1069 Compression: zstd1070 NarHash: sha256:09xwn7wvkqcd7zvi4r9qxivyixzc61qz54xzdl5hc8l2rp65c5vi1071 NarSize: 2241072 References: /build/TestClientSharedPathCommittedMidPush4175778413/001/store/afgyvwchd5afw6vg1lb2hfzqq6vi3i0a-shared-dep1073 CA: text:sha256:1f1clslq1p5nav0756zxi6afcix44mj47hwx6az0qllg8qs5bvas10742026/11/02 09:26:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10752026/11/02 09:26:06 WARN Failed to register uploaded object key=4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr.narinfo error="server returned 404: 404 page not found\n"1076--- PASS: TestClientSharedPathCommittedMidPush (0.64s)1077=== CONT TestService_ReadAuthMiddleware10782026/11/02 09:26:06 INFO Completed upload id=1 objects=6 duration=4.617882ms10792026/11/02 09:26:06 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10802026/11/02 09:26:06 INFO Completed upload id=2 objects=6 duration=1.664555ms10812026/11/02 09:26:06 INFO Upload complete. (67ms)1082=== NAME TestClientFallsBackToClosures1083 client_pushes_test.go:112: Retrieved narinfo from S3:1084 StorePath: /build/TestClientFallsBackToClosures772280526/001/store/4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr-shared-dep1085 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1086 Compression: zstd1087 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821088 NarSize: 1361089 References: 1090 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1091 client_pushes_test.go:112: Retrieved narinfo from S3:1092 StorePath: /build/TestClientFallsBackToClosures772280526/001/store/m0nrri7n8asliygdq3x91fbfrzywb2yn-a1093 URL: nar/1mdc30y9h8yfx00g880b56wv32hx81r14020b1xl0nbszl8snal7.nar.zst1094 Compression: zstd1095 NarHash: sha256:1mdc30y9h8yfx00g880b56wv32hx81r14020b1xl0nbszl8snal71096 NarSize: 2161097 References: /build/TestClientFallsBackToClosures772280526/001/store/4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr-shared-dep1098 CA: text:sha256:0fq41pz5cy4aagc170wd5pwjg4a5bvw5w4ym1g2h1vqr2rxyln9l1099=== NAME TestClientCADerivations1100 client_ca_test.go:139: Found 1 dependencies (including self)1101=== NAME TestClientFallsBackToClosures1102 client_pushes_test.go:112: Retrieved narinfo from S3:1103 StorePath: /build/TestClientFallsBackToClosures772280526/001/store/09kcpjsqx9a4mxgraiwjzqrw57h9qwzg-b1104 URL: nar/1mdc30y9h8yfx00g880b56wv32hx81r14020b1xl0nbszl8snal7.nar.zst1105 Compression: zstd1106 NarHash: sha256:1mdc30y9h8yfx00g880b56wv32hx81r14020b1xl0nbszl8snal71107 NarSize: 2161108 References: /build/TestClientFallsBackToClosures772280526/001/store/4w6g3jlnynbvgdqi9rzg7f3g0vhlkgsr-shared-dep1109 CA: text:sha256:0fq41pz5cy4aagc170wd5pwjg4a5bvw5w4ym1g2h1vqr2rxyln9l1110--- PASS: TestClientFallsBackToClosures (0.66s)1111=== CONT TestGCSweepSkipsPendingObjects11122026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes11132026/11/02 09:26:06 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11142026/11/02 09:26:06 INFO Uploading a1h3i8nvvw6ishz2iph78z3hff0n8sph-shared-dep (136B)11152026/11/02 09:26:06 INFO Uploading xmcpxxn2ymxr665cc7gc8df6s7jidlnk-b (216B)11162026/11/02 09:26:06 WARN Failed to register uploaded object key=a1h3i8nvvw6ishz2iph78z3hff0n8sph.ls error="server returned 404: 404 page not found\n"11172026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11182026/11/02 09:26:06 WARN Failed to register uploaded object key=xmcpxxn2ymxr665cc7gc8df6s7jidlnk.ls error="server returned 404: 404 page not found\n"11192026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11202026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1if6jfwv8b0gi3hlc3rx5v2qvzlaxcgvqgbagfp8k3b892kw9gfz.nar.zst error="server returned 404: 404 page not found\n"11212026/11/02 09:26:06 WARN Failed to register uploaded object key=a46r9jslal19zs1snrciajib0acnyrqv.ls error="server returned 404: 404 page not found\n"11222026/11/02 09:26:06 INFO Signed narinfos id=1 count=311232026/11/02 09:26:06 INFO Uploading 3 narinfos11242026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/1/complete11252026/11/02 09:26:06 WARN Failed to register uploaded object key=a46r9jslal19zs1snrciajib0acnyrqv.narinfo error="server returned 404: 404 page not found\n"11262026/11/02 09:26:06 WARN Failed to register uploaded object key=a1h3i8nvvw6ishz2iph78z3hff0n8sph.narinfo error="server returned 404: 404 page not found\n"11272026/11/02 09:26:06 WARN Failed to register uploaded object key=xmcpxxn2ymxr665cc7gc8df6s7jidlnk.narinfo error="server returned 404: 404 page not found\n"1128=== NAME TestPinProtectsFromGC1129 client_integration_test.go:778: Pinned store path: /build/TestPinProtectsFromGC4195958578/001/store/594q5nac75v6vj21knw567z3wm1nc7di-pinned-file.txt1130 client_integration_test.go:779: Unpinned store path: /build/TestPinProtectsFromGC4195958578/001/store/kjy8y187fqilb09c550bczhy08jcgllw-unpinned-file.txt11312026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures11322026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures1133=== NAME TestClientMultipleUploads1134 client_integration_test.go:405: Created store path 0: /build/TestClientMultipleUploads4168356270/001/store/mib4vs36axapn30h22jj888g4pzbndys-test-file-0.txt11352026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures11362026/11/02 09:26:06 INFO Completed push id=1 objects=8 duration=7.726329ms11372026/11/02 09:26:06 INFO Upload complete. (63ms)1138=== NAME TestClientPushesUseOnePush1139 client_pushes_test.go:97: Retrieved narinfo from S3:1140 StorePath: /build/TestClientPushesUseOnePush1031934261/001/store/a1h3i8nvvw6ishz2iph78z3hff0n8sph-shared-dep1141 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1142 Compression: zstd1143 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821144 NarSize: 1361145 References: 1146 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1147 client_pushes_test.go:97: Retrieved narinfo from S3:1148 StorePath: /build/TestClientPushesUseOnePush1031934261/001/store/a46r9jslal19zs1snrciajib0acnyrqv-a1149 URL: nar/1if6jfwv8b0gi3hlc3rx5v2qvzlaxcgvqgbagfp8k3b892kw9gfz.nar.zst1150 Compression: zstd1151 NarHash: sha256:1if6jfwv8b0gi3hlc3rx5v2qvzlaxcgvqgbagfp8k3b892kw9gfz1152 NarSize: 2161153 References: /build/TestClientPushesUseOnePush1031934261/001/store/a1h3i8nvvw6ishz2iph78z3hff0n8sph-shared-dep1154 CA: text:sha256:0kx5fmgb27424pb44yic863izhd0z33q6pbpc2yi82mijgmfanpc1155 client_pushes_test.go:97: Retrieved narinfo from S3:1156 StorePath: /build/TestClientPushesUseOnePush1031934261/001/store/xmcpxxn2ymxr665cc7gc8df6s7jidlnk-b1157 URL: nar/1if6jfwv8b0gi3hlc3rx5v2qvzlaxcgvqgbagfp8k3b892kw9gfz.nar.zst1158 Compression: zstd1159 NarHash: sha256:1if6jfwv8b0gi3hlc3rx5v2qvzlaxcgvqgbagfp8k3b892kw9gfz1160 NarSize: 2161161 References: /build/TestClientPushesUseOnePush1031934261/001/store/a1h3i8nvvw6ishz2iph78z3hff0n8sph-shared-dep1162 CA: text:sha256:0kx5fmgb27424pb44yic863izhd0z33q6pbpc2yi82mijgmfanpc1163--- PASS: TestClientPushesUseOnePush (0.71s)1164=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11652026/11/02 09:26:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38445/oidc11662026/11/02 09:26:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11672026/11/02 09:26:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1168--- PASS: TestCompleteMultipartUnregistered (0.72s)1169=== CONT TestPushWaitsForSweepHoldingRow1170=== NAME TestClientMultipleUploads1171 client_integration_test.go:405: Created store path 1: /build/TestClientMultipleUploads4168356270/001/store/7z1n7rf7w8nlrag9d1wkd449wrvinrii-test-file-1.txt11722026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes11732026/11/02 09:26:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11742026/11/02 09:26:06 INFO Uploading md55mq03mjpca8l9jylcyyanj1xmjv6w-ca-test (144B)11752026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes11762026/11/02 09:26:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11772026/11/02 09:26:06 INFO Uploading 594q5nac75v6vj21knw567z3wm1nc7di-pinned-file.txt (128B)1178=== NAME TestClientWithDependencies1179 client_integration_test.go:660: Built derivation: /build/TestClientWithDependencies1707972908/001/store/9d59xp8y7pwfhhh8ph45jw6snwn7bgf6-test-script11802026/11/02 09:26:06 WARN Failed to register uploaded object key=md55mq03mjpca8l9jylcyyanj1xmjv6w.ls error="server returned 404: 404 page not found\n"11812026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"11822026/11/02 09:26:06 WARN Failed to register uploaded object key=log/xwjj111gzd74s59ml854x3ds2kh485cc-ca-test.drv error="server returned 404: 404 page not found\n"11832026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11842026/11/02 09:26:06 INFO Signed narinfos id=1 count=111852026/11/02 09:26:06 INFO Uploading 1 narinfos1186=== NAME TestClientMultipleUploads1187 client_integration_test.go:405: Created store path 2: /build/TestClientMultipleUploads4168356270/001/store/2s93gmza19axlkvh40b1ld47zz7nbnwx-test-file-2.txt11882026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11892026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11902026/11/02 09:26:06 WARN Failed to register uploaded object key=594q5nac75v6vj21knw567z3wm1nc7di.ls error="server returned 404: 404 page not found\n"11912026/11/02 09:26:06 INFO Signed narinfos id=1 count=111922026/11/02 09:26:06 INFO Uploading 1 narinfos11932026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/1/complete11942026/11/02 09:26:06 WARN Failed to register uploaded object key=md55mq03mjpca8l9jylcyyanj1xmjv6w.narinfo error="server returned 404: 404 page not found\n"11952026/11/02 09:26:06 INFO Received uploads request method=POST path=/api/pending_closures11962026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/1/complete11972026/11/02 09:26:06 WARN Failed to register uploaded object key=594q5nac75v6vj21knw567z3wm1nc7di.narinfo error="server returned 404: 404 page not found\n"11982026/11/02 09:26:06 INFO Completed push id=1 objects=4 duration=7.171824ms11992026/11/02 09:26:06 INFO Upload complete. (92ms)12002026/11/02 09:26:06 INFO Completed push id=1 objects=3 duration=6.942322ms12012026/11/02 09:26:06 INFO Upload complete. (61ms)1202=== NAME TestClientCADerivations1203 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1961553641/001/store/md55mq03mjpca8l9jylcyyanj1xmjv6w-ca-test1204 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1205 Compression: zstd1206 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1207 NarSize: 1441208 References: 1209 Deriver: /build/TestClientCADerivations1961553641/001/store/xwjj111gzd74s59ml854x3ds2kh485cc-ca-test.drv1210 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1211 client_ca_test.go:185: Checking for realisation files in S3...1212 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1213 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1214--- PASS: TestService_ReadScope_PublicByDefault (0.49s)1215=== CONT TestService_AuthMiddleware_MTLSProxyHeader1216=== NAME TestClientIntegration1217 client_integration_test.go:291: Created store path: /build/TestClientIntegration3991957125/002/store/ww02bgzg85wcbjx1b327a6sl69x3zwnj-test-file.txt1218=== NAME TestClientWithDependencies1219 client_integration_test.go:662: Found 1 dependencies (including self)1220--- PASS: TestGCBugBareHashReferences (0.80s)1221=== CONT TestSweepRechecksPendingAfterLocking12222026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes12232026/11/02 09:26:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12242026/11/02 09:26:06 INFO Uploading 7z1n7rf7w8nlrag9d1wkd449wrvinrii-test-file-1.txt (160B)12252026/11/02 09:26:06 INFO Uploading mib4vs36axapn30h22jj888g4pzbndys-test-file-0.txt (160B)12262026/11/02 09:26:06 INFO Uploading 2s93gmza19axlkvh40b1ld47zz7nbnwx-test-file-2.txt (160B)12272026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes12282026/11/02 09:26:06 WARN Failed to register uploaded object key=7z1n7rf7w8nlrag9d1wkd449wrvinrii.ls error="server returned 404: 404 page not found\n"12292026/11/02 09:26:06 WARN Failed to register uploaded object key=mib4vs36axapn30h22jj888g4pzbndys.ls error="server returned 404: 404 page not found\n"12302026/11/02 09:26:06 WARN Failed to register uploaded object key=2s93gmza19axlkvh40b1ld47zz7nbnwx.ls error="server returned 404: 404 page not found\n"12312026/11/02 09:26:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12322026/11/02 09:26:06 INFO Uploading kjy8y187fqilb09c550bczhy08jcgllw-unpinned-file.txt (128B)12332026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12342026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12352026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12362026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12372026/11/02 09:26:06 INFO Signed narinfos id=1 count=312382026/11/02 09:26:06 INFO Uploading 3 narinfos12392026/11/02 09:26:06 WARN Failed to register uploaded object key=kjy8y187fqilb09c550bczhy08jcgllw.ls error="server returned 404: 404 page not found\n"12402026/11/02 09:26:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12412026/11/02 09:26:06 WARN Failed to register uploaded object key=mib4vs36axapn30h22jj888g4pzbndys.narinfo error="server returned 404: 404 page not found\n"12422026/11/02 09:26:06 WARN Failed to register uploaded object key=7z1n7rf7w8nlrag9d1wkd449wrvinrii.narinfo error="server returned 404: 404 page not found\n"12432026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/1/complete12442026/11/02 09:26:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12452026/11/02 09:26:06 INFO Signed narinfos id=2 count=112462026/11/02 09:26:06 WARN Failed to register uploaded object key=2s93gmza19axlkvh40b1ld47zz7nbnwx.narinfo error="server returned 404: 404 page not found\n"12472026/11/02 09:26:06 INFO Uploading 1 narinfos12482026/11/02 09:26:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12492026/11/02 09:26:06 INFO Received complete push request method=POST path=/api/pushes/2/complete12502026/11/02 09:26:06 WARN Failed to register uploaded object key=kjy8y187fqilb09c550bczhy08jcgllw.narinfo error="server returned 404: 404 page not found\n"12512026/11/02 09:26:06 INFO Aborted multipart uploads count=0 kept=012522026/11/02 09:26:06 INFO Completed push id=1 objects=9 duration=6.471679ms12532026/11/02 09:26:06 INFO Upload complete. (64ms)1254=== NAME TestClientMultipleUploads1255 client_integration_test.go:416: Uploaded 3 paths in 98.806147ms12562026/11/02 09:26:06 INFO Completed push id=2 objects=3 duration=2.422182ms12572026/11/02 09:26:06 INFO Upload complete. (51ms)12582026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes12592026/11/02 09:26:06 WARN Force mode enabled - objects will be deleted immediately without grace period12602026/11/02 09:26:06 INFO Aborted multipart uploads count=0 kept=012612026/11/02 09:26:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12622026/11/02 09:26:06 INFO Uploading ww02bgzg85wcbjx1b327a6sl69x3zwnj-test-file.txt (152B)1263--- PASS: TestClientMultipleUploads (0.87s)1264=== CONT TestService_AuthMiddleware12652026/11/02 09:26:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012662026/11/02 09:26:06 INFO Received push request method=POST path=/api/pushes12672026/11/02 09:26:07 INFO Vacuumed table table=pending_closures12682026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period12692026/11/02 09:26:07 INFO Vacuumed table table=pending_objects12702026/11/02 09:26:07 WARN Failed to register uploaded object key=ww02bgzg85wcbjx1b327a6sl69x3zwnj.ls error="server returned 404: 404 page not found\n"12712026/11/02 09:26:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12722026/11/02 09:26:07 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12732026/11/02 09:26:07 INFO Signed narinfos id=1 count=112742026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads12752026/11/02 09:26:07 INFO Uploading 1 narinfos12762026/11/02 09:26:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12772026/11/02 09:26:07 INFO Uploading 9d59xp8y7pwfhhh8ph45jw6snwn7bgf6-test-script (136B)12782026/11/02 09:26:07 INFO Vacuumed table table=closures12792026/11/02 09:26:07 INFO Vacuumed table table=objects12802026/11/02 09:26:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjIyMWUxMjZkLTJhMmUtNDU5OS1hYWI0LTA4NWFiMjgwOTI5MngxNzkzNjExNTY2NjcxNTEzMjU0 parts=1012812026/11/02 09:26:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1282=== RUN TestService_RequireScope_OIDC/builder_may_write1283=== PAUSE TestService_RequireScope_OIDC/builder_may_write1284=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1285=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1286=== RUN TestService_RequireScope_OIDC/ops_may_admin1287=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1288=== RUN TestService_RequireScope_OIDC/ops_may_not_write1289=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1290=== RUN TestService_RequireScope_OIDC/reader_may_not_write1291=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1292=== RUN TestService_RequireScope_OIDC/static_token_may_admin1293=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1294=== RUN TestService_RequireScope_OIDC/static_token_may_write1295=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1296=== RUN TestService_RequireScope_OIDC/reader_may_read1297=== PAUSE TestService_RequireScope_OIDC/reader_may_read1298=== RUN TestService_RequireScope_OIDC/writer_implies_read1299=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1300=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1301=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1302=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1303=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1304=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1305=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1306=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1307=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1308=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1309=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1310=== CONT TestDeduplicatedObjectsRecordedAsPending13112026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/1/complete13122026/11/02 09:26:07 WARN Failed to register uploaded object key=ww02bgzg85wcbjx1b327a6sl69x3zwnj.narinfo error="server returned 404: 404 page not found\n"13132026/11/02 09:26:07 INFO Completed upload id=1 objects=2 duration=2.480323ms13142026/11/02 09:26:07 WARN Failed to register uploaded object key=9d59xp8y7pwfhhh8ph45jw6snwn7bgf6.ls error="server returned 404: 404 page not found\n"13152026/11/02 09:26:07 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13162026/11/02 09:26:07 WARN Failed to register uploaded object key=log/an3w70dhaiwkdzhikz096i0hfy8qyjc5-test-script.drv error="server returned 404: 404 page not found\n"13172026/11/02 09:26:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13182026/11/02 09:26:07 INFO Signed narinfos id=1 count=113192026/11/02 09:26:07 INFO Uploading 1 narinfos13202026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures1321--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.47s)1322=== CONT TestGetExistingObjectsLocksRows13232026/11/02 09:26:07 INFO Completed push id=1 objects=3 duration=5.49203ms13242026/11/02 09:26:07 INFO Upload complete. (61ms)13252026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/1/complete13262026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures13272026/11/02 09:26:07 WARN Failed to register uploaded object key=9d59xp8y7pwfhhh8ph45jw6snwn7bgf6.narinfo error="server returned 404: 404 page not found\n"13282026/11/02 09:26:07 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13292026/11/02 09:26:07 WARN Found objects in DB but missing from S3, will re-upload count=11330--- PASS: TestService_verifyS3Integrity (0.89s)1331=== CONT TestPushDedupSurvivesConcurrentGC13322026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures13332026/11/02 09:26:07 INFO Completed push id=1 objects=4 duration=7.395046ms13342026/11/02 09:26:07 INFO Upload complete. (66ms)1335=== NAME TestClientWithDependencies1336 client_integration_test.go:664: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1707972908/001/store) requires matching store prefix13372026/11/02 09:26:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures13382026/11/02 09:26:07 INFO Garbage collection started1339--- PASS: TestClientWithDependencies (0.90s)1340=== CONT TestFailedS3DeleteKeepsTombstone1341--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.28s)1342=== CONT TestGCMetrics13432026/11/02 09:26:07 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=013442026/11/02 09:26:07 INFO Vacuumed table table=pending_closures13452026/11/02 09:26:07 INFO Vacuumed table table=pending_objects13462026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads13472026/11/02 09:26:07 INFO Vacuumed table table=closures1348--- PASS: TestService_ReadAuthMiddleware (0.28s)1349=== CONT TestSweepSkipsRowsLockedByPush13502026/11/02 09:26:07 INFO Vacuumed table table=objects1351--- PASS: TestGCSweepDeliversEachKeyOnce (0.43s)1352=== CONT TestRegisterCompletedObjectNeedsPendingRow13532026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=01354=== NAME TestClientCADerivations1355 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1356 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1357 error: binary cache 's3://bucket16?endpoint=http://localhost:37859®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1961553641/001/store'1358 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 113592026/11/02 09:26:07 INFO All 1 paths already cached1360=== NAME TestClientIntegration1361 client_integration_test.go:317: Retrieved narinfo from S3:1362 StorePath: /build/TestClientIntegration3991957125/002/store/ww02bgzg85wcbjx1b327a6sl69x3zwnj-test-file.txt1363 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1364 Compression: zstd1365 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11366 NarSize: 1521367 References: 1368 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11369--- PASS: TestClientCADerivations (0.93s)1370=== CONT TestReadProxy40413712026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period1372=== NAME TestClientIntegration1373 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1374 client_integration_test.go:318: Decompressed .ls content (64 bytes):1375 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}13762026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures1377=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1378=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1379=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1380=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1381=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1382=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1383=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1384=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1385=== CONT TestPush_RepeatedRootCommitsOnce13862026/11/02 09:26:07 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=013872026/11/02 09:26:07 INFO Vacuumed table table=pending_closures13882026/11/02 09:26:07 INFO Vacuumed table table=pending_objects13892026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=013902026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads13912026/11/02 09:26:07 INFO Vacuumed table table=closures1392--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.65s)1393=== CONT TestReadRedirectNar13942026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period13952026/11/02 09:26:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13962026/11/02 09:26:07 WARN mTLS auth: bound subjects configured but subject DN unavailable13972026/11/02 09:26:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1398--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.28s)1399=== CONT TestReadProxyDisabled14002026/11/02 09:26:07 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014012026/11/02 09:26:07 INFO Vacuumed table table=objects14022026/11/02 09:26:07 INFO Vacuumed table table=pending_closures14032026/11/02 09:26:07 INFO Vacuumed table table=pending_objects14042026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads14052026/11/02 09:26:07 INFO Vacuumed table table=closures14062026/11/02 09:26:07 INFO Vacuumed table table=objects1407--- PASS: TestGCSweepSkipsPendingObjects (0.35s)1408=== CONT TestPush_CompleteCommitsEveryRoot14092026/11/02 09:26:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14102026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures14112026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes14122026/11/02 09:26:07 INFO Object in database but missing from S3 key=ww02bgzg85wcbjx1b327a6sl69x3zwnj.ls14132026/11/02 09:26:07 WARN Found objects in DB but missing from S3, will re-upload count=114142026/11/02 09:26:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14152026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/2/complete14162026/11/02 09:26:07 WARN Failed to register uploaded object key=ww02bgzg85wcbjx1b327a6sl69x3zwnj.ls error="server returned 404: 404 page not found\n"14172026/11/02 09:26:07 INFO Completed push id=2 objects=3 duration=4.574001ms14182026/11/02 09:26:07 INFO Upload complete. (59ms)1419=== NAME TestClientIntegration1420 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1421 client_integration_test.go:335: Decompressed .ls content (49 bytes):1422 {"version":1,"root":{"type":"regular","size":39}}14232026/11/02 09:26:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmI1N2MxMjk3LWEyNTUtNGVjMi05MzAwLTQyY2I2NzE1OWY2MXgxNzkzNjExNTY2ODI0Mzk2MzQ2 parts=1014242026/11/02 09:26:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14252026/11/02 09:26:07 INFO Completed upload id=1 objects=2 duration=4.159497ms14262026/11/02 09:26:07 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000014272026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures14282026/11/02 09:26:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures14292026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=014302026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=014312026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period1432--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)1433=== CONT TestService_Rustfstest14342026/11/02 09:26:07 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=014352026/11/02 09:26:07 INFO Vacuumed table table=pending_closures14362026/11/02 09:26:07 INFO Vacuumed table table=pending_objects14372026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads14382026/11/02 09:26:07 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=014392026/11/02 09:26:07 INFO Vacuumed table table=closures14402026/11/02 09:26:07 INFO Vacuumed table table=objects14412026/11/02 09:26:07 INFO Vacuumed table table=pending_closures14422026/11/02 09:26:07 INFO Vacuumed table table=pending_objects14432026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads14442026/11/02 09:26:07 INFO Vacuumed table table=closures14452026/11/02 09:26:07 INFO Vacuumed table table=objects14462026/11/02 09:26:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1447--- PASS: TestService_AuthMiddleware (0.22s)1448=== CONT TestReadProxyRootRedirectsToIndexHTML1449--- PASS: TestSweepRechecksPendingAfterLocking (0.30s)1450=== CONT TestPush_OverlappingRootsStoreOneRowPerKey14512026/11/02 09:26:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001452--- PASS: TestService_createPendingClosureHandler (1.10s)1453=== CONT TestPresignedUploadRegisteredBeforeCommit14542026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures14552026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes1456--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.25s)1457=== CONT TestReadProxyConditionalGet14582026/11/02 09:26:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14592026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/3/complete14602026/11/02 09:26:07 WARN Failed to register uploaded object key=ww02bgzg85wcbjx1b327a6sl69x3zwnj.ls error="server returned 404: 404 page not found\n"14612026/11/02 09:26:07 INFO Completed push id=3 objects=3 duration=2.592423ms14622026/11/02 09:26:07 INFO Upload complete. (46ms)1463=== NAME TestClientIntegration1464 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1465 client_integration_test.go:352: Decompressed .ls content (49 bytes):1466 {"version":1,"root":{"type":"regular","size":39}}1467 client_integration_test.go:363: Testing garbage collection...1468--- PASS: TestGetExistingObjectsLocksRows (0.27s)1469=== CONT TestReadRedirectUsesPublicS3URL14702026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures14712026/11/02 09:26:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures14722026/11/02 09:26:07 INFO Garbage collection started1473--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.27s)1474=== CONT TestReadProxyOutlastsServerWriteTimeout14752026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=014762026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period14772026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures14782026/11/02 09:26:07 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=014792026/11/02 09:26:07 INFO Vacuumed table table=pending_closures14802026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=014812026/11/02 09:26:07 INFO Vacuumed table table=pending_objects14822026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads14832026/11/02 09:26:07 INFO Vacuumed table table=closures14842026/11/02 09:26:07 INFO Vacuumed table table=objects14852026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period14862026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=014872026/11/02 09:26:07 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=014882026/11/02 09:26:07 INFO Vacuumed table table=pending_closures14892026/11/02 09:26:07 INFO Vacuumed table table=pending_objects14902026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads14912026/11/02 09:26:07 INFO Vacuumed table table=closures14922026/11/02 09:26:07 INFO Vacuumed table table=objects14932026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period1494--- PASS: TestGCMetrics (0.35s)1495=== CONT TestReadProxyRangeRequest14962026/11/02 09:26:07 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14972026/11/02 09:26:07 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1498--- PASS: TestFailedS3DeleteKeepsTombstone (0.36s)1499=== CONT TestCompletedNarNotReofferedAcrossClosures15002026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=015012026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period15022026/11/02 09:26:07 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/11/02 09:26:07 INFO Vacuumed table table=pending_closures15042026/11/02 09:26:07 INFO Vacuumed table table=pending_objects15052026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads15062026/11/02 09:26:07 INFO Vacuumed table table=closures15072026/11/02 09:26:07 INFO Vacuumed table table=objects15082026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=015092026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes15102026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=015112026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period15122026/11/02 09:26:07 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=015132026/11/02 09:26:07 INFO Vacuumed table table=pending_closures15142026/11/02 09:26:07 INFO Vacuumed table table=pending_objects15152026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/1/complete15162026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads15172026/11/02 09:26:07 INFO Vacuumed table table=closures15182026/11/02 09:26:07 INFO Vacuumed table table=objects15192026/11/02 09:26:07 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=015202026/11/02 09:26:07 INFO Vacuumed table table=pending_closures15212026/11/02 09:26:07 INFO Completed push id=1 objects=4 duration=8.621477ms15222026/11/02 09:26:07 INFO Vacuumed table table=pending_objects1523--- PASS: TestPush_RepeatedRootCommitsOnce (0.36s)1524=== CONT TestReadProxyHead15252026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads15262026/11/02 09:26:07 INFO Vacuumed table table=closures15272026/11/02 09:26:07 INFO Aborted multipart uploads count=0 kept=01528--- PASS: TestReadProxy404 (0.39s)1529=== CONT TestReadRedirectKeepsNarinfoProxied15302026/11/02 09:26:07 WARN Force mode enabled - objects will be deleted immediately without grace period15312026/11/02 09:26:07 INFO Vacuumed table table=objects15322026/11/02 09:26:07 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=01533--- PASS: TestSweepSkipsRowsLockedByPush (0.41s)1534=== CONT TestCompleteRefusedAfterAbortClaim1535--- PASS: TestReadRedirectNar (0.35s)1536=== CONT TestReadProxyInvalidPath15372026/11/02 09:26:07 INFO Vacuumed table table=pending_closures15382026/11/02 09:26:07 INFO Vacuumed table table=pending_objects15392026/11/02 09:26:07 INFO Vacuumed table table=multipart_uploads15402026/11/02 09:26:07 INFO Vacuumed table table=closures15412026/11/02 09:26:07 INFO Vacuumed table table=objects1542--- PASS: TestPushDedupSurvivesConcurrentGC (0.44s)1543=== CONT TestObjectStatsUpdatedOncePerCommit1544--- PASS: TestReadProxyDisabled (0.36s)1545=== CONT TestParseSingleRange1546=== RUN TestParseSingleRange/none1547=== PAUSE TestParseSingleRange/none1548=== RUN TestParseSingleRange/unknown_unit1549=== PAUSE TestParseSingleRange/unknown_unit1550=== RUN TestParseSingleRange/multi-range_ignored1551=== PAUSE TestParseSingleRange/multi-range_ignored1552=== RUN TestParseSingleRange/malformed_no_dash1553=== PAUSE TestParseSingleRange/malformed_no_dash1554=== RUN TestParseSingleRange/malformed_both_empty1555=== PAUSE TestParseSingleRange/malformed_both_empty1556=== RUN TestParseSingleRange/malformed_end_before_start1557=== PAUSE TestParseSingleRange/malformed_end_before_start1558=== RUN TestParseSingleRange/closed1559=== PAUSE TestParseSingleRange/closed1560=== RUN TestParseSingleRange/open-ended1561=== PAUSE TestParseSingleRange/open-ended1562=== RUN TestParseSingleRange/end_clamped_to_size1563=== PAUSE TestParseSingleRange/end_clamped_to_size1564=== RUN TestParseSingleRange/suffix1565=== PAUSE TestParseSingleRange/suffix1566=== RUN TestParseSingleRange/suffix_exceeds_size1567=== PAUSE TestParseSingleRange/suffix_exceeds_size1568=== RUN TestParseSingleRange/single_byte1569=== PAUSE TestParseSingleRange/single_byte1570=== RUN TestParseSingleRange/start_past_EOF1571=== PAUSE TestParseSingleRange/start_past_EOF1572=== RUN TestParseSingleRange/start_far_past_EOF1573=== PAUSE TestParseSingleRange/start_far_past_EOF1574=== CONT TestMetricsCommit15752026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes15762026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/1/complete1577--- PASS: TestService_Rustfstest (0.32s)1578=== CONT TestReadProxyNarStreaming15792026/11/02 09:26:07 INFO Completed push id=1 objects=6 duration=16.366186ms1580--- PASS: TestPush_CompleteCommitsEveryRoot (0.39s)1581=== CONT TestPresentNotReportedWhileGCDeletesClosure1582=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1583=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1584=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1585=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1586=== CONT TestObjectStatsTrigger15872026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes1588--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.34s)1589=== CONT TestReadProxyContentNegotiation15902026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures15912026/11/02 09:26:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst15922026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures1593--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.35s)1594=== CONT TestPendingCleanupUsesOneCutoff1595--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.37s)1596=== CONT TestReadProxyNarinfoAlreadyDecompressed1597--- PASS: TestReadProxyConditionalGet (0.36s)1598=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1599--- PASS: TestReadRedirectUsesPublicS3URL (0.36s)1600=== CONT TestPresentRefreshesOnlyStaleClosures1601--- PASS: TestPushWaitsForSweepHoldingRow (0.81s)1602=== CONT TestReadProxyNarinfo1603--- PASS: TestReadProxyRangeRequest (0.29s)1604=== CONT TestMultipartCleanup16052026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures16062026/11/02 09:26:07 INFO lead: released remote=192.0.2.1:12341607--- PASS: TestReadProxyHead (0.27s)1608=== CONT TestPresentReportsOnlyClosureRoots1609--- PASS: TestReadProxyInvalidPath (0.28s)1610=== CONT TestServerTLSConfig1611=== RUN TestServerTLSConfig/no_client_CA1612=== PAUSE TestServerTLSConfig/no_client_CA1613=== RUN TestServerTLSConfig/missing_CA_file1614=== PAUSE TestServerTLSConfig/missing_CA_file1615=== RUN TestServerTLSConfig/not_a_PEM_file1616=== PAUSE TestServerTLSConfig/not_a_PEM_file1617=== CONT TestCreatePin_ReservedPins16182026/11/02 09:26:07 INFO lead: acquired remote=192.0.2.1:12341619--- PASS: TestDeleteClosuresRacingPins (1.64s)1620=== CONT TestService_NativeMTLS1621--- PASS: TestReadRedirectKeepsNarinfoProxied (0.31s)1622=== CONT TestRedundantAbortSkipsCompletingUpload16232026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures16242026/11/02 09:26:07 INFO lead: released remote=192.0.2.1:12341625--- PASS: TestLeadEndsOnShutdown (1.69s)1626=== CONT TestOrphanedObjectsGCStressTest16272026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures1628--- PASS: TestObjectStatsUpdatedOncePerCommit (0.35s)1629=== CONT TestOrphanedObjectsGC16302026/11/02 09:26:07 INFO Received push request method=POST path=/api/pushes16312026/11/02 09:26:07 INFO Received complete push request method=POST path=/api/pushes/1/complete16322026/11/02 09:26:07 INFO Completed push id=1 objects=4 duration=9.806268ms1633--- PASS: TestReadProxyNarStreaming (0.34s)1634=== CONT TestPush_RejectsBadRequests16352026/11/02 09:26:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16362026/11/02 09:26:07 INFO Completed upload id=2 objects=2 duration=7.600088ms1637--- PASS: TestMetricsCommit (0.40s)1638=== CONT TestPush_RootsAreLockedInByteOrder1639--- PASS: TestObjectStatsTrigger (0.36s)1640=== CONT TestPush_CompleteWaitsForCleanupOfThePush16412026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures16422026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures16432026/11/02 09:26:07 INFO Received cleanup request method=DELETE path=/api/pending_closures1644--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.36s)1645=== CONT TestCompleteMultipartUpload_ErrorButObjectExists16462026/11/02 09:26:07 INFO Received uploads request method=POST path=/api/pending_closures1647--- PASS: TestReadProxyContentNegotiation (0.42s)1648=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1649--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.37s)1650=== CONT TestRedundantMultipartUpload16512026/11/02 09:26:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43293/oidc1652--- PASS: TestPresentRefreshesOnlyStaleClosures (0.37s)1653=== CONT TestCreatePendingClosureRejectsOversizedNAR16542026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1655--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1656=== CONT TestMetricsInventory16572026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures16582026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16592026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjU1ZmNjOTBmLTU5NmYtNDRjOS04M2YxLWY1Y2M1NjVhYmI1N3gxNzkzNjExNTY3Njk0MjQ2Njkx parts=1216602026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1661--- PASS: TestPresentReportsOnlyClosureRoots (0.36s)1662=== CONT TestPush_SignsNarinfosOfItsPendingObjects1663--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.69s)1664=== CONT TestNARDeduplicationMetadataUploadBug16652026/11/02 09:26:08 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1666--- PASS: TestReadProxyNarinfo (0.44s)1667=== CONT TestGenerateLandingPage16682026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1669--- PASS: TestGenerateLandingPage (0.00s)1670=== CONT TestService_readinessHandler16712026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures16722026/11/02 09:26:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16732026/11/02 09:26:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1674--- PASS: TestService_NativeMTLS (0.35s)1675=== CONT TestCacheConfigHandlerMaxNarSize1676--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1677=== CONT TestIsValidCachePath1678=== RUN TestIsValidCachePath/narinfo1679=== PAUSE TestIsValidCachePath/narinfo1680=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1681=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1682=== RUN TestIsValidCachePath/nar_zst1683=== PAUSE TestIsValidCachePath/nar_zst1684=== RUN TestIsValidCachePath/nar_xz1685=== PAUSE TestIsValidCachePath/nar_xz1686=== RUN TestIsValidCachePath/nar_bz21687=== PAUSE TestIsValidCachePath/nar_bz21688=== RUN TestIsValidCachePath/nar_uncompressed1689=== PAUSE TestIsValidCachePath/nar_uncompressed1690=== RUN TestIsValidCachePath/ls1691=== PAUSE TestIsValidCachePath/ls1692=== RUN TestIsValidCachePath/log1693=== PAUSE TestIsValidCachePath/log1694=== RUN TestIsValidCachePath/realisation1695=== PAUSE TestIsValidCachePath/realisation1696=== RUN TestIsValidCachePath/nix-cache-info1697=== PAUSE TestIsValidCachePath/nix-cache-info1698=== RUN TestIsValidCachePath/index.html1699=== PAUSE TestIsValidCachePath/index.html1700=== RUN TestIsValidCachePath/traversal_parent1701=== PAUSE TestIsValidCachePath/traversal_parent1702=== RUN TestIsValidCachePath/traversal_in_middle1703=== PAUSE TestIsValidCachePath/traversal_in_middle1704=== RUN TestIsValidCachePath/invalid_char_e1705=== PAUSE TestIsValidCachePath/invalid_char_e1706=== RUN TestIsValidCachePath/invalid_char_u1707=== PAUSE TestIsValidCachePath/invalid_char_u1708=== RUN TestIsValidCachePath/random_path1709=== PAUSE TestIsValidCachePath/random_path1710=== RUN TestIsValidCachePath/empty1711=== PAUSE TestIsValidCachePath/empty1712=== RUN TestIsValidCachePath/leading_slash1713=== PAUSE TestIsValidCachePath/leading_slash1714=== RUN TestIsValidCachePath/wrong_extension1715=== PAUSE TestIsValidCachePath/wrong_extension1716=== RUN TestIsValidCachePath/short_hash1717=== PAUSE TestIsValidCachePath/short_hash1718=== CONT TestResolveDBConnectionString/flag_wins1719=== CONT TestProxyWriteTimeout/narinfo1720=== CONT TestResolveDBConnectionString/nothing_configured1721=== CONT TestIsValidUploadKey/narinfo1722=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed17232026/11/02 09:26:08 INFO Received cleanup request method=DELETE path=/api/pending_closures17242026/11/02 09:26:08 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17252026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=117262026/11/02 09:26:08 INFO Received cleanup request method=DELETE path=/api/pending_closures17272026/11/02 09:26:08 INFO Aborted multipart uploads count=1 kept=017282026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1729--- PASS: TestMultipartCleanup (0.50s)1730=== CONT TestResolveDBConnectionString/missing_file_is_an_error1731=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1732=== CONT TestProxyWriteTimeout/unknown_size1733=== CONT TestResolveDBConnectionString/file_when_flag_empty1734=== CONT TestIsValidUploadKey/build_log_equals1735=== CONT TestIsValidUploadKey/unknown_type1736=== CONT TestIsValidUploadKey/empty_key1737=== CONT TestIsValidUploadKey/absolute1738=== CONT TestIsValidUploadKey/traversal_nar1739=== CONT TestIsValidUploadKey/traversal1740=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1741=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1742=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1743=== CONT TestIsValidUploadKey/index.html1744=== CONT TestIsValidUploadKey/nix-cache-info1745=== CONT TestIsValidUploadKey/realisation_plus_in_output1746=== CONT TestIsValidUploadKey/realisation1747=== CONT TestProxyWriteTimeout/10_GiB_nar1748=== CONT TestIsValidUploadKey/nar_xz1749=== CONT TestIsValidUploadKey/build_log_question_mark1750=== CONT TestIsValidUploadKey/build_log_plus_in_name1751=== CONT TestIsValidUploadKey/build_log_home-manager_file1752=== CONT TestIsValidUploadKey/build_log1753=== CONT TestIsValidUploadKey/listing1754=== CONT TestIsValidUploadKey/nar_plain1755=== CONT TestProxyWriteTimeout/1_GiB_nar1756=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed1757--- PASS: TestResolveDBConnectionString (0.00s)1758 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1759 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1760 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1761 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1762 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1763--- PASS: TestProxyWriteTimeout (0.00s)1764 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1765 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1766 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1767 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1768=== RUN TestPush_RejectsBadRequests/no_roots1769=== PAUSE TestPush_RejectsBadRequests/no_roots1770=== RUN TestPush_RejectsBadRequests/no_objects1771=== PAUSE TestPush_RejectsBadRequests/no_objects1772=== RUN TestPush_RejectsBadRequests/bad_root1773=== PAUSE TestPush_RejectsBadRequests/bad_root1774=== RUN TestPush_RejectsBadRequests/root_not_in_objects1775=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1776=== CONT TestIsValidUploadKey/nar_zst1777=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1778--- PASS: TestIsValidUploadKey (0.01s)1779 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1780 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1781 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1782 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1783 --- PASS: TestIsValidUploadKey/absolute (0.00s)1784 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1785 --- PASS: TestIsValidUploadKey/traversal (0.00s)1786 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1787 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1788 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1789 --- PASS: TestIsValidUploadKey/index.html (0.00s)1790 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1791 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1792 --- PASS: TestIsValidUploadKey/realisation (0.00s)1793 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1794 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1795 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1796 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1797 --- PASS: TestIsValidUploadKey/build_log (0.00s)1798 --- PASS: TestIsValidUploadKey/listing (0.00s)1799 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1800 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)18012026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18022026/11/02 09:26:08 ERROR Failed to get multipart upload error="no rows in result set" upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmYyYWNmZTU4LTFlMzQtNGZlMC04ODMwLWY1NDNhOTA2NjM1NHgxNzkzNjExNTY3ODE1NDc2MDM4 object_key=nar/gggggggggggggggggggggggggggggg0500000000000000000000.nar.zst18032026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0500000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjVkYzNjMzU0LTc2ZTMtNDk4Zi04NmY0LTc2NGZkNWY5Yjg1Y3gxNzkzNjExNTY3ODA4NDkwMjM2 parts=121804--- PASS: TestCompleteRefusedAfterAbortClaim (0.74s)1805=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed18062026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes18072026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes18082026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures18092026-11-02 09:26:08.249 UTC [1703] ERROR: could not obtain lock on row in relation "closures"18102026-11-02 09:26:08.249 UTC [1703] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18112026-11-02 09:26:08.249 UTC [1703] ERROR: could not obtain lock on row in relation "closures"18122026-11-02 09:26:08.249 UTC [1703] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18132026-11-02 09:26:08.249 UTC [1703] ERROR: could not obtain lock on row in relation "closures"18142026-11-02 09:26:08.249 UTC [1703] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18152026-11-02 09:26:08.249 UTC [1703] ERROR: could not obtain lock on row in relation "closures"18162026-11-02 09:26:08.249 UTC [1703] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT18172026-11-02 09:26:08.250 UTC [1703] ERROR: could not obtain lock on row in relation "closures"18182026-11-02 09:26:08.250 UTC [1703] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1819--- PASS: TestPush_RootsAreLockedInByteOrder (0.39s)1820=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed18212026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes18222026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18232026/11/02 09:26:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjhhMWMwZjljLTcwZmItNDA0Ni1iMzk4LWU1YjNhZGE5ODkzY3gxNzkzNjExNTY4MjU0ODAwMDE518242026/11/02 09:26:08 INFO Received complete push request method=POST path=/api/pushes/1/complete18252026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjhhMWMwZjljLTcwZmItNDA0Ni1iMzk4LWU1YjNhZGE5ODkzY3gxNzkzNjExNTY4MjU0ODAwMDE5 parts=11826--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.34s)1827=== CONT TestPendingClosureWriteTimeout/empty1828=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18292026/11/02 09:26:08 INFO Completed push id=1 objects=4 duration=8.422995ms18302026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes18312026/11/02 09:26:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18322026/11/02 09:26:08 WARN Refused reserved pin name=worker-x86_64-linux18332026/11/02 09:26:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18342026/11/02 09:26:08 INFO Received create pin request method=POST path=/api/pins/my-app18352026/11/02 09:26:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1836--- PASS: TestCreatePin_ReservedPins (0.57s)1837=== CONT TestPendingClosureWriteTimeout/670k_objects1838=== CONT TestPendingClosureWriteTimeout/400_objects1839=== CONT TestClientErrorHandling/InvalidStorePath18402026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures18412026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1842--- PASS: TestMetricsInventory (0.34s)1843=== CONT TestClientErrorHandling/ServerNotAvailable18442026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=018452026/11/02 09:26:08 WARN Force mode enabled - objects will be deleted immediately without grace period18462026/11/02 09:26:08 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=018472026/11/02 09:26:08 INFO Vacuumed table table=pending_closures18482026/11/02 09:26:08 INFO Vacuumed table table=pending_objects18492026/11/02 09:26:08 INFO Vacuumed table table=multipart_uploads18502026/11/02 09:26:08 INFO Vacuumed table table=closures18512026/11/02 09:26:08 INFO Vacuumed table table=objects18522026/11/02 09:26:08 INFO Received complete push request method=POST path=/api/pushes/2/complete18532026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes18542026/11/02 09:26:08 INFO Completed push id=2 objects=4 duration=2.25438ms1855--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.41s)1856=== CONT TestClientErrorHandling/InvalidAuthToken18572026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18582026/11/02 09:26:08 INFO Signed narinfos id=1 count=118592026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18602026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18612026/11/02 09:26:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"18622026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18632026/11/02 09:26:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"18642026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18652026/11/02 09:26:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=118662026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18672026/11/02 09:26:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1868--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.31s)1869=== CONT TestCacheConfigHandler/full_config,_no_issuer1870=== CONT TestCacheConfigHandler/no_signing_keys1871=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1872=== CONT TestCacheConfigHandler/no_cache_url_configured1873--- PASS: TestCacheConfigHandler (0.00s)1874 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1875 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1876 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1877 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1878=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18792026/11/02 09:26:08 INFO Received uploads request method=POST path=/1880=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18812026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/1882=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18832026/11/02 09:26:08 INFO Received uploads request method=POST path=/1884=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18852026/11/02 09:26:08 INFO Received request for more parts method=POST path=/1886--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1887 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1888 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1889 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1890 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1891=== CONT TestGCEndsOnShutdown/before_the_run1892=== NAME TestNARDeduplicationMetadataUploadBug1893 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4236829823/001/store/wn2anafadwg9gqps8kf5pg76dk09z1m9-file1.txt18942026/11/02 09:26:08 WARN readiness check failed error="closed pool"1895--- PASS: TestService_readinessHandler (0.31s)1896=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark18972026/11/02 09:26:08 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/present18982026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures18992026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures19002026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19012026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0400000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmY3MzBmNWVhLTZlM2QtNGFiOC05ODI5LTc0ZGQxYmNiOWMxM3gxNzkzNjExNTY4MDk3MDc1OTI0 parts=1219022026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures19032026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes19042026/11/02 09:26:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19052026/11/02 09:26:08 INFO Uploading wn2anafadwg9gqps8kf5pg76dk09z1m9-file1.txt (160B)19062026/11/02 09:26:08 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19072026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19082026/11/02 09:26:08 WARN Failed to register uploaded object key=wn2anafadwg9gqps8kf5pg76dk09z1m9.ls error="server returned 404: 404 page not found\n"19092026/11/02 09:26:08 INFO Signed narinfos id=1 count=119102026/11/02 09:26:08 INFO Uploading 1 narinfos19112026/11/02 09:26:08 INFO Received complete push request method=POST path=/api/pushes/1/complete19122026/11/02 09:26:08 WARN Failed to register uploaded object key=wn2anafadwg9gqps8kf5pg76dk09z1m9.narinfo error="server returned 404: 404 page not found\n"19132026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures19142026/11/02 09:26:08 INFO Completed push id=1 objects=3 duration=5.703471ms19152026/11/02 09:26:08 INFO Upload complete. (63ms)1916=== NAME TestNARDeduplicationMetadataUploadBug1917 metadata_upload_test.go:54: Retrieved narinfo from S3:1918 StorePath: /build/TestNARDeduplicationMetadataUploadBug4236829823/001/store/wn2anafadwg9gqps8kf5pg76dk09z1m9-file1.txt1919 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1920 Compression: zstd1921 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1922 NarSize: 1601923 References: 1924 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1925 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1926 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1927 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1928=== NAME TestOrphanedObjectsGC1929 orphaned_objects_gc_test.go:287: GC Test Summary:1930 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1931 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1932 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1933 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1934 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1935--- PASS: TestOrphanedObjectsGC (0.70s)1936=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19372026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures19382026/11/02 09:26:08 WARN Request failed, retrying attempt=2 backoff=202.548377ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1939=== NAME TestNARDeduplicationMetadataUploadBug1940 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4236829823/001/store/m45p22bc0bms8493c1l8kvn402svz14j-file2.txt19412026-11-02 09:26:08.545 UTC [1704] ERROR: Push does not exist: id=119422026-11-02 09:26:08.545 UTC [1704] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19432026-11-02 09:26:08.545 UTC [1704] STATEMENT: SELECT commit_push($1)1944--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.66s)1945=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19462026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1947=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19482026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes19492026/11/02 09:26:08 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19502026/11/02 09:26:08 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19512026/11/02 09:26:08 WARN Failed to register uploaded object key=m45p22bc0bms8493c1l8kvn402svz14j.ls error="server returned 404: 404 page not found\n"19522026/11/02 09:26:08 INFO Signed narinfos id=2 count=119532026/11/02 09:26:08 INFO Uploading 1 narinfos19542026/11/02 09:26:08 INFO Received complete push request method=POST path=/api/pushes/2/complete19552026/11/02 09:26:08 WARN Failed to register uploaded object key=m45p22bc0bms8493c1l8kvn402svz14j.narinfo error="server returned 404: 404 page not found\n"19562026/11/02 09:26:08 INFO Completed push id=2 objects=3 duration=3.450211ms19572026/11/02 09:26:08 INFO Upload complete. (54ms)1958=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19592026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/1960=== NAME TestNARDeduplicationMetadataUploadBug1961 metadata_upload_test.go:76: Retrieved narinfo from S3:1962 StorePath: /build/TestNARDeduplicationMetadataUploadBug4236829823/001/store/m45p22bc0bms8493c1l8kvn402svz14j-file2.txt1963 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1964 Compression: zstd1965 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1966 NarSize: 1601967 References: 1968 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1969 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1970 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1971 {"version":1,"root":{"type":"regular","size":44}}1972--- PASS: TestNARDeduplicationMetadataUploadBug (0.56s)1973=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19742026/11/02 09:26:08 INFO Received uploads request method=POST path=/19752026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=019762026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19772026/11/02 09:26:08 WARN Force mode enabled - objects will be deleted immediately without grace period1978=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19792026/11/02 09:26:08 INFO Received request for more parts method=POST path=/1980=== CONT TestService_RequireScope_OIDC/builder_may_write19812026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjI4NGQ3MjgwLWM3NWUtNDIzNS05OTFjLTQwODQyNWU0YzI2YngxNzkzNjExNTY4MzIxNTMyNjc4 parts=1219822026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=01983=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1984=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1985=== CONT TestService_RequireScope_OIDC/reader_may_read19862026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures1987=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19882026/11/02 09:26:08 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]1989=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1990=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1991=== CONT TestService_RequireScope_OIDC/reader_may_not_write1992=== CONT TestService_RequireScope_OIDC/writer_implies_read1993=== CONT TestService_RequireScope_OIDC/static_token_may_admin1994=== CONT TestService_RequireScope_OIDC/ops_may_not_write1995=== CONT TestService_RequireScope_OIDC/ops_may_admin1996=== CONT TestService_RequireScope_OIDC/static_token_may_write1997=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1998=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1999--- PASS: TestService_RequireScope_OIDC (0.48s)2000 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2001 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2002 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2003 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2004 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2005 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2006 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2007 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2008 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2009 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2010 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2011 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2012 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2013 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20142026/11/02 09:26:08 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20152026/11/02 09:26:08 WARN Force mode enabled - objects will be deleted immediately without grace period2016=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20172026/11/02 09:26:08 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]2018=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2019=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20202026/11/02 09:26:08 WARN Authentication failed token_preview=eyJhbGciOi...4tSNZaTLfg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2021=== CONT TestParseSingleRange/none2022=== CONT TestParseSingleRange/single_byte2023=== CONT TestParseSingleRange/suffix_exceeds_size2024=== CONT TestParseSingleRange/suffix2025=== CONT TestParseSingleRange/end_clamped_to_size2026=== CONT TestParseSingleRange/open-ended2027=== CONT TestParseSingleRange/start_past_EOF2028=== CONT TestParseSingleRange/closed2029=== CONT TestParseSingleRange/malformed_end_before_start2030=== CONT TestParseSingleRange/malformed_both_empty2031=== CONT TestParseSingleRange/malformed_no_dash2032=== CONT TestParseSingleRange/multi-range_ignored2033=== CONT TestParseSingleRange/unknown_unit2034=== CONT TestParseSingleRange/start_far_past_EOF2035--- PASS: TestParseSingleRange (0.00s)2036 --- PASS: TestParseSingleRange/none (0.00s)2037 --- PASS: TestParseSingleRange/single_byte (0.00s)2038 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2039 --- PASS: TestParseSingleRange/suffix (0.00s)2040 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2041 --- PASS: TestParseSingleRange/open-ended (0.00s)2042 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2043 --- PASS: TestParseSingleRange/closed (0.00s)2044 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2045 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2046 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2047 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2048 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2049 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2050=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2051--- PASS: TestService_AuthMiddleware_OIDC (0.38s)2052 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2053 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2054 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2055 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20562026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures20572026/11/02 09:26:08 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37859/bucket103/?delete=\": context canceled"2058--- PASS: TestGCEndsOnShutdown (0.00s)2059 --- PASS: TestGCEndsOnShutdown/before_the_run (0.24s)2060 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.29s)2061 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.19s)2062=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh20632026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures20642026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=020652026/11/02 09:26:08 WARN Request failed, retrying attempt=3 backoff=402.202377ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20662026/11/02 09:26:08 WARN Force mode enabled - objects will be deleted immediately without grace period20672026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20682026/11/02 09:26:08 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2069=== CONT TestServerTLSConfig/no_client_CA2070=== CONT TestServerTLSConfig/not_a_PEM_file2071=== CONT TestServerTLSConfig/missing_CA_file2072=== CONT TestIsValidCachePath/narinfo2073=== CONT TestIsValidCachePath/leading_slash2074=== CONT TestIsValidCachePath/empty2075--- PASS: TestServerTLSConfig (0.00s)2076 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2077 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2078 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2079=== CONT TestIsValidCachePath/wrong_extension2080=== CONT TestIsValidCachePath/random_path2081=== CONT TestIsValidCachePath/log2082=== CONT TestIsValidCachePath/realisation2083=== CONT TestIsValidCachePath/ls2084=== CONT TestIsValidCachePath/short_hash2085=== CONT TestIsValidCachePath/invalid_char_u2086=== CONT TestIsValidCachePath/nar_uncompressed2087=== CONT TestIsValidCachePath/nar_bz22088=== CONT TestIsValidCachePath/invalid_char_e2089=== CONT TestIsValidCachePath/nar_zst2090=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2091=== CONT TestIsValidCachePath/nar_xz2092=== CONT TestIsValidCachePath/index.html2093=== CONT TestIsValidCachePath/traversal_in_middle2094=== CONT TestIsValidCachePath/traversal_parent2095=== CONT TestPush_RejectsBadRequests/no_roots2096=== CONT TestIsValidCachePath/nix-cache-info2097=== CONT TestPush_RejectsBadRequests/bad_root20982026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes2099--- PASS: TestIsValidCachePath (0.00s)2100 --- PASS: TestIsValidCachePath/narinfo (0.00s)2101 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2102 --- PASS: TestIsValidCachePath/empty (0.00s)2103 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2104 --- PASS: TestIsValidCachePath/random_path (0.00s)2105 --- PASS: TestIsValidCachePath/log (0.00s)2106 --- PASS: TestIsValidCachePath/realisation (0.00s)2107 --- PASS: TestIsValidCachePath/ls (0.00s)2108 --- PASS: TestIsValidCachePath/short_hash (0.00s)2109 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2110 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2111 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2112 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2113 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2114 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2115 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2116 --- PASS: TestIsValidCachePath/index.html (0.00s)2117 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2118 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2119 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)21202026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes2121=== CONT TestPush_RejectsBadRequests/no_objects2122=== CONT TestPush_RejectsBadRequests/root_not_in_objects21232026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes21242026/11/02 09:26:08 INFO Received push request method=POST path=/api/pushes2125--- PASS: TestPush_RejectsBadRequests (0.33s)2126 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2127 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2128 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2129 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)21302026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmJiOWYxMGY1LTZiZmItNGMyNi1hZTQyLWJkOWZhMGI5YjQxNXgxNzkzNjExNTY4NDMyNjgzOTM2 parts=1021312026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21322026/11/02 09:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21332026/11/02 09:26:08 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=021342026/11/02 09:26:08 INFO Vacuumed table table=pending_closures21352026/11/02 09:26:08 INFO Vacuumed table table=pending_objects21362026/11/02 09:26:08 INFO Vacuumed table table=multipart_uploads21372026/11/02 09:26:08 INFO Vacuumed table table=closures21382026/11/02 09:26:08 INFO Completed upload id=1 objects=3 duration=3.670133ms21392026/11/02 09:26:08 INFO Vacuumed table table=objects21402026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures21412026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21422026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmJmNzk0ODY0LWZmNDYtNGVlMi05NzVkLTFlMWZhOGZkNDc2OHgxNzkzNjExNTY4NDU1MjQ0Njc4 parts=1021432026/11/02 09:26:08 INFO Aborted multipart uploads count=0 kept=021442026/11/02 09:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21452026/11/02 09:26:08 INFO Completed upload id=1 objects=3 duration=2.658384ms21462026/11/02 09:26:08 WARN Force mode enabled - objects will be deleted immediately without grace period21472026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures21482026/11/02 09:26:08 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=021492026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmJlOTg2MzBhLTIyYTQtNDJmZC1hMzYzLTUzMjY1MzQ4ZGJkOHgxNzkzNjExNTY4NDc4NTg0NTI3 parts=1021502026/11/02 09:26:08 INFO Vacuumed table table=pending_closures21512026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21522026/11/02 09:26:08 INFO Vacuumed table table=pending_objects21532026/11/02 09:26:08 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21542026/11/02 09:26:08 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21552026/11/02 09:26:08 INFO Vacuumed table table=multipart_uploads21562026/11/02 09:26:08 INFO Vacuumed table table=closures21572026/11/02 09:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21582026/11/02 09:26:08 INFO Vacuumed table table=objects21592026/11/02 09:26:08 INFO Completed upload id=1 objects=3 duration=2.458282ms21602026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures2161--- PASS: TestForceGCDuringPushOffersSweptObject (0.02s)2162 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.23s)2163 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.19s)21642026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjBmZTQ2NmViLTE4ZjQtNGNlMy1hMGI2LTQ1YTYwN2I2MDU4MHgxNzkzNjExNTY4NTAyNDY2MzIx parts=1021652026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures21662026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21672026/11/02 09:26:08 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21682026/11/02 09:26:08 WARN Found objects in DB but missing from S3, will re-upload count=121692026/11/02 09:26:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21702026/11/02 09:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21712026/11/02 09:26:08 INFO Completed upload id=1 objects=3 duration=2.555223ms21722026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures21732026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0400000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjI0Zjk5ZGNkLWU2ZjEtNDViNi04YTkzLTlhOTQzMDM1MjA4N3gxNzkzNjExNTY4MTA0NzkwOTEz parts=1221742026/11/02 09:26:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjIzNGJmMDY4LTg5OWQtNGQ2Mi1hMjEwLWYyMmRkMjEwYTEyNXgxNzkzNjExNTY4NTI3NDc5Mzg2 parts=102175--- PASS: TestRedundantAbortSkipsCompletingUpload (1.06s)21762026/11/02 09:26:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21772026/11/02 09:26:08 INFO Completed upload id=1 objects=3 duration=2.24062ms21782026/11/02 09:26:08 INFO Received uploads request method=POST path=/api/pending_closures21792026/11/02 09:26:08 INFO lead: released remote=192.0.2.1:12342180--- PASS: TestLeadElectsOneAndHandsOver (2.74s)21812026/11/02 09:26:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21822026/11/02 09:26:09 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLmY0OTBmMGU3LTI1NDItNDc0Zi05OGFhLTFjYzIyYzEyZTA2ZXgxNzkzNjExNTY4NzExNzcwNDk5 error="Get \"http://127.0.0.1:1/bucket88/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21832026/11/02 09:26:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjg3YzViNjM1LTU2ZjQtNDhhMi05MzI0LTBlZWQ0ODQ2MTE5ZHgxNzkzNjExNTY4NzA2NzEyMjc0 parts=1221842026/11/02 09:26:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021852026/11/02 09:26:09 INFO Received cleanup request method=DELETE path=/api/pending_closures21862026/11/02 09:26:09 INFO Received create pin request method=POST path=/api/pins/myapp21872026/11/02 09:26:09 INFO Aborted multipart uploads count=1 kept=02188--- PASS: TestRedundantMultipartUpload (1.05s)21892026/11/02 09:26:09 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4195958578/001/store/594q5nac75v6vj21knw567z3wm1nc7di-pinned-file.txt narinfo_key=594q5nac75v6vj21knw567z3wm1nc7di.narinfo21902026/11/02 09:26:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures21912026/11/02 09:26:09 INFO Garbage collection started21922026/11/02 09:26:09 INFO Aborted multipart uploads count=0 kept=021932026/11/02 09:26:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21942026/11/02 09:26:09 WARN Force mode enabled - objects will be deleted immediately without grace period21952026/11/02 09:26:09 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=021962026/11/02 09:26:09 INFO Vacuumed table table=pending_closures21972026/11/02 09:26:09 INFO Vacuumed table table=pending_objects21982026/11/02 09:26:09 INFO Vacuumed table table=multipart_uploads21992026/11/02 09:26:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjNmMmQxMTNhLWVkNzItNGFlNS1iM2QzLTM2Y2YzYWQ5NjE5NHgxNzkzNjExNTY4NzkzNjE0MjE0 parts=1022002026/11/02 09:26:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22012026/11/02 09:26:09 INFO Vacuumed table table=closures22022026/11/02 09:26:09 INFO Completed upload id=2 objects=3 duration=1.021949ms22032026/11/02 09:26:09 INFO Vacuumed table table=objects22042026/11/02 09:26:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22052026/11/02 09:26:09 INFO Received uploads request method=POST path=/api/pending_closures22062026/11/02 09:26:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NzU3MDgwZTAtYzBlNC00MjQ0LWE4MTUtNmRlNmM0ZTlkYWRlLjAzMjBhZGI5LTIyNjQtNGY3Ny1iNjZkLTk0MjI4MjYwNzQ5MHgxNzkzNjExNTY4ODE1ODE4NjUy parts=1022072026/11/02 09:26:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22082026/11/02 09:26:09 INFO Completed upload id=2 objects=3 duration=837.588µs22092026/11/02 09:26:09 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22102026/11/02 09:26:09 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo22112026/11/02 09:26:09 INFO Received uploads request method=POST path=/api/pending_closures22122026/11/02 09:26:09 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22132026/11/02 09:26:09 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2214--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2215 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (0.67s)2216 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (0.63s)2217 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (0.58s)2218 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (0.90s)2219 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (0.91s)22202026/11/02 09:26:09 WARN Request failed, retrying attempt=4 backoff=742.046114ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22212026/11/02 09:26:09 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02222=== NAME TestClientIntegration2223 client_integration_test.go:370: Objects in database after GC:2224 client_integration_test.go:370: Successfully deleted all objects with GC --force2225--- PASS: TestClientIntegration (3.19s)2226--- PASS: TestPendingClosureWriteTimeout (0.01s)2227 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2228 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2229 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2230 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)2231--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2232 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.64s)2233 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.66s)2234--- PASS: TestUploadHandlersRejectOversizedBody (0.14s)2235 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2236 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2237 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.83s)2238=== NAME TestOrphanedObjectsGCStressTest2239 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2240 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22412026/11/02 09:26:09 WARN Request failed, retrying attempt=5 backoff=1.486538045s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2242 orphaned_objects_gc_test.go:503: Stress test completed successfully:2243 orphaned_objects_gc_test.go:504: - Active objects preserved: 202244 orphaned_objects_gc_test.go:505: - Objects deleted: 2102245 orphaned_objects_gc_test.go:506: - Total GC'd: 2102246--- PASS: TestOrphanedObjectsGCStressTest (2.24s)22472026/11/02 09:26:10 WARN Rate limiter enabled after throttle name=s3-test rate=522482026/11/02 09:26:10 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2249=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2250 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102251 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002252--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.82s)2253=== NAME TestPinProtectsFromGC2254 client_integration_test.go:887: Pin successfully protected closure from garbage collection2255--- PASS: TestPinProtectsFromGC (4.92s)2256--- PASS: TestConnectWaitsForAPeerMigration (5.19s)22572026/11/02 09:26:11 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-config22582026/11/02 09:26:11 WARN Request failed, retrying attempt=2 backoff=206.116776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22592026/11/02 09:26:11 WARN Request failed, retrying attempt=3 backoff=418.416511ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2260--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.54s)22612026/11/02 09:26:12 WARN Request failed, retrying attempt=4 backoff=846.783199ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22622026/11/02 09:26:12 WARN Request failed, retrying attempt=5 backoff=1.621052374s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22632026/11/02 09:26:13 INFO Aborted multipart uploads count=1 kept=022642026/11/02 09:26:13 INFO Received cleanup request method=DELETE path=/api/pending_closures22652026/11/02 09:26:13 INFO Aborted multipart uploads count=1 kept=02266--- PASS: TestPendingCleanupUsesOneCutoff (6.38s)22672026/11/02 09:26:14 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"22682026/11/02 09:26:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22692026/11/02 09:26:14 WARN Request failed, retrying attempt=2 backoff=217.996215ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22702026/11/02 09:26:14 WARN Request failed, retrying attempt=3 backoff=432.214732ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22712026/11/02 09:26:15 WARN Request failed, retrying attempt=4 backoff=781.911079ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22722026/11/02 09:26:16 WARN Request failed, retrying attempt=5 backoff=1.667413085s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22732026/11/02 09:26:17 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_closures22742026/11/02 09:26:17 WARN Request failed, retrying attempt=2 backoff=193.34764ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22752026/11/02 09:26:18 WARN Request failed, retrying attempt=3 backoff=419.818094ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22762026/11/02 09:26:18 WARN Request failed, retrying attempt=4 backoff=846.256529ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22772026/11/02 09:26:19 WARN Request failed, retrying attempt=5 backoff=1.519994964s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2278--- PASS: TestClientErrorHandling (0.00s)2279 --- PASS: TestClientErrorHandling/InvalidStorePath (0.30s)2280 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2281 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.53s)2282PASS22832026-11-02 09:26:21.115 UTC [128] LOG: received smart shutdown request22842026-11-02 09:26:21.118 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 122852026-11-02 09:26:21.128 UTC [133] LOG: shutting down22862026-11-02 09:26:21.128 UTC [133] LOG: checkpoint starting: shutdown immediate22872026-11-02 09:26:22.040 UTC [133] LOG: checkpoint complete: wrote 11150 buffers (68.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=0.181 s, sync=0.695 s, total=0.912 s; sync files=36397, longest=0.012 s, average=0.001 s; distance=526654 kB, estimate=526654 kB; lsn=0/219B58A8, redo lsn=0/219B58A822882026-11-02 09:26:22.114 UTC [128] LOG: database system is shut down2289Running OIDC tests...2290=== RUN TestAudienceForIssuer2291=== PAUSE TestAudienceForIssuer2292=== RUN TestGlobMatch2293=== PAUSE TestGlobMatch2294=== RUN TestValidateToken_ValidToken2295=== PAUSE TestValidateToken_ValidToken2296=== RUN TestValidateToken_WrongAudience2297=== PAUSE TestValidateToken_WrongAudience2298=== RUN TestValidateToken_Expired2299=== PAUSE TestValidateToken_Expired2300=== RUN TestValidateToken_BoundClaimsMismatch2301=== PAUSE TestValidateToken_BoundClaimsMismatch2302=== RUN TestValidateToken_BoundSubjectMismatch2303=== PAUSE TestValidateToken_BoundSubjectMismatch2304=== RUN TestValidateToken_MultipleProviders2305=== PAUSE TestValidateToken_MultipleProviders2306=== RUN TestValidateToken_NoMatchingProvider2307=== PAUSE TestValidateToken_NoMatchingProvider2308=== RUN TestValidateToken_KubernetesServiceAccount2309=== PAUSE TestValidateToken_KubernetesServiceAccount2310=== RUN TestNewValidator_KubernetesRequiresCA2311=== PAUSE TestNewValidator_KubernetesRequiresCA2312=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2313=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2314=== RUN TestPins_ReservedForMatchingRule2315=== PAUSE TestPins_ReservedForMatchingRule2316=== RUN TestPins_TopLevelShorthand2317=== PAUSE TestPins_TopLevelShorthand2318=== RUN TestPins_ConfigValidation2319=== PAUSE TestPins_ConfigValidation2320=== RUN TestScopes_LegacyProviderDefaultsToWrite2321=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2322=== RUN TestScopes_Rules2323=== PAUSE TestScopes_Rules2324=== RUN TestScopes_ConfigValidation2325=== PAUSE TestScopes_ConfigValidation2326=== CONT TestAudienceForIssuer2327=== CONT TestPins_TopLevelShorthand2328=== CONT TestScopes_Rules2329=== CONT TestPins_ConfigValidation2330=== CONT TestScopes_LegacyProviderDefaultsToWrite2331=== CONT TestScopes_ConfigValidation2332=== CONT TestValidateToken_BoundClaimsMismatch2333=== CONT TestValidateToken_NoMatchingProvider2334=== CONT TestValidateToken_MultipleProviders2335=== CONT TestValidateToken_BoundSubjectMismatch2336=== CONT TestValidateToken_WrongAudience2337=== CONT TestValidateToken_Expired2338=== CONT TestValidateToken_ValidToken2339=== CONT TestGlobMatch2340=== RUN TestGlobMatch/foo_foo2341=== PAUSE TestGlobMatch/foo_foo2342=== RUN TestGlobMatch/foo_bar2343=== PAUSE TestGlobMatch/foo_bar2344=== RUN TestGlobMatch/*_2345=== PAUSE TestGlobMatch/*_2346=== RUN TestGlobMatch/*_anything2347=== PAUSE TestGlobMatch/*_anything2348=== RUN TestGlobMatch/foo*_foo2349=== PAUSE TestGlobMatch/foo*_foo2350=== RUN TestGlobMatch/foo*_foobar2351=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2352=== CONT TestPins_ReservedForMatchingRule2353--- PASS: TestAudienceForIssuer (0.00s)2354=== CONT TestNewValidator_KubernetesRequiresCA2355=== CONT TestValidateToken_KubernetesServiceAccount2356=== PAUSE TestGlobMatch/foo*_foobar2357=== RUN TestGlobMatch/foo*_bar2358=== PAUSE TestGlobMatch/foo*_bar2359=== RUN TestGlobMatch/*bar_bar2360=== PAUSE TestGlobMatch/*bar_bar2361=== RUN TestGlobMatch/*bar_foobar2362=== PAUSE TestGlobMatch/*bar_foobar2363=== RUN TestGlobMatch/*bar_foo2364=== PAUSE TestGlobMatch/*bar_foo2365=== RUN TestGlobMatch/foo*bar_foobar2366=== PAUSE TestGlobMatch/foo*bar_foobar2367=== RUN TestGlobMatch/foo*bar_foo123bar2368=== PAUSE TestGlobMatch/foo*bar_foo123bar2369=== RUN TestGlobMatch/foo*bar_foobarbaz2370=== PAUSE TestGlobMatch/foo*bar_foobarbaz2371=== RUN TestGlobMatch/*/*_foo/bar2372=== PAUSE TestGlobMatch/*/*_foo/bar2373=== RUN TestGlobMatch/*/*_foo2374=== PAUSE TestGlobMatch/*/*_foo2375=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2376=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2377=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02378=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02379=== RUN TestGlobMatch/refs/*/main_refs/heads/main2380=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2381=== RUN TestGlobMatch/fo?_foo2382=== PAUSE TestGlobMatch/fo?_foo2383=== RUN TestGlobMatch/fo?_fo2384=== PAUSE TestGlobMatch/fo?_fo2385=== RUN TestGlobMatch/fo?_fooo2386=== PAUSE TestGlobMatch/fo?_fooo2387=== RUN TestGlobMatch/?oo_foo2388=== PAUSE TestGlobMatch/?oo_foo2389=== RUN TestGlobMatch/?oo_boo2390=== PAUSE TestGlobMatch/?oo_boo2391--- PASS: TestPins_ConfigValidation (0.00s)2392--- PASS: TestScopes_ConfigValidation (0.00s)2393=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2394=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2395=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2396=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2397=== CONT TestGlobMatch/foo_foo2398=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2399=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2400=== CONT TestGlobMatch/?oo_boo2401=== CONT TestGlobMatch/?oo_foo2402=== CONT TestGlobMatch/fo?_fooo2403=== CONT TestGlobMatch/fo?_fo2404=== CONT TestGlobMatch/fo?_foo2405=== CONT TestGlobMatch/refs/*/main_refs/heads/main2406=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02407=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2408=== CONT TestGlobMatch/*/*_foo2409=== CONT TestGlobMatch/*/*_foo/bar2410=== CONT TestGlobMatch/foo*bar_foobarbaz2411=== CONT TestGlobMatch/foo*bar_foo123bar2412=== CONT TestGlobMatch/foo*bar_foobar2413=== CONT TestGlobMatch/*bar_foo2414=== CONT TestGlobMatch/*bar_foobar2415=== CONT TestGlobMatch/*bar_bar2416=== CONT TestGlobMatch/foo*_bar2417=== CONT TestGlobMatch/foo*_foobar2418=== CONT TestGlobMatch/foo*_foo2419=== CONT TestGlobMatch/*_anything2420=== CONT TestGlobMatch/*_2421=== CONT TestGlobMatch/foo_bar2422--- PASS: TestGlobMatch (0.00s)2423 --- PASS: TestGlobMatch/foo_foo (0.00s)2424 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2425 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2426 --- PASS: TestGlobMatch/?oo_boo (0.00s)2427 --- PASS: TestGlobMatch/?oo_foo (0.00s)2428 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2429 --- PASS: TestGlobMatch/fo?_fo (0.00s)2430 --- PASS: TestGlobMatch/fo?_foo (0.00s)2431 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2432 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2433 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2434 --- PASS: TestGlobMatch/*/*_foo (0.00s)2435 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2436 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2437 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2438 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2439 --- PASS: TestGlobMatch/*bar_foo (0.00s)2440 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2441 --- PASS: TestGlobMatch/*bar_bar (0.00s)2442 --- PASS: TestGlobMatch/foo*_bar (0.00s)2443 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2444 --- PASS: TestGlobMatch/foo*_foo (0.00s)2445 --- PASS: TestGlobMatch/*_anything (0.00s)2446 --- PASS: TestGlobMatch/*_ (0.00s)2447 --- PASS: TestGlobMatch/foo_bar (0.00s)24482026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46057/oidc2449--- PASS: TestValidateToken_Expired (0.06s)24502026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44279/oidc2451--- PASS: TestPins_ReservedForMatchingRule (0.08s)24522026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37201/oidc2453--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24542026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37601/oidc2455--- PASS: TestValidateToken_ValidToken (0.10s)24562026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34341/oidc2457--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)24582026/11/02 09:26:23 http: TLS handshake error from 127.0.0.1:38956: remote error: tls: bad certificate2459--- PASS: TestNewValidator_KubernetesRequiresCA (0.13s)24602026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46151/oidc2461--- PASS: TestValidateToken_BoundClaimsMismatch (0.14s)24622026/11/02 09:26:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:340672463--- PASS: TestValidateToken_KubernetesServiceAccount (0.14s)24642026/11/02 09:26:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40687/oidc2465--- PASS: TestValidateToken_WrongAudience (0.17s)24662026/11/02 09:26:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39987/oidc24672026/11/02 09:26:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46541/oidc2468--- PASS: TestValidateToken_MultipleProviders (0.21s)24692026/11/02 09:26:24 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43295/oidc2470--- PASS: TestValidateToken_NoMatchingProvider (0.22s)24712026/11/02 09:26:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35453/oidc2472--- PASS: TestScopes_Rules (0.26s)24732026/11/02 09:26:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43421/oidc24742026/11/02 09:26:24 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232475--- PASS: TestPins_TopLevelShorthand (0.30s)2476--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.30s)2477PASS2478Running hook tests...2479=== RUN TestSendPathsEmpty2480=== PAUSE TestSendPathsEmpty2481=== RUN TestQueueEnqueueAndFetch2482=== PAUSE TestQueueEnqueueAndFetch2483=== RUN TestQueueDeduplication2484=== PAUSE TestQueueDeduplication2485=== RUN TestQueueRemove2486=== PAUSE TestQueueRemove2487=== RUN TestQueueFetchBatchLimit2488=== PAUSE TestQueueFetchBatchLimit2489=== RUN TestQueueRetryMovesToBack2490=== PAUSE TestQueueRetryMovesToBack2491=== RUN TestQueueFetchRemoveLifecycle2492=== PAUSE TestQueueFetchRemoveLifecycle2493=== RUN TestQueueConcurrentWriters2494=== PAUSE TestQueueConcurrentWriters2495=== RUN TestQueueRemoveLargeClosure2496=== PAUSE TestQueueRemoveLargeClosure2497=== RUN TestServerClientIntegration2498--- PASS: TestServerClientIntegration (0.00s)2499=== RUN TestServerQueueError25002026/11/02 09:26:24 ERROR Failed to queue paths error="permission denied" count=12501--- PASS: TestServerQueueError (0.00s)2502=== RUN TestGetListenerSocketActivation2503 server_test.go:218: === RUN TestGetListenerSocketActivation2504 --- PASS: TestGetListenerSocketActivation (0.00s)2505 PASS2506 2507--- PASS: TestGetListenerSocketActivation (0.01s)2508=== RUN TestServerStalledClientDoesNotBlockShutdown2509=== PAUSE TestServerStalledClientDoesNotBlockShutdown2510=== RUN TestServerBacksOffOnAcceptErrors2511=== PAUSE TestServerBacksOffOnAcceptErrors2512=== RUN TestDrainIsolatesPoisonPath2513=== PAUSE TestDrainIsolatesPoisonPath2514=== RUN TestRunNotBlockedByPoisonHead2515=== PAUSE TestRunNotBlockedByPoisonHead2516=== RUN TestDrainGivesUpWhenServerDown2517=== PAUSE TestDrainGivesUpWhenServerDown2518=== RUN TestFailedPathPrunedByLaterClosure2519=== PAUSE TestFailedPathPrunedByLaterClosure2520=== RUN TestWorkerUploadsAndRemoves2521=== PAUSE TestWorkerUploadsAndRemoves2522=== RUN TestWorkerSkipsGCdPaths2523=== PAUSE TestWorkerSkipsGCdPaths2524=== RUN TestWorkerPrunesClosureDeps2525=== PAUSE TestWorkerPrunesClosureDeps2526=== RUN TestDrainTimeout2527=== PAUSE TestDrainTimeout2528=== RUN TestWorkerRemoveFailureIsNotProgress2529=== PAUSE TestWorkerRemoveFailureIsNotProgress2530=== RUN TestWorkerKeepsPathItCannotStat2531=== PAUSE TestWorkerKeepsPathItCannotStat2532=== CONT TestSendPathsEmpty2533=== CONT TestWorkerPrunesClosureDeps2534=== CONT TestQueueRetryMovesToBack2535=== CONT TestWorkerKeepsPathItCannotStat2536=== CONT TestServerBacksOffOnAcceptErrors25372026/11/02 09:26:24 ERROR Accept failed error="too many open files"2538=== CONT TestDrainTimeout2539=== CONT TestServerStalledClientDoesNotBlockShutdown2540=== CONT TestQueueRemoveLargeClosure2541--- PASS: TestSendPathsEmpty (0.00s)2542=== CONT TestWorkerRemoveFailureIsNotProgress2543=== CONT TestQueueConcurrentWriters2544=== CONT TestQueueFetchBatchLimit2545=== CONT TestQueueDeduplication2546=== CONT TestQueueEnqueueAndFetch2547=== CONT TestQueueRemove2548=== CONT TestQueueFetchRemoveLifecycle2549=== CONT TestRunNotBlockedByPoisonHead2550=== CONT TestFailedPathPrunedByLaterClosure2551=== CONT TestWorkerUploadsAndRemoves2552=== CONT TestWorkerSkipsGCdPaths2553=== CONT TestDrainGivesUpWhenServerDown2554=== CONT TestDrainIsolatesPoisonPath25552026/11/02 09:26:24 ERROR Accept failed error="too many open files"25562026/11/02 09:26:24 INFO Uploading batch count=225572026/11/02 09:26:24 INFO Upload queue status pending=225582026/11/02 09:26:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1863169989/002/nonexistent2559--- PASS: TestQueueEnqueueAndFetch (0.01s)25602026/11/02 09:26:24 INFO Uploading batch count=125612026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=125622026/11/02 09:26:24 INFO Upload queue status pending=225632026/11/02 09:26:24 INFO Upload queue status pending=225642026/11/02 09:26:24 INFO Uploading batch count=125652026/11/02 09:26:24 INFO Uploading batch count=225662026/11/02 09:26:24 ERROR Accept failed error="too many open files"2567--- PASS: TestQueueRetryMovesToBack (0.02s)25682026/11/02 09:26:24 INFO Uploading batch count=125692026/11/02 09:26:24 INFO Uploading batch count=125702026/11/02 09:26:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa: permission denied"25712026/11/02 09:26:24 INFO Uploading batch count=225722026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=225732026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/a25742026/11/02 09:26:24 INFO Upload queue status pending=32575--- PASS: TestQueueFetchBatchLimit (0.02s)2576--- PASS: TestQueueRemove (0.02s)25772026/11/02 09:26:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa: permission denied"25782026/11/02 09:26:24 INFO Uploading batch count=125792026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=12580--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25812026/11/02 09:26:24 INFO Uploading batch count=425822026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=425832026/11/02 09:26:24 INFO Uploading batch count=125842026/11/02 09:26:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa error="stat /build/TestWorkerKeepsPathItCannotStat4167532106/002/locked/aaa: permission denied"25852026/11/02 09:26:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress133929271/002/nonexistent25862026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/b25872026/11/02 09:26:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125882026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath857257718/002/bbb25892026/11/02 09:26:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress133929271/002/nonexistent25902026/11/02 09:26:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125912026/11/02 09:26:24 ERROR Drain finished with paths left in queue remaining=125922026/11/02 09:26:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgress133929271/002/nonexistent25932026/11/02 09:26:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12594--- PASS: TestQueueDeduplication (0.02s)25952026/11/02 09:26:24 INFO Uploading batch count=225962026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=225972026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/c25982026/11/02 09:26:24 ERROR Drain finished with paths left in queue remaining=125992026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/d2600--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)26012026/11/02 09:26:24 INFO Uploading batch count=126022026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=126032026/11/02 09:26:24 INFO Uploading batch count=226042026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=226052026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/e26062026/11/02 09:26:24 INFO Uploading batch count=126072026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=12608--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2609--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)26102026/11/02 09:26:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2764715971/002/f26112026/11/02 09:26:24 INFO Uploading batch count=126122026/11/02 09:26:24 ERROR Upload failed error="upload failed" count=126132026/11/02 09:26:24 ERROR Drain finished with paths left in queue remaining=1026142026/11/02 09:26:24 ERROR Drain finished with paths left in queue remaining=12615--- PASS: TestDrainIsolatesPoisonPath (0.02s)2616--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2617--- PASS: TestWorkerSkipsGCdPaths (0.03s)26182026/11/02 09:26:24 ERROR Accept failed error="too many open files"2619--- PASS: TestWorkerPrunesClosureDeps (0.04s)2620--- PASS: TestWorkerUploadsAndRemoves (0.04s)26212026/11/02 09:26:24 ERROR Accept failed error="too many open files"2622--- PASS: TestQueueConcurrentWriters (0.10s)2623--- PASS: TestQueueRemoveLargeClosure (0.11s)26242026/11/02 09:26:24 ERROR Accept failed error="too many open files"26252026/11/02 09:26:24 ERROR Failed to decode request error="read unix /build/hook4270932249/test.sock->@: i/o timeout"26262026/11/02 09:26:24 ERROR Failed to write response error="write unix /build/hook4270932249/test.sock->@: i/o timeout"2627--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26282026/11/02 09:26:24 ERROR Upload failed error="context deadline exceeded" count=226292026/11/02 09:26:24 ERROR Drain finished with paths left in queue remaining=42630--- PASS: TestDrainTimeout (0.22s)26312026/11/02 09:26:24 ERROR Accept failed error="too many open files"26322026/11/02 09:26:24 ERROR Accept failed error="too many open files"2633--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26342026/11/02 09:26:25 INFO Uploading batch count=126352026/11/02 09:26:25 INFO Uploading batch count=126362026/11/02 09:26:25 INFO Uploading batch count=126372026/11/02 09:26:25 ERROR Upload failed error="upload failed" count=126382026/11/02 09:26:25 INFO Uploading batch count=126392026/11/02 09:26:25 ERROR Upload failed error="upload failed" count=126402026/11/02 09:26:25 INFO Uploading batch count=126412026/11/02 09:26:25 ERROR Upload failed error="upload failed" count=126422026/11/02 09:26:25 INFO Uploading batch count=126432026/11/02 09:26:25 ERROR Upload failed error="upload failed" count=126442026/11/02 09:26:25 ERROR Drain finished with paths left in queue remaining=12645--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2646PASS2647Running signing tests...2648=== RUN TestExternalSigner2649=== PAUSE TestExternalSigner2650=== RUN TestExternalSignerWrongPublicKey2651=== PAUSE TestExternalSignerWrongPublicKey2652=== RUN TestExternalSignerErrors2653=== PAUSE TestExternalSignerErrors2654=== RUN TestExternalSignerRestartsAfterCrash2655=== PAUSE TestExternalSignerRestartsAfterCrash2656=== RUN TestExternalSignerProgramErrorKeepsProcess2657=== PAUSE TestExternalSignerProgramErrorKeepsProcess2658=== RUN TestExternalSignerClose2659=== PAUSE TestExternalSignerClose2660=== RUN TestExternalSignerRejectsInvalidPublicKey2661=== PAUSE TestExternalSignerRejectsInvalidPublicKey2662=== RUN TestExternalSignerCancellation2663=== PAUSE TestExternalSignerCancellation2664=== RUN TestGenerateFingerprint2665=== PAUSE TestGenerateFingerprint2666=== RUN TestParseSigningKey2667=== PAUSE TestParseSigningKey2668=== RUN TestSign2669=== PAUSE TestSign2670=== RUN TestSignBatch2671=== PAUSE TestSignBatch2672=== RUN TestNilKeyPublicKey2673=== PAUSE TestNilKeyPublicKey2674=== RUN TestSignErrors2675=== PAUSE TestSignErrors2676=== CONT TestExternalSigner2677=== CONT TestSignBatch2678=== CONT TestExternalSignerCancellation2679=== CONT TestExternalSignerProgramErrorKeepsProcess2680=== CONT TestSign2681=== CONT TestSignErrors2682=== CONT TestParseSigningKey2683=== RUN TestParseSigningKey/valid_32-byte_key2684=== PAUSE TestParseSigningKey/valid_32-byte_key2685=== CONT TestGenerateFingerprint2686=== RUN TestGenerateFingerprint/basic_with_references2687=== PAUSE TestGenerateFingerprint/basic_with_references2688=== RUN TestGenerateFingerprint/no_references2689=== CONT TestExternalSignerRejectsInvalidPublicKey2690=== RUN TestExternalSignerRejectsInvalidPublicKey/#002691=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002692=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2693=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2694=== CONT TestExternalSignerClose2695=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2696=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2697=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2698=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2699=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2700=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2701=== CONT TestExternalSignerRejectsInvalidPublicKey/#002702=== CONT TestExternalSignerErrors2703=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2704=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2705=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2706=== RUN TestExternalSignerErrors/null2707=== CONT TestExternalSignerRestartsAfterCrash2708=== CONT TestExternalSignerWrongPublicKey2709=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2710=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2711=== RUN TestParseSigningKey/no_colon2712=== PAUSE TestParseSigningKey/no_colon2713=== PAUSE TestGenerateFingerprint/no_references2714=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2715--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2716 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2717 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2718 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2719 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2720 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2721=== CONT TestNilKeyPublicKey2722=== PAUSE TestExternalSignerErrors/null2723=== RUN TestExternalSignerErrors/wrong_signatures_shape2724=== RUN TestParseSigningKey/empty_name2725=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2726=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2727--- PASS: TestNilKeyPublicKey (0.00s)2728=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2729=== PAUSE TestParseSigningKey/empty_name2730=== RUN TestExternalSignerErrors/unrequested_key2731=== PAUSE TestExternalSignerErrors/unrequested_key2732=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2733=== RUN TestParseSigningKey/invalid_base642734=== RUN TestExternalSignerErrors/invalid_signature_base642735=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2736=== RUN TestGenerateFingerprint/invalid_nar_hash_length2737=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2738=== PAUSE TestParseSigningKey/invalid_base642739=== RUN TestParseSigningKey/wrong_length2740=== PAUSE TestParseSigningKey/wrong_length2741=== CONT TestParseSigningKey/valid_32-byte_key2742=== CONT TestParseSigningKey/wrong_length2743=== PAUSE TestExternalSignerErrors/invalid_signature_base642744=== RUN TestExternalSignerErrors/wrong_signature_length2745=== CONT TestParseSigningKey/no_colon2746=== CONT TestParseSigningKey/invalid_base642747=== RUN TestGenerateFingerprint/invalid_store_path_prefix2748=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2749=== RUN TestGenerateFingerprint/invalid_reference_prefix2750=== CONT TestParseSigningKey/empty_name2751=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2752=== PAUSE TestExternalSignerErrors/wrong_signature_length2753=== RUN TestExternalSignerErrors/exit_on_request2754=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2755=== CONT TestGenerateFingerprint/basic_with_references2756=== PAUSE TestExternalSignerErrors/exit_on_request2757=== RUN TestExternalSignerErrors/missing_signatures2758=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2759=== CONT TestGenerateFingerprint/invalid_nar_hash_length2760=== CONT TestGenerateFingerprint/invalid_reference_prefix2761=== CONT TestGenerateFingerprint/invalid_store_path_prefix2762=== CONT TestGenerateFingerprint/no_references2763=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2764--- PASS: TestGenerateFingerprint (0.00s)2765 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2766 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2767 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2768 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2769 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2770 --- PASS: TestGenerateFingerprint/no_references (0.00s)2771 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2772=== PAUSE TestExternalSignerErrors/missing_signatures2773=== RUN TestExternalSignerErrors/missing_signature_name2774=== PAUSE TestExternalSignerErrors/missing_signature_name2775=== RUN TestExternalSignerErrors/wrong_signature_name2776=== PAUSE TestExternalSignerErrors/wrong_signature_name2777=== RUN TestExternalSignerErrors/exit_at_startup2778=== PAUSE TestExternalSignerErrors/exit_at_startup2779=== RUN TestExternalSignerErrors/invalid_JSON2780=== PAUSE TestExternalSignerErrors/invalid_JSON2781=== RUN TestExternalSignerErrors/wrong_shape2782=== PAUSE TestExternalSignerErrors/wrong_shape2783=== RUN TestExternalSignerErrors/wrong_id2784=== PAUSE TestExternalSignerErrors/wrong_id2785=== RUN TestExternalSignerErrors/too_few_signatures2786=== PAUSE TestExternalSignerErrors/too_few_signatures2787=== RUN TestExternalSignerErrors/program_error2788=== PAUSE TestExternalSignerErrors/program_error2789=== RUN TestExternalSignerErrors/null_signatures2790=== PAUSE TestExternalSignerErrors/null_signatures2791=== CONT TestExternalSignerErrors/null2792=== CONT TestExternalSignerErrors/missing_signatures2793=== CONT TestExternalSignerErrors/exit_at_startup2794=== CONT TestExternalSignerErrors/null_signatures2795=== CONT TestExternalSignerErrors/program_error2796=== CONT TestExternalSignerErrors/too_few_signatures2797=== RUN TestSignErrors/nil_key2798=== PAUSE TestSignErrors/nil_key2799=== RUN TestSignErrors/nil_narinfo2800=== PAUSE TestSignErrors/nil_narinfo2801=== RUN TestSignErrors/invalid_narinfo2802=== PAUSE TestSignErrors/invalid_narinfo2803=== RUN TestSignErrors/canceled2804=== PAUSE TestSignErrors/canceled2805--- PASS: TestParseSigningKey (0.00s)2806 --- PASS: TestParseSigningKey/wrong_length (0.00s)2807 --- PASS: TestParseSigningKey/no_colon (0.00s)2808 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2809 --- PASS: TestParseSigningKey/empty_name (0.00s)2810 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2811 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2812=== CONT TestExternalSignerErrors/wrong_shape2813=== CONT TestExternalSignerErrors/wrong_signature_length2814--- PASS: TestSign (0.00s)2815=== CONT TestExternalSignerErrors/invalid_JSON2816--- PASS: TestSignBatch (0.00s)2817=== CONT TestExternalSignerErrors/wrong_signature_name2818=== CONT TestSignErrors/canceled2819=== CONT TestSignErrors/invalid_narinfo2820=== CONT TestExternalSignerErrors/invalid_signature_base642821=== CONT TestExternalSignerErrors/exit_on_request2822=== CONT TestExternalSignerErrors/missing_signature_name2823=== CONT TestExternalSignerErrors/wrong_id2824=== CONT TestExternalSignerErrors/wrong_signatures_shape2825=== CONT TestExternalSignerErrors/unrequested_key2826=== CONT TestSignErrors/nil_key2827=== CONT TestSignErrors/nil_narinfo2828--- PASS: TestSignErrors (0.00s)2829 --- PASS: TestSignErrors/canceled (0.00s)2830 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2831 --- PASS: TestSignErrors/nil_key (0.00s)2832 --- PASS: TestSignErrors/nil_narinfo (0.00s)2833--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2834--- PASS: TestExternalSignerClose (0.01s)2835--- PASS: TestExternalSignerWrongPublicKey (0.01s)2836--- PASS: TestExternalSignerErrors (0.00s)2837 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)2838 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2839 --- PASS: TestExternalSignerErrors/null (0.00s)2840 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)2841 --- PASS: TestExternalSignerErrors/program_error (0.00s)2842 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2843 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2844 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)2845 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)2846 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2847 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2848 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2849 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)2850 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)2851 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2852 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2853--- PASS: TestExternalSigner (0.01s)2854--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2855--- PASS: TestExternalSignerCancellation (0.02s)2856PASS2857Running OpenBao signer tests...2858=== RUN TestSign2859=== PAUSE TestSign2860=== RUN TestSignErrors2861=== PAUSE TestSignErrors2862=== RUN TestServe2863=== PAUSE TestServe2864=== RUN TestServeRejectsGarbage2865=== PAUSE TestServeRejectsGarbage2866=== CONT TestSign2867=== CONT TestServe2868=== CONT TestServeRejectsGarbage2869--- PASS: TestServeRejectsGarbage (0.00s)2870=== CONT TestSignErrors2871=== RUN TestSignErrors/http_error2872=== PAUSE TestSignErrors/http_error2873=== RUN TestSignErrors/invalid_json2874=== PAUSE TestSignErrors/invalid_json2875=== RUN TestSignErrors/no_prefix2876=== PAUSE TestSignErrors/no_prefix2877=== RUN TestSignErrors/invalid_base642878=== PAUSE TestSignErrors/invalid_base642879=== CONT TestSignErrors/http_error2880=== CONT TestSignErrors/invalid_json2881--- PASS: TestServe (0.00s)2882=== CONT TestSignErrors/no_prefix2883=== CONT TestSignErrors/invalid_base642884--- PASS: TestSign (0.01s)2885--- PASS: TestSignErrors (0.00s)2886 --- PASS: TestSignErrors/invalid_base64 (0.00s)2887 --- PASS: TestSignErrors/invalid_json (0.00s)2888 --- PASS: TestSignErrors/http_error (0.00s)2889 --- PASS: TestSignErrors/no_prefix (0.00s)2890PASS